Sailaja Mada created CLOUDSTACK-4587: ----------------------------------------
Summary: [VMWARE]VM is failing to deploy on a Legacy zone after adding zone wide primary storage and moving cluster wide primary storage to maintenance mode Key: CLOUDSTACK-4587 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4587 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. Upgraded from 307 to 4.2 using VMWARE Cluster with Cluster level primary storage 2. Add Zone wide primary storage after upgrade 3. Move the cluster level scope storage to Maintenance mode 4. Try to deploy new VM. Observation: VM is failing to deploy on a Legacy zone after adding zone wide primary storage and moving cluster wide primary storage to maintenance mode 2013-09-01 14:21:10,323 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Network id=207 is already implemented 2013-09-01 14:21:10,354 DEBUG [network.guru.PodBasedNetworkGuru] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Allocated a nic NicProfile[119-35-4a8f547b-7bff-4b3f-ba10-b0146af4d1bb-10.102.195.111-null for VM[DomainRouter|r-35-VM] 2013-09-01 14:21:10,390 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Checking if we need to prepare 1 volumes for VM[DomainRouter|r-35-VM] 2013-09-01 14:21:10,400 DEBUG [storage.image.TemplateDataFactoryImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) template 203 is already in store:2, type:Image 2013-09-01 14:21:10,409 DEBUG [storage.image.TemplateDataFactoryImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) template 203 is already in store:203, type:Primary 2013-09-01 14:21:10,410 DEBUG [storage.volume.VolumeServiceImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Found template 203-2-3cfe22ca-3a33-39a0-bf5e-0dab154869fd in storage pool 203 with VMTemplateStoragePool id: 11 2013-09-01 14:21:10,421 DEBUG [storage.volume.VolumeServiceImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Acquire lock on VMTemplateStoragePool 11 with timeout 3600 seconds 2013-09-01 14:21:10,423 INFO [storage.volume.VolumeServiceImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) lock is acquired for VMTemplateStoragePool 11 2013-09-01 14:21:10,431 DEBUG [storage.motion.AncientDataMotionStrategy] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type TEMPLATE 2013-09-01 14:21:10,519 DEBUG [storage.motion.AncientDataMotionStrategy] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) copy object failed: java.lang.NullPointerException at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyObject(AncientDataMotionStrategy.java:210) at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:411) at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:55) at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:440) at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:569) at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2536) at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2592) at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888) at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2740) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1872) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1972) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1950) at com.cloud.network.element.VirtualRouterElement.implement(VirtualRouterElement.java:188) at com.cloud.network.NetworkManagerImpl.implementNetworkElementsAndResources(NetworkManagerImpl.java:2034) at com.cloud.network.NetworkManagerImpl.implementNetwork(NetworkManagerImpl.java:1939) at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2120) at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:886) at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578) 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:3406) at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966) at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952) at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420) 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-09-01 14:21:10,520 DEBUG [storage.motion.AncientDataMotionStrategy] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) copy failed com.cloud.utils.exception.CloudRuntimeException: java.lang.NullPointerException at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyObject(AncientDataMotionStrategy.java:231) at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:411) at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:55) at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:440) at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:569) at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2536) at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2592) at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888) at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2740) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1872) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1972) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1950) at com.cloud.network.element.VirtualRouterElement.implement(VirtualRouterElement.java:188) at com.cloud.network.NetworkManagerImpl.implementNetworkElementsAndResources(NetworkManagerImpl.java:2034) at com.cloud.network.NetworkManagerImpl.implementNetwork(NetworkManagerImpl.java:1939) at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2120) at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:886) at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578) 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:3406) at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966) at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952) at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420) 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-09-01 14:21:10,525 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-152:null) Seq 5-1348865999: Response Received: 2013-09-01 14:21:10,525 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 5-1348865999: Received: { Ans: , MgmtId: 227594284004867, via: 5, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2013-09-01 14:21:10,530 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-172:null) Seq 6-1919947690: Executing request 2013-09-01 14:21:10,558 INFO [storage.volume.VolumeServiceImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) releasing lock for VMTemplateStoragePool 11 2013-09-01 14:21:10,558 WARN [utils.db.Merovingian2] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Was unable to find lock for the key template_spool_ref11 and thread id 595423976 2013-09-01 14:21:10,558 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Unable to create Vol[98|vm=35|ROOT]:com.cloud.utils.exception.CloudRuntimeException: java.lang.NullPointerException 2013-09-01 14:21:10,558 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Unable to contact resource. 2013-09-01 14:21:10,558 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Unable to create Vol[98|vm=35|ROOT]:com.cloud.utils.exception.CloudRuntimeException: java.lang.NullPointerException 2013-09-01 14:21:10,558 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Unable to contact resource. com.cloud.exception.StorageUnavailableException: Resource [StoragePool:203] is unreachable: Unable to create Vol[98|vm=35|ROOT]:com.cloud.utils.exception.CloudRuntimeException: java.lang.NullPointerException at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2544) at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2592) at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888) at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNetworkApplianceManagerImpl.java:2740) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRouter(VirtualNetworkApplianceManagerImpl.java:1872) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(VirtualNetworkApplianceManagerImpl.java:1972) at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1950) at com.cloud.network.element.VirtualRouterElement.implement(VirtualRouterElement.java:188) at com.cloud.network.NetworkManagerImpl.implementNetworkElementsAndResources(NetworkManagerImpl.java:2034) at com.cloud.network.NetworkManagerImpl.implementNetwork(NetworkManagerImpl.java:1939) at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2120) at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:886) at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578) 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:3406) at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966) at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952) at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420) 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-09-01 14:21:10,592 DEBUG [vmware.resource.VmwareResource] (DirectAgent-172:10.102.192.20) Datastore summary info, storageId: 55e6d095-7e22-3f4a-b533-874a9fede8df, localPath: /cpg_vol/sailaja/vmwareps1, poolType: NetworkFilesystem, capacity: 879609303040, free: 376848912384, used: 502760390656 2013-09-01 14:21:10,679 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-172:null) Seq 6-1919947690: Response Received: 2013-09-01 14:21:10,679 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 6-1919947690: Received: { Ans: , MgmtId: 227594284004867, via: 6, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2013-09-01 14:21:10,685 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-271:null) Seq 6-1919947691: Executing request 2013-09-01 14:21:10,694 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Cleaning up resources for the vm VM[DomainRouter|r-35-VM] in Starting state 2013-09-01 14:21:10,696 DEBUG [agent.transport.Request] (Job-Executor-119:job-199 = [ 4837d9ec-d365-4653-960c-83fa1dc4fa87 ]) Seq 6-1919947692: Sending { Cmd , MgmtId: 227594284004867, via: 6, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"r-35-VM","wait":0}}] } -- 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