You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Nezar Madbouh <ne...@ipscape.com.au> on 2016/03/13 22:46:40 UTC

Unable to create a New VM - Error message: Unable to start instance due to Unable to get answer that is of class com.cloud.agent.api.StartAnswer

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.

Re: Unable to create a New VM - Error message: Unable to start instance due to Unable to get answer that is of class com.cloud.agent.api.StartAnswer

Posted by Shweta Agarwal <sh...@accelerite.com>.
Hi Nezar,

Can you provide your Management Server logs from the time deploy command is issued till the time you are getting this exception for the better analysis of the issue.


Thanks

Shweta



________________________________
From: Nezar Madbouh <ne...@ipscape.com.au>
Sent: Monday, March 14, 2016 3:16 AM
To: users@cloudstack.apache.org
Subject: Unable to create a New VM - Error message: Unable to start instance due to Unable to get answer that is of class com.cloud.agent.api.StartAnswer

Hi,

I am trying to create a new VM instance but it fails with the following message:
[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<http://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:
[Inline images 2]

Please advise why the system is failing to create the VM.

Your help is much appreciated,

Nezar.




DISCLAIMER
==========
This e-mail may contain privileged and confidential information which is the property of Accelerite, a Persistent Systems business. It is intended only for the use of the individual or entity to which it is addressed. If you are not the intended recipient, you are not authorized to read, retain, copy, print, distribute or use this message. If you have received this communication in error, please notify the sender and delete all copies of this message. Accelerite, a Persistent Systems business does not accept any liability for virus infected mails.

RE: Unable to create a New VM - Error message: Unable to start instance due to Unable to get answer that is of class com.cloud.agent.api.StartAnswer

Posted by Suresh Sadhu <su...@accelerite.com>.
HI Nezar,

What is the state of the host as well agent  state in  your kVM host.
Based on logs it seems  agent has problem in accessing  the storage pool.

Please upload agent log as well as  management log.

Regards
Sadhu



From: Nezar Madbouh [mailto:nezar.madbouh@ipscape.com.au]
Sent: Monday, March 14, 2016 3:17 AM
To: users@cloudstack.apache.org
Subject: Unable to create a New VM - Error message: Unable to start instance due to Unable to get answer that is of class com.cloud.agent.api.StartAnswer

Hi,

I am trying to create a new VM instance but it fails with the following message:
[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<http://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:
[Inline images 2]

Please advise why the system is failing to create the VM.

Your help is much appreciated,

Nezar.




DISCLAIMER
==========
This e-mail may contain privileged and confidential information which is the property of Accelerite, a Persistent Systems business. It is intended only for the use of the individual or entity to which it is addressed. If you are not the intended recipient, you are not authorized to read, retain, copy, print, distribute or use this message. If you have received this communication in error, please notify the sender and delete all copies of this message. Accelerite, a Persistent Systems business does not accept any liability for virus infected mails.