[ https://issues.apache.org/jira/browse/CLOUDSTACK-5008?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13823817#comment-13823817 ]
Sudha Ponnaganti commented on CLOUDSTACK-5008: ---------------------------------------------- Fix seem to be available. - need to commit to 4.3/master > [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 > Assignee: Sateesh Chodapuneedi > Priority: Critical > Fix For: 4.2.1 > > Attachments: migrationlogs.rar > > > 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)