Rayees Namathponnan created CLOUDSTACK-4459:
-----------------------------------------------
Summary: [Automation] Vm deployment failed in KVM with missing
storage pool error
Key: CLOUDSTACK-4459
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4459
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
Fix For: 4.2.0
This is observed during automation; few VM deployment failed due to missing
storage pool;
See the error from MS
2013-08-21 19:55:29,239 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-23:job-40 = [ 5244a122-13cb-4480-976f-d464c1e461fb ]) Start
completed for VM VM[User|1ce406e5-67c5-43fc-8284-8190bf29c42c]
2013-08-21 19:55:29,285 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-23:job-40 = [ 5244a122-13cb-4480-976f-d464c1e461fb ]) Complete
async job-40 = [ 5244a122-13cb-4480-976f-d464c1e461fb ], jobStatus: 1,
resultCode: 0, result: org.apache.cloudstack.api.response.UserVmResponse@d912e1d
2013-08-21 19:55:29,289 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-23:job-40 = [ 5244a122-13cb-4480-976f-d464c1e461fb ]) Done
executing org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-40 = [
5244a122-13cb-4480-976f-d464c1e461fb ]
2013-08-21 19:55:29,400 DEBUG [agent.transport.Request]
(AgentManager-Handler-6:null) Seq 2-861536310: Processing: { Ans: , MgmtId:
29066118877352, via: 2, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException:
org.libvirt.LibvirtException: Storage volume not found: no storage vol with
matching name '8acfcc0f-5389-4d9a-8072-3494b8eb0197'\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getVolume(LibvirtStorageAdaptor.java:111)\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getPhysicalDisk(LibvirtStorageAdaptor.java:411)\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStoragePool.getPhysicalDisk(LibvirtStoragePool.java:123)\n\tat
com.cloud.hypervisor.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$AgentRequestHandler.doTask(Agent.java:852)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat
java.lang.Thread.run(Thread.java:679)\n","wait":0}}] }
2013-08-21 19:55:29,401 DEBUG [agent.transport.Request] (Job-Executor-24:job-41
= [ 30ed2109-5ffd-455f-8ad7-3eeff366d9f5 ]) Seq 2-861536310: Received: { Ans:
, MgmtId: 29066118877352, via: 2, Ver: v1, Flags: 10, { Answer } }
2013-08-21 19:55:29,404 ERROR [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-24:job-41 = [ 30ed2109-5ffd-455f-8ad7-3eeff366d9f5 ]) Failed to
start instance VM[User|76e3d7a7-825e-49d2-b663-783b65081d43]
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-21 19:55:29,423 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-24:job-41 = [ 30ed2109-5ffd-455f-8ad7-3eeff366d9f5 ]) Cleaning up
resources for the vm VM[User|76e3d7a7-825e-49d2-b663-783b65081d43] in Starting
state
2013-08-21 19:55:29,424 DEBUG [agent.transport.Request] (Job-Executor-24:job-41
= [ 30ed2109-5ffd-455f-8ad7-3eeff366d9f5 ]) Seq 2-861536311: Sending { Cmd ,
MgmtId: 29066118877352, via: 2, Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-15-11-QA","wait":0}}]
}
2013-08-21 19:55:29,452 DEBUG [cloud.api.ApiServlet] (catalina-exec-16:null)
===START=== 10.223.240.194 -- GET
signature=e4Hny9U69FytbQJvEGXyOINqAnE%3D&apiKey=Ty4Px5VTEEtyO3iOqLGHgQybcOQSbJSbvjy6EJCorms5oJPfsjEHzzrMVuBXvDnBfeURYj25CTJxY6AH7bmTOA&command=queryAsyncJobResult&response=json&jobid=2544e998-5f88-4ed9-92cb-cfc5816196e2
2013-08-21 19:55:29,469 DEBUG [cloud.api.ApiServlet] (catalina-exec-16:null)
===END=== 10.223.240.194 -- GET
signature=e4Hny9U69FytbQJvEGXyOINqAnE%3D&apiKey=Ty4Px5VTEEtyO3iOqLGHgQybcOQSbJSbvjy6EJCorms5oJPfsjEHzzrMVuBXvDnBfeURYj25CTJxY6AH7bmTOA&command=queryAsyncJobResult&response=json&jobid=2544e998-5f88-4ed9-92cb-cfc5816196e2
Error from Agent log
2013-08-21 19:55:48,406 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null)
Seq 2-861536309: { Ans: , MgmtId: 29066118877352, via: 2, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StartAnswer":{"vm":{"id":9,"name":"i-13-9-QA","t
ype":"User","cpus":1,"minSpeed":100,"maxSpeed":100,"minRam":268435456,"maxRam":268435456,"arch":"x86_64","os":"CentOS
5.5
(64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm
":false,"vncPassword":"a60225fa04019d4b","vncAddr":"10.223.50.66","params":{},"uuid":"1ce406e5-67c5-43fc-8284-8190bf29c42c","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"394f3f2b-0fa5-4ec1-8986-b41b5
8f7ee41","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"fff90cb5-06dd-33b3-8815-d78c08ca01d9","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/raye
es/SC_QA_AUTO4/primary","port":2049}},"name":"ROOT-9","size":8589934592,"path":"3d447769-65f0-433e-b13a-e168948c6c20","volumeId":10,"vmName":"i-13-9-QA","accountId":13,"format":"QCOW2","id":10,"hypervisorType":"KVM"}},"diskSeq":0,
"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"523d8e
8f-bbac-4da4-946d-a6b27a6b9b63","ip":"10.1.1.217","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:37:4e:00:01","dns1":"8.8.8.8","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://2306","isolationUri":"vlan://
2306","isSecurityGroupEnabled":false}]},"result":true,"wait":0}}] }
2013-08-21 19:55:48,445 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null)
Request:Seq 2-861536310: { Cmd , MgmtId: 29066118877352, via: 2, Ver: v1,
Flags: 100011,
[{"com.cloud.agent.api.StartCommand":{"vm":{"id":11,"name":"i-15-11-QA","type":"User","cpus":1,"minSpeed":100,"maxSpeed":100,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"CentOS
5.5
(64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"88cb5c1b394aa3fe","params":{},"uuid":"76e3d7a7-825e-49d2-b663-783b65081d43","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"026f0b34-550f-4888-965e-83be2728b411","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"fff90cb5-06dd-33b3-8815-d78c08ca01d9","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/rayees/SC_QA_AUTO4/primary","port":2049}},"name":"ROOT-11","size":8589934592,"path":"8acfcc0f-5389-4d9a-8072-3494b8eb0197","volumeId":12,"vmName":"i-15-11-QA","accountId":15,"format":"QCOW2","id":12,"hypervisorType":"KVM"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"ae40fb43-0763-42e6-89ea-f48dc6de7316","ip":"10.1.1.28","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:21:39:00:01","dns1":"8.8.8.8","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://2355","isolationUri":"vlan://2355","isSecurityGroupEnabled":false}]},"hostIp":"10.223.50.66","executeInSequence":false,"wait":0}}]
}
2013-08-21 19:55:48,446 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null)
Processing command: com.cloud.agent.api.StartCommand
2013-08-21 19:55:48,587 WARN [cloud.agent.Agent] (agentRequest-Handler-5:null)
Caught:
com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException:
Storage volume not found: no storage vol with matching name
'8acfcc0f-5389-4d9a-8072-3494b8eb0197'
at
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getVolume(LibvirtStorageAdaptor.java:111)
at
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getPhysicalDisk(LibvirtStorageAdaptor.java:411)
at
com.cloud.hypervisor.kvm.storage.LibvirtStoragePool.getPhysicalDisk(LibvirtStoragePool.java:123)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.createVbd(LibvirtComputingResource.java:3650)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3519)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1252)
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-08-21 19:55:48,589 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null)
Seq 2-861536310: { Ans: , MgmtId: 29066118877352, via: 2, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException:
org.libvirt.LibvirtException: Storage volume not found: no storage vol with
matching name '8acfcc0f-5389-4d9a-8072-3494b8eb0197'\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getVolume(LibvirtStorageAdaptor.java:111)\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getPhysicalDisk(LibvirtStorageAdaptor.java:411)\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStoragePool.getPhysicalDisk(LibvirtStoragePool.java:123)\n\tat
com.cloud.hypervisor.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$AgentRequestHandler.doTask(Agent.java:852)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat
java.lang.Thread.run(Thread.java:679)\n","wait":0}}] }
2013-08-21 19:55:48,658 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null)
Request:Seq 2-861536311: { Cmd , MgmtId: 29066118877352, via: 2, Ver: v1,
Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-15-11-QA","wait":0}}]
}
2013-08-21 19:55:48,659 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null)
Processing command: com.cloud.agent.api.StopCommand
2013-08-21 19:55:48,661 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-3:null) can't find connection: KVM, for vm: i-15-11-QA,
continue
2013-08-21 19:55:48,676 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-3:null) can't find connection: LXC, for vm: i-15-11-QA,
continue
2013-08-21 19:55:48,676 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-3:null) can't find which hypervisor the vm used , then
use the default hypervisor
--
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
