cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "sadhu suresh (JIRA)" <j...@apache.org>
Subject [jira] [Created] (CLOUDSTACK-5020) fail to recreate system VM in a specific scenario during storage maintenance
Date Fri, 01 Nov 2013 10:43:17 GMT
sadhu suresh created CLOUDSTACK-5020:
----------------------------------------

             Summary: 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)

Mime
View raw message