Sorry I didn't wait enough, after five minutes I saw a timeout in log:Wed Nov 28 09:38:36 2012 [VMM][I]: Command execution fail: /var/tmp/one/vmm/kvm/shutdown one-147 nubacesga-9-1 147 nubacesga-9-1
Wed Nov 28 09:38:36 2012 [VMM][E]: Timed out shutting down one-147 Wed Nov 28 09:38:36 2012 [VMM][I]: ExitCode: 255
I will check that now El 28/11/12 09:38, Roberto Rosende Dopazo escribió:
Yes, I did a SHUTDOWN from SunStone, when it failed I did the DELETENow I tried again doing it all from shell in frontend, machine is still in shutdown not deleted if I can try any more:[grid@cloud ~]$ onetemplate instantiate 6 -n "cream.emi.cesga.es" VM ID: 147 [grid@cloud ~]$ onevm show 147 VIRTUAL MACHINE 147 INFORMATION ID : 147 NAME : cream.emi.cesga.es USER : grid GROUP : oneadmin STATE : ACTIVE LCM_STATE : RUNNING RESCHED : No HOST : nubacesga-9-1 START TIME : 11/28 09:30:10 END TIME : - DEPLOY ID : one-147 VIRTUAL MACHINE MONITORING USED MEMORY : 0K NET_TX : 0K USED CPU : 0 NET_RX : 0K PERMISSIONS OWNER : um- GROUP : --- OTHER : --- VIRTUAL MACHINE TEMPLATE CPU="1" DISK=[ BUS="virtio", CLONE="YES", CLUSTER_ID="100", DATASTORE="GRID EMC", DATASTORE_ID="100", DEV_PREFIX="hd", DISK_ID="0", DRIVER="qcow2", IMAGE="GRID SL6_emi_cream_orig", IMAGE_ID="11", READONLY="NO", SAVE="NO", SOURCE="/var/lib/one/datastores/100/3dfef6d01e7e624f13ef13698ed04710", TARGET="hda", TM_MAD="shared", TYPE="FILE" ] DISK=[ DEV_PREFIX="hd", DISK_ID="1", SIZE="1024", TARGET="hdb", TYPE="swap" ] GRAPHICS=[ KEYMAP="es", LISTEN="0.0.0.0", PORT="6047", TYPE="vnc" ] MEMORY="2512" NAME="cream.emi.cesga.es" NIC=[ BRIDGE="virbrPUBLIC", CLUSTER_ID="100", IP="193.144.35.36", MAC="02:00:c1:90:23:24", MODEL="e1000", NETWORK="red-193.144.35", NETWORK_ID="0", VLAN="NO" ] OS=[ ROOT="hda1" ] PRODUCT="EMI-test" REQUIREMENTS="CLUSTER_ID = 100" TEMPLATE_ID="6" VCPU="1" VMID="147" VIRTUAL MACHINE HISTORY SEQ HOST REASON START TIME PROLOG_TIME0 nubacesga-9-1 none 11/28 09:30:26 0d 00h01m19s 0d 00h00m23s[grid@cloud ~]$ onevm saveas 147 0 changes01 Image ID: 39 [grid@cloud ~]$ oneimage list | grep 39 39 grid oneadmin changes01 GRID EMC 2.2G OS No lock 0 [grid@cloud ~]$ onevm shutdown 147 [grid@cloud ~]$ onevm list | grep 147147 grid oneadmin cream.emi.cesga.es shut 0 0K nubacesga-9-1 0d 00h03[grid@cloud ~]$ oneimage list | grep 39 39 grid oneadmin changes01 GRID EMC 2.2G OS No lock 0Doing from here image never goes to Ready states and keep it in No lock status, but again file is not created[grid@cloud ~]$ oneimage show 39 IMAGE 39 INFORMATION ID : 39 NAME : changes01 USER : grid GROUP : oneadmin DATASTORE : GRID EMC TYPE : OS REGISTER TIME : 11/28 09:32:15 PERSISTENT : NoSOURCE : /var/lib/one/datastores/100/3fdd5ab05c8ceed8c813e9829f1530b7FSTYPE : save_as SIZE : 2.2G STATE : lock RUNNING_VMS : 0 PERMISSIONS OWNER : um- GROUP : --- OTHER : --- IMAGE TEMPLATE DEV_PREFIX="hd" SAVED_DISK_ID="0" SAVED_IMAGE_ID="11" SAVED_VM_ID="147" SAVE_AS="YES"[grid@cloud ~]$ file /var/lib/one/datastores/100/3fdd5ab05c8ceed8c813e9829f1530b7 /var/lib/one/datastores/100/3fdd5ab05c8ceed8c813e9829f1530b7: cannot open `/var/lib/one/datastores/100/3fdd5ab05c8ceed8c813e9829f1530b7' (No such file or directory)[root@cloud one]# grep -n7 3fdd5ab05c8ceed8c813e9829f1530b7 oned.log 547114-547115-Wed Nov 28 09:32:15 2012 [ReM][D]: Req:7392 UID:2 VirtualMachineSaveDisk invoked, 147, 0, "changes01", "" 547116-Wed Nov 28 09:32:15 2012 [ImM][I]: Creating disk at of 2216Mb (type: save_as) 547117-Wed Nov 28 09:32:15 2012 [ReM][D]: Req:7392 UID:2 VirtualMachineSaveDisk result SUCCESS, 39 547118-Wed Nov 28 09:32:15 2012 [ImG][D]: Message received: LOG I 39 ExitCode: 0547119- 547120-Wed Nov 28 09:32:15 2012 [ImM][I]: ExitCode: 0547121:Wed Nov 28 09:32:15 2012 [ImG][D]: Message received: MKFS SUCCESS 39 /var/lib/one/datastores/100/3fdd5ab05c8ceed8c813e9829f1530b7547122-547123-Wed Nov 28 09:32:26 2012 [ReM][D]: Req:8912 UID:0 HostPoolInfo invoked 547124-Wed Nov 28 09:32:26 2012 [ReM][D]: Req:8912 UID:0 HostPoolInfo result SUCCESS, "<HOST_POOL><HOST><ID..." 547125-Wed Nov 28 09:32:26 2012 [ReM][D]: Req:208 UID:0 VirtualMachinePoolInfo invoked, -2, -1, -1, -1 547126-Wed Nov 28 09:32:26 2012 [InM][I]: Monitoring host nubacesga-08-4 (1) 547127-Wed Nov 28 09:32:26 2012 [ReM][D]: Req:208 UID:0 VirtualMachinePoolInfo result SUCCESS, "<VM_POOL><VM><ID>69<..."547128-Wed Nov 28 09:32:26 2012 [ReM][D]: Req:9280 UID:0 AclInfo invoked [root@cloud one]# cat 147.log Wed Nov 28 09:30:26 2012 [DiM][I]: New VM state is ACTIVE. Wed Nov 28 09:30:26 2012 [LCM][I]: New VM state is PROLOG. Wed Nov 28 09:30:26 2012 [VM][I]: Virtual Machine has no contextWed Nov 28 09:30:28 2012 [TM][I]: clone: Cloning /var/lib/one/datastores/100/3dfef6d01e7e624f13ef13698ed04710 in nubacesga-9-1:/var/lib/one/datastores/0/147/disk.0Wed Nov 28 09:30:28 2012 [TM][I]: ExitCode: 0Wed Nov 28 09:30:49 2012 [TM][I]: mkimage: Making filesystem of 1024M and type swap at nubacesga-9-1:/var/lib/one/datastores/0/147/disk.1Wed Nov 28 09:30:49 2012 [TM][I]: ExitCode: 0 Wed Nov 28 09:30:49 2012 [LCM][I]: New VM state is BOOTWed Nov 28 09:30:49 2012 [VMM][I]: Generating deployment file: /var/lib/one/147/deployment.0Wed Nov 28 09:30:50 2012 [VMM][I]: ExitCode: 0Wed Nov 28 09:30:50 2012 [VMM][I]: Successfully execute network driver operation: pre.Wed Nov 28 09:30:50 2012 [VMM][I]: ExitCode: 0Wed Nov 28 09:30:50 2012 [VMM][I]: Successfully execute virtualization driver operation: deploy.Wed Nov 28 09:30:50 2012 [VMM][I]: ExitCode: 0Wed Nov 28 09:30:50 2012 [VMM][I]: Successfully execute network driver operation: post.Wed Nov 28 09:30:50 2012 [LCM][I]: New VM state is RUNNING Wed Nov 28 09:33:15 2012 [LCM][I]: New VM state is SHUTDOWN Cheers, Roberto El 27/11/12 14:30, Javier Fontan escribió:Images are only saved when you "power off" a machine with SHUTDOWN or CANCEL but not with DELETE. Delete command is ment to get rid of a VM that is in a wrong state or we just don't care about so no image saving is done. From what I see in the logs you are executing delete. If you just want to unplug the VM (not an ordered shutdown) you can use cancel. This will trigger the correct epilog that saves the images. On Tue, Nov 27, 2012 at 2:25 PM, Roberto Rosende Dopazo <[email protected]> wrote:Hi El 27/11/12 13:58, Ruben S. Montero escribió: Hi, Just to add a few considerations:1.- Save_as images are not created on the datastore, just an ID is generated as a placeholder for the new image (this is the fstype: save_as). So, it is normal that no image (actual path) is created after a save_as operation, and the state is supposed to be locked (waiting for the real image) as reported.I do not see any issue here. Ok, I understood that file was created at that moment. 2.- The save_as image is moved to the final destination when the VM isshutdown, shutdown means onevm shutdown (delete or stop will not move the image, for example). Could you send the output vm.log of the image after theshutdown. You should look for messages about a MVDS command.The complete log for that machine, there is not MVDS message. From onevmshow image was created at REGISTER TIME : 11/27 11:36:26 [root@cloud one]# cat 138.log Tue Nov 27 11:34:56 2012 [DiM][I]: New VM state is ACTIVE. Tue Nov 27 11:34:56 2012 [LCM][I]: New VM state is PROLOG. Tue Nov 27 11:34:56 2012 [VM][I]: Virtual Machine has no context Tue Nov 27 11:34:58 2012 [TM][I]: clone: Cloning /var/lib/one/datastores/100/3dfef6d01e7e624f13ef13698ed04710 in nubacesga-01-4:/var/lib/one/datastores/0/138/disk.0 Tue Nov 27 11:34:58 2012 [TM][I]: ExitCode: 0Tue Nov 27 11:35:18 2012 [TM][I]: mkimage: Making filesystem of 1024M andtype swap at nubacesga-01-4:/var/lib/one/datastores/0/138/disk.1 Tue Nov 27 11:35:18 2012 [TM][I]: ExitCode: 0 Tue Nov 27 11:35:18 2012 [LCM][I]: New VM state is BOOT Tue Nov 27 11:35:18 2012 [VMM][I]: Generating deployment file: /var/lib/one/138/deployment.0 Tue Nov 27 11:35:18 2012 [VMM][I]: ExitCode: 0 Tue Nov 27 11:35:18 2012 [VMM][I]: Successfully execute network driver operation: pre. Tue Nov 27 11:35:19 2012 [VMM][I]: ExitCode: 0 Tue Nov 27 11:35:19 2012 [VMM][I]: Successfully execute virtualization driver operation: deploy. Tue Nov 27 11:35:19 2012 [VMM][I]: ExitCode: 0 Tue Nov 27 11:35:19 2012 [VMM][I]: Successfully execute network driver operation: post. Tue Nov 27 11:35:19 2012 [LCM][I]: New VM state is RUNNING Tue Nov 27 11:38:01 2012 [LCM][I]: New VM state is CLEANUP. Tue Nov 27 11:38:01 2012 [DiM][I]: New VM state is DONETue Nov 27 11:38:01 2012 [VMM][W]: Ignored: LOG I 138 Driver command for 138cancelled Tue Nov 27 11:38:01 2012 [TM][W]: Ignored: LOG I 138 ExitCode: 0 Tue Nov 27 11:38:01 2012 [TM][W]: Ignored: LOG I 138 ExitCode: 0 Tue Nov 27 11:38:01 2012 [TM][W]: Ignored: LOG I 138 delete: Deleting /var/lib/one/datastores/0/138 Tue Nov 27 11:38:01 2012 [TM][W]: Ignored: LOG I 138 ExitCode: 0 Tue Nov 27 11:38:01 2012 [TM][W]: Ignored: TRANSFER SUCCESS 138 - Tue Nov 27 11:38:01 2012 [VMM][W]: Ignored: LOG I 138 ExitCode: 0Tue Nov 27 11:38:01 2012 [VMM][W]: Ignored: LOG I 138 Successfully executevirtualization driver operation: cancel. Tue Nov 27 11:38:01 2012 [VMM][W]: Ignored: LOG I 138 ExitCode: 0Tue Nov 27 11:38:01 2012 [VMM][W]: Ignored: LOG I 138 Successfully executenetwork driver operation: clean. Tue Nov 27 11:38:01 2012 [VMM][W]: Ignored: CANCEL SUCCESS 138 - Cheers RubenOn Tue, Nov 27, 2012 at 12:41 PM, Roberto Rosende Dopazo <[email protected]>wrote:Hi, El 27/11/12 11:50, Javier Fontan escribió:It's kvm image and dynamic_ownership was wrong because I misunderstood andHi,I'm struggling to understand the situation you are describing. Correctme if I am wrong. You mention dom0. Are you using Xen? If that is true disregard what I said about changing dynamic_ownership parameter in libvirt as Xen drivers do not use libvirt for hypervisor communication.put it to 1, now is 0 and owner and group is not changed.But option save as still doesn't work, I tried it directly from frontendshell instead SunStone and I got that: [grid@cloud ~]$ onevm show 138 VIRTUAL MACHINE 138 INFORMATION ID : 138 NAME : one-138 USER : emi GROUP : oneadmin STATE : ACTIVE LCM_STATE : RUNNING RESCHED : No HOST : nubacesga-01-4 START TIME : 11/27 11:34:32 END TIME : - DEPLOY ID : one-138 VIRTUAL MACHINE MONITORING USED MEMORY : 0K NET_RX : 0K USED CPU : 0 NET_TX : 0K PERMISSIONS OWNER : um- GROUP : --- OTHER : --- VIRTUAL MACHINE TEMPLATE CPU="1" DISK=[ BUS="virtio", CLONE="YES", CLUSTER_ID="100", DATASTORE="GRID EMC", DATASTORE_ID="100", DEV_PREFIX="hd", DISK_ID="0", DRIVER="qcow2", IMAGE="GRID SL6_emi_cream_orig", IMAGE_ID="11", READONLY="NO", SAVE="NO", SOURCE="/var/lib/one/datastores/100/3dfef6d01e7e624f13ef13698ed04710", TARGET="hda", TM_MAD="shared", TYPE="FILE" ] DISK=[ DEV_PREFIX="hd", DISK_ID="1", SIZE="1024", TARGET="hdb", TYPE="swap" ] GRAPHICS=[ KEYMAP="es", LISTEN="0.0.0.0", PORT="6038", TYPE="vnc" ] MEMORY="2512" NAME="one-138" NIC=[ BRIDGE="virbrPUBLIC", CLUSTER_ID="100", IP="193.144.35.36", MAC="02:00:c1:90:23:24", MODEL="e1000", NETWORK="red-193.144.35", NETWORK_ID="0", VLAN="NO" ] OS=[ ROOT="hda1" ] PRODUCT="EMI-test" REQUIREMENTS="CLUSTER_ID = 100" TEMPLATE_ID="6" VCPU="1" VMID="138" VIRTUAL MACHINE HISTORYSEQ HOST REASON START TIME PROLOG_TIME0 nubacesga-01-4 none 11/27 11:34:56 0d 00h01m09s 0d 00h00m22s [grid@cloud ~]$ onevm saveas 138 0 changes01 Image ID: 31 [grid@cloud ~]$ oneimage list ID USER GROUP NAME DATASTORE SIZE TYPE PER STAT RVMS [...]31 grid oneadmin changes01 GRID EMC 2.2G OS No lock 0[grid@cloud ~]$ oneimage show 31 IMAGE 31 INFORMATION ID : 31 NAME : changes01 USER : grid GROUP : oneadmin DATASTORE : GRID EMC TYPE : OS REGISTER TIME : 11/27 11:36:26 PERSISTENT : No SOURCE : /var/lib/one/datastores/100/08cee146d8bff43c6c61794f1ba947d3 FSTYPE : save_as SIZE : 2.2G STATE : lock RUNNING_VMS : 0 PERMISSIONS OWNER : um- GROUP : --- OTHER : --- IMAGE TEMPLATE DEV_PREFIX="hd" SAVED_DISK_ID="0" SAVED_IMAGE_ID="11" SAVED_VM_ID="138" SAVE_AS="YES" From onevm help I understood that now it's supposed I have the file : saveas <vmid> <diskid> <img_name>Sets the specified VM disk to be saved in a new Image. The Imageiscreated immediately, but the contents are saved only if the VM isshut down gracefully (i.e., using 'onevm shutdown' and not 'onevm delete') But it does not exist: [grid@cloud ~]$ file /var/lib/one/datastores/100/08cee146d8bff43c6c61794f1ba947d3/var/lib/one/datastores/100/08cee146d8bff43c6c61794f1ba947d3: cannot open `/var/lib/one/datastores/100/08cee146d8bff43c6c61794f1ba947d3' (No such fileor directory)After a shutdown file still does not exist but image is marked as READY[grid@cloud ~]$ oneimage list ID USER GROUP NAME DATASTORE SIZE TYPE PER STAT RVMS [...]31 grid oneadmin changes01 GRID EMC 2.2G OS No rdy 0And file doesn't exists anyway, from oned.log492501-Tue Nov 27 11:36:26 2012 [ReM][D]: Req:5808 UID:0 AclInfo invoked 492502-Tue Nov 27 11:36:26 2012 [ReM][D]: Req:5808 UID:0 AclInfo resultSUCCESS, "<ACL_POOL><ACL><ID>0..." 492503-Tue Nov 27 11:36:26 2012 [ReM][D]: Req:4608 UID:2 VirtualMachineSaveDisk invoked, 138, 0, "changes01", "" 492504-Tue Nov 27 11:36:26 2012 [ImM][I]: Creating disk at of 2216Mb (type: save_as) 492505-Tue Nov 27 11:36:26 2012 [ReM][D]: Req:4608 UID:2 VirtualMachineSaveDisk result SUCCESS, 31 492506-Tue Nov 27 11:36:26 2012 [ImG][D]: Message received: LOG I 31 ExitCode: 0 492507- 492508-Tue Nov 27 11:36:26 2012 [ImM][I]: ExitCode: 0492509:Tue Nov 27 11:36:26 2012 [ImG][D]: Message received: MKFS SUCCESS31 /var/lib/one/datastores/100/08cee146d8bff43c6c61794f1ba947d3 492510- Cheers, RobertoFirst line I see in the in the log file seems seriously broken: 426622-Mon Nov 26 14:06:42 2012 [ImM][I]: Creating disk at of 2216Mb (type: save_as) It's not saying where it is creating the image (source in OpenNebula parlance) and give an strange type. Could you please send us the VM and Image templates from onevm and oneimage show? Maybe I am missing something and other developers could help me here. I also see this line that says the image was created: 426627:Mon Nov 26 14:06:42 2012 [ImG][D]: Message received: MKFSSUCCESS 25 /var/lib/one/datastores/100/a3e076f377a855dc76f44ac373c9b0caBut you are telling me that the image does not exist. Are you checkingthe hypervisor node or the frontend? More comments inline On Mon, Nov 26, 2012 at 2:33 PM, Roberto Rosende Dopazo <[email protected]> wrote:[...] After delete machine image state is showed as READY in Sunstone.In dom0 deployment dir and file are still present and disk files disk.0and disk.1 have their user and group changed to root.root and image file doesn't exist A new file appears # file /var/lib/one/datastores/0/123/checkpoint /var/lib/one/datastores/0/123/checkpoint: dataThis is really strange. After EPILOG (the state that comes after successful shutdown, delete or cancel) the VM directory in the system datastore is deleted, so those files should not be there. Also, then only way OpeNebula tells Xen to create checkpoint is on SAVE, STOP or MIGRATE. Are you sure that you have deleted the VM? It looks to me that the image was suspended or stopped. Bear in mind that save_as is not done in that state.Also with root.root but 666 file permission and in this case directoryand files of this machine are never deleted from running datastoreThe non deletion of images is consistent my the SAVE/STOP theory. Cheers -- Javier Fontán Muiños Project Engineer OpenNebula - The Open Source Toolkit for Data Center Virtualization www.OpenNebula.org | [email protected] | @OpenNebula_______________________________________________ Users mailing list [email protected] http://lists.opennebula.org/listinfo.cgi/users-opennebula.org-- Ruben S. Montero, PhD Project co-Lead and Chief Architect OpenNebula - The Open Source Solution for Data Center Virtualization www.OpenNebula.org | [email protected] | @OpenNebula_______________________________________________ Users mailing list [email protected] http://lists.opennebula.org/listinfo.cgi/users-opennebula.org
_______________________________________________ Users mailing list [email protected] http://lists.opennebula.org/listinfo.cgi/users-opennebula.org
