[
https://issues.apache.org/jira/browse/CLOUDSTACK-4459?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Sudha Ponnaganti updated CLOUDSTACK-4459:
-----------------------------------------
Priority: Critical (was: Major)
> [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
> Assignee: edison su
> Priority: Critical
> Fix For: 4.2.0
>
> Attachments: CLOUDSTACK-4457_Agent.rar, CLOUDSTACK-4457_MS.rar,
> KVM_Regression_24_Aug_Agent.rar, KVM_Regression_24_Aug_MS.rar
>
>
> 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
