[ https://issues.apache.org/jira/browse/CLOUDSTACK-4459?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Rayees Namathponnan reopened CLOUDSTACK-4459: --------------------------------------------- Issue found with last run also , need to open this defect > [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, 4.2.1 > > 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