It may be the template I don't know. When I said do a grep, I meant something like - grep "job-56" management-server.log | less - then read through the operation and find out the first failure.
Somesh CloudPlatform Escalations Citrix Systems, Inc. -----Original Message----- From: José Egas López [mailto:josee...@farmaenlace.com] Sent: Wednesday, January 28, 2015 2:40 PM To: users@cloudstack.apache.org Subject: RE: Unable to create VM It's a fresh deployment, I don't know why it throws that InsufficientServerCapacityException. Somesh, what do you exactly mean with doing a grep? Thanks! Regards, José -----Mensaje original----- De: Somesh Naidu [mailto:somesh.na...@citrix.com] Enviado el: miércoles, 28 de enero de 2015 13:51 Para: users@cloudstack.apache.org Asunto: RE: Unable to create VM It say's " InsufficientServerCapacityException" but not sure which resource based on the logs below. You could do a grep on 'job-56" to get more insight. If not, share that output via pastebin. Somesh CloudPlatform Escalations Citrix Systems, Inc. -----Original Message----- From: José Egas López [mailto:josee...@farmaenlace.com] Sent: Wednesday, January 28, 2015 1:43 PM To: users@cloudstack.apache.org Subject: Unable to create VM 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é
