[
https://issues.apache.org/jira/browse/CLOUDSTACK-4362?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13754980#comment-13754980
]
ASF subversion and git services commented on CLOUDSTACK-4362:
-------------------------------------------------------------
Commit e362f51f37b718466f2d80d9193e58e1fafcb8fb in branch
refs/heads/4.2-forward from [~kelveny]
[ https://git-wip-us.apache.org/repos/asf?p=cloudstack.git;h=e362f51 ]
CLOUDSTACK-4362: always honor vCenter on-disk meta data to work with live
migration better
> VM's are failing to start after its DATA volume is migrated to other primary
> storage
> -------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-4362
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4362
> 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.0
> Reporter: Sailaja Mada
> Assignee: Sateesh Chodapuneedi
> Priority: Critical
> Fix For: 4.2.0
>
> Attachments: alllogs.rar, apilog.log, apilog.log, db1.sql,
> management-server.log, management-server.log, ssvmlogs.rar
>
>
> Steps:
> 1. Configure Adv zone with 2 zone wide primary storage's
> 2. Create new account and Deploy instance using this account
> 3. Add new DATA volume and attach to this instance
> 4. Resize this volume from 5 GB to 7 GB
> 5. As admin, Migrate this volume from Storage 1 to Storage2 ( Zone wide
> primary)
> 6. Stop and Start this instance
> Observation:
> VM's are failing to start after its DATA volume is migrated to second zone
> wide primary storage
> 2013-08-16 12:04:48,465 DEBUG [cloud.storage.VolumeManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Checking
> if we need to prepare 2 volumes for VM[User|inst2]
> 2013-08-16 12:04:48,471 DEBUG [cloud.storage.VolumeManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Mismatch
> in storage pool Pool[1|NetworkFilesystem] assigned by deploymentPlanner and
> the one associated with volume Vol[14|vm=5|DATADISK]
> 2013-08-16 12:04:48,471 DEBUG [cloud.storage.VolumeManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Shared
> volume Vol[14|vm=5|DATADISK] will be migrated on storage pool
> Pool[1|NetworkFilesystem] assigned by deploymentPlanner
> 2013-08-16 12:04:48,524 DEBUG [storage.motion.AncientDataMotionStrategy]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) copyAsync
> inspecting src type VOLUME copyAsync inspecting dest type VOLUME
> 2013-08-16 12:04:48,528 DEBUG [cache.allocator.StorageCacheRandomAllocator]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Can't
> find staging storage in zone: 1
> 2013-08-16 12:04:48,591 DEBUG [agent.transport.Request]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Seq
> 3-1725105201: Sending { Cmd , MgmtId: 187767034175903, via: 3, Ver: v1,
> Flags: 100011,
> [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b55516ba-da2e-454a-8cee-7d1a927ce25a","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b33e996a-444e-3685-9070-0865067454c4","id":2,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/sailajaps2","port":2049}},"name":"new32","size":7516192768,"path":"a04a400289624aad99ab92e7c089343d","volumeId":14,"vmName":"i-3-5-VM","accountId":3,"format":"OVA","id":14,"hypervisorType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b55516ba-da2e-454a-8cee-7d1a927ce25a","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.102.192.100/cpg_vol/sailaja/sailajass1","_role":"Image"}},"name":"new32","size":7516192768,"path":"volumes/3/14","volumeId":14,"vmName":"i-3-5-VM","accountId":3,"format":"OVA","id":14,"hypervisorType":"VMware"}},"executeInSequence":false,"wait":10800}}]
> }
> 2013-08-16 12:04:48,700 DEBUG [agent.transport.Request]
> (AgentManager-Handler-1:null) Seq 3-1725105201: Processing: { Ans: , MgmtId:
> 187767034175903, via: 3, Ver: v1, Flags: 10,
> [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"copy
> volume from primary to secondary failed due to exception: Exception:
> java.lang.NullPointerException\nMessage: null\n","wait":0}}] }
> 2013-08-16 12:04:48,702 DEBUG [agent.transport.Request]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Seq
> 3-1725105201: Received: { Ans: , MgmtId: 187767034175903, via: 3, Ver: v1,
> Flags: 10, { CopyCmdAnswer } }
> 2013-08-16 12:04:48,706 DEBUG [storage.motion.AncientDataMotionStrategy]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) copy to
> image store failed: copy volume from primary to secondary failed due to
> exception: Exception: java.lang.NullPointerException
> Message: null
> 2013-08-16 12:04:48,728 DEBUG [storage.image.BaseImageStoreDriverImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Unable to
> destoy VOLUME: 14
> java.lang.NullPointerException
> at
> org.apache.cloudstack.storage.volume.VolumeObject.getPath(VolumeObject.java:338)
> at
> org.apache.cloudstack.storage.to.VolumeObjectTO.<init>(VolumeObjectTO.java:53)
> at
> org.apache.cloudstack.storage.volume.VolumeObject.getTO(VolumeObject.java:460)
> at
> org.apache.cloudstack.storage.image.BaseImageStoreDriverImpl.deleteAsync(BaseImageStoreDriverImpl.java:237)
> at
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.delete(ImageStoreImpl.java:148)
> at
> org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyVolumeBetweenPools(AncientDataMotionStrategy.java:323)
> at
> org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:406)
> at
> org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:55)
> at
> org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyVolume(VolumeServiceImpl.java:790)
> at
> com.cloud.storage.VolumeManagerImpl.migrateVolume(VolumeManagerImpl.java:2239)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2580)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:885)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:575)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3405)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:1947)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.vm.StartVMCmd.execute(StartVMCmd.java:120)
> 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)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:679)
> 2013-08-16 12:04:48,733 WARN
> [storage.datastore.ObjectInDataStoreManagerImpl] (Job-Executor-37:job-74 = [
> 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Volume 14 is not found on image store
> 1, so no need to delete
> 2013-08-16 12:04:48,745 WARN
> [storage.datastore.ObjectInDataStoreManagerImpl] (Job-Executor-37:job-74 = [
> 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Unsupported data object (VOLUME,
> org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@41542faa), no
> need to delete from object in store ref table
> 2013-08-16 12:04:48,758 WARN
> [storage.datastore.ObjectInDataStoreManagerImpl] (Job-Executor-37:job-74 = [
> 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Unsupported data object (VOLUME,
> org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@16f51b82), no
> need to delete from object in store ref table
> 2013-08-16 12:04:48,827 DEBUG [agent.transport.Request]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Seq
> 1-1608257161: Sending { Cmd , MgmtId: 187767034175903, via: 1, Ver: v1,
> Flags: 100011,
> [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"ea17ef59-dafe-4286-9dc2-606b4e8ea513","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"7f18caf5-397a-340a-934e-d37c558aee2b","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/sailajaps1","port":2049}},"name":"new32","size":7516192768,"path":"a04a400289624aad99ab92e7c089343d","volumeId":20,"vmName":"i-3-5-VM","accountId":3,"id":20,"hypervisorType":"VMware"}},"wait":0}}]
> }
> 2013-08-16 12:04:48,828 DEBUG [agent.transport.Request]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Seq
> 1-1608257161: Executing: { Cmd , MgmtId: 187767034175903, via: 1, Ver: v1,
> Flags: 100011,
> [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"ea17ef59-dafe-4286-9dc2-606b4e8ea513","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"7f18caf5-397a-340a-934e-d37c558aee2b","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/sailajaps1","port":2049}},"name":"new32","size":7516192768,"path":"a04a400289624aad99ab92e7c089343d","volumeId":20,"vmName":"i-3-5-VM","accountId":3,"id":20,"hypervisorType":"VMware"}},"wait":0}}]
> }
> 2013-08-16 12:04:48,836 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-392:null) Seq 1-1608257161: Executing request
> 2013-08-16 12:04:48,839 INFO [storage.resource.VmwareStorageProcessor]
> (DirectAgent-392:10.102.192.18) Executing resource DestroyCommand:
> {"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"ea17ef59-dafe-4286-9dc2-606b4e8ea513","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"7f18caf5-397a-340a-934e-d37c558aee2b","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/sailajaps1","port":2049}},"name":"new32","size":7516192768,"path":"a04a400289624aad99ab92e7c089343d","volumeId":20,"vmName":"i-3-5-VM","accountId":3,"id":20,"hypervisorType":"VMware"}},"wait":0}
> 2013-08-16 12:04:48,962 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) Search file
> a04a400289624aad99ab92e7c089343d.vmdk on [7f18caf5397a340a934ed37c558aee2b]
> 2013-08-16 12:04:48,999 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) File [7f18caf5397a340a934ed37c558aee2b]
> a04a400289624aad99ab92e7c089343d.vmdk does not exist on datastore
> 2013-08-16 12:04:49,010 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) Search file
> a04a400289624aad99ab92e7c089343d.vmdk on [7f18caf5397a340a934ed37c558aee2b]
> 2013-08-16 12:04:49,036 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) File [7f18caf5397a340a934ed37c558aee2b]
> a04a400289624aad99ab92e7c089343d.vmdk does not exist on datastore
> 2013-08-16 12:04:49,036 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) Searching file
> a04a400289624aad99ab92e7c089343d.vmdk in [7f18caf5397a340a934ed37c558aee2b]
> 2013-08-16 12:04:49,201 WARN [storage.resource.VmwareStorageLayoutHelper]
> (DirectAgent-392:10.102.192.18) Unable to locate VMDK file:
> a04a400289624aad99ab92e7c089343d.vmdk
> 2013-08-16 12:04:49,205 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) Search file
> a04a400289624aad99ab92e7c089343d-flat.vmdk on
> [7f18caf5397a340a934ed37c558aee2b]
> 2013-08-16 12:04:49,229 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) File [7f18caf5397a340a934ed37c558aee2b]
> a04a400289624aad99ab92e7c089343d-flat.vmdk does not exist on datastore
> 2013-08-16 12:04:49,233 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) Search file
> a04a400289624aad99ab92e7c089343d-flat.vmdk on
> [7f18caf5397a340a934ed37c558aee2b]
> 2013-08-16 12:04:49,254 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) File [7f18caf5397a340a934ed37c558aee2b]
> a04a400289624aad99ab92e7c089343d-flat.vmdk does not exist on datastore
> 2013-08-16 12:04:49,254 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) Searching file
> a04a400289624aad99ab92e7c089343d-flat.vmdk in
> [7f18caf5397a340a934ed37c558aee2b]
> 2013-08-16 12:04:49,334 WARN [storage.resource.VmwareStorageLayoutHelper]
> (DirectAgent-392:10.102.192.18) Unable to locate VMDK file:
> a04a400289624aad99ab92e7c089343d-flat.vmdk
> 2013-08-16 12:04:49,340 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) Search file
> a04a400289624aad99ab92e7c089343d-delta.vmdk on
> [7f18caf5397a340a934ed37c558aee2b]
> 2013-08-16 12:04:49,360 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) File [7f18caf5397a340a934ed37c558aee2b]
> a04a400289624aad99ab92e7c089343d-delta.vmdk does not exist on datastore
> 2013-08-16 12:04:49,364 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) Search file
> a04a400289624aad99ab92e7c089343d-delta.vmdk on
> [7f18caf5397a340a934ed37c558aee2b]
> 2013-08-16 12:04:49,387 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) File [7f18caf5397a340a934ed37c558aee2b]
> a04a400289624aad99ab92e7c089343d-delta.vmdk does not exist on datastore
> 2013-08-16 12:04:49,387 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-392:10.102.192.18) Searching file
> a04a400289624aad99ab92e7c089343d-delta.vmdk in
> [7f18caf5397a340a934ed37c558aee2b]
> 2013-08-16 12:04:49,480 WARN [storage.resource.VmwareStorageLayoutHelper]
> (DirectAgent-392:10.102.192.18) Unable to locate VMDK file:
> a04a400289624aad99ab92e7c089343d-delta.vmdk
> 2013-08-16 12:04:49,480 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-392:null) Seq 1-1608257161: Response Received:
> 2013-08-16 12:04:49,483 DEBUG [agent.transport.Request]
> (DirectAgent-392:null) Seq 1-1608257161: Processing: { Ans: , MgmtId:
> 187767034175903, via: 1, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":true,"details":"Success","wait":0}}]
> }
> 2013-08-16 12:04:49,483 DEBUG [agent.transport.Request]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Seq
> 1-1608257161: Received: { Ans: , MgmtId: 187767034175903, via: 1, Ver: v1,
> Flags: 10, { Answer } }
> 2013-08-16 12:04:49,520 INFO [storage.volume.VolumeServiceImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Volume 20
> is not referred anywhere, remove it from volumes table
> 2013-08-16 12:04:49,529 ERROR [cloud.storage.VolumeManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) migrate
> volume failed:copy volume from primary to secondary failed due to exception:
> Exception: java.lang.NullPointerException
> Message: null
> 2013-08-16 12:04:49,530 INFO [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Unable to
> contact resource.
> com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is
> unreachable: migrate volume failed: copy volume from primary to secondary
> failed due to exception: Exception: java.lang.NullPointerException
> Message: null
> at
> com.cloud.storage.VolumeManagerImpl.migrateVolume(VolumeManagerImpl.java:2244)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2580)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:885)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:575)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3405)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:1947)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.vm.StartVMCmd.execute(StartVMCmd.java:120)
> 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)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:679)
> 2013-08-16 12:04:49,539 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Cleaning
> up resources for the vm VM[User|inst2] in Starting state
> 2013-08-16 12:04:49,542 DEBUG [agent.transport.Request]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Seq
> 1-1608257162: Sending { Cmd , MgmtId: 187767034175903, via: 1, Ver: v1,
> Flags: 100011,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-3-5-VM","wait":0}}]
> }
> 2013-08-16 12:04:49,543 DEBUG [agent.transport.Request]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Seq
> 1-1608257162: Executing: { Cmd , MgmtId: 187767034175903, via: 1, Ver: v1,
> Flags: 100011,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-3-5-VM","wait":0}}]
> }
> 2013-08-16 12:04:49,543 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-135:null) Seq 1-1608257162: Executing request
> 2013-08-16 12:04:49,543 INFO [vmware.resource.VmwareResource]
> (DirectAgent-135:10.102.192.18) Executing resource StopCommand:
> {"isProxy":false,"executeInSequence":false,"vmName":"i-3-5-VM","wait":0}
> 2013-08-16 12:04:49,543 DEBUG [vmware.mo.HostMO]
> (DirectAgent-135:10.102.192.18) find VM i-3-5-VM on host
> 2013-08-16 12:04:49,543 INFO [vmware.mo.HostMO]
> (DirectAgent-135:10.102.192.18) VM i-3-5-VM not found in host cache
> 2013-08-16 12:04:49,543 DEBUG [vmware.mo.HostMO]
> (DirectAgent-135:10.102.192.18) load VM cache on host
> 2013-08-16 12:04:49,643 INFO [vmware.resource.VmwareResource]
> (DirectAgent-135:10.102.192.18) VM i-3-5-VM is no longer in vSphere
> 2013-08-16 12:04:49,644 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-135:null) Seq 1-1608257162: Response Received:
> 2013-08-16 12:04:49,645 DEBUG [agent.transport.Request]
> (DirectAgent-135:null) Seq 1-1608257162: Processing: { Ans: , MgmtId:
> 187767034175903, via: 1, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM
> i-3-5-VM is no longer in vSphere","wait":0}}] }
> 2013-08-16 12:04:49,645 DEBUG [agent.transport.Request]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Seq
> 1-1608257162: Received: { Ans: , MgmtId: 187767034175903, via: 1, Ver: v1,
> Flags: 10, { StopAnswer } }
> 2013-08-16 12:04:49,986 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Trying to
> allocate a host and storage pools from dc:1, pod:1,cluster:null, requested
> cpu: 500, requested ram: 536870912
> 2013-08-16 12:04:49,986 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Is ROOT
> volume READY (pool already allocated)?: No
> 2013-08-16 12:04:49,986 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) This VM
> has last host_id specified, trying to choose the same host: 1
> 2013-08-16 12:04:49,989 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) The last
> host of this VM is in avoid set
> 2013-08-16 12:04:49,989 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Cannot
> choose the last host to deploy this VM
> 2013-08-16 12:04:49,989 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Searching
> resources only under specified Pod: 1
> 2013-08-16 12:04:49,989 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Listing
> clusters in order of aggregate capacity, that have (atleast one host with)
> enough CPU and RAM capacity under this Pod: 1
> 2013-08-16 12:04:49,993 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Removing
> from the clusterId list these clusters from avoid set: [1]
> 2013-08-16 12:04:49,995 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) No
> clusters found after removing disabled clusters and clusters in avoid list,
> returning.
> 2013-08-16 12:04:50,019 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) VM state
> transitted from :Starting to Stopped with event: OperationFailedvm's original
> host id: 1 new host id: null host id before state transition: null
> 2013-08-16 12:04:50,052 INFO [user.vm.StartVMCmd] (Job-Executor-37:job-74 =
> [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ])
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|inst2]Scope=interface com.cloud.dc.DataCenter; id=1
> 2013-08-16 12:04:50,057 INFO [user.vm.StartVMCmd] (Job-Executor-37:job-74 =
> [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Unable to create a deployment for
> VM[User|inst2]
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|inst2]Scope=interface com.cloud.dc.DataCenter; id=1
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:839)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:575)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3405)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:1947)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.vm.StartVMCmd.execute(StartVMCmd.java:120)
> 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)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:679)
> 2013-08-16 12:04:50,062 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-37:job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ]) Complete
> async job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588 ], jobStatus: 2,
> resultCode: 530, result: Error Code: 533 Error text: Unable to create a
> deployment for VM[User|inst2]
> 2013-08-16 12:04:50,531 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null)
> ===START=== 10.104.255.13 -- GET
> command=queryAsyncJobResult&jobId=039d4ba9-0507-4dea-b658-5a784fdc0588&response=json&sessionkey=LLRVMYnhKE5X9Ai%2FjTFfOsinB6o%3D&_=1376635107558
> 2013-08-16 12:04:50,544 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-6:null) Async job-74 = [ 039d4ba9-0507-4dea-b658-5a784fdc0588
> ] completed
> 2013-08-16 12:04:50,550 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null)
> ===END=== 10.104.255.13 -- GET
> command=queryAsyncJobResult&jobId=039d4ba9-0507-4dea-b658-5a784fdc0588&response=json&sessionkey=LLRVMYnhKE5X9Ai%2FjTFfOsinB6o%3D&_=1376635107558
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
