Hi Peter, Glad to hear you got it sorted
Regards Geoff Higginbottom D: +44 20 3603 0542 | S: +44 20 3603 0540 | M: +447968161581 geoff.higginbot...@shapeblue.com -----Original Message----- From: Peter Sadowski [mailto:psadow...@dbr360.com] Sent: 30 May 2014 18:04 To: users@cloudstack.apache.org Subject: RE: Can't create VM under specific account Hi Geoff, Thank you for the reply. I agree that the log and errors are rather cryptic. It took me some time to figure it out, the portion with not able to contact the virtual router. After I rebooted the virtual router under this account I was able to create new VM's. -----Original Message----- From: Geoff Higginbottom [mailto:geoff.higginbot...@shapeblue.com] Sent: Friday, May 30, 2014 12:09 PM To: users@cloudstack.apache.org Subject: RE: Can't create VM under specific account Hi Peter, The log section you included does not appear to highlight the error, but have you checked ALL of the Accounts limits, such as total number of vCPUs across all VMs etc. Regards Geoff Higginbottom D: +44 20 3603 0542 | S: +44 20 3603 0540 | M: +447968161581 geoff.higginbot...@shapeblue.com -----Original Message----- From: Peter Sadowski [mailto:psadow...@dbr360.com] Sent: 30 May 2014 16:30 To: users@cloudstack.apache.org Subject: Can't create VM under specific account Hello, I'm having a strange issue under one account, which cannot spin up a VM. I have plenty of capacity in terms of cpu/memory/storage, but for some reason the VM creation fails. When trying with different accounts, VM's are created no problems. Any pointers would be appreciated. The error log is below. [root@mgmt-01 management]# grep job-4180 management-server.log 2014-05-30 11:01:17,301 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-4:null) submit async job-4180, details: AsyncJobVO {id:4180, userId: 52, accountId: 52, sessionKey: null, instanceType: VirtualMachine, instanceId: 291, cmd: com.cloud.api.commands.DeployVMCmd, cmdOriginator: null, cmdInfo: {"serviceofferingid":"e989a1ff-e311-4eed-83da-f65bc4b615b7","keyboard":"","ctxUserId":"52","zoneid":"a3ee28a3-5ea5-4b34-9322-ee2530e03301","templateid":"4d9ac466-d3c3-4196-982f-a1838ba0012c","domainid":"99a65170-11f6-49e6-91c5-33d1237a165f","networkids":"8f9caca4-e150-401b-a719-1083a6c011fa,0de0333d-eebf-4b9f-9fbf-c3bc13edc2c1","apikey":"wfwvLHoSAY9LzD_n0Ji6JZlar2QpPrCvkB7hAfDOt5vYkRniGoDM7SO8hyTqZngPf1PqlX1BRhScrcm3-I1AgA","id":"291","hypervisor":"XenServer","name":"tsiapp01","account":"ptearne","ctxAccountId":"52","ctxStartEventId":"76571","signature":"iIzlDRdf9eKP+w6cppDdZRq9bjI\u003d","displayname":"tsiapp01"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 257985870280807, completeMsid: null, lastUpdated: null, lastPolled: null, created: null} 2014-05-30 11:01:17,306 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-1:job-4180) Executing com.cloud.api.commands.DeployVMCmd for job-4180 2014-05-30 11:01:17,499 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-1:job-4180) Access to VM[User|tsiapp01] granted to Acct[52-ptearne] by DomainChecker 2014-05-30 11:01:17,602 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Service SecurityGroup is not supported in the network id=231 2014-05-30 11:01:17,684 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Service SecurityGroup is not supported in the network id=238 2014-05-30 11:01:17,716 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Service SecurityGroup is not supported in the network id=231 2014-05-30 11:01:17,731 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Service SecurityGroup is not supported in the network id=238 2014-05-30 11:01:17,780 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) VM state transitted from :Stopped to Starting with event: StartRequestedvm's original host id: null new host id: null host id before state transition: null 2014-05-30 11:01:17,781 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-4180) Successfully transitioned to start state for VM[User|tsiapp01] reservation id = bc00de2f-4c97-421d-bb7f-da01a333a586 2014-05-30 11:01:17,807 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-4180) Trying to deploy VM, vm has dcId: 1 and podId: null 2014-05-30 11:01:17,808 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-4180) Deploy avoids pods: null, clusters: null, hosts: null 2014-05-30 11:01:17,824 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) DeploymentPlanner allocation algorithm: random 2014-05-30 11:01:17,824 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 4000, requested ram: 8589934592 2014-05-30 11:01:17,824 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Is ROOT volume READY (pool already allocated)?: No 2014-05-30 11:01:17,824 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Searching all possible resources under this Zone: 1 2014-05-30 11:01:17,838 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1 2014-05-30 11:01:17,845 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) CPUOverprovisioningFactor considered: 2.0 2014-05-30 11:01:17,920 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Checking resources in Cluster: 1 under Pod: 1 2014-05-30 11:01:17,920 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Calling HostAllocators to find suitable hosts 2014-05-30 11:01:17,920 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1 2014-05-30 11:01:17,935 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) FirstFitAllocator has 6 hosts to check for allocation: [Host[-2-Routing], Host[-45-Routing], Host[-3-Routing], Host[-6-Routing], Host[-5-Routing], Host[-1-Routing]] 2014-05-30 11:01:18,004 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Found 6 hosts for allocation after prioritization: [Host[-2-Routing], Host[-45-Routing], Host[-3-Routing], Host[-6-Routing], Host[-5-Routing], Host[-1-Routing]] 2014-05-30 11:01:18,004 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Looking for speed=4000Mhz, Ram=8192 2014-05-30 11:01:18,030 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Checking if host: 2 has enough capacity for requested CPU: 4000 and requested RAM: 8589934592 , cpuOverprovisioningFactor: 2.0 2014-05-30 11:01:18,045 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 128000 2014-05-30 11:01:18,045 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free CPU: 91500 , Requested CPU: 4000 2014-05-30 11:01:18,045 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free RAM: 94066777344 , Requested RAM: 8589934592 2014-05-30 11:01:18,045 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Host has enough CPU and RAM available 2014-05-30 11:01:18,045 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 2, used: 36500, reserved: 0, actual total: 64000, total with overprovisioning: 128000; requested cpu:4000,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,046 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 2, used: 40265318400, reserved: 0, total: 134332095744; requested mem: 8589934592,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,046 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Found a suitable host, adding to list: 2 2014-05-30 11:01:18,059 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Checking if host: 45 has enough capacity for requested CPU: 4000 and requested RAM: 8589934592 , cpuOverprovisioningFactor: 2.0 2014-05-30 11:01:18,074 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 128000 2014-05-30 11:01:18,074 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free CPU: 112000 , Requested CPU: 4000 2014-05-30 11:01:18,074 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free RAM: 117152226560 , Requested RAM: 8589934592 2014-05-30 11:01:18,074 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Host has enough CPU and RAM available 2014-05-30 11:01:18,074 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 45, used: 16000, reserved: 0, actual total: 64000, total with overprovisioning: 128000; requested cpu:4000,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,074 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 45, used: 17179869184, reserved: 0, total: 134332095744; requested mem: 8589934592,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,075 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Found a suitable host, adding to list: 45 2014-05-30 11:01:18,088 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Checking if host: 3 has enough capacity for requested CPU: 4000 and requested RAM: 8589934592 , cpuOverprovisioningFactor: 2.0 2014-05-30 11:01:18,103 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 128000 2014-05-30 11:01:18,103 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free CPU: 101000 , Requested CPU: 4000 2014-05-30 11:01:18,103 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free RAM: 99569704192 , Requested RAM: 8589934592 2014-05-30 11:01:18,103 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Host has enough CPU and RAM available 2014-05-30 11:01:18,103 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 3, used: 27000, reserved: 0, actual total: 64000, total with overprovisioning: 128000; requested cpu:4000,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,103 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 3, used: 34762391552, reserved: 0, total: 134332095744; requested mem: 8589934592,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,104 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Found a suitable host, adding to list: 3 2014-05-30 11:01:18,117 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Checking if host: 6 has enough capacity for requested CPU: 4000 and requested RAM: 8589934592 , cpuOverprovisioningFactor: 2.0 2014-05-30 11:01:18,132 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 128000 2014-05-30 11:01:18,132 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free CPU: 110000 , Requested CPU: 4000 2014-05-30 11:01:18,132 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free RAM: 115541613824 , Requested RAM: 8589934592 2014-05-30 11:01:18,132 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Host has enough CPU and RAM available 2014-05-30 11:01:18,132 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 6, used: 18000, reserved: 0, actual total: 64000, total with overprovisioning: 128000; requested cpu:4000,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,132 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 6, used: 18790481920, reserved: 0, total: 134332095744; requested mem: 8589934592,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,133 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Found a suitable host, adding to list: 6 2014-05-30 11:01:18,147 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Checking if host: 5 has enough capacity for requested CPU: 4000 and requested RAM: 8589934592 , cpuOverprovisioningFactor: 2.0 2014-05-30 11:01:18,162 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 128000 2014-05-30 11:01:18,163 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free CPU: 90500 , Requested CPU: 4000 2014-05-30 11:01:18,163 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free RAM: 72457723136 , Requested RAM: 8589934592 2014-05-30 11:01:18,163 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Host has enough CPU and RAM available 2014-05-30 11:01:18,163 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 5, used: 37500, reserved: 0, actual total: 64000, total with overprovisioning: 128000; requested cpu:4000,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,163 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 5, used: 61874372608, reserved: 0, total: 134332095744; requested mem: 8589934592,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,163 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Found a suitable host, adding to list: 5 2014-05-30 11:01:18,179 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 4000 and requested RAM: 8589934592 , cpuOverprovisioningFactor: 2.0 2014-05-30 11:01:18,193 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Hosts's actual total CPU: 26000 and CPU after applying overprovisioning: 52000 2014-05-30 11:01:18,194 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free CPU: 32000 , Requested CPU: 4000 2014-05-30 11:01:18,194 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Free RAM: 98898615552 , Requested RAM: 8589934592 2014-05-30 11:01:18,194 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Host has enough CPU and RAM available 2014-05-30 11:01:18,194 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 20000, reserved: 0, actual total: 26000, total with overprovisioning: 52000; requested cpu:4000,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,194 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 35433480192, reserved: 0, total: 134332095744; requested mem: 8589934592,alloc_from_last_host?:false ,considerReservedCapacity?: true 2014-05-30 11:01:18,194 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Found a suitable host, adding to list: 1 2014-05-30 11:01:18,194 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-1:job-4180 FirstFitRoutingAllocator) Host Allocator returning 6 suitable hosts 2014-05-30 11:01:18,203 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Checking suitable pools for volume (Id, Type): (416,ROOT) 2014-05-30 11:01:18,203 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) We need to allocate new storagepool for this volume 2014-05-30 11:01:18,212 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Calling StoragePoolAllocators to find suitable pools 2014-05-30 11:01:18,221 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-1:job-4180) Looking for pools in dc: 1 pod:1 cluster:1 having tags:[sata] 2014-05-30 11:01:18,236 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-1:job-4180) FirstFitStoragePoolAllocator has 1 pools to check for allocation 2014-05-30 11:01:18,236 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-1:job-4180) Checking if storage pool is suitable, name: NJR2-Z1-P1-C1-D1 ,poolId: 204 2014-05-30 11:01:18,237 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-1:job-4180) Is localStorageAllocationNeeded? false 2014-05-30 11:01:18,237 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-1:job-4180) Is storage pool shared? true 2014-05-30 11:01:18,244 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-1:job-4180) Attempting to look for pool 204 for storage, totalSize: 5222680231936, usedBytes: 3857897684992, usedPct: 0.738681579891004, disable threshold: 0.9 2014-05-30 11:01:18,263 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-1:job-4180) Attempting to look for pool 204 for storage, maxSize : 20890720927744, totalAllocatedSize : 8235745441792, askingSize : 42949672960, allocated disable threshold: 0.9 2014-05-30 11:01:18,263 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-1:job-4180) FirstFitStoragePoolAllocator returning 1 suitable storage pools 2014-05-30 11:01:18,263 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM 2014-05-30 11:01:18,263 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Checking if host: 2 can access any suitable storage pool for volume: ROOT 2014-05-30 11:01:18,271 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Host: 2 can access pool: 204 2014-05-30 11:01:18,271 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Found a potential host id: 2 name: nj5-z1p1c1h04 and associated storage pools for this VM 2014-05-30 11:01:18,280 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(2)-Storage(Volume(416|ROOT-->Pool(204))] 2014-05-30 11:01:18,281 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-4180) Deployment found - P0=VM[User|tsiapp01], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(2)-Storage(Volume(416|ROOT-->Pool(204))] 2014-05-30 11:01:18,319 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 2 host id before state transition: null 2014-05-30 11:01:18,363 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 128000 2014-05-30 11:01:18,363 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) We are allocating VM, increasing the used capacity of this host:2 2014-05-30 11:01:18,363 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) Current Used CPU: 36500 , Free CPU:91500 ,Requested CPU: 4000 2014-05-30 11:01:18,363 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) Current Used RAM: 40265318400 , Free RAM:94066777344 ,Requested RAM: 8589934592 2014-05-30 11:01:18,363 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) CPU STATS after allocation: for host: 2, old used: 36500, old reserved: 0, actual total: 64000, total with overprovisioning: 128000; new used:40500, reserved:0; requested cpu:4000,alloc_from_last:false 2014-05-30 11:01:18,363 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) RAM STATS after allocation: for host: 2, old used: 40265318400, old reserved: 0, total: 134332095744; new used: 48855252992, reserved: 0; requested mem: 8589934592,alloc_from_last:false 2014-05-30 11:01:18,391 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-4180) VM is being created in podId: 1 2014-05-30 11:01:18,417 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Lock is acquired for network id 231 as a part of network implement 2014-05-30 11:01:18,417 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Network id=231 is already implemented 2014-05-30 11:01:18,423 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Lock is released for network id 231 as a part of network implement 2014-05-30 11:01:18,515 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Service SecurityGroup is not supported in the network id=231 2014-05-30 11:01:18,543 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Changing active number of nics for network id=231 on 1 2014-05-30 11:01:18,581 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking JuniperSRX to prepare for Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:18,610 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking Netscaler to prepare for Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:18,636 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking F5BigIp to prepare for Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:18,663 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking VirtualRouter to prepare for Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:18,738 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-1:job-4180) Lock is acquired for network id 231 as a part of router startup in Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(2)-Storage(Volume(416|ROOT-->Pool(204))] 2014-05-30 11:01:18,763 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-1:job-4180) Lock is released for network id 231 as a part of router startup in Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(2)-Storage(Volume(416|ROOT-->Pool(204))] 2014-05-30 11:01:18,815 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Service SecurityGroup is not supported in the network id=231 2014-05-30 11:01:18,835 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-1:job-4180) Applying dhcp entry in network Ntwk[231|Guest|8] 2014-05-30 11:01:18,979 DEBUG [agent.manager.ClusteredAgentAttache] (Job-Executor-1:job-4180) Seq 3-46465042: Forwarding Seq 3-46465042: { Cmd , MgmtId: 257985870280807, via: 3, Ver: v1, Flags: 100111, [{"routing.DhcpEntryCommand":{"vmMac":"02:00:13:5f:00:29","vmIpAddress":"172.30.0.245","vmName":"tsiapp01","defaultRouter":"172.30.0.1","defaultDns":"172.30.0.1","accessDetails":{"router.guest.ip":"172.30.0.1","zone.network.type":"Advanced","router.name":"r-258-VM","router.ip":"169.254.1.143"},"wait":0}}] } to 42026829063690 2014-05-30 11:01:30,993 DEBUG [agent.transport.Request] (Job-Executor-1:job-4180) Seq 3-46465042: Received: { Ans: , MgmtId: 257985870280807, via: 3, Ver: v1, Flags: 110, { Answer } } 2014-05-30 11:01:30,994 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-4180) Unable to contact resource. 2014-05-30 11:01:31,023 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-4180) Cleaning up resources for the vm VM[User|tsiapp01] in Starting state 2014-05-30 11:01:31,041 DEBUG [agent.manager.ClusteredAgentAttache] (Job-Executor-1:job-4180) Seq 2-154009619: Forwarding Seq 2-154009619: { Cmd , MgmtId: 257985870280807, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"i-52-291-VM","wait":0}}] } to 42026829063690 2014-05-30 11:01:31,269 DEBUG [agent.transport.Request] (Job-Executor-1:job-4180) Seq 2-154009619: Received: { Ans: , MgmtId: 257985870280807, via: 2, Ver: v1, Flags: 110, { StopAnswer } } 2014-05-30 11:01:31,337 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Service SecurityGroup is not supported in the network id=231 2014-05-30 11:01:31,375 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Changing active number of nics for network id=231 on -1 2014-05-30 11:01:31,402 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking JuniperSRX to release Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:31,402 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking Netscaler to release Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:31,402 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking F5BigIp to release Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:31,402 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking VirtualRouter to release Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:31,403 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking Ovs to release Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:31,403 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking ExternalDhcpServer to release Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:31,403 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking BareMetal to release Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:31,403 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking SecurityGroupProvider to release Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:31,403 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking CiscoNexus1000vVSM to release Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:31,403 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-1:job-4180) Asking VpcVirtualRouter to release Nic[492-291-bc00de2f-4c97-421d-bb7f-da01a333a586-172.30.0.245] 2014-05-30 11:01:31,411 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-4180) Successfully released network resources for the vm VM[User|tsiapp01] 2014-05-30 11:01:31,412 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-4180) Successfully cleanued up resources for the vm VM[User|tsiapp01] in Starting state 2014-05-30 11:01:31,419 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-4180) DataCenter id = '1' provided is in avoid set, DeploymentPlanner cannot allocate the VM, returning. 2014-05-30 11:01:31,464 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 2 2014-05-30 11:01:31,489 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 128000 2014-05-30 11:01:31,489 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) release cpu from host: 2, old used: 40500,reserved: 0, actual total: 64000, total with overprovisioning: 128000; new used: 36500,reserved:0; movedfromreserved: false,moveToReserveredfalse 2014-05-30 11:01:31,490 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) release mem from host: 2, old used: 48855252992,reserved: 0, total: 134332095744; new used: 40265318400,reserved:0; movedfromreserved: false,moveToReserveredfalse 2014-05-30 11:01:31,519 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-1:job-4180) Destroying vm VM[User|tsiapp01] as it failed to create 2014-05-30 11:01:31,571 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-4180) 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 2014-05-30 11:01:31,788 ERROR [cloud.alert.AlertManagerImpl] (Job-Executor-1:job-4180) Problem sending email alert 2014-05-30 11:01:31,877 INFO [api.commands.DeployVMCmd] (Job-Executor-1:job-4180) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|tsiapp01]Scope=interface com.cloud.dc.DataCenter; id=1 2014-05-30 11:01:31,878 WARN [cloud.api.ApiDispatcher] (Job-Executor-1:job-4180) class com.cloud.api.ServerApiException : Unable to create a deployment for VM[User|tsiapp01] 2014-05-30 11:01:31,879 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-1:job-4180) Complete async job-4180, jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable to create a deployment for VM[User|tsiapp01] 2014-05-30 11:01:32,927 DEBUG [cloud.async.AsyncJobManagerImpl] (ApiServer-4:null) Async job-4180 completed Find out more about ShapeBlue and our range of CloudStack related services IaaS Cloud Design & Build<http://shapeblue.com/iaas-cloud-design-and-build//> CSForge – rapid IaaS deployment framework<http://shapeblue.com/csforge/> CloudStack Consulting<http://shapeblue.com/cloudstack-consultancy/> CloudStack Infrastructure Support<http://shapeblue.com/cloudstack-infrastructure-support/> CloudStack Bootcamp Training Courses<http://shapeblue.com/cloudstack-training/> This email and any attachments to it may be confidential and are intended solely for the use of the individual to whom it is addressed. Any views or opinions expressed are solely those of the author and do not necessarily represent those of Shape Blue Ltd or related companies. If you are not the intended recipient of this email, you must neither take any action based upon its contents, nor copy or show it to anyone. Please contact the sender if you believe you have received this email in error. Shape Blue Ltd is a company incorporated in England & Wales. ShapeBlue Services India LLP is a company incorporated in India and is operated under license from Shape Blue Ltd. Shape Blue Brasil Consultoria Ltda is a company incorporated in Brasil and is operated under license from Shape Blue Ltd. ShapeBlue is a registered trademark. Find out more about ShapeBlue and our range of CloudStack related services IaaS Cloud Design & Build<http://shapeblue.com/iaas-cloud-design-and-build//> CSForge – rapid IaaS deployment framework<http://shapeblue.com/csforge/> CloudStack Consulting<http://shapeblue.com/cloudstack-consultancy/> CloudStack Infrastructure Support<http://shapeblue.com/cloudstack-infrastructure-support/> CloudStack Bootcamp Training Courses<http://shapeblue.com/cloudstack-training/> This email and any attachments to it may be confidential and are intended solely for the use of the individual to whom it is addressed. Any views or opinions expressed are solely those of the author and do not necessarily represent those of Shape Blue Ltd or related companies. If you are not the intended recipient of this email, you must neither take any action based upon its contents, nor copy or show it to anyone. Please contact the sender if you believe you have received this email in error. Shape Blue Ltd is a company incorporated in England & Wales. ShapeBlue Services India LLP is a company incorporated in India and is operated under license from Shape Blue Ltd. Shape Blue Brasil Consultoria Ltda is a company incorporated in Brasil and is operated under license from Shape Blue Ltd. ShapeBlue is a registered trademark.