Hi all, pleas help, I'm on a new ACS 4.4 deployment, I just created
successfully a new zone, and added successfully both ISOs and Templates.
When I try to add a new VM from an ISO or a Template, it shows the following
error: "Failed to deploy a VM".
Here is the log:
2015-01-28 13:25:26,383 DEBUG [c.c.d.FirstFitPlanner]
(API-Job-Executor-16:ctx-ee81845c job-56 ctx-91e83bb7) No clusters found after
removing disabled clusters and clusters in avoid list, returning.
2015-01-28 13:25:26,387 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-16:ctx-ee81845c job-56 ctx-91e83bb7) Destroying vm
VM[User|i-2-10-VM] as it failed to create on Host with Id:null
2015-01-28 13:25:26,395 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-16:ctx-ee81845c job-56 ctx-91e83bb7) VM state transitted from
:Stopped to Error with event: OperationFailedToErrorvm's original host id: null
new host id: null host id before state transition: null
2015-01-28 13:25:26,420 WARN [o.a.c.alerts] (API-Job-Executor-16:ctx-ee81845c
job-56 ctx-91e83bb7) alertType:: 8 // dataCenterId:: 1 // podId:: null //
clusterId:: null // message:: Failed to deploy Vm with Id: 10, on Host with Id:
null
2015-01-28 13:25:26,461 INFO [o.a.c.a.c.a.v.DeployVMCmdByAdmin]
(API-Job-Executor-16:ctx-ee81845c job-56 ctx-91e83bb7)
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-10-VM]Scope=interface com.cloud.dc.DataCenter; id=1
2015-01-28 13:25:26,464 INFO [o.a.c.a.c.a.v.DeployVMCmdByAdmin]
(API-Job-Executor-16:ctx-ee81845c job-56 ctx-91e83bb7) Unable to create a
deployment for VM[User|i-2-10-VM]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-10-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:214)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:200)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3468)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3123)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3111)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:106)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy207.startVirtualMachine(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin.execute(DeployVMCmdByAdmin.java:48)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
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)
2015-01-28 13:25:42,875 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-8:null) SeqA 2-12120: Processing Seq 2-12120: { Cmd ,
MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2015-01-28 13:25:42,882 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-8:null) SeqA 2-12120: Sending Seq 2-12120: { Ans: ,
MgmtId: 345052570767, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-01-28 13:25:47,916 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-10:null) SeqA 2-12121: Processing Seq 2-12121: { Cmd ,
MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2015-01-28 13:25:47,924 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-10:null) SeqA 2-12121: Sending Seq 2-12121: { Ans: ,
MgmtId: 345052570767, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-01-28 13:25:48,604 DEBUG [c.c.s.StatsCollector]
(StatsCollector-2:ctx-9d139d8a) VmStatsCollector is running...
2015-01-28 13:25:49,053 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-7d9d2976) Zone 1 is ready to launch secondary storage VM
2015-01-28 13:25:49,089 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-ad8345af) Zone 1 is ready to launch console proxy
2015-01-28 13:25:55,280 DEBUG [c.c.s.StatsCollector]
(StatsCollector-1:ctx-6104c29d) HostStatsCollector is running...
2015-01-28 13:25:55,290 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-249:ctx-beef1490) Seq 1-2736499723581002626: Executing request
2015-01-28 13:25:55,396 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-249:ctx-beef1490) Seq 1-2736499723581002626: Response Received:
2015-01-28 13:25:55,396 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-6104c29d)
Seq 1-2736499723581002626: Received: { Ans: , MgmtId: 345052570767, via: 1,
Ver: v1, Flags: 10, { GetHostStatsAnswer } }
2015-01-28 13:25:57,917 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-9:null) SeqA 2-12122: Processing Seq 2-12122: { Cmd ,
MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2015-01-28 13:25:57,922 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-9:null) SeqA 2-12122: Sending Seq 2-12122: { Ans: ,
MgmtId: 345052570767, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-01-28 13:26:02,919 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-11:null) SeqA 2-12123: Processing Seq 2-12123: { Cmd ,
MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2015-01-28 13:26:02,926 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-11:null) SeqA 2-12123: Sending Seq 2-12123: { Ans: ,
MgmtId: 345052570767, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-01-28 13:26:03,096 INFO [c.c.h.HighAvailabilityManagerImpl]
(HA-2:ctx-fde4102c) checking health of usage server
2015-01-28 13:26:03,099 DEBUG [c.c.h.HighAvailabilityManagerImpl]
(HA-2:ctx-fde4102c) usage server running? false, heartbeat: null
2015-01-28 13:26:03,099 WARN [o.a.c.alerts] (HA-2:ctx-fde4102c) alertType::
13 // dataCenterId:: 0 // podId:: 0 // clusterId:: null // message:: No usage
server process running
2015-01-28 13:26:03,102 DEBUG [c.c.a.AlertManagerImpl] (HA-2:ctx-fde4102c) Have
already sent: 1 emails for alert type '13' -- skipping send email
2015-01-28 13:26:03,103 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterMonitor-1:ctx-e8221180) Found 0 running routers.
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)
2015-01-28 13:25:26,465 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-16:ctx-ee81845c job-56) Complete async job-56, jobStatus:
FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":533,"errortext":"Unable
to create a deployment for VM[User|i-2-10-VM]"}
2015-01-28 13:25:26,474 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-16:ctx-ee81845c job-56) Done executing
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin for job-56
2015-01-28 13:25:26,479 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-16:ctx-ee81845c job-56) Remove job-56 from job monitoring
2015-01-28 13:25:29,281 DEBUG [c.c.a.ApiServlet]
(catalina-exec-10:ctx-4cf28a51) ===START=== 172.30.1.107 -- GET
command=queryAsyncJobResult&jobId=5468a10a-f9a8-42a0-89b1-9ed2fa9f03af&response=json&sessionkey=0gy1TAsx4KpwKGthGWas2qJ%2B0Qw%3D&_=1422469641427
2015-01-28 13:25:29,321 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-4cf28a51
ctx-88a81a86) ===END=== 172.30.1.107 -- GET
command=queryAsyncJobResult&jobId=5468a10a-f9a8-42a0-89b1-9ed2fa9f03af&response=json&sessionkey=0gy1TAsx4KpwKGthGWas2qJ%2B0Qw%3D&_=1422469641427
2015-01-28 13:25:29,328 DEBUG [c.c.a.ApiServlet]
(catalina-exec-16:ctx-63ce020e) ===START=== 172.30.1.107 -- GET
command=listVirtualMachines&id=dbdce965-d247-4d8d-adfd-cc4f7feaca62&response=json&sessionkey=0gy1TAsx4KpwKGthGWas2qJ%2B0Qw%3D&_=1422469641478
2015-01-28 13:25:29,368 DEBUG [c.c.a.ApiServlet] (catalina-exec-16:ctx-63ce020e
ctx-6b6f64e1) ===END=== 172.30.1.107 -- GET
command=listVirtualMachines&id=dbdce965-d247-4d8d-adfd-cc4f7feaca62&response=json&sessionkey=0gy1TAsx4KpwKGthGWas2qJ%2B0Qw%3D&_=1422469641478
2015-01-28 13:25:32,913 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-7:null) SeqA 2-12119: Processing Seq 2-12119: { Cmd ,
MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2015-01-28 13:25:32,977 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-7:null) SeqA 2-12119: Sending Seq 2-12119: { Ans: ,
MgmtId: 345052570767, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-01-28 13:25:33,111 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-3eeff4ff) Found 0 routers to update status.
2015-01-28 13:25:33,114 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-3eeff4ff) Found 0 networks to update RvR status.
2015-01-28 13:25:38,338 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-875fa248) Resetting hosts suitable for reconnect
2015-01-28 13:25:38,340 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
Timer:ctx-875fa248) Completed resetting hosts suitable for reconnect
Regards,
José
