[
https://issues.apache.org/jira/browse/CLOUDSTACK-5020?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13815926#comment-13815926
]
sadhu suresh commented on CLOUDSTACK-5020:
------------------------------------------
This issue also applicable to guest vms .some times guest vms are fail to
migrate to destination storage as existing storage has uncleaned volumes with
same name.
> fail to recreate system VM in a specific scenario during storage maintenance
> -----------------------------------------------------------------------------
>
> Key: CLOUDSTACK-5020
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5020
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: VMware
> Affects Versions: 4.2.1
> Reporter: sadhu suresh
>
> fail to recreate to system vm(eg console proxy root volume) and fails with
> Root-2 volume already exits error when it try to start the system vm during
> storage maintenance.
> some times during storage maintenance , CS fail to delete root voulme of a
> systemvm and recreate the system vm's volume in another storage and
> corresponding volume exits in previous storage .
> when we put second primary storage in maintenance mode and it tries to
> recreate system vm in primary storage 1 but same volume(existing volume due
> to failure will exits in primary storage1) already exits and its fail to
> start due below error:
> "
> Unable to create Vol[89|vm=2|ROOT]:java.lang.RuntimeException: The name
> 'ROOT-2' already exists.
> "
> steps:
> 1.deploy advanced zone with vmware +2 host
> 2.enabled ha on cluster(from vcenter)
> 3.deploy few vm from cs
> 4.add one more primary storage
> 5.put first primary storage in to maintenance mode
> 6.once its successful,cancel the maintenance ode
> 7.put second primary storage into maintenance mode
> second scenario::
> 1.put enable.ha.storage.migration to false
> 2.put first primary storage in to maintenance mode
> 3.once its successful,cancel the maintenance ode
> 4.put second primary storage into maintenance mode
> content of management log:
> ***************************
> 2013-11-01 17:30:38,636 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-39:10.147.40.30) Search file ROOT-2-delta.vmdk on
> [9142ce532cf63ce68edf4c43061121ad]
> 2013-11-01 17:30:38,668 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-39:10.147.40.30) File [9142ce532cf63ce68edf4c43061121ad]
> ROOT-2-delta.vmdk does not exist on datastore
> 2013-11-01 17:30:38,677 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-39:10.147.40.30) Search file ROOT-2-delta.vmdk on
> [9142ce532cf63ce68edf4c43061121ad]
> 2013-11-01 17:30:38,709 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-39:10.147.40.30) File [9142ce532cf63ce68edf4c43061121ad]
> ROOT-2-delta.vmdk does not exist on datastore
> 2013-11-01 17:30:38,710 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-39:10.147.40.30) Searching file ROOT-2-delta.vmdk in
> [9142ce532cf63ce68edf4c43061121ad]
> 2013-11-01 17:30:38,852 WARN [storage.resource.VmwareStorageLayoutHelper]
> (DirectAgent-39:10.147.40.30) Unable to locate VMDK file: ROOT-2-delta.vmdk
> 2013-11-01 17:30:38,852 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-39:null) Seq 4-1510146130: Response Received:
> 2013-11-01 17:30:38,853 DEBUG [agent.transport.Request] (DirectAgent-39:null)
> Seq 4-1510146130: Processing: { Ans: , MgmtId: 7363452993625, via: 4, Ver:
> v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":true,"details":"Success","wait":0}}]
> }
> 2013-11-01 17:30:38,853 DEBUG [agent.transport.Request]
> (StorageManager-Scavenger-1:null) Seq 4-1510146130: Received: { Ans: ,
> MgmtId: 7363452993625, via: 4, Ver: v1, Flags: 10, { Answer } }
> 2013-11-01 17:30:38,869 INFO [storage.volume.VolumeServiceImpl]
> (StorageManager-Scavenger-1:null) Volume 83 is not referred anywhere, remove
> it from volumes table
> 2013-11-01 17:30:44,168 INFO [storage.resource.VmwareStorageProcessor]
> (DirectAgent-3:10.147.40.30) Move volume out of volume-wrapper VM
> 2013-11-01 17:30:44,354 ERROR [storage.resource.VmwareStorageProcessor]
> (DirectAgent-3:10.147.40.30) clone volume from base image failed due to
> Exception: java.lang.RuntimeException
> Message: File [722e618184973d319933a0a267ae376c] ROOT-2/ROOT-2.vmdk was not
> found
> java.lang.RuntimeException: File [722e618184973d319933a0a267ae376c]
> ROOT-2/ROOT-2.vmdk was not found
> at
> com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:411)
> at
> com.cloud.hypervisor.vmware.mo.DatastoreMO.moveDatastoreFile(DatastoreMO.java:235)
> at
> com.cloud.storage.resource.VmwareStorageProcessor.createVMFullClone(VmwareStorageProcessor.java:308)
> at
> com.cloud.storage.resource.VmwareStorageProcessor.cloneVolumeFromBaseTemplate(VmwareStorageProcessor.java:382)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:73)
> at
> com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:155)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:559)
> 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-11-01 17:30:44,356 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-3:null) Seq 4-1510146125: Response Received:
> 2013-11-01 17:30:44,356 DEBUG [agent.transport.Request] (DirectAgent-3:null)
> Seq 4-1510146125: Processing: { Ans: , MgmtId: 7363452993625, via: 4, Ver:
> v1, Flags: 110,
> [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"java.lang.RuntimeException:
> File [722e618184973d319933a0a267ae376c] ROOT-2/ROOT-2.vmdk was not
> found","wait":0}}] }
> 2013-11-01 17:30:44,357 DEBUG [agent.transport.Request]
> (Job-Executor-7:job-295 = [ 3850fe84-ac4b-4b26-9abf-cd5c6e3cbadd ]) Seq
> 4-1510146125: Received: { Ans: , MgmtId: 7363452993625, via: 4, Ver: v1,
> Flags: 110, { CopyCmdAnswer } }
> 2013-11-01 17:30:44,361 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-3:null) Seq 4-1510146125: No more commands found
> 2013-11-01 17:30:44,368 WARN
> [storage.datastore.ObjectInDataStoreManagerImpl] (Job-Executor-7:job-295 = [
> 3850fe84-ac4b-4b26-9abf-cd5c6e3cbadd ]) Unsupported data object (VOLUME,
> org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@4891af8), no
> need to delete from object in store ref table
> 2013-11-01 17:30:44,370 DEBUG [cloud.storage.VolumeManagerImpl]
> (Job-Executor-7:job-295 = [ 3850fe84-ac4b-4b26-9abf-cd5c6e3cbadd ]) Unable to
> create Vol[89|vm=2|ROOT]:java.lang.RuntimeException: File
> [722e618184973d319933a0a267ae376c] ROOT-2/ROOT-2.vmdk was not found
> 2013-11-01 17:30:44,375 INFO [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-7:job-295 = [ 3850fe84-ac4b-4b26-9abf-cd5c6e3cbadd ]) Unable to
> contact resource.
> com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is
> unreachable: Unable to create Vol[89|vm=2|ROOT]:java.lang.RuntimeException:
> File [722e618184973d319933a0a267ae376c] ROOT-2/ROOT-2.vmdk was not found
> at
> com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2580)
> at
> com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2631)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:712)
> at
> com.cloud.storage.StoragePoolAutomationImpl.maintain(StoragePoolAutomationImpl.java:250)
> at
> org.apache.cloudstack.storage.datastore.lifecycle.CloudStackPrimaryDataStoreLifeCycleImpl.maintain(CloudStackPrimaryDataStoreLifeCycleImpl.java:435)
> at
> com.cloud.storage.StorageManagerImpl.preparePrimaryStorageForMaintenance(StorageManagerImpl.java:1379)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> com.cloud.storage.StorageManagerImpl.preparePrimaryStorageForMaintenance(StorageManagerImpl.java:179)
> at
> org.apache.cloudstack.api.command.admin.storage.PreparePrimaryStorageForMaintenanceCmd.execute(PreparePrimaryStorageForMaintenanceCmd.java:102)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at
> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> 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.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> ....
> ,,,,,
> 07,345 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) VM is
> being created in podId: 1
> 2013-11-01 17:31:07,355 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Network id=200 is already implemented
> 2013-11-01 17:31:07,389 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Network id=202 is already implemented
> 2013-11-01 17:31:07,422 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Network id=201 is already implemented
> 2013-11-01 17:31:07,454 DEBUG [network.guru.PodBasedNetworkGuru]
> (consoleproxy-1:null) Allocated a nic
> NicProfile[7-2-9b9add98-aa49-42f8-9e7e-cea991ab1e49-10.147.40.159-null for
> VM[ConsoleProxy|v-2-VM]
> 2013-11-01 17:31:07,465 DEBUG [cloud.storage.VolumeManagerImpl]
> (consoleproxy-1:null) Checking if we need to prepare 1 volumes for
> VM[ConsoleProxy|v-2-VM]
> 2013-11-01 17:31:07,481 DEBUG [storage.image.TemplateDataFactoryImpl]
> (consoleproxy-1:null) template 8 is already in store:1, type:Image
> 2013-11-01 17:31:07,488 DEBUG [storage.image.TemplateDataFactoryImpl]
> (consoleproxy-1:null) template 8 is already in store:1, type:Primary
> 2013-11-01 17:31:07,525 DEBUG [storage.motion.AncientDataMotionStrategy]
> (consoleproxy-1:null) copyAsync inspecting src type TEMPLATE copyAsync
> inspecting dest type VOLUME
> 2013-11-01 17:31:07,544 DEBUG [agent.transport.Request] (consoleproxy-1:null)
> Seq 1-1512833105: Sending { Cmd , MgmtId: 7363452993625, via: 1, Ver: v1,
> Flags: 100111,
> [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"62b98e5419753ca0a727d73fff2d95b3","origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-4.2-vh7.ova","uuid":"aee4482e-40c6-11e3-b6b3-06b270000059","id":8,"format":"OVA","accountId":1,"checksum":"8fde62b1089e5844a9cd3b9b953f9596","hvm":false,"displayText":"SystemVM
> Template
> (vSphere)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"722e6181-8497-3d31-9933-a0a267ae376c","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/talluri/vmware.campo/primary","port":2049}},"name":"routing-8","hypervisorType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"7b64af46-64f6-44f0-91e5-ff3b03323b5c","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"722e6181-8497-3d31-9933-a0a267ae376c","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/talluri/vmware.campo/primary","port":2049}},"name":"ROOT-2","size":0,"volumeId":89,"vmName":"v-2-VM","accountId":1,"format":"OVA","id":89,"hypervisorType":"VMware"}},"executeInSequence":true,"wait":0}}]
> }
> 2013-11-01 17:31:07,546 DEBUG [agent.transport.Request] (consoleproxy-1:null)
> Seq 1-1512833105: Executing: { Cmd , MgmtId: 7363452993625, via: 1, Ver: v1,
> Flags: 100111,
> [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"62b98e5419753ca0a727d73fff2d95b3","origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-4.2-vh7.ova","uuid":"aee4482e-40c6-11e3-b6b3-06b270000059","id":8,"format":"OVA","accountId":1,"checksum":"8fde62b1089e5844a9cd3b9b953f9596","hvm":false,"displayText":"SystemVM
> Template
> (vSphere)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"722e6181-8497-3d31-9933-a0a267ae376c","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/talluri/vmware.campo/primary","port":2049}},"name":"routing-8","hypervisorType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"7b64af46-64f6-44f0-91e5-ff3b03323b5c","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"722e6181-8497-3d31-9933-a0a267ae376c","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/talluri/vmware.campo/primary","port":2049}},"name":"ROOT-2","size":0,"volumeId":89,"vmName":"v-2-VM","accountId":1,"format":"OVA","id":89,"hypervisorType":"VMware"}},"executeInSequence":true,"wait":0}}]
> }
> 2013-11-01 17:31:07,546 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-40:null) Seq 1-1512833105: Executing request
> 2013-11-01 17:31:07,712 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 routers to update status.
> 2013-11-01 17:31:07,716 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-11-01 17:31:07,732 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-40:10.147.40.29) Folder ROOT-2 exists on datastore
> 2013-11-01 17:31:07,732 INFO [storage.resource.VmwareStorageProcessor]
> (DirectAgent-40:10.147.40.29) deleting files in folder ROOT-2
> 2013-11-01 17:31:07,737 INFO [storage.resource.VmwareStorageProcessor]
> (DirectAgent-40:10.147.40.29) creating full clone from template
> 2013-11-01 17:31:07,829 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 routers to update status.
> 2013-11-01 17:31:07,832 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-11-01 17:31:08,135 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (HostReservationReleaseChecker:null) Checking if any host reservation can be
> released ...
> 2013-11-01 17:31:08,137 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Running Capacity Checker ...
> 2013-11-01 17:31:08,138 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) recalculating system capacity
> 2013-11-01 17:31:08,138 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Executing cpu/ram capacity update
> 2013-11-01 17:31:08,145 ERROR [storage.resource.VmwareStorageProcessor]
> (DirectAgent-40:10.147.40.29) clone volume from base image failed due to
> Exception: java.lang.RuntimeException
> Message: The name 'ROOT-2' already exists.
> java.lang.RuntimeException: The name 'ROOT-2' already exists.
> at
> com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:411)
> at
> com.cloud.hypervisor.vmware.mo.VirtualMachineMO.createFullClone(VirtualMachineMO.java:602)
> at
> com.cloud.storage.resource.VmwareStorageProcessor.createVMFullClone(VmwareStorageProcessor.java:296)
> at
> com.cloud.storage.resource.VmwareStorageProcessor.cloneVolumeFromBaseTemplate(VmwareStorageProcessor.java:382)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:73)
> at
> com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:155)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:559)
> 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-11-01 17:31:08,154 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-40:null) Seq 1-1512833105: Response Received:
> 2013-11-01 17:31:08,155 DEBUG [agent.transport.Request] (DirectAgent-40:null)
> Seq 1-1512833105: Processing: { Ans: , MgmtId: 7363452993625, via: 1, Ver:
> v1, Flags: 110,
> [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"java.lang.RuntimeException:
> The name 'ROOT-2' already exists.","wait":0}}] }
> 2013-11-01 17:31:08,158 DEBUG [agent.transport.Request] (consoleproxy-1:null)
> Seq 1-1512833105: Received: { Ans: , MgmtId: 7363452993625, via: 1, Ver: v1,
> Flags: 110, { CopyCmdAnswer } }
> 2013-11-01 17:31:08,165 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-40:null) Seq 1-1512833105: No more commands found
> 2013-11-01 17:31:08,175 WARN
> [storage.datastore.ObjectInDataStoreManagerImpl] (consoleproxy-1:null)
> Unsupported data object (VOLUME,
> org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@6e3345cb), no
> need to delete from object in store ref table
> 2013-11-01 17:31:08,176 DEBUG [cloud.storage.VolumeManagerImpl]
> (consoleproxy-1:null) Unable to create
> Vol[89|vm=2|ROOT]:java.lang.RuntimeException: The name 'ROOT-2' already
> exists.
> 2013-11-01 17:31:08,176 INFO [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Unable to contact resource.
--
This message was sent by Atlassian JIRA
(v6.1#6144)
