Hi,
I am trying to create a new VM instance but it fails with the following
message:
[image: Inline images 1]
management-server.log showed the following messages at the same time the VM
failed:
2016-03-13 21:31:12,812 DEBUG [c.c.a.t.Request]
(AgentManager-Handler-8:null) Seq 18-7892276871990243843: Processing: {
Ans: , MgmtId: 247232645209385, via: 18, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException:
com.cloud.utils.exception.CloudRuntimeException: Can't find
volume:95ef7e18-a79f-4f53-9aa8-222afe0f545c\n\tat
com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getPhysicalDisk(KVMStoragePoolManager.java:262)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.createVbd(LibvirtComputingResource.java:3921)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3789)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1333)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:501)\n\tat
com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:808)\n\tat
com.cloud.utils.nio.Task.run(Task.java:84)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat
java.lang.Thread.run(Thread.java:745)\n","wait":0}}] }
2016-03-13 21:31:12,812 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32) Seq
18-7892276871990243843: Received: { Ans: , MgmtId: 247232645209385, via:
18, Ver: v1, Flags: 10, { Answer } }
2016-03-13 21:31:12,815 ERROR [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32) Failed
to start instance VM[User|i-11-599-VM]
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.orchestrateStart(VirtualMachineManagerImpl.java:1020)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5195)
at sun.reflect.GeneratedMethodAccessor644.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5340)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-03-13 21:31:12,817 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32)
Cleaning up resources for the vm VM[User|i-11-599-VM] in Starting state
2016-03-13 21:31:12,820 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32) Seq
18-7892276871990243858: Sending { Cmd , MgmtId: 247232645209385, via: 18(
eqx-cs-cmp-11.ipscape.com.au), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-11-599-VM","wait":0}}]
}
2016-03-13 21:31:12,914 DEBUG [c.c.a.t.Request]
(StatsCollector-1:ctx-dab0660e) Seq 5-6307009803155810732: Received: {
Ans: , MgmtId: 247232645209385, via: 5, Ver: v1, Flags: 10, {
GetHostStatsAnswer } }
2016-03-13 21:31:13,213 DEBUG [c.c.a.t.Request]
(AgentManager-Handler-13:null) Seq 18-7892276871990243858: Processing: {
Ans: , MgmtId: 247232645209385, via: 18, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2016-03-13 21:31:13,213 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32) Seq
18-7892276871990243858: Received: { Ans: , MgmtId: 247232645209385, via:
18, Ver: v1, Flags: 10, { StopAnswer } }
2016-03-13 21:31:13,218 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32)
Changing active number of nics for network id=264 on -1
2016-03-13 21:31:13,220 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32)
Successfully released network resources for the vm VM[User|i-11-599-VM]
2016-03-13 21:31:13,220 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32)
Successfully cleanued up resources for the vm VM[User|i-11-599-VM] in
Starting state
2016-03-13 21:31:13,225 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32) VM
state transitted from :Starting to Stopped with event: OperationFailedvm's
original host id: null new host id: null host id before state transition: 18
2016-03-13 21:31:13,229 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32) Hosts's
actual total CPU: 95960 and CPU after applying overprovisioning: 95960
2016-03-13 21:31:13,229 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32) Hosts's
actual total RAM: 101359075328 and RAM after applying overprovisioning:
101359075328
2016-03-13 21:31:13,229 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32) release
cpu from host: 18, old used: 40000,reserved: 0, actual total: 95960, total
with overprovisioning: 95960; new used: 36000,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2016-03-13 21:31:13,229 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32) release
mem from host: 18, old used: 40802189312,reserved: 0, total: 101359075328;
new used: 38654705664,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2016-03-13 21:31:13,235 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32)
Invocation exception, caused by:
com.cloud.exception.AgentUnavailableException: Resource [Host:18] is
unreachable: Host 18: Unable to start instance due to Unable to get answer
that is of class com.cloud.agent.api.StartAnswer
2016-03-13 21:31:13,235 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799 ctx-2fe7ec32) Rethrow
exception com.cloud.exception.AgentUnavailableException: Resource [Host:18]
is unreachable: Host 18: Unable to start instance due to Unable to get
answer that is of class com.cloud.agent.api.StartAnswer
2016-03-13 21:31:13,235 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-112:ctx-2a66c4c9 job-9797/job-9799) Done with run of VM
work job: com.cloud.vm.VmWorkStart for VM 599, job origin: 9797
There is plenty of resources available:
[image: Inline images 2]
Please advise why the system is failing to create the VM.
Your help is much appreciated,
Nezar.
