You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Chandan Purushothama (JIRA)" <ji...@apache.org> on 2013/03/15 00:34:13 UTC

[jira] [Created] (CLOUDSTACK-1687) VMSnapshot: VM Fails to Start after a RevertToVMSnapshot Operation

Chandan Purushothama created CLOUDSTACK-1687:
------------------------------------------------

             Summary: VMSnapshot: VM Fails to Start after a RevertToVMSnapshot Operation
                 Key: CLOUDSTACK-1687
                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-1687
             Project: CloudStack
          Issue Type: Bug
      Security Level: Public (Anyone can view this level - this is the default.)
          Components: Management Server
    Affects Versions: 4.2.0
            Reporter: Chandan Purushothama
            Priority: Critical
             Fix For: 4.2.0



========================
Steps to Reproduce the Bug:
========================

1. Deploy Vm.  Attach muiltiple data disks to this VM.
2. Log in to the Vm and create few directories and files on the root volume. Create few more directories on each of  the data disks.
3. Stop the VM.
4. Create VMSnapshot for this VM with "vm_snapshot_type" set to "Disk"
5. Start the VM.
6. Delete few of the above created directories and add few more directories on the root volume.Delete few of the above created directories and add few more directories on the data disks.
7. Stop the VM.
8. Revert this Vm to the above created Snapshot.
9. Start the VM.


===========
Observations:
===========

*Management Server Log*

2013-03-14 16:06:15,703 INFO  [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) Executing resource StartCommand: {"vm":{"id":9,"name":"i-3-9-VMSNAP","bootloader":"HVM","type":"User","cpus":1,"minSpeed":100,"maxSpeed":100,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"CentOS 5.3 (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"ec119fd35127c44e","params":{"rootDiskController":"ide","nicAdapter":"E1000"},"uuid":"1c64977b-db4f-415e-98ce-83b53a612493","disks":[{"id":14,"name":"ROOT-9","mountPoint":"/export/home/chandan/asf4-131-170/primary","path":"ROOT-9-14-000001","size":2147483648,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"f42a60c2-0940-305b-bb14-23d8b40f42bc","deviceId":0},{"id":15,"name":"DATA-9","mountPoint":"/export/home/chandan/asf4-131-170/primary","path":"c7adbf5e2509484d8ac4959ae53e6146-000001","size":5368709120,"type":"DATADISK","storagePoolType":"NetworkFilesystem","storagePoolUuid":"f42a60c2-0940-305b-bb14-23d8b40f42bc","deviceId":1},{"id":16,"name":"NEWDISK-3","mountPoint":"/export/home/chandan/asf4-131-170/primary","path":"fba51dce35d24c19a224090f3cb597e8-000001","size":5368709120,"type":"DATADISK","storagePoolType":"NetworkFilesystem","storagePoolUuid":"f42a60c2-0940-305b-bb14-23d8b40f42bc","deviceId":2},{"id":9,"name":"CentOS 5.3(64-bit) no GUI (vSphere)","size":0,"type":"ISO","storagePoolType":"ISO","deviceId":3}],"nics":[{"deviceId":0,"networkRateMbps":495,"defaultNic":true,"uuid":"06e76915-e16d-4f60-a311-3a5fbdd7d5ab","ip":"10.1.1.66","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:48:7a:00:07","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://2254","isolationUri":"vlan://2254","isSecurityGroupEnabled":false}]},"hostIp":"10.223.58.2","wait":0}
2013-03-14 16:06:15,703 DEBUG [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) VM i-3-9-VMSNAP will be started with NIC device type: E1000
2013-03-14 16:06:15,703 DEBUG [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) Drop invalid disk option, volumeTO: {"id":9,"name":"CentOS 5.3(64-bit) no GUI (vSphere)","size":0,"type":"ISO","storagePoolType":"ISO","deviceId":3}
2013-03-14 16:06:15,723 DEBUG [vmware.mo.HostMO] (DirectAgent-242:10.223.58.2) find VM i-3-9-VMSNAP on host
2013-03-14 16:06:15,723 DEBUG [vmware.mo.HostMO] (DirectAgent-242:10.223.58.2) load VM cache on host
2013-03-14 16:06:15,728 INFO  [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) VM i-3-9-VMSNAP already exists, tear down devices for reconfiguration
2013-03-14 16:06:15,750 DEBUG [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) Prepare ISO volume at existing device {"key":3000,"deviceInfo":{"label":"CD/DVD drive 1","summary":"Remote device"},"backing":{"exclusive":false,"deviceName":""},"connectable":{"startConnected":true,"allowGuestControl":false,"connected":true},"controllerKey":200,"unitNumber":0}
2013-03-14 16:06:15,753 DEBUG [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) Prepare volume at new device {"capacityInKB":0,"key":-2,"backing":{"diskMode":"persistent","fileName":"[f42a60c20940305bbb1423d8b40f42bc] ROOT-9-14-000001.vmdk","datastore":{"value":"datastore-22919","type":"Datastore"}},"connectable":{"startConnected":true,"allowGuestControl":false,"connected":true},"controllerKey":200,"unitNumber":1}
2013-03-14 16:06:15,753 DEBUG [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) Prepare volume at new device {"capacityInKB":0,"key":-3,"backing":{"diskMode":"persistent","fileName":"[f42a60c20940305bbb1423d8b40f42bc] c7adbf5e2509484d8ac4959ae53e6146-000001.vmdk","datastore":{"value":"datastore-22919","type":"Datastore"}},"connectable":{"startConnected":true,"allowGuestControl":false,"connected":true},"controllerKey":1000,"unitNumber":2}
2013-03-14 16:06:15,753 DEBUG [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) Prepare volume at new device {"capacityInKB":0,"key":-4,"backing":{"diskMode":"persistent","fileName":"[f42a60c20940305bbb1423d8b40f42bc] fba51dce35d24c19a224090f3cb597e8-000001.vmdk","datastore":{"value":"datastore-22919","type":"Datastore"}},"connectable":{"startConnected":true,"allowGuestControl":false,"connected":true},"controllerKey":1000,"unitNumber":3}
2013-03-14 16:06:15,753 INFO  [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) Prepare NIC device based on NicTO: {"deviceId":0,"networkRateMbps":495,"defaultNic":true,"uuid":"06e76915-e16d-4f60-a311-3a5fbdd7d5ab","ip":"10.1.1.66","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:48:7a:00:07","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://2254","isolationUri":"vlan://2254","isSecurityGroupEnabled":false}
2013-03-14 16:06:15,757 INFO  [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) Prepare network on vmwaresvs P[vSwitch0:untagged] with name prefix: cloud.guest
2013-03-14 16:06:15,841 INFO  [vmware.mo.HypervisorHostHelper] (DirectAgent-242:10.223.58.2) Network cloud.guest.2254.495.1-vSwitch0 is ready on vSwitch vSwitch0
2013-03-14 16:06:15,841 INFO  [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) Preparing NIC device on network cloud.guest.2254.495.1-vSwitch0
2013-03-14 16:06:15,841 DEBUG [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) Prepare NIC at new device {"operation":"ADD","device":{"addressType":"Manual","macAddress":"02:00:48:7a:00:07","key":-5,"backing":{"network":{"value":"network-22944","type":"Network"},"deviceName":"cloud.guest.2254.495.1-vSwitch0"},"connectable":{"startConnected":true,"allowGuestControl":true,"connected":true},"unitNumber":4}}
2013-03-14 16:06:15,841 DEBUG [vmware.mo.HostMO] (DirectAgent-242:10.223.58.2) find VM i-3-9-VMSNAP on host
2013-03-14 16:06:15,841 DEBUG [vmware.mo.HostMO] (DirectAgent-242:10.223.58.2) VM i-3-9-VMSNAP found in host cache
2013-03-14 16:06:15,869 INFO  [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) Configure VNC port for VM i-3-9-VMSNAP, port: 5914, host: 10.223.58.2
2013-03-14 16:06:15,923 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 2 routers to update status.
2013-03-14 16:06:15,924 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2013-03-14 16:06:16,054 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 2 routers to update status.
2013-03-14 16:06:16,055 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2013-03-14 16:06:16,066 WARN  [vmware.resource.VmwareResource] (DirectAgent-242:10.223.58.2) StartCommand failed due to Exception: java.lang.RuntimeException
Message: File []/vmfs/volumes/23dd55b9-15861742/ROOT-9-14-000001.vmdk was not found

java.lang.RuntimeException: File []/vmfs/volumes/23dd55b9-15861742/ROOT-9-14-000001.vmdk was not found
        at com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:291)
        at com.cloud.hypervisor.vmware.mo.VirtualMachineMO.configureVm(VirtualMachineMO.java:806)
        at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2345)
        at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:432)
        at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-03-14 16:06:16,067 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-242:null) Seq 1-970065218: Response Received:
2013-03-14 16:06:16,068 DEBUG [agent.transport.Request] (DirectAgent-242:null) Seq 1-970065218: Processing:  { Ans: , MgmtId: 7200344900649, via: 1, Ver: v1, Flags: 110, [{"StartAnswer":{"vm":{"id":9,"name":"i-3-9-VMSNAP","bootloader":"HVM","type":"User","cpus":1,"minSpeed":100,"maxSpeed":100,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"CentOS 5.3 (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"ec119fd35127c44e","params":{"rootDiskController":"ide","nicAdapter":"E1000"},"uuid":"1c64977b-db4f-415e-98ce-83b53a612493","disks":[{"id":14,"name":"ROOT-9","mountPoint":"/export/home/chandan/asf4-131-170/primary","path":"ROOT-9-14-000001","size":2147483648,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"f42a60c2-0940-305b-bb14-23d8b40f42bc","deviceId":0},{"id":15,"name":"DATA-9","mountPoint":"/export/home/chandan/asf4-131-170/primary","path":"c7adbf5e2509484d8ac4959ae53e6146-000001","size":5368709120,"type":"DATADISK","storagePoolType":"NetworkFilesystem","storagePoolUuid":"f42a60c2-0940-305b-bb14-23d8b40f42bc","deviceId":1},{"id":16,"name":"NEWDISK-3","mountPoint":"/export/home/chandan/asf4-131-170/primary","path":"fba51dce35d24c19a224090f3cb597e8-000001","size":5368709120,"type":"DATADISK","storagePoolType":"NetworkFilesystem","storagePoolUuid":"f42a60c2-0940-305b-bb14-23d8b40f42bc","deviceId":2},{"id":9,"name":"CentOS 5.3(64-bit) no GUI (vSphere)","size":0,"type":"ISO","storagePoolType":"ISO","deviceId":3}],"nics":[{"deviceId":0,"networkRateMbps":495,"defaultNic":true,"uuid":"06e76915-e16d-4f60-a311-3a5fbdd7d5ab","ip":"10.1.1.66","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:48:7a:00:07","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://2254","isolationUri":"vlan://2254","isSecurityGroupEnabled":false}]},"result":false,"details":"StartCommand failed due to Exception: java.lang.RuntimeException\nMessage: File []/vmfs/volumes/23dd55b9-15861742/ROOT-9-14-000001.vmdk was not found\n","wait":0}}] }
2013-03-14 16:06:16,068 DEBUG [agent.transport.Request] (Job-Executor-87:job-93) Seq 1-970065218: Received:  { Ans: , MgmtId: 7200344900649, via: 1, Ver: v1, Flags: 110, { StartAnswer } }
2013-03-14 16:06:16,070 DEBUG [agent.manager.AgentAttache] (DirectAgent-242:null) Seq 1-970065218: No more commands found
2013-03-14 16:06:16,073 INFO  [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-87:job-93) Unable to start VM on Host[-1-Routing] due to StartCommand failed due to Exception: java.lang.RuntimeException
Message: File []/vmfs/volumes/23dd55b9-15861742/ROOT-9-14-000001.vmdk was not found

2013-03-14 16:06:16,079 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-87:job-93) Cleaning up resources for the vm VM[User|boron-VM-6] in Starting state
2013-03-14 16:06:16,081 DEBUG [agent.transport.Request] (Job-Executor-87:job-93) Seq 1-970065219: Sending  { Cmd , MgmtId: 7200344900649, via: 1, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"i-3-9-VMSNAP","wait":0}}] }
2013-03-14 16:06:16,081 DEBUG [agent.transport.Request] (Job-Executor-87:job-93) Seq 1-970065219: Executing:  { Cmd , MgmtId: 7200344900649, via: 1, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"i-3-9-VMSNAP","wait":0}}] }

**On the primary Storage, the ROOT Volume is indeed missing**

[root@nfs2 primary]# ls
08c2826505b646b3bf3d3e03dfc2bce2-000001-delta.vmdk  fba51dce35d24c19a224090f3cb597e8.vmdk  ROOT-11-18.vmdk              ROOT-7-11.vmdk
08c2826505b646b3bf3d3e03dfc2bce2-000001.vmdk        i-3-3-VMSNAP                           ROOT-1-1-delta.vmdk          ROOT-8-12-000001-delta.vmdk
08c2826505b646b3bf3d3e03dfc2bce2-flat.vmdk          i-3-5-VMSNAP                           ROOT-1-1.vmdk                ROOT-8-12-000001.vmdk
08c2826505b646b3bf3d3e03dfc2bce2.vmdk               i-3-6-VMSNAP                           ROOT-2-2-delta.vmdk          ROOT-8-12-delta.vmdk
8c26613e6e5f344b928e0530ec4817c3                    i-3-7-VMSNAP                           ROOT-2-2.vmdk                ROOT-8-12.vmdk
c7adbf5e2509484d8ac4959ae53e6146-000002-delta.vmdk  i-3-8-VMSNAP                           ROOT-3-3-delta.vmdk          ROOT-9-14-000002-delta.vmdk
c7adbf5e2509484d8ac4959ae53e6146-000002.vmdk        i-3-9-VMSNAP                           ROOT-4-5-delta.vmdk          ROOT-9-14-000002.vmdk
c7adbf5e2509484d8ac4959ae53e6146-flat.vmdk          i-6-10-VMSNAP                          ROOT-4-5.vmdk                ROOT-9-14-delta.vmdk
c7adbf5e2509484d8ac4959ae53e6146.vmdk               r-11-VMSNAP                            ROOT-5-6-delta.vmdk          ROOT-9-14.vmdk
cf04b6e2026f3369b893bdab955c3ff0                    r-4-VMSNAP                             ROOT-6-7-delta.vmdk          s-1-VMSNAP
fba51dce35d24c19a224090f3cb597e8-000002-delta.vmdk  ROOT-10-17-delta.vmdk                  ROOT-7-11-000001-delta.vmdk  v-2-VMSNAP
fba51dce35d24c19a224090f3cb597e8-000002.vmdk        ROOT-10-17.vmdk                        ROOT-7-11-000001.vmdk
fba51dce35d24c19a224090f3cb597e8-flat.vmdk          ROOT-11-18-delta.vmdk                  ROOT-7-11-delta.vmdk
[root@nfs2 primary]#

==========
Bug Impact:
==========

RevertToVMSnapshot Operations are blocked.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira