Hi all,
we are using CloudStack 4.1.1 against KVM hypervisors
and from time to time we are getting the following strange exception, hence we
got failure in VM deployment:
2013-09-23 09:12:25,793 DEBUG [cloud.template.TemplateManagerImpl]
(Job-Executor-150:job-1730) Template 223 has already been downloaded to pool 200
67976 2013-09-23 09:12:25,799 DEBUG [agent.transport.Request]
(Job-Executor-150:job-1730) Seq 8-1681006550: Sending { Cmd , MgmtId:
345050729630, via: 8, Ver: v1, Flags: 100111,
[{"storage.CreateCommand":{"volId":512,"pool":{"id":20
0,"uuid":"e6949998-9773-38ad-86bd-87ce37bf0e9b","host":"172.17.208.4","path":"/C_8016_shared_cloudstack_1/primary","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":42949672960,"tags":[],"type":"ROOT","name"
:"ROOT-529","useLocalStorage":false,"recreatable":true,"diskOfferingId":1,"volumeId":512,"hyperType":"KVM"},"templateUrl":"1eaa2f45-b4e3-452f-b4e6-2ed95f2d0d99","wait":0}}]
}
67977 2013-09-23 09:12:25,853 DEBUG [agent.transport.Request]
(AgentManager-Handler-3:null) Seq 8-1681006550: Processing: { Ans: , MgmtId:
345050729630, via: 8, Ver: v1, Flags: 110,
[{"storage.CreateAnswer":{"requestTemplateReload":
false,"result":false,"details":"Exception:
com.cloud.utils.exception.CloudRuntimeException\nMessage:
org.libvirt.LibvirtException: Storage pool not found: no storage pool with
matching uuid �s8�����7�\u000e�
d.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException: Storage
pool not found: no storage pool with matching uuid
�s8�����7�\u000e�\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdapto
LibvirtStorageAdaptor.java:427)\n\tat
com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool(KVMStoragePoolManager.java:71)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputin
gResource.java:1271)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1072)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:525)\n\tat
com.cloud.agent.Agent$Age ntRequestHandler.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}}] }
67978 2013-09-23 09:12:25,854 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-3:null) Seq 8-1681006550: No more commands found
67979 2013-09-23 09:12:25,854 DEBUG [agent.transport.Request]
(Job-Executor-150:job-1730) Seq 8-1681006550: Received: { Ans: , MgmtId:
345050729630, via: 8, Ver: v1, Flags: 110, { CreateAnswer } }
67980 2013-09-23 09:12:25,854 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-150:job-1730) Unable to create volume Vol[512|vm=529|ROOT]
67981 2013-09-23 09:12:25,863 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-150:job-1730) Unable to contact resource.
67982 com.cloud.exception.StorageUnavailableException: Resource
[StoragePool:200] is unreachable: Unable to create Vol[512|vm=529|ROOT]
67983 at
com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3488)
67984 at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:762)
67985 at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:485)
67986 at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:212)
67987 at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:210)
67988 at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3954)
67989 at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3464)
67990 at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3450)
67991 at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
67992 at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:379)
67993 at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:162)
67994 at
com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)
67995 at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
67996 at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
67997 at java.util.concurrent.FutureTask.run(FutureTask.java:166)
67998 at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
67999 at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
68000 at java.lang.Thread.run(Thread.java:724)
68001 2013-09-23 09:12:25,870 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-150:job-1730) Cleaning up resources for the vm
VM[User|f77938ba-4b4c-4e99-98d8-03299560fbe1] in Starting state
Any idea?
Niki
