Rayees Namathponnan created CLOUDSTACK-4525:
-----------------------------------------------
Summary: [Automation] Deploy volume failing during race condition;
Delete template and create volume from the same template
Key: CLOUDSTACK-4525
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4525
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Automation, KVM
Affects Versions: 4.2.0
Environment: Automation
KVM
Reporter: Rayees Namathponnan
Priority: Critical
Fix For: 4.2.1
This issue observed during regression test, few deployment failed; delete
template from primary storage and create volume from the same template happens
same time; then deployment will failed
Observed below error in MS log
2013-08-27 03:06:48,567 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null)
===START=== 10.223.240.194 -- GET
signature=mP4tF8pK8yEV%2F7PbOLTBfVvXaFY%3D&apiKey=uzYh-lz4WfBC_2V9IEDRZX4KDd1G7oCoVZkXTlKIyro
2OeHVLwI70XLEUsIur0teiJoLNEvJGK_YPb3GareqHg&command=queryAsyncJobResult&response=json&jobid=eedf8879-e2c0-453c-8b6c-0fb67b6b4f62
2013-08-27 03:06:48,582 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null)
===END=== 10.223.240.194 -- GET
signature=mP4tF8pK8yEV%2F7PbOLTBfVvXaFY%3D&apiKey=uzYh-lz4WfBC_2V9IEDRZX4KDd1G7oCoVZkXTlKIyro2O
eHVLwI70XLEUsIur0teiJoLNEvJGK_YPb3GareqHg&command=queryAsyncJobResult&response=json&jobid=eedf8879-e2c0-453c-8b6c-0fb67b6b4f62
2013-08-27 03:06:48,887 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null)
===START=== 10.223.240.194 -- GET
signature=AvltVJOEtkR6vGWGhYLKqRXmkxo%3D&apiKey=uzYh-lz4WfBC_2V9IEDRZX4KDd1G7oCoVZkXTlKIyro2Oe
HVLwI70XLEUsIur0teiJoLNEvJGK_YPb3GareqHg&command=queryAsyncJobResult&response=json&jobid=82e670d1-6078-4491-afd2-7aa2fa2c4d54
2013-08-27 03:06:48,902 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null)
===END=== 10.223.240.194 -- GET
signature=AvltVJOEtkR6vGWGhYLKqRXmkxo%3D&apiKey=uzYh-lz4WfBC_2V9IEDRZX4KDd1G7oCoVZkXTlKIyro2OeHV
LwI70XLEUsIur0teiJoLNEvJGK_YPb3GareqHg&command=queryAsyncJobResult&response=json&jobid=82e670d1-6078-4491-afd2-7aa2fa2c4d54
2013-08-27 03:06:49,065 DEBUG [agent.transport.Request]
(AgentManager-Handler-10:null) Seq 1-497093089: Processing: { Ans: , MgmtId:
29066118877352, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answ
er":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException:
com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException:
cannot stat file '/mnt/fff90cb5-06dd-33b3-8815-
d78c08ca01d9/0c93e206-679a-4a96-8c6f-c45d5ee463df': No such file or
directory\n\tat
com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getPhysicalDisk(KVMStoragePoolManager.java:166)\n\tat
com.cloud.hyp
ervisor.kvm.resource.LibvirtComputingResource.createVbd(LibvirtComputingResource.java:3650)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3519)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1252)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:525)\n\tat
com.cloud.agent.Agent$AgentReq
uestHandler.doTask(Agent.java:852)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n\tat
java.util.concurrent.ThreadPoo
lExecutor$Worker.run(ThreadPoolExecutor.java:603)\n\tat
java.lang.Thread.run(Thread.java:679)\n","wait":0}}] }
2013-08-27 03:06:49,066 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-10:null) Seq 1-497093090: Sending now. is current
sequence.
2013-08-27 03:06:49,066 DEBUG [agent.transport.Request]
(Job-Executor-130:job-702 = [ 6b532b5e-ea40-4f66-97bc-5fe9259899e1 ]) Seq
1-497093089: Received: { Ans: , MgmtId: 29066118877352, via: 1, Ver: v1, Fl
ags: 110, { Answer } }
2013-08-27 03:06:49,070 ERROR [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-130:job-702 = [ 6b532b5e-ea40-4f66-97bc-5fe9259899e1 ]) Failed to
start instance VM[User|1a1361fc-31dc-4f5f-ae80-09917b636dd1
]
com.cloud.utils.exception.CloudRuntimeException: Unable to get answer that is
of class com.cloud.agent.api.StartAnswer
at com.cloud.agent.manager.Commands.getAnswer(Commands.java:80)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:917)
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: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-08-27 03:06:49,156 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-130:job-702 = [ 6b532b5e-ea40-4f66-97bc-5fe9259899e1 ]) Cleaning
up resources for the vm VM[User|1a1361fc-31dc-4f5f-ae80-0991
7b636dd1] in Starting state
--
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
