Sailaja Mada created CLOUDSTACK-5068:
----------------------------------------
Summary: [VMWARE]Failed to deploy VM with NPE while copying the
template from Secondary to Primary storage
Key: CLOUDSTACK-5068
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5068
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: Blocker
Steps:
1. Configure Adv zone using Nexus vSwitch - VMWARE hypervisor
2. Tried to deploy VM using user account using the Guest network offering with
CISCO VNMC.
Observation :
Failed to deploy VM with NPE while copying the template from Secondary to
Primary storage
cloud.log from SSVM:
2013-11-07 03:19:58,199 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null)
Request:Seq 4-1214186144: { Cmd , MgmtId: 94838926819810, via: 4, Ver: v1,
Flags: 100111,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/204/f2a0dc98-a076-3a49-bff8-d7dadedc2fbc.ova","origUrl":"http://10.147.28.7/templates/vmware/CentOS5.3-x86_64.ova","uuid":"d1c829f8-3dba-470e-b4be-d5e7453a0880","id":204,"format":"OVA","accountId":2,"checksum":"f6f881b7f2292948d8494db837fe0f47","hvm":true,"displayText":"CentOS5.3new1","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.102.192.100/cpg_vol/sailaja/pnscss1","_role":"Image"}},"name":"204-2-e8cb84f5-e156-3a8c-8ab3-b3ecb6308b11","hypervisorType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"http://10.147.28.7/templates/vmware/CentOS5.3-x86_64.ova","uuid":"d1c829f8-3dba-470e-b4be-d5e7453a0880","id":204,"format":"OVA","accountId":2,"checksum":"f6f881b7f2292948d8494db837fe0f47","hvm":true,"displayText":"CentOS5.3new1","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9da88b99-1a1e-3fee-9bbd-01a34eb96b6b","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/pnscps1","port":2049}},"name":"204-2-e8cb84f5-e156-3a8c-8ab3-b3ecb6308b11","hypervisorType":"VMware"}},"executeInSequence":true,"wait":10800}}]
}
2013-11-07 03:19:58,199 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null)
Processing command: org.apache.cloudstack.storage.command.CopyCommand
2013-11-07 03:19:58,200 INFO
[storage.resource.VmwareSecondaryStorageResourceHandler]
(agentRequest-Handler-4:null) Open new VmwareContext. vCenter: 10.102.192.248,
user: administrator, password: v********
2013-11-07 03:19:58,200 ERROR
[storage.resource.VmwareSecondaryStorageResourceHandler]
(agentRequest-Handler-4:null) Unexpected exception
java.lang.NullPointerException
java.lang.NullPointerException
at
com.cloud.storage.resource.VmwareSecondaryStorageContextFactory.create(VmwareSecondaryStorageContextFactory.java:57)
at
com.cloud.storage.resource.VmwareSecondaryStorageContextFactory.getContext(VmwareSecondaryStorageContextFactory.java:73)
at
com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.getServiceContext(VmwareSecondaryStorageResourceHandler.java:215)
at
com.cloud.storage.resource.VmwareStorageProcessor.copyTemplateToPrimaryStorage(VmwareStorageProcessor.java:208)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:70)
at
com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:155)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
at
com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.executeRequest(VmwareSecondaryStorageResourceHandler.java:99)
at
com.cloud.storage.resource.PremiumSecondaryStorageResource.executeRequest(PremiumSecondaryStorageResource.java:56)
at com.cloud.agent.Agent.processRequest(Agent.java:525)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)
at com.cloud.utils.nio.Task.run(Task.java:83)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
2013-11-07 03:19:58,210 WARN
[storage.resource.VmwareSecondaryStorageResourceHandler]
(agentRequest-Handler-4:null) Unable to retrive host network information due to
exception java.lang.NullPointerException, host: HostSystem-host-15965
2013-11-07 03:19:58,210 ERROR [storage.resource.VmwareStorageProcessor]
(agentRequest-Handler-4:null) Unable to copy template to primary storage due to
exception:Exception: java.lang.NullPointerException
Message: null
java.lang.NullPointerException
at
com.cloud.hypervisor.vmware.mo.DatacenterMO.getOwnerDatacenter(DatacenterMO.java:311)
at
com.cloud.hypervisor.vmware.mo.HostMO.getHyperHostDatacenter(HostMO.java:215)
at
com.cloud.storage.resource.VmwareStorageProcessor.copyTemplateToPrimaryStorage(VmwareStorageProcessor.java:214)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:70)
at
com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:155)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
at
com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.executeRequest(VmwareSecondaryStorageResourceHandler.java:99)
at
com.cloud.storage.resource.PremiumSecondaryStorageResource.executeRequest(PremiumSecondaryStorageResource.java:56)
at com.cloud.agent.Agent.processRequest(Agent.java:525)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)
at com.cloud.utils.nio.Task.run(Task.java:83)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
2013-11-07 03:19:58,212 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null)
Seq 4-1214186144: { Ans: , MgmtId: 94838926819810, via: 4, Ver: v1, Flags:
110,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"Unable
to copy template to primary storage due to exception:Exception:
java.lang.NullPointerException\nMessage: null\n","wait":0}}] }
2013-11-07 03:20:16,974 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null)
Processing command: com.cloud.agent.api.GetStorageStatsCommand
2013-11-07 03:20:52,331 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending
ping: Seq 4-647: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.PingStorageCommand":{"changes":{},"hostType":"Storage","hostId":4,"wait":0}}]
}
Ms log :
2013-11-07 09:31:02,710 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-27:job-27 = [ 3227baaf-9c41-4432-bf3d-45a91871761e ]) copyAsync
inspecting src type TEMPLATE copyAsync inspecting dest type TEMPLATE
2013-11-07 09:31:02,736 DEBUG [agent.transport.Request] (Job-Executor-27:job-27
= [ 3227baaf-9c41-4432-bf3d-45a91871761e ]) Seq 4-1214186144: Sending { Cmd ,
MgmtId: 94838926819810, via: 4, Ver: v1, Flags: 100111,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/204/f2a0dc98-a076-3a49-bff8-d7dadedc2fbc.ova","origUrl":"http://10.147.28.7/templates/vmware/CentOS5.3-x86_64.ova","uuid":"d1c829f8-3dba-470e-b4be-d5e7453a0880","id":204,"format":"OVA","accountId":2,"checksum":"f6f881b7f2292948d8494db837fe0f47","hvm":true,"displayText":"CentOS5.3new1","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.102.192.100/cpg_vol/sailaja/pnscss1","_role":"Image"}},"name":"204-2-e8cb84f5-e156-3a8c-8ab3-b3ecb6308b11","hypervisorType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"http://10.147.28.7/templates/vmware/CentOS5.3-x86_64.ova","uuid":"d1c829f8-3dba-470e-b4be-d5e7453a0880","id":204,"format":"OVA","accountId":2,"checksum":"f6f881b7f2292948d8494db837fe0f47","hvm":true,"displayText":"CentOS5.3new1","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9da88b99-1a1e-3fee-9bbd-01a34eb96b6b","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/pnscps1","port":2049}},"name":"204-2-e8cb84f5-e156-3a8c-8ab3-b3ecb6308b11","hypervisorType":"VMware"}},"executeInSequence":true,"wait":10800}}]
}
2013-11-07 09:31:02,795 DEBUG [agent.transport.Request]
(AgentManager-Handler-13:null) Seq 4-1214186144: Processing: { Ans: , MgmtId:
94838926819810, via: 4, Ver: v1, Flags: 110,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"Unable
to copy template to primary storage due to exception:Exception:
java.lang.NullPointerException\nMessage: null\n","wait":0}}] }
2013-11-07 09:31:02,797 DEBUG [agent.transport.Request] (Job-Executor-27:job-27
= [ 3227baaf-9c41-4432-bf3d-45a91871761e ]) Seq 4-1214186144: Received: { Ans:
, MgmtId: 94838926819810, via: 4, Ver: v1, Flags: 110, { CopyCmdAnswer } }
2013-11-07 09:31:02,801 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-13:null) Seq 4-1214186144: No more commands found
2013-11-07 09:31:02,821 INFO [storage.volume.VolumeServiceImpl]
(Job-Executor-27:job-27 = [ 3227baaf-9c41-4432-bf3d-45a91871761e ]) releasing
lock for VMTemplateStoragePool 4
2013-11-07 09:31:02,822 WARN [utils.db.Merovingian2] (Job-Executor-27:job-27 =
[ 3227baaf-9c41-4432-bf3d-45a91871761e ]) Was unable to find lock for the key
template_spool_ref4 and thread id 1018684760
2013-11-07 09:31:02,822 DEBUG [cloud.storage.VolumeManagerImpl]
(Job-Executor-27:job-27 = [ 3227baaf-9c41-4432-bf3d-45a91871761e ]) Unable to
create Vol[7|vm=6|ROOT]:Unable to copy template to primary storage due to
exception:Exception: java.lang.NullPointerException
Message: null
2013-11-07 09:31:02,823 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-27:job-27 = [ 3227baaf-9c41-4432-bf3d-45a91871761e ]) Unable to
contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is
unreachable: Unable to create Vol[7|vm=6|ROOT]:Unable to copy template to
primary storage due to exception:Exception: java.lang.NullPointerException
Message: null
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.start(VirtualMachineManagerImpl.java:577)
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:3440)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3000)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2986)
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-11-07 09:31:02,838 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-27:job-27 = [ 3227baaf-9c41-4432-bf3d-45a91871761e ]) Cleaning up
resources for the vm VM[User|i1] in Starting state
2013-11-07 09:31:02,840 DEBUG [agent.transport.Request] (Job-Executor-27:job-27
= [ 3227baaf-9c41-4432-bf3d-45a91871761e ]) Seq 1-1079576433: Sending { Cmd ,
MgmtId: 94838926819810, via: 1, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-3-6-VM","wait":0}}]
}
2013-11-07 09:31:02,841 DEBUG [agent.transport.Request] (Job-Executor-27:job-27
= [ 3227baaf-9c41-4432-bf3d-45a91871761e ]) Seq 1-1079576433: Executing: { Cmd
, MgmtId: 94838926819810, via: 1, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-3-6-VM","wait":0}}]
}
2013-11-07 09:31:02,841 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-276:null) Seq 1-1079576433: Executing request
2013-11-07 09:31:02,841 INFO [vmware.resource.VmwareResource]
(DirectAgent-276:10.102.192.20) Executing resource StopCommand:
{"isProxy":false,"executeInSequence":true,"vmName":"i-3-6-VM","wait":0}
--
This message was sent by Atlassian JIRA
(v6.1#6144)
