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:45:25 UTC
[jira] [Created] (CLOUDSTACK-5008) [VMWARE]Failed to start the VM
after performing Cold Migration of Volume to Second Zone wide primary
Storage
Sailaja Mada created CLOUDSTACK-5008:
----------------------------------------
Summary: [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
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)