cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Sateesh Chodapuneedi (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CLOUDSTACK-5008) [VMWARE]Failed to start the VM after performing Cold Migration of Volume to Second Zone wide primary Storage
Date Mon, 11 Nov 2013 17:39:17 GMT

    [ https://issues.apache.org/jira/browse/CLOUDSTACK-5008?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13819145#comment-13819145
] 

Sateesh Chodapuneedi commented on CLOUDSTACK-5008:
--------------------------------------------------

The reported bug is not reproducible with specified steps from bug description, i.e. first
cold migration of volume did not cause failure in VM start operation. But second migration
of volume back to same primary storage pool did. The exception observed is, 

2013-11-11 17:29:38,889 INFO  [vmware.mo.DatastoreMO] (DirectAgent-218:10.102.192.3) Folder
i-2-3-VM exists on datastore
2013-11-11 17:29:38,889 WARN  [vmware.resource.VmwareResource] (DirectAgent-218:10.102.192.3)
WARN!!! Folder already exists on datastore for new VM i-2-3-VM, erase it
2013-11-11 17:29:38,893 INFO  [vmware.mo.HypervisorHostHelper] (DirectAgent-218:10.102.192.3)
Create blank VM. cpuCount: 1, cpuSpeed(MHz): 500, mem(Mb): 512
2013-11-11 17:29:39,123 WARN  [vmware.resource.VmwareResource] (DirectAgent-218:10.102.192.3)
StartCommand failed due to Exception: java.lang.RuntimeException
Message: The name 'i-2-3-VM' already exists.

java.lang.RuntimeException: The name 'i-2-3-VM' already exists.
    at com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:411)

Currently debugging this issue in my setup. Will update the root cause shortly.

> [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)

Mime
View raw message