You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sailaja Mada (JIRA)" <ji...@apache.org> on 2013/10/30 15:49:32 UTC

[jira] [Updated] (CLOUDSTACK-5008) [VMWARE]Failed to start the VM after performing Cold Migration of Volume to Second Zone wide primary Storage

     [ https://issues.apache.org/jira/browse/CLOUDSTACK-5008?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Sailaja Mada updated CLOUDSTACK-5008:
-------------------------------------

    Fix Version/s: 4.2.1

> [VMWARE]Failed to start the VM after performing Cold Migration of Volume to Second Zone wide primary Storage
> ------------------------------------------------------------------------------------------------------------
>
>                 Key: CLOUDSTACK-5008
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5008
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: Storage Controller, VMware
>    Affects Versions: 4.2.1
>            Reporter: Sailaja Mada
>            Priority: Critical
>             Fix For: 4.2.1
>
>
> Steps:
> 1. Configure Adv zone with VMWARE ESXi 5.0 Update 2 hypervisor 
> 2. Configure two Zone wide primary storages 
> 3. Have 2 VMWARE clusters each with 5.0 Update2 ESXi hosts
> 4. Deploy VM using user account 
> 5. Attach 3 DATA volumes. Write DATA onto first DISK 
> 6. Stop the VM 
> 7. Migrate the DATA DISK 1 to second zone wide primary storage
> 8. Tried to start the VM after migration is completed. 
> Observation: 
> [VMWARE]Failed to start the VM after performing Cold Migration of Volume to Second Zone wide primary Storage
> 2013-10-30 19:49:49,187 WARN  [vmware.resource.VmwareResource] (DirectAgent-267:10.102.192.19) StartCommand failed due to Exception: java.lang.RuntimeException
> Message: File []/vmfs/volumes/371681b9-ed4b0743/i-4-10-VM/9db1d292e0394eb39e69c8adee09e26c.vmdk was not found
> java.lang.RuntimeException: File []/vmfs/volumes/371681b9-ed4b0743/i-4-10-VM/9db1d292e0394eb39e69c8adee09e26c.vmdk was not found
>         at com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:411)
>         at com.cloud.hypervisor.vmware.mo.VirtualMachineMO.configureVm(VirtualMachineMO.java:843)
>         at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2966)
>         at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:513)
>         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-10-30 19:49:49,194 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-267:null) Seq 8-1057948407: Response Received:
> 2013-10-30 19:49:49,198 DEBUG [agent.transport.Request] (DirectAgent-267:null) Seq 8-1057948407: Processing:  { Ans: , MgmtId: 94838926819810, via: 8, Ver: v1, Flags: 110, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":10,"name":"i-4-10-VM","bootloader":"HVM","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"hostName":"sharedinst1","arch":"x86_64","os":"CentOS 5.3 (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"4f62f2fc9be065a7","params":{"nicAdapter":"E1000","vmware.reserve.cpu":"false","nestedVirtualizationFlag":"false","Message.ReservedCapacityFreed.Flag":"false","rootDiskController":"ide","vmware.reserve.mem":"false"},"uuid":"faa8546b-85e5-4fa1-8a7a-c0fbb476c649","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"a6d0d1ac-2791-40f0-a9f5-26b524a45972","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"29cbd2fe-d168-3f80-b380-08ca5c399ba7","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/newps1","port":2049}},"name":"ROOT-10","size":2147483648,"path":"ROOT-10","volumeId":10,"vmName":"i-4-10-VM","accountId":4,"chainInfo":"{\"diskDeviceBusName\":\"ide0:1\",\"diskChain\":[\"[29cbd2fed1683f80b38008ca5c399ba7] i-4-10-VM/ROOT-10.vmdk\"]}","format":"OVA","id":10,"hypervisorType":"VMware"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"0b57572c-5f4e-42f9-9d9d-01b1e96698ea","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"29cbd2fe-d168-3f80-b380-08ca5c399ba7","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/newps1","port":2049}},"name":"newd1","size":5368709120,"path":"0a46a41a02e045d0a310d4b2d9e56b9f","volumeId":18,"vmName":"i-4-10-VM","accountId":4,"chainInfo":"{\"diskDeviceBusName\":\"scsi0:1\",\"diskChain\":[\"[29cbd2fed1683f80b38008ca5c399ba7] i-4-10-VM/0a46a41a02e045d0a310d4b2d9e56b9f.vmdk\"]}","format":"OVA","id":18,"hypervisorType":"VMware"}},"diskSeq":2,"type":"DATADISK"},{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b58f7371-2570-49c2-b9f3-0ef412e2a260","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"29cbd2fe-d168-3f80-b380-08ca5c399ba7","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/newps1","port":2049}},"name":"newd2","size":5368709120,"path":"eee0f43fdfbc4572821c5f5a9fc32678","volumeId":19,"vmName":"i-4-10-VM","accountId":4,"chainInfo":"{\"diskDeviceBusName\":\"scsi0:2\",\"diskChain\":[\"[29cbd2fed1683f80b38008ca5c399ba7] i-4-10-VM/eee0f43fdfbc4572821c5f5a9fc32678.vmdk\"]}","format":"OVA","id":19,"hypervisorType":"VMware"}},"diskSeq":4,"type":"DATADISK"},{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"313118e2-a6a0-43ad-acbb-a5fe0ac3de1d","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"25505c51-4b14-3f06-b3fe-9c36fe69a753","id":2,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/cluster2ps1","port":2049}},"name":"DATA-10","size":5368709120,"path":"75a1abccb8684639a12f615116e68b24","volumeId":20,"vmName":"i-4-10-VM","accountId":4,"chainInfo":"{\"diskDeviceBusName\":\"scsi0:0\",\"diskChain\":[\"[29cbd2fed1683f80b38008ca5c399ba7] i-4-10-VM/9db1d292e0394eb39e69c8adee09e26c.vmdk\"]}","format":"OVA","id":20,"hypervisorType":"VMware"}},"diskSeq":1,"type":"DATADISK"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"a5507bf6-5ccd-4d33-b21e-41acbfd7b027","ip":"10.102.198.12","netmask":"255.255.255.128","gateway":"10.102.198.1","mac":"06:cd:f4:00:00:23","dns1":"10.103.128.15","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://110","isolationUri":"vlan://110","isSecurityGroupEnabled":false}]},"result":false,"details":"StartCommand failed due to Exception: java.lang.RuntimeException\nMessage: File []/vmfs/volumes/371681b9-ed4b0743/i-4-10-VM/9db1d292e0394eb39e69c8adee09e26c.vmdk was not found\n","wait":0}}] }
> 2013-10-30 19:49:49,198 DEBUG [agent.transport.Request] (Job-Executor-126:job-103 = [ 3c563876-b27a-4bf3-bc90-dbf2aaa98628 ]) Seq 8-1057948407: Received:  { Ans: , MgmtId: 94838926819810, via: 8, Ver: v1, Flags: 110, { StartAnswer } }
> 2013-10-30 19:49:49,200 DEBUG [agent.manager.AgentAttache] (DirectAgent-267:null) Seq 8-1057948407: No more commands found
> 2013-10-30 19:49:49,204 INFO  [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-126:job-103 = [ 3c563876-b27a-4bf3-bc90-dbf2aaa98628 ]) Unable to start VM on Host[-8-Routing] due to StartCommand failed due to Exception: java.lang.RuntimeException
> Message: File []/vmfs/volumes/371681b9-ed4b0743/i-4-10-VM/9db1d292e0394eb39e69c8adee09e26c.vmdk was not found
> 2013-10-30 19:49:49,214 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-126:job-103 = [ 3c563876-b27a-4bf3-bc90-dbf2aaa98628 ]) Cleaning up resources for the vm VM[User|sharedinst1] in Starting state
> 2013-10-30 19:49:49,216 DEBUG [agent.transport.Request] (Job-Executor-126:job-103 = [ 3c563876-b27a-4bf3-bc90-dbf2aaa98628 ]) Seq 8-1057948408: Sending  { Cmd , MgmtId: 94838926819810, via: 8, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-4-10-VM","wait":0}}] }
> 2013-10-30 19:49:49,216 DEBUG [agent.transport.Request] (Job-Executor-126:job-103 = [ 3c563876-b27a-4bf3-bc90-dbf2aaa98628 ]) Seq 8-1057948408: Executing:  { Cmd , MgmtId: 94838926819810, via: 8, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-4-10-VM","wait":0}}] }
> 2013-10-30 19:49:49,216 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-197:null) Seq 8-1057948408: Executing request
> 2013-10-30 19:49:49,217 INFO  [vmware.resource.VmwareResource] (DirectAgent-197:10.102.192.19) Executing resource StopCommand: {"isProxy":false,"executeInSequence":true,"vmName":"i-4-10-VM","wait":0}
> 2013-10-30 19:49:50,841 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-366:null) Ping from 7
> 2013-10-30 19:49:50,980 WARN  [vmware.resource.VmwareResource] (DirectAgent-122:10.102.192.20) StartCommand failed due to Exception: java.lang.RuntimeException
> Message: The name 'i-4-10-VM' already exists.
> java.lang.RuntimeException: The name 'i-4-10-VM' already exists.
>         at com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:411)
>         at com.cloud.hypervisor.vmware.mo.HostMO.createVm(HostMO.java:574)
>         at com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.createBlankVm(HypervisorHostHelper.java:1184)
>         at com.cloud.hypervisor.vmware.mo.HostMO.createBlankVm(HostMO.java:761)
>         at com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2717)
>         at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:513)
>         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-10-30 19:37:43,310 INFO  [cloud.server.ManagementServerImpl] (catalina-exec-16:null) Volume Vol[11|vm=10|DATADISK] isn't attached to any running vm. Looking for storage pools in the cluster to which this volumes can be migrated.
> 2013-10-30 19:37:45,696 DEBUG [cloud.api.ApiServlet] (catalina-exec-21:null) ===START===  10.104.255.45 -- GET  command=migrateVolume&livemigrate=true&storageid=25505c51-4b14-3f06-b3fe-9c36fe69a753&volumeid=5f4fef52-c7e3-4a44-bb86-40005f2fa763&response=json&sessionkey=aBW1O134QVprgEZEHjdVdGfH6cY%3D&_=1383142396380
> 2013-10-30 19:37:45,770 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-21:null) submit async job-102 = [ 0af73b05-444e-4a19-a82a-045852e8e61b ], details: AsyncJobVO {id:102, userId: 2, accountId: 2, sessionKey: null, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.volume.MigrateVolumeCmd, cmdOriginator: null, cmdInfo: {"response":"json","sessionkey":"aBW1O134QVprgEZEHjdVdGfH6cY\u003d","cmdEventType":"VOLUME.MIGRATE","ctxUserId":"2","storageid":"25505c51-4b14-3f06-b3fe-9c36fe69a753","livemigrate":"true","httpmethod":"GET","volumeid":"5f4fef52-c7e3-4a44-bb86-40005f2fa763","_":"1383142396380","ctxAccountId":"2","ctxStartEventId":"403"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 94838926819810, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2013-10-30 19:37:45,772 DEBUG [cloud.api.ApiServlet] (catalina-exec-21:null) ===END===  10.104.255.45 -- GET  command=migrateVolume&livemigrate=true&storageid=25505c51-4b14-3f06-b3fe-9c36fe69a753&volumeid=5f4fef52-c7e3-4a44-bb86-40005f2fa763&response=json&sessionkey=aBW1O134QVprgEZEHjdVdGfH6cY%3D&_=1383142396380
> mysql> select * from volumes where uuid='5f4fef52-c7e3-4a44-bb86-40005f2fa763'\G;
> *************************** 1. row ***************************
>                         id: 11
>                 account_id: 4
>                  domain_id: 1
>                    pool_id: 1
>               last_pool_id: NULL
>                instance_id: 10
>                  device_id: 1
>                       name: DATA-10
>                       uuid: 5f4fef52-c7e3-4a44-bb86-40005f2fa763
>                       size: 5368709120
>                     folder: NULL
>                       path: 9db1d292e0394eb39e69c8adee09e26c
>                     pod_id: NULL
>             data_center_id: 2
>                 iscsi_name: NULL
>                    host_ip: NULL
>                volume_type: DATADISK
>                  pool_type: NULL
>           disk_offering_id: 3
>                template_id: NULL
> first_snapshot_backup_uuid: NULL
>                recreatable: 0
>                    created: 2013-10-30 05:52:24
>                   attached: NULL
>                    updated: 2013-10-30 14:16:29
>                    removed: 2013-10-30 14:16:29
>                      state: Expunged
>                 chain_info: {"diskDeviceBusName":"scsi0:0","diskChain":["[29cbd2fed1683f80b38008ca5c399ba7] i-4-10-VM/9db1d292e0394eb39e69c8adee09e26c.vmdk"]}
>               update_count: 8
>                  disk_type: NULL
>     vm_snapshot_chain_size: NULL
>                     iso_id: NULL
>             display_volume: 0
>                     format: OVA
>                   min_iops: NULL
>                   max_iops: NULL
> 1 row in set (0.00 sec)
> ERROR:
> No query specified
> mysql>



--
This message was sent by Atlassian JIRA
(v6.1#6144)