You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by José Egas López <jo...@farmaenlace.com> on 2014/12/30 23:41:01 UTC

Can't create or deploy VMs

Hi all, when I try to create or deploy a new VM, it shows the following 
error:

    User VM

    Failed to deploy Vm with Id: 42on Host with Id: null

    Mon29 Dec 2014 19:22:27 GMT

So I can do nothing, I can't create VMs or deploy them from a template.
How can I fix it?

I was creating and deploying VMs normally.
I have ACS 4.3.1 with VMware 5.5
-- 
*


Regards,
José

*

Re: Can't create or deploy VMs

Posted by José Egas López <jo...@farmaenlace.com>.
Ok, thank you, I'll do that.


*Regards,
José
*

El 05/01/2015 a las 13:58, Somesh Naidu escribió:
> Note quite.
>
>> Insufficient space on pool: 1 since its usage percentage: 0.9072490225390984 has crossed the pool.storage.capacity.disablethreshold: 0.85
> As Prashant pointed out, the used threshold for this storage has been reached. What you are seeing on the dashboard is allocated percentage. That is why he suggested workaround of manipulating "pool.storage.capacity.disablethreshold" and not "pool.storage.allocated.capacity.disablethreshold". This will buy you some time but eventually, you need to provision more storage.
>
> Check the physical usage on the storage to understand what we mean.
>
> -----Original Message-----
> From: José Egas López [mailto:joseegas@farmaenlace.com]
> Sent: Monday, January 05, 2015 1:43 PM
> To: users@cloudstack.apache.org
> Subject: Re: Can't create or deploy VMs
>
> Hi Naidu, in the dashboard, it shows there is used only 38% of Primary
> Storage:
>
>    *
>      Zone: ZonePharma
>      38%
>      Primary Storage
>      211.44 GB / 543.50 GB
>
> So it seems there is more than enough of Primary Storage for creating VMs.
>
> *Regards,
> * *José
>
> *
>
> Teléf. (593-2)2993100 ext. 1639
> Teléf. (593-99)8-824047
> El 31/12/2014 a las 12:49, Somesh Naidu escribió:
>>> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found
>>> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable storagePools found under this Cluster: 1
>>> 2014-12-31 07:49:44,407 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Could not find suitable Deployment Destination for this VM under any clusters, returning.
>> Apparently, you only have 1 cluster in Zone 1 where the VM is being deployed and the storage on that one is full. You need to provision more space.
>>
>> -----Original Message-----
>> From: José Egas López [mailto:joseegas@farmaenlace.com]
>> Sent: Wednesday, December 31, 2014 8:18 AM
>> To: users@cloudstack.apache.org
>> Subject: Re: Can't create or deploy VMs
>>
>> The log on mgmt is:
>>
>> ***************
>> 2014-12-31 07:49:44,138 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-de733770) ===START===  172.30.1.107 -- GET  command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpgjMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c5194c&displayname=test&name=test&_=1420030300055
>> 2014-12-31 07:49:44,150 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
>> 2014-12-31 07:49:44,153 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
>> 2014-12-31 07:49:44,158 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.DiskOffering
>> 2014-12-31 07:49:44,190 DEBUG [c.c.v.UserVmManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating in the DB for vm
>> 2014-12-31 07:49:44,219 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating entries for VM: VM[User|test]
>> 2014-12-31 07:49:44,221 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nics for VM[User|test]
>> 2014-12-31 07:49:44,222 DEBUG [o.a.c.e.o.NetworkOrchestrator] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nic for vm VM[User|test] in network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
>> 2014-12-31 07:49:44,233 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating disks for VM[User|test]
>> 2014-12-31 07:49:44,244 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocation completed for VM: VM[User|test]
>> 2014-12-31 07:49:44,244 DEBUG [c.c.v.UserVmManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Successfully allocated DB entry for VM[User|test]
>> 2014-12-31 07:49:44,296 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) submit async job-419, details: AsyncJobVO {id:419, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 47, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo: {"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","templateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"47","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEventId":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
>> 2014-12-31 07:49:44,297 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-22:ctx-f2bc1611) Add job-419 into job monitoring
>> 2014-12-31 07:49:44,297 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) ===END===  172.30.1.107 -- GET  command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpgjMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c5194c&displayname=test&name=test&_=1420030300055
>> 2014-12-31 07:49:44,297 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Executing AsyncJobVO {id:419, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 47, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo: {"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","templateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"47","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEventId":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
>> 2014-12-31 07:49:44,303 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
>> 2014-12-31 07:49:44,305 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
>> 2014-12-31 07:49:44,307 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.DiskOffering
>> 2014-12-31 07:49:44,360 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Deploy avoids pods: [], clusters: [], hosts: []
>> 2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@5303f245
>> 2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
>> 2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Is ROOT volume READY (pool already allocated)?: No
>> 2014-12-31 07:49:44,362 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible resources under this Zone: 1
>> 2014-12-31 07:49:44,363 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
>> 2014-12-31 07:49:44,366 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId list these clusters from avoid set: []
>> 2014-12-31 07:49:44,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking resources in Cluster: 1 under Pod: 1
>> 2014-12-31 07:49:44,377 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  cluster:1
>> 2014-12-31 07:49:44,380 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
>> 2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]]
>> 2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Looking for speed=1000Mhz, Ram=1024
>> 2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host: 1 has cpu capability (cpu:32, speed:1999) to support requested CPU: 1 and requested speed: 1000
>> 2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 1000 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
>> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Hosts's actual total CPU: 63968 and CPU after applying overprovisioning: 63968
>> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free CPU: 45868 , Requested CPU: 1000
>> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free RAM: 50983145472 , Requested RAM: 1073741824
>> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host has enough CPU and RAM available
>> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 18100, reserved: 0, actual total: 63968, total with overprovisioning: 63968; requested cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?: true
>> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 17699962880, reserved: 0, total: 68683108352; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
>> 2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
>> 2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
>> 2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking suitable pools for volume (Id, Type): (52,ROOT)
>> 2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) We need to allocate new storagepool for this volume
>> 2014-12-31 07:49:44,394 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Calling StoragePoolAllocators to find suitable pools
>> 2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) LocalStoragePoolAllocator trying to find storage pool to fit the vm
>> 2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ClusterScopeStoragePoolAllocator looking for storage pool
>> 2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Looking for pools in dc: 1  pod:1  cluster:1
>> 2014-12-31 07:49:44,396 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Found pools matching tags: []
>> 2014-12-31 07:49:44,397 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No storage pools available for shared volume allocation, returning
>> 2014-12-31 07:49:44,397 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ZoneWideStoragePoolAllocator to find storage pool
>> 2014-12-31 07:49:44,401 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing pool Pool[1|VMFS] from avoid set, must have been inserted when searching for another disk's tag
>> 2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking pool 1 for storage, totalSize: 291789340672, usedBytes: 264725594112, usedPct: 0.9072490225390984, disable threshold: 0.85
>> 2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Insufficient space on pool: 1 since its usage percentage: 0.9072490225390984 has crossed the pool.storage.capacity.disablethreshold: 0.85
>> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found for volume: Vol[52|vm=47|ROOT] under cluster: 1
>> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found
>> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable storagePools found under this Cluster: 1
>> 2014-12-31 07:49:44,407 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Could not find suitable Deployment Destination for this VM under any clusters, returning.
>> 2014-12-31 07:49:44,407 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible resources under this Zone: 1
>> 2014-12-31 07:49:44,408 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
>> 2014-12-31 07:49:44,410 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId list these clusters from avoid set: [1]
>> 2014-12-31 07:49:44,411 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No clusters found after removing disabled clusters and clusters in avoid list, returning.
>> 2014-12-31 07:49:44,413 DEBUG [c.c.v.UserVmManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Destroying vm VM[User|test] as it failed to create on Host with Id:null
>> 2014-12-31 07:49:44,421 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) 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
>> 014-12-31 07:49:44,431 WARN  [o.a.c.alerts] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5)  alertType:: 8 // dataCenterId:: 1 // podId:: null // clusterId:: null // message:: Failed to deploy Vm with Id: 47, on Host with Id: null
>> 2014-12-31 07:49:44,458 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter; id=1
>> 2014-12-31 07:49:44,459 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Unable to create a deployment for VM[User|test]
>> com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter; id=1
>>           at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:210)
>>           at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:196)
>>           at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3549)
>>           at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3157)
>>           at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3143)
>>           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:622)
>>           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 com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
>>           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.$Proxy169.startVirtualMachine(Unknown Source)
>>           at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443)
>>           at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
>>           at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
>>           at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
>>           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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
>>           at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:509)
>>           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.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>>           at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
>>           at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>           at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
>>           at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>>           at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
>>           at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>>           at java.lang.Thread.run(Thread.java:701)
>> 2014-12-31 07:49:44,460 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Complete async job-419, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":533,"errortext":"Unable to create a deployment for VM[User|test]"}
>> 2014-12-31 07:49:44,483 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Done executing org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-419
>> 2014-12-31 07:49:44,487 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-22:ctx-f2bc1611) Remove job-419 from job monitoring
>> 2014-12-31 07:49:45,692 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-981122: Processing Seq 2-981122:  { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n  \"connections\": []\n}","wait":0}}] }
>> 2014-12-31 07:49:45,697 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-981122: Sending Seq 2-981122:  { Ans: , MgmtId: 345050676845, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
>> 2014-12-31 07:49:46,059 DEBUG [o.a.c.s.RemoteHostEndPoint] (Timer-12:ctx-89509527) Sending command org.apache.cloudstack.storage.command.DownloadProgressCommand to host: 3
>>
>>
>>
>>
>> ***************
>>
>>
>>
>>
>> ----- Original Message -----
>> From: "Somesh Naidu" <So...@citrix.com>
>> To: users@cloudstack.apache.org
>> Sent: Tuesday, December 30, 2014 5:53:55 PM
>> Subject: RE: Can't create or deploy VMs
>>
>> It would be helpful if you could share a larger chunk of mgmt. server logs via paste bin so we can see what's happening/failing.
>>
>> -----Original Message-----
>> From: José Egas López [mailto:joseegas@farmaenlace.com]
>> Sent: Tuesday, December 30, 2014 5:41 PM
>> To: users@cloudstack.apache.org
>> Subject: Can't create or deploy VMs
>>
>> Hi all, when I try to create or deploy a new VM, it shows the following
>> error:
>>
>>       User VM
>>
>>       Failed to deploy Vm with Id: 42on Host with Id: null
>>
>>       Mon29 Dec 2014 19:22:27 GMT
>>
>> So I can do nothing, I can't create VMs or deploy them from a template.
>> How can I fix it?
>>
>> I was creating and deploying VMs normally.
>> I have ACS 4.3.1 with VMware 5.5


RE: Can't create or deploy VMs

Posted by Somesh Naidu <So...@citrix.com>.
Note quite.

> Insufficient space on pool: 1 since its usage percentage: 0.9072490225390984 has crossed the pool.storage.capacity.disablethreshold: 0.85

As Prashant pointed out, the used threshold for this storage has been reached. What you are seeing on the dashboard is allocated percentage. That is why he suggested workaround of manipulating "pool.storage.capacity.disablethreshold" and not "pool.storage.allocated.capacity.disablethreshold". This will buy you some time but eventually, you need to provision more storage.

Check the physical usage on the storage to understand what we mean.

-----Original Message-----
From: José Egas López [mailto:joseegas@farmaenlace.com] 
Sent: Monday, January 05, 2015 1:43 PM
To: users@cloudstack.apache.org
Subject: Re: Can't create or deploy VMs

Hi Naidu, in the dashboard, it shows there is used only 38% of Primary 
Storage:

  *
    Zone: ZonePharma
    38%
    Primary Storage
    211.44 GB / 543.50 GB

So it seems there is more than enough of Primary Storage for creating VMs.

*Regards,
* *José

*

Teléf. (593-2)2993100 ext. 1639
Teléf. (593-99)8-824047
El 31/12/2014 a las 12:49, Somesh Naidu escribió:
>> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found
>> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable storagePools found under this Cluster: 1
>> 2014-12-31 07:49:44,407 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Could not find suitable Deployment Destination for this VM under any clusters, returning.
> Apparently, you only have 1 cluster in Zone 1 where the VM is being deployed and the storage on that one is full. You need to provision more space.
>
> -----Original Message-----
> From: José Egas López [mailto:joseegas@farmaenlace.com]
> Sent: Wednesday, December 31, 2014 8:18 AM
> To: users@cloudstack.apache.org
> Subject: Re: Can't create or deploy VMs
>
> The log on mgmt is:
>
> ***************
> 2014-12-31 07:49:44,138 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-de733770) ===START===  172.30.1.107 -- GET  command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpgjMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c5194c&displayname=test&name=test&_=1420030300055
> 2014-12-31 07:49:44,150 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
> 2014-12-31 07:49:44,153 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
> 2014-12-31 07:49:44,158 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.DiskOffering
> 2014-12-31 07:49:44,190 DEBUG [c.c.v.UserVmManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating in the DB for vm
> 2014-12-31 07:49:44,219 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating entries for VM: VM[User|test]
> 2014-12-31 07:49:44,221 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nics for VM[User|test]
> 2014-12-31 07:49:44,222 DEBUG [o.a.c.e.o.NetworkOrchestrator] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nic for vm VM[User|test] in network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
> 2014-12-31 07:49:44,233 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating disks for VM[User|test]
> 2014-12-31 07:49:44,244 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocation completed for VM: VM[User|test]
> 2014-12-31 07:49:44,244 DEBUG [c.c.v.UserVmManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Successfully allocated DB entry for VM[User|test]
> 2014-12-31 07:49:44,296 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) submit async job-419, details: AsyncJobVO {id:419, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 47, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo: {"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","templateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"47","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEventId":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-12-31 07:49:44,297 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-22:ctx-f2bc1611) Add job-419 into job monitoring
> 2014-12-31 07:49:44,297 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) ===END===  172.30.1.107 -- GET  command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpgjMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c5194c&displayname=test&name=test&_=1420030300055
> 2014-12-31 07:49:44,297 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Executing AsyncJobVO {id:419, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 47, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo: {"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","templateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"47","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEventId":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-12-31 07:49:44,303 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
> 2014-12-31 07:49:44,305 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
> 2014-12-31 07:49:44,307 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.DiskOffering
> 2014-12-31 07:49:44,360 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Deploy avoids pods: [], clusters: [], hosts: []
> 2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@5303f245
> 2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
> 2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Is ROOT volume READY (pool already allocated)?: No
> 2014-12-31 07:49:44,362 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible resources under this Zone: 1
> 2014-12-31 07:49:44,363 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
> 2014-12-31 07:49:44,366 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId list these clusters from avoid set: []
> 2014-12-31 07:49:44,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking resources in Cluster: 1 under Pod: 1
> 2014-12-31 07:49:44,377 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  cluster:1
> 2014-12-31 07:49:44,380 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
> 2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]]
> 2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Looking for speed=1000Mhz, Ram=1024
> 2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host: 1 has cpu capability (cpu:32, speed:1999) to support requested CPU: 1 and requested speed: 1000
> 2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 1000 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Hosts's actual total CPU: 63968 and CPU after applying overprovisioning: 63968
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free CPU: 45868 , Requested CPU: 1000
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free RAM: 50983145472 , Requested RAM: 1073741824
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host has enough CPU and RAM available
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 18100, reserved: 0, actual total: 63968, total with overprovisioning: 63968; requested cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?: true
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 17699962880, reserved: 0, total: 68683108352; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
> 2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
> 2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
> 2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking suitable pools for volume (Id, Type): (52,ROOT)
> 2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) We need to allocate new storagepool for this volume
> 2014-12-31 07:49:44,394 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Calling StoragePoolAllocators to find suitable pools
> 2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) LocalStoragePoolAllocator trying to find storage pool to fit the vm
> 2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ClusterScopeStoragePoolAllocator looking for storage pool
> 2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Looking for pools in dc: 1  pod:1  cluster:1
> 2014-12-31 07:49:44,396 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Found pools matching tags: []
> 2014-12-31 07:49:44,397 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No storage pools available for shared volume allocation, returning
> 2014-12-31 07:49:44,397 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ZoneWideStoragePoolAllocator to find storage pool
> 2014-12-31 07:49:44,401 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing pool Pool[1|VMFS] from avoid set, must have been inserted when searching for another disk's tag
> 2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking pool 1 for storage, totalSize: 291789340672, usedBytes: 264725594112, usedPct: 0.9072490225390984, disable threshold: 0.85
> 2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Insufficient space on pool: 1 since its usage percentage: 0.9072490225390984 has crossed the pool.storage.capacity.disablethreshold: 0.85
> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found for volume: Vol[52|vm=47|ROOT] under cluster: 1
> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found
> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable storagePools found under this Cluster: 1
> 2014-12-31 07:49:44,407 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Could not find suitable Deployment Destination for this VM under any clusters, returning.
> 2014-12-31 07:49:44,407 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible resources under this Zone: 1
> 2014-12-31 07:49:44,408 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
> 2014-12-31 07:49:44,410 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId list these clusters from avoid set: [1]
> 2014-12-31 07:49:44,411 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No clusters found after removing disabled clusters and clusters in avoid list, returning.
> 2014-12-31 07:49:44,413 DEBUG [c.c.v.UserVmManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Destroying vm VM[User|test] as it failed to create on Host with Id:null
> 2014-12-31 07:49:44,421 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) 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
> 014-12-31 07:49:44,431 WARN  [o.a.c.alerts] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5)  alertType:: 8 // dataCenterId:: 1 // podId:: null // clusterId:: null // message:: Failed to deploy Vm with Id: 47, on Host with Id: null
> 2014-12-31 07:49:44,458 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter; id=1
> 2014-12-31 07:49:44,459 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Unable to create a deployment for VM[User|test]
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter; id=1
>          at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:210)
>          at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:196)
>          at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3549)
>          at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3157)
>          at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3143)
>          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:622)
>          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 com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
>          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.$Proxy169.startVirtualMachine(Unknown Source)
>          at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443)
>          at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
>          at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
>          at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
>          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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
>          at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:509)
>          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.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>          at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
>          at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>          at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
>          at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
>          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>          at java.lang.Thread.run(Thread.java:701)
> 2014-12-31 07:49:44,460 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Complete async job-419, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":533,"errortext":"Unable to create a deployment for VM[User|test]"}
> 2014-12-31 07:49:44,483 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Done executing org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-419
> 2014-12-31 07:49:44,487 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-22:ctx-f2bc1611) Remove job-419 from job monitoring
> 2014-12-31 07:49:45,692 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-981122: Processing Seq 2-981122:  { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n  \"connections\": []\n}","wait":0}}] }
> 2014-12-31 07:49:45,697 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-981122: Sending Seq 2-981122:  { Ans: , MgmtId: 345050676845, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2014-12-31 07:49:46,059 DEBUG [o.a.c.s.RemoteHostEndPoint] (Timer-12:ctx-89509527) Sending command org.apache.cloudstack.storage.command.DownloadProgressCommand to host: 3
>
>
>
>
> ***************
>
>
>
>
> ----- Original Message -----
> From: "Somesh Naidu" <So...@citrix.com>
> To: users@cloudstack.apache.org
> Sent: Tuesday, December 30, 2014 5:53:55 PM
> Subject: RE: Can't create or deploy VMs
>
> It would be helpful if you could share a larger chunk of mgmt. server logs via paste bin so we can see what's happening/failing.
>
> -----Original Message-----
> From: José Egas López [mailto:joseegas@farmaenlace.com]
> Sent: Tuesday, December 30, 2014 5:41 PM
> To: users@cloudstack.apache.org
> Subject: Can't create or deploy VMs
>
> Hi all, when I try to create or deploy a new VM, it shows the following
> error:
>
>      User VM
>
>      Failed to deploy Vm with Id: 42on Host with Id: null
>
>      Mon29 Dec 2014 19:22:27 GMT
>
> So I can do nothing, I can't create VMs or deploy them from a template.
> How can I fix it?
>
> I was creating and deploying VMs normally.
> I have ACS 4.3.1 with VMware 5.5


Re: Can't create or deploy VMs

Posted by José Egas López <jo...@farmaenlace.com>.
Hi Naidu, in the dashboard, it shows there is used only 38% of Primary 
Storage:

  *
    Zone: ZonePharma
    38%
    Primary Storage
    211.44 GB / 543.50 GB

So it seems there is more than enough of Primary Storage for creating VMs.

*Regards,
* *José

*

Teléf. (593-2)2993100 ext. 1639
Teléf. (593-99)8-824047
El 31/12/2014 a las 12:49, Somesh Naidu escribió:
>> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found
>> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable storagePools found under this Cluster: 1
>> 2014-12-31 07:49:44,407 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Could not find suitable Deployment Destination for this VM under any clusters, returning.
> Apparently, you only have 1 cluster in Zone 1 where the VM is being deployed and the storage on that one is full. You need to provision more space.
>
> -----Original Message-----
> From: José Egas López [mailto:joseegas@farmaenlace.com]
> Sent: Wednesday, December 31, 2014 8:18 AM
> To: users@cloudstack.apache.org
> Subject: Re: Can't create or deploy VMs
>
> The log on mgmt is:
>
> ***************
> 2014-12-31 07:49:44,138 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-de733770) ===START===  172.30.1.107 -- GET  command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpgjMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c5194c&displayname=test&name=test&_=1420030300055
> 2014-12-31 07:49:44,150 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
> 2014-12-31 07:49:44,153 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
> 2014-12-31 07:49:44,158 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.DiskOffering
> 2014-12-31 07:49:44,190 DEBUG [c.c.v.UserVmManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating in the DB for vm
> 2014-12-31 07:49:44,219 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating entries for VM: VM[User|test]
> 2014-12-31 07:49:44,221 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nics for VM[User|test]
> 2014-12-31 07:49:44,222 DEBUG [o.a.c.e.o.NetworkOrchestrator] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nic for vm VM[User|test] in network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
> 2014-12-31 07:49:44,233 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating disks for VM[User|test]
> 2014-12-31 07:49:44,244 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocation completed for VM: VM[User|test]
> 2014-12-31 07:49:44,244 DEBUG [c.c.v.UserVmManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Successfully allocated DB entry for VM[User|test]
> 2014-12-31 07:49:44,296 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) submit async job-419, details: AsyncJobVO {id:419, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 47, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo: {"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","templateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"47","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEventId":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-12-31 07:49:44,297 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-22:ctx-f2bc1611) Add job-419 into job monitoring
> 2014-12-31 07:49:44,297 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) ===END===  172.30.1.107 -- GET  command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpgjMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c5194c&displayname=test&name=test&_=1420030300055
> 2014-12-31 07:49:44,297 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Executing AsyncJobVO {id:419, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 47, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo: {"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","templateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"47","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEventId":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-12-31 07:49:44,303 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
> 2014-12-31 07:49:44,305 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
> 2014-12-31 07:49:44,307 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.DiskOffering
> 2014-12-31 07:49:44,360 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Deploy avoids pods: [], clusters: [], hosts: []
> 2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@5303f245
> 2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
> 2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Is ROOT volume READY (pool already allocated)?: No
> 2014-12-31 07:49:44,362 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible resources under this Zone: 1
> 2014-12-31 07:49:44,363 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
> 2014-12-31 07:49:44,366 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId list these clusters from avoid set: []
> 2014-12-31 07:49:44,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking resources in Cluster: 1 under Pod: 1
> 2014-12-31 07:49:44,377 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  cluster:1
> 2014-12-31 07:49:44,380 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
> 2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]]
> 2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Looking for speed=1000Mhz, Ram=1024
> 2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host: 1 has cpu capability (cpu:32, speed:1999) to support requested CPU: 1 and requested speed: 1000
> 2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 1000 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Hosts's actual total CPU: 63968 and CPU after applying overprovisioning: 63968
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free CPU: 45868 , Requested CPU: 1000
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free RAM: 50983145472 , Requested RAM: 1073741824
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host has enough CPU and RAM available
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 18100, reserved: 0, actual total: 63968, total with overprovisioning: 63968; requested cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?: true
> 2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 17699962880, reserved: 0, total: 68683108352; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
> 2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
> 2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
> 2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking suitable pools for volume (Id, Type): (52,ROOT)
> 2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) We need to allocate new storagepool for this volume
> 2014-12-31 07:49:44,394 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Calling StoragePoolAllocators to find suitable pools
> 2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) LocalStoragePoolAllocator trying to find storage pool to fit the vm
> 2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ClusterScopeStoragePoolAllocator looking for storage pool
> 2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Looking for pools in dc: 1  pod:1  cluster:1
> 2014-12-31 07:49:44,396 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Found pools matching tags: []
> 2014-12-31 07:49:44,397 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No storage pools available for shared volume allocation, returning
> 2014-12-31 07:49:44,397 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ZoneWideStoragePoolAllocator to find storage pool
> 2014-12-31 07:49:44,401 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing pool Pool[1|VMFS] from avoid set, must have been inserted when searching for another disk's tag
> 2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking pool 1 for storage, totalSize: 291789340672, usedBytes: 264725594112, usedPct: 0.9072490225390984, disable threshold: 0.85
> 2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Insufficient space on pool: 1 since its usage percentage: 0.9072490225390984 has crossed the pool.storage.capacity.disablethreshold: 0.85
> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found for volume: Vol[52|vm=47|ROOT] under cluster: 1
> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found
> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable storagePools found under this Cluster: 1
> 2014-12-31 07:49:44,407 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Could not find suitable Deployment Destination for this VM under any clusters, returning.
> 2014-12-31 07:49:44,407 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible resources under this Zone: 1
> 2014-12-31 07:49:44,408 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
> 2014-12-31 07:49:44,410 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId list these clusters from avoid set: [1]
> 2014-12-31 07:49:44,411 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No clusters found after removing disabled clusters and clusters in avoid list, returning.
> 2014-12-31 07:49:44,413 DEBUG [c.c.v.UserVmManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Destroying vm VM[User|test] as it failed to create on Host with Id:null
> 2014-12-31 07:49:44,421 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) 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
> 014-12-31 07:49:44,431 WARN  [o.a.c.alerts] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5)  alertType:: 8 // dataCenterId:: 1 // podId:: null // clusterId:: null // message:: Failed to deploy Vm with Id: 47, on Host with Id: null
> 2014-12-31 07:49:44,458 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter; id=1
> 2014-12-31 07:49:44,459 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Unable to create a deployment for VM[User|test]
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter; id=1
>          at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:210)
>          at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:196)
>          at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3549)
>          at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3157)
>          at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3143)
>          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:622)
>          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 com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
>          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.$Proxy169.startVirtualMachine(Unknown Source)
>          at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443)
>          at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
>          at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
>          at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
>          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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
>          at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:509)
>          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.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>          at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
>          at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>          at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
>          at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
>          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>          at java.lang.Thread.run(Thread.java:701)
> 2014-12-31 07:49:44,460 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Complete async job-419, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":533,"errortext":"Unable to create a deployment for VM[User|test]"}
> 2014-12-31 07:49:44,483 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Done executing org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-419
> 2014-12-31 07:49:44,487 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-22:ctx-f2bc1611) Remove job-419 from job monitoring
> 2014-12-31 07:49:45,692 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-981122: Processing Seq 2-981122:  { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n  \"connections\": []\n}","wait":0}}] }
> 2014-12-31 07:49:45,697 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-981122: Sending Seq 2-981122:  { Ans: , MgmtId: 345050676845, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2014-12-31 07:49:46,059 DEBUG [o.a.c.s.RemoteHostEndPoint] (Timer-12:ctx-89509527) Sending command org.apache.cloudstack.storage.command.DownloadProgressCommand to host: 3
>
>
>
>
> ***************
>
>
>
>
> ----- Original Message -----
> From: "Somesh Naidu" <So...@citrix.com>
> To: users@cloudstack.apache.org
> Sent: Tuesday, December 30, 2014 5:53:55 PM
> Subject: RE: Can't create or deploy VMs
>
> It would be helpful if you could share a larger chunk of mgmt. server logs via paste bin so we can see what's happening/failing.
>
> -----Original Message-----
> From: José Egas López [mailto:joseegas@farmaenlace.com]
> Sent: Tuesday, December 30, 2014 5:41 PM
> To: users@cloudstack.apache.org
> Subject: Can't create or deploy VMs
>
> Hi all, when I try to create or deploy a new VM, it shows the following
> error:
>
>      User VM
>
>      Failed to deploy Vm with Id: 42on Host with Id: null
>
>      Mon29 Dec 2014 19:22:27 GMT
>
> So I can do nothing, I can't create VMs or deploy them from a template.
> How can I fix it?
>
> I was creating and deploying VMs normally.
> I have ACS 4.3.1 with VMware 5.5


Re: Can't create or deploy VMs

Posted by Prashant Kumar Mishra <pr...@citrix.com>.
For now you can set ³pool.storage.capacity.disablethreshold² to 1 in
global settings , and restart ms .

Insufficient space on pool: 1 since its usage percentage:
0.9072490225390984 has crossed the pool.storage.capacity.disablethreshold:
0.85



On 12/31/14, 11:19 PM, "Somesh Naidu" <So...@citrix.com> wrote:

>> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found
>> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable storagePools
>>found under this Cluster: 1
>> 2014-12-31 07:49:44,407 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Could not find suitable
>>Deployment Destination for this VM under any clusters, returning.
>
>Apparently, you only have 1 cluster in Zone 1 where the VM is being
>deployed and the storage on that one is full. You need to provision more
>space.
>
>-----Original Message-----
>From: José Egas López [mailto:joseegas@farmaenlace.com]
>Sent: Wednesday, December 31, 2014 8:18 AM
>To: users@cloudstack.apache.org
>Subject: Re: Can't create or deploy VMs
>
>The log on mgmt is:
>
>***************
>2014-12-31 07:49:44,138 DEBUG [c.c.a.ApiServlet]
>(catalina-exec-2:ctx-de733770) ===START===  172.30.1.107 -- GET
>command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpg
>jMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489
>-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-
>afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c
>5194c&displayname=test&name=test&_=1420030300055
>2014-12-31 07:49:44,150 DEBUG [c.c.a.ApiDispatcher]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name
>is:com.cloud.offering.ServiceOffering
>2014-12-31 07:49:44,153 DEBUG [c.c.a.ApiDispatcher]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) ControlledEntity name
>is:com.cloud.template.VirtualMachineTemplate
>2014-12-31 07:49:44,158 DEBUG [c.c.a.ApiDispatcher]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name
>is:com.cloud.offering.DiskOffering
>2014-12-31 07:49:44,190 DEBUG [c.c.v.UserVmManagerImpl]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating in the DB for vm
>2014-12-31 07:49:44,219 DEBUG [c.c.v.VirtualMachineManagerImpl]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating entries for VM:
>VM[User|test]
>2014-12-31 07:49:44,221 DEBUG [c.c.v.VirtualMachineManagerImpl]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nics for
>VM[User|test]
>2014-12-31 07:49:44,222 DEBUG [o.a.c.e.o.NetworkOrchestrator]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nic for vm
>VM[User|test] in network Ntwk[204|Guest|6] with requested profile
>NicProfile[0-0-null-null-null
>2014-12-31 07:49:44,233 DEBUG [c.c.v.VirtualMachineManagerImpl]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating disks for
>VM[User|test]
>2014-12-31 07:49:44,244 DEBUG [c.c.v.VirtualMachineManagerImpl]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocation completed for VM:
>VM[User|test]
>2014-12-31 07:49:44,244 DEBUG [c.c.v.UserVmManagerImpl]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) Successfully allocated DB
>entry for VM[User|test]
>2014-12-31 07:49:44,296 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) submit async job-419,
>details: AsyncJobVO {id:419, userId: 2, accountId: 2, instanceType:
>VirtualMachine, instanceId: 47, cmd:
>org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo:
>{"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"
>ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":
>"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","te
>mplateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"4
>7","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":
>"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEvent
>Id":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS,
>processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845,
>completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
>2014-12-31 07:49:44,297 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
>(Job-Executor-22:ctx-f2bc1611) Add job-419 into job monitoring
>2014-12-31 07:49:44,297 DEBUG [c.c.a.ApiServlet]
>(catalina-exec-2:ctx-de733770 ctx-77cccfb5) ===END===  172.30.1.107 --
>GET  
>command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpg
>jMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489
>-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-
>afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c
>5194c&displayname=test&name=test&_=1420030300055
>2014-12-31 07:49:44,297 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>(Job-Executor-22:ctx-f2bc1611) Executing AsyncJobVO {id:419, userId: 2,
>accountId: 2, instanceType: VirtualMachine, instanceId: 47, cmd:
>org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo:
>{"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"
>ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":
>"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","te
>mplateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"4
>7","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":
>"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEvent
>Id":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS,
>processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845,
>completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
>2014-12-31 07:49:44,303 DEBUG [c.c.a.ApiDispatcher]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name
>is:com.cloud.offering.ServiceOffering
>2014-12-31 07:49:44,305 DEBUG [c.c.a.ApiDispatcher]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ControlledEntity name
>is:com.cloud.template.VirtualMachineTemplate
>2014-12-31 07:49:44,307 DEBUG [c.c.a.ApiDispatcher]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name
>is:com.cloud.offering.DiskOffering
>2014-12-31 07:49:44,360 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Deploy avoids pods: [],
>clusters: [], hosts: []
>2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) DeploymentPlanner allocation
>algorithm: com.cloud.deploy.FirstFitPlanner@5303f245
>2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Trying to allocate a host and
>storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000,
>requested ram: 1073741824
>2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Is ROOT volume READY (pool
>already allocated)?: No
>2014-12-31 07:49:44,362 DEBUG [c.c.d.FirstFitPlanner]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible
>resources under this Zone: 1
>2014-12-31 07:49:44,363 DEBUG [c.c.d.FirstFitPlanner]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of
>aggregate capacity, that have (atleast one host with) enough CPU and RAM
>capacity under this Zone: 1
>2014-12-31 07:49:44,366 DEBUG [c.c.d.FirstFitPlanner]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId
>list these clusters from avoid set: []
>2014-12-31 07:49:44,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking resources in
>Cluster: 1 under Pod: 1
>2014-12-31 07:49:44,377 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator)
>Looking for hosts in dc: 1  pod:1  cluster:1
>2014-12-31 07:49:44,380 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator)
>FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
>2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator)
>Found 1 hosts for allocation after prioritization: [Host[-1-Routing]]
>2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator)
>Looking for speed=1000Mhz, Ram=1024
>2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator)
>Host: 1 has cpu capability (cpu:32, speed:1999) to support requested CPU:
>1 and requested speed: 1000
>2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator)
>Checking if host: 1 has enough capacity for requested CPU: 1000 and
>requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
>2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator)
>Hosts's actual total CPU: 63968 and CPU after applying overprovisioning:
>63968
>2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free
>CPU: 45868 , Requested CPU: 1000
>2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free
>RAM: 50983145472 , Requested RAM: 1073741824
>2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host
>has enough CPU and RAM available
>2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator)
>STATS: Can alloc CPU from host: 1, used: 18100, reserved: 0, actual
>total: 63968, total with overprovisioning: 63968; requested
>cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?: true
>2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator)
>STATS: Can alloc MEM from host: 1, used: 17699962880, reserved: 0, total:
>68683108352; requested mem: 1073741824,alloc_from_last_host?:false
>,considerReservedCapacity?: true
>2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator)
>Found a suitable host, adding to list: 1
>2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host
>Allocator returning 1 suitable hosts
>2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking suitable pools for
>volume (Id, Type): (52,ROOT)
>2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) We need to allocate new
>storagepool for this volume
>2014-12-31 07:49:44,394 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Calling StoragePoolAllocators
>to find suitable pools
>2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) LocalStoragePoolAllocator
>trying to find storage pool to fit the vm
>2014-12-31 07:49:44,395 DEBUG
>[o.a.c.s.a.ClusterScopeStoragePoolAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5)
>ClusterScopeStoragePoolAllocator looking for storage pool
>2014-12-31 07:49:44,395 DEBUG
>[o.a.c.s.a.ClusterScopeStoragePoolAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Looking for pools in dc: 1
>pod:1  cluster:1
>2014-12-31 07:49:44,396 DEBUG
>[o.a.c.s.a.ClusterScopeStoragePoolAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Found pools matching tags: []
>2014-12-31 07:49:44,397 DEBUG
>[o.a.c.s.a.ClusterScopeStoragePoolAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No storage pools available
>for shared volume allocation, returning
>2014-12-31 07:49:44,397 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ZoneWideStoragePoolAllocator
>to find storage pool
>2014-12-31 07:49:44,401 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing pool Pool[1|VMFS]
>from avoid set, must have been inserted when searching for another disk's
>tag
>2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking pool 1 for storage,
>totalSize: 291789340672, usedBytes: 264725594112, usedPct:
>0.9072490225390984, disable threshold: 0.85
>2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Insufficient space on pool: 1
>since its usage percentage: 0.9072490225390984 has crossed the
>pool.storage.capacity.disablethreshold: 0.85
>2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found for
>volume: Vol[52|vm=47|ROOT] under cluster: 1
>2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found
>2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable storagePools
>found under this Cluster: 1
>2014-12-31 07:49:44,407 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Could not find suitable
>Deployment Destination for this VM under any clusters, returning.
>2014-12-31 07:49:44,407 DEBUG [c.c.d.FirstFitPlanner]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible
>resources under this Zone: 1
>2014-12-31 07:49:44,408 DEBUG [c.c.d.FirstFitPlanner]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of
>aggregate capacity, that have (atleast one host with) enough CPU and RAM
>capacity under this Zone: 1
>2014-12-31 07:49:44,410 DEBUG [c.c.d.FirstFitPlanner]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId
>list these clusters from avoid set: [1]
>2014-12-31 07:49:44,411 DEBUG [c.c.d.FirstFitPlanner]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No clusters found after
>removing disabled clusters and clusters in avoid list, returning.
>2014-12-31 07:49:44,413 DEBUG [c.c.v.UserVmManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Destroying vm VM[User|test]
>as it failed to create on Host with Id:null
>2014-12-31 07:49:44,421 DEBUG [c.c.c.CapacityManagerImpl]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) 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
>014-12-31 07:49:44,431 WARN  [o.a.c.alerts] (Job-Executor-22:ctx-f2bc1611
>ctx-77cccfb5)  alertType:: 8 // dataCenterId:: 1 // podId:: null //
>clusterId:: null // message:: Failed to deploy Vm with Id: 47, on Host
>with Id: null
>2014-12-31 07:49:44,458 INFO  [o.a.c.a.c.u.v.DeployVMCmd]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5)
>com.cloud.exception.InsufficientServerCapacityException: Unable to create
>a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter;
>id=1
>2014-12-31 07:49:44,459 INFO  [o.a.c.a.c.u.v.DeployVMCmd]
>(Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Unable to create a deployment
>for VM[User|test]
>com.cloud.exception.InsufficientServerCapacityException: Unable to create
>a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter;
>id=1
>        at 
>org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveV
>irtualMachine(VMEntityManagerImpl.java:210)
>        at 
>org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.res
>erve(VirtualMachineEntityImpl.java:196)
>        at 
>com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:
>3549)
>        at 
>com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:
>3157)
>        at 
>com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:
>3143)
>        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>        at 
>sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:
>57)
>        at 
>sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorIm
>pl.java:43)
>        at java.lang.reflect.Method.invoke(Method.java:622)
>        at 
>org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(Ao
>pUtils.java:317)
>        at 
>org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoi
>nt(ReflectiveMethodInvocation.java:183)
>        at 
>org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Refle
>ctiveMethodInvocation.java:150)
>        at 
>com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:
>50)
>        at 
>org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Refle
>ctiveMethodInvocation.java:161)
>        at 
>org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(Exp
>oseInvocationInterceptor.java:91)
>        at 
>org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Refle
>ctiveMethodInvocation.java:172)
>        at 
>org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopP
>roxy.java:204)
>        at com.sun.proxy.$Proxy169.startVirtualMachine(Unknown Source)
>        at 
>org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.
>java:443)
>        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
>        at 
>com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.
>java:109)
>        at 
>com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
>        at 
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(De
>faultManagedContext.java:56)
>        at 
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithC
>ontext(DefaultManagedContext.java:103)
>        at 
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithCo
>ntext(DefaultManagedContext.java:53)
>        at 
>com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
>        at 
>org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInConte
>xt(AsyncJobManagerImpl.java:509)
>        at 
>org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Managed
>ContextRunnable.java:49)
>        at 
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(De
>faultManagedContext.java:56)
>        at 
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithC
>ontext(DefaultManagedContext.java:103)
>        at 
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithCo
>ntext(DefaultManagedContext.java:53)
>        at 
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithCo
>ntext(DefaultManagedContext.java:53)
>        at 
>org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedCo
>ntextRunnable.java:46)
>        at 
>java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>        at 
>java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
>        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>        at 
>java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:
>1146)
>        at 
>java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java
>:615)
>        at java.lang.Thread.run(Thread.java:701)
>2014-12-31 07:49:44,460 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>(Job-Executor-22:ctx-f2bc1611) Complete async job-419, jobStatus: FAILED,
>resultCode: 530, result:
>org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"
>errorcode":533,"errortext":"Unable to create a deployment for
>VM[User|test]"}
>2014-12-31 07:49:44,483 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>(Job-Executor-22:ctx-f2bc1611) Done executing
>org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-419
>2014-12-31 07:49:44,487 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
>(Job-Executor-22:ctx-f2bc1611) Remove job-419 from job monitoring
>2014-12-31 07:49:45,692 DEBUG [c.c.a.m.AgentManagerImpl]
>(AgentManager-Handler-1:null) SeqA 2-981122: Processing Seq 2-981122:  {
>Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
>[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_lo
>adInfo":"{\n  \"connections\": []\n}","wait":0}}] }
>2014-12-31 07:49:45,697 DEBUG [c.c.a.m.AgentManagerImpl]
>(AgentManager-Handler-1:null) SeqA 2-981122: Sending Seq 2-981122:  {
>Ans: , MgmtId: 345050676845, via: 2, Ver: v1, Flags: 100010,
>[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
>2014-12-31 07:49:46,059 DEBUG [o.a.c.s.RemoteHostEndPoint]
>(Timer-12:ctx-89509527) Sending command
>org.apache.cloudstack.storage.command.DownloadProgressCommand to host: 3
>
>
>
>
>***************
>
>
>
>
>----- Original Message -----
>From: "Somesh Naidu" <So...@citrix.com>
>To: users@cloudstack.apache.org
>Sent: Tuesday, December 30, 2014 5:53:55 PM
>Subject: RE: Can't create or deploy VMs
>
>It would be helpful if you could share a larger chunk of mgmt. server
>logs via paste bin so we can see what's happening/failing.
>
>-----Original Message-----
>From: José Egas López [mailto:joseegas@farmaenlace.com]
>Sent: Tuesday, December 30, 2014 5:41 PM
>To: users@cloudstack.apache.org
>Subject: Can't create or deploy VMs
>
>Hi all, when I try to create or deploy a new VM, it shows the following
>error:
>
>    User VM
>
>    Failed to deploy Vm with Id: 42on Host with Id: null
>
>    Mon29 Dec 2014 19:22:27 GMT
>
>So I can do nothing, I can't create VMs or deploy them from a template.
>How can I fix it?
>
>I was creating and deploying VMs normally.
>I have ACS 4.3.1 with VMware 5.5
>-- 
>*
>
>
>Regards,
>José
>
>*


RE: Can't create or deploy VMs

Posted by Somesh Naidu <So...@citrix.com>.
> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found
> 2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable storagePools found under this Cluster: 1
> 2014-12-31 07:49:44,407 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Could not find suitable Deployment Destination for this VM under any clusters, returning.

Apparently, you only have 1 cluster in Zone 1 where the VM is being deployed and the storage on that one is full. You need to provision more space.

-----Original Message-----
From: José Egas López [mailto:joseegas@farmaenlace.com] 
Sent: Wednesday, December 31, 2014 8:18 AM
To: users@cloudstack.apache.org
Subject: Re: Can't create or deploy VMs

The log on mgmt is:

***************
2014-12-31 07:49:44,138 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-de733770) ===START===  172.30.1.107 -- GET  command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpgjMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c5194c&displayname=test&name=test&_=1420030300055
2014-12-31 07:49:44,150 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
2014-12-31 07:49:44,153 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
2014-12-31 07:49:44,158 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.DiskOffering
2014-12-31 07:49:44,190 DEBUG [c.c.v.UserVmManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating in the DB for vm
2014-12-31 07:49:44,219 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating entries for VM: VM[User|test]
2014-12-31 07:49:44,221 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nics for VM[User|test]
2014-12-31 07:49:44,222 DEBUG [o.a.c.e.o.NetworkOrchestrator] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nic for vm VM[User|test] in network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
2014-12-31 07:49:44,233 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating disks for VM[User|test]
2014-12-31 07:49:44,244 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocation completed for VM: VM[User|test]
2014-12-31 07:49:44,244 DEBUG [c.c.v.UserVmManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Successfully allocated DB entry for VM[User|test]
2014-12-31 07:49:44,296 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) submit async job-419, details: AsyncJobVO {id:419, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 47, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo: {"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","templateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"47","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEventId":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-12-31 07:49:44,297 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-22:ctx-f2bc1611) Add job-419 into job monitoring
2014-12-31 07:49:44,297 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) ===END===  172.30.1.107 -- GET  command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpgjMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c5194c&displayname=test&name=test&_=1420030300055
2014-12-31 07:49:44,297 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Executing AsyncJobVO {id:419, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 47, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo: {"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","templateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"47","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEventId":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-12-31 07:49:44,303 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
2014-12-31 07:49:44,305 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
2014-12-31 07:49:44,307 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.DiskOffering
2014-12-31 07:49:44,360 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Deploy avoids pods: [], clusters: [], hosts: []
2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@5303f245
2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Is ROOT volume READY (pool already allocated)?: No
2014-12-31 07:49:44,362 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible resources under this Zone: 1
2014-12-31 07:49:44,363 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2014-12-31 07:49:44,366 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId list these clusters from avoid set: []
2014-12-31 07:49:44,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking resources in Cluster: 1 under Pod: 1
2014-12-31 07:49:44,377 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  cluster:1
2014-12-31 07:49:44,380 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]]
2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Looking for speed=1000Mhz, Ram=1024
2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host: 1 has cpu capability (cpu:32, speed:1999) to support requested CPU: 1 and requested speed: 1000
2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 1000 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Hosts's actual total CPU: 63968 and CPU after applying overprovisioning: 63968
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free CPU: 45868 , Requested CPU: 1000
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free RAM: 50983145472 , Requested RAM: 1073741824
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 18100, reserved: 0, actual total: 63968, total with overprovisioning: 63968; requested cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 17699962880, reserved: 0, total: 68683108352; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking suitable pools for volume (Id, Type): (52,ROOT)
2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) We need to allocate new storagepool for this volume
2014-12-31 07:49:44,394 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Calling StoragePoolAllocators to find suitable pools
2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ClusterScopeStoragePoolAllocator looking for storage pool
2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Looking for pools in dc: 1  pod:1  cluster:1
2014-12-31 07:49:44,396 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Found pools matching tags: []
2014-12-31 07:49:44,397 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No storage pools available for shared volume allocation, returning
2014-12-31 07:49:44,397 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ZoneWideStoragePoolAllocator to find storage pool
2014-12-31 07:49:44,401 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing pool Pool[1|VMFS] from avoid set, must have been inserted when searching for another disk's tag
2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking pool 1 for storage, totalSize: 291789340672, usedBytes: 264725594112, usedPct: 0.9072490225390984, disable threshold: 0.85
2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Insufficient space on pool: 1 since its usage percentage: 0.9072490225390984 has crossed the pool.storage.capacity.disablethreshold: 0.85
2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found for volume: Vol[52|vm=47|ROOT] under cluster: 1
2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found
2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable storagePools found under this Cluster: 1
2014-12-31 07:49:44,407 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2014-12-31 07:49:44,407 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible resources under this Zone: 1
2014-12-31 07:49:44,408 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2014-12-31 07:49:44,410 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId list these clusters from avoid set: [1]
2014-12-31 07:49:44,411 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2014-12-31 07:49:44,413 DEBUG [c.c.v.UserVmManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Destroying vm VM[User|test] as it failed to create on Host with Id:null
2014-12-31 07:49:44,421 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) 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
014-12-31 07:49:44,431 WARN  [o.a.c.alerts] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5)  alertType:: 8 // dataCenterId:: 1 // podId:: null // clusterId:: null // message:: Failed to deploy Vm with Id: 47, on Host with Id: null
2014-12-31 07:49:44,458 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter; id=1
2014-12-31 07:49:44,459 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Unable to create a deployment for VM[User|test]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter; id=1
        at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:210)
        at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:196)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3549)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3157)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3143)
        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:622)
        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 com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
        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.$Proxy169.startVirtualMachine(Unknown Source)
        at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
        at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
        at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
        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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:509)
        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.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:701)
2014-12-31 07:49:44,460 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Complete async job-419, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":533,"errortext":"Unable to create a deployment for VM[User|test]"}
2014-12-31 07:49:44,483 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Done executing org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-419
2014-12-31 07:49:44,487 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-22:ctx-f2bc1611) Remove job-419 from job monitoring
2014-12-31 07:49:45,692 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-981122: Processing Seq 2-981122:  { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n  \"connections\": []\n}","wait":0}}] }
2014-12-31 07:49:45,697 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-981122: Sending Seq 2-981122:  { Ans: , MgmtId: 345050676845, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-12-31 07:49:46,059 DEBUG [o.a.c.s.RemoteHostEndPoint] (Timer-12:ctx-89509527) Sending command org.apache.cloudstack.storage.command.DownloadProgressCommand to host: 3




***************




----- Original Message -----
From: "Somesh Naidu" <So...@citrix.com>
To: users@cloudstack.apache.org
Sent: Tuesday, December 30, 2014 5:53:55 PM
Subject: RE: Can't create or deploy VMs

It would be helpful if you could share a larger chunk of mgmt. server logs via paste bin so we can see what's happening/failing.

-----Original Message-----
From: José Egas López [mailto:joseegas@farmaenlace.com] 
Sent: Tuesday, December 30, 2014 5:41 PM
To: users@cloudstack.apache.org
Subject: Can't create or deploy VMs

Hi all, when I try to create or deploy a new VM, it shows the following 
error:

    User VM

    Failed to deploy Vm with Id: 42on Host with Id: null

    Mon29 Dec 2014 19:22:27 GMT

So I can do nothing, I can't create VMs or deploy them from a template.
How can I fix it?

I was creating and deploying VMs normally.
I have ACS 4.3.1 with VMware 5.5
-- 
*


Regards,
José

*

Re: Can't create or deploy VMs

Posted by José Egas López <jo...@farmaenlace.com>.
The log on mgmt is:

***************
2014-12-31 07:49:44,138 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-de733770) ===START===  172.30.1.107 -- GET  command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpgjMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c5194c&displayname=test&name=test&_=1420030300055
2014-12-31 07:49:44,150 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
2014-12-31 07:49:44,153 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
2014-12-31 07:49:44,158 DEBUG [c.c.a.ApiDispatcher] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.DiskOffering
2014-12-31 07:49:44,190 DEBUG [c.c.v.UserVmManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating in the DB for vm
2014-12-31 07:49:44,219 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating entries for VM: VM[User|test]
2014-12-31 07:49:44,221 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nics for VM[User|test]
2014-12-31 07:49:44,222 DEBUG [o.a.c.e.o.NetworkOrchestrator] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating nic for vm VM[User|test] in network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null
2014-12-31 07:49:44,233 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocating disks for VM[User|test]
2014-12-31 07:49:44,244 DEBUG [c.c.v.VirtualMachineManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Allocation completed for VM: VM[User|test]
2014-12-31 07:49:44,244 DEBUG [c.c.v.UserVmManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) Successfully allocated DB entry for VM[User|test]
2014-12-31 07:49:44,296 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) submit async job-419, details: AsyncJobVO {id:419, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 47, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo: {"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","templateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"47","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEventId":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-12-31 07:49:44,297 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-22:ctx-f2bc1611) Add job-419 into job monitoring
2014-12-31 07:49:44,297 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-de733770 ctx-77cccfb5) ===END===  172.30.1.107 -- GET  command=deployVirtualMachine&response=json&sessionkey=ExqHTfNe1JVXnQXRkEpgjMoDqu0%3D&zoneid=80b7c240-9204-43eb-85c8-762c7d7f6a15&templateid=449e3489-292e-4888-9682-d57d58a0ea1a&hypervisor=VMware&serviceofferingid=a6e438f6-afce-4388-9498-78cf2525cac2&diskofferingid=3df3bee2-bdee-4b80-9a0b-5ef039c5194c&displayname=test&name=test&_=1420030300055
2014-12-31 07:49:44,297 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Executing AsyncJobVO {id:419, userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 47, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo: {"serviceofferingid":"a6e438f6-afce-4388-9498-78cf2525cac2","sessionkey":"ExqHTfNe1JVXnQXRkEpgjMoDqu0\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","zoneid":"80b7c240-9204-43eb-85c8-762c7d7f6a15","httpmethod":"GET","templateid":"449e3489-292e-4888-9682-d57d58a0ea1a","response":"json","id":"47","hypervisor":"VMware","name":"test","_":"1420030300055","ctxAccountId":"2","diskofferingid":"3df3bee2-bdee-4b80-9a0b-5ef039c5194c","ctxStartEventId":"1099","displayname":"test"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050676845, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-12-31 07:49:44,303 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
2014-12-31 07:49:44,305 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
2014-12-31 07:49:44,307 DEBUG [c.c.a.ApiDispatcher] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) InfrastructureEntity name is:com.cloud.offering.DiskOffering
2014-12-31 07:49:44,360 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Deploy avoids pods: [], clusters: [], hosts: []
2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner@5303f245
2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
2014-12-31 07:49:44,361 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Is ROOT volume READY (pool already allocated)?: No
2014-12-31 07:49:44,362 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible resources under this Zone: 1
2014-12-31 07:49:44,363 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2014-12-31 07:49:44,366 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId list these clusters from avoid set: []
2014-12-31 07:49:44,374 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking resources in Cluster: 1 under Pod: 1
2014-12-31 07:49:44,377 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  cluster:1
2014-12-31 07:49:44,380 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]]
2014-12-31 07:49:44,383 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Looking for speed=1000Mhz, Ram=1024
2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host: 1 has cpu capability (cpu:32, speed:1999) to support requested CPU: 1 and requested speed: 1000
2014-12-31 07:49:44,389 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 1000 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Hosts's actual total CPU: 63968 and CPU after applying overprovisioning: 63968
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free CPU: 45868 , Requested CPU: 1000
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Free RAM: 50983145472 , Requested RAM: 1073741824
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 18100, reserved: 0, actual total: 63968, total with overprovisioning: 63968; requested cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-12-31 07:49:44,392 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 17699962880, reserved: 0, total: 68683108352; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2014-12-31 07:49:44,392 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5 FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking suitable pools for volume (Id, Type): (52,ROOT)
2014-12-31 07:49:44,393 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) We need to allocate new storagepool for this volume
2014-12-31 07:49:44,394 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Calling StoragePoolAllocators to find suitable pools
2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ClusterScopeStoragePoolAllocator looking for storage pool
2014-12-31 07:49:44,395 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Looking for pools in dc: 1  pod:1  cluster:1
2014-12-31 07:49:44,396 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Found pools matching tags: []
2014-12-31 07:49:44,397 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No storage pools available for shared volume allocation, returning
2014-12-31 07:49:44,397 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) ZoneWideStoragePoolAllocator to find storage pool
2014-12-31 07:49:44,401 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing pool Pool[1|VMFS] from avoid set, must have been inserted when searching for another disk's tag
2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Checking pool 1 for storage, totalSize: 291789340672, usedBytes: 264725594112, usedPct: 0.9072490225390984, disable threshold: 0.85
2014-12-31 07:49:44,405 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Insufficient space on pool: 1 since its usage percentage: 0.9072490225390984 has crossed the pool.storage.capacity.disablethreshold: 0.85
2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found for volume: Vol[52|vm=47|ROOT] under cluster: 1
2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable pools found
2014-12-31 07:49:44,405 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No suitable storagePools found under this Cluster: 1
2014-12-31 07:49:44,407 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2014-12-31 07:49:44,407 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Searching all possible resources under this Zone: 1
2014-12-31 07:49:44,408 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2014-12-31 07:49:44,410 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Removing from the clusterId list these clusters from avoid set: [1]
2014-12-31 07:49:44,411 DEBUG [c.c.d.FirstFitPlanner] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2014-12-31 07:49:44,413 DEBUG [c.c.v.UserVmManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Destroying vm VM[User|test] as it failed to create on Host with Id:null
2014-12-31 07:49:44,421 DEBUG [c.c.c.CapacityManagerImpl] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) 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
014-12-31 07:49:44,431 WARN  [o.a.c.alerts] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5)  alertType:: 8 // dataCenterId:: 1 // podId:: null // clusterId:: null // message:: Failed to deploy Vm with Id: 47, on Host with Id: null
2014-12-31 07:49:44,458 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter; id=1
2014-12-31 07:49:44,459 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (Job-Executor-22:ctx-f2bc1611 ctx-77cccfb5) Unable to create a deployment for VM[User|test]
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test]Scope=interface com.cloud.dc.DataCenter; id=1
        at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:210)
        at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:196)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3549)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3157)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3143)
        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:622)
        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 com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
        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.$Proxy169.startVirtualMachine(Unknown Source)
        at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
        at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
        at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
        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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:509)
        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.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:701)
2014-12-31 07:49:44,460 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Complete async job-419, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":533,"errortext":"Unable to create a deployment for VM[User|test]"}
2014-12-31 07:49:44,483 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-22:ctx-f2bc1611) Done executing org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-419
2014-12-31 07:49:44,487 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-22:ctx-f2bc1611) Remove job-419 from job monitoring
2014-12-31 07:49:45,692 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-981122: Processing Seq 2-981122:  { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n  \"connections\": []\n}","wait":0}}] }
2014-12-31 07:49:45,697 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-981122: Sending Seq 2-981122:  { Ans: , MgmtId: 345050676845, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-12-31 07:49:46,059 DEBUG [o.a.c.s.RemoteHostEndPoint] (Timer-12:ctx-89509527) Sending command org.apache.cloudstack.storage.command.DownloadProgressCommand to host: 3




***************




----- Original Message -----
From: "Somesh Naidu" <So...@citrix.com>
To: users@cloudstack.apache.org
Sent: Tuesday, December 30, 2014 5:53:55 PM
Subject: RE: Can't create or deploy VMs

It would be helpful if you could share a larger chunk of mgmt. server logs via paste bin so we can see what's happening/failing.

-----Original Message-----
From: José Egas López [mailto:joseegas@farmaenlace.com] 
Sent: Tuesday, December 30, 2014 5:41 PM
To: users@cloudstack.apache.org
Subject: Can't create or deploy VMs

Hi all, when I try to create or deploy a new VM, it shows the following 
error:

    User VM

    Failed to deploy Vm with Id: 42on Host with Id: null

    Mon29 Dec 2014 19:22:27 GMT

So I can do nothing, I can't create VMs or deploy them from a template.
How can I fix it?

I was creating and deploying VMs normally.
I have ACS 4.3.1 with VMware 5.5
-- 
*


Regards,
José

*

RE: Can't create or deploy VMs

Posted by Somesh Naidu <So...@citrix.com>.
It would be helpful if you could share a larger chunk of mgmt. server logs via paste bin so we can see what's happening/failing.

-----Original Message-----
From: José Egas López [mailto:joseegas@farmaenlace.com] 
Sent: Tuesday, December 30, 2014 5:41 PM
To: users@cloudstack.apache.org
Subject: Can't create or deploy VMs

Hi all, when I try to create or deploy a new VM, it shows the following 
error:

    User VM

    Failed to deploy Vm with Id: 42on Host with Id: null

    Mon29 Dec 2014 19:22:27 GMT

So I can do nothing, I can't create VMs or deploy them from a template.
How can I fix it?

I was creating and deploying VMs normally.
I have ACS 4.3.1 with VMware 5.5
-- 
*


Regards,
José

*