CS on Ubuntu 12.04 LTS, 4.1 is working correctly on the same hardware
(partition1).
This problem is with CS 4.3 on Ubuntu 14.04 LTS (partition2):
2014-09-01 17:21:23,267 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Job-Executor-6:ctx-d1e72afb) Add job-27 into job monitoring
2014-09-01 17:21:23,267 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Job-Executor-6:ctx-d1e72afb) Executing AsyncJobVO {id:27, userId: 2,
accountId: 2, instanceType: VirtualMachine, instanceId: 6, cmd:
org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdInfo:
{"sessionkey":"aaaaaaaaaaaaaa/bbbbbbbbbbbbb/cccc","serviceofferingid":"dddddddddddddddddddddddddddd","cmdEventType":"VM.CREATE","ctxUserId":"2","zoneid":"eeeeeeeeeeeeeeeeeeeeeeee","httpmethod":"GET","networkids":"ffffffffffffffffffffffffffffffff","response":"json","id":"6","hypervisor":"KVM","name":"ubuntu-12-04-64bit-admin-Instance","_":"1409572282666","ctxAccountId":"2","diskofferingid":"99218ad6-b601-4dc1-a266-9b0616e7474a","ctxStartEventId":"105","displayname":"ubuntu-12-04-64bit-admin-Instance"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 279278805451282, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null}
2014-09-01 17:21:23,272 DEBUG [c.c.a.ApiDispatcher]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) InfrastructureEntity name
is:com.cloud.offering.ServiceOffering
2014-09-01 17:21:23,273 DEBUG [c.c.a.ApiDispatcher]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) ControlledEntity name
is:com.cloud.template.VirtualMachineTemplate
2014-09-01 17:21:23,275 DEBUG [c.c.a.ApiDispatcher]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) ControlledEntity name
is:com.cloud.network.Network
2014-09-01 17:21:23,277 DEBUG [c.c.a.ApiDispatcher]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) InfrastructureEntity name
is:com.cloud.offering.DiskOffering
2014-09-01 17:21:23,443 DEBUG [c.c.n.NetworkModelImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Service SecurityGroup is not
supported in the network id=204
2014-09-01 17:21:23,445 DEBUG [c.c.n.NetworkModelImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Service SecurityGroup is not
supported in the network id=204
2014-09-01 17:21:23,455 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Deploy avoids pods: [], clusters:
[], hosts: []
2014-09-01 17:21:23,456 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) DeploymentPlanner allocation
algorithm: com.cloud.deploy.FirstFitPlanner@7c4a754a
2014-09-01 17:21:23,456 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Trying to allocate a host and
storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested
ram: 1073741824
2014-09-01 17:21:23,456 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Is ROOT volume READY (pool already
allocated)?: No
2014-09-01 17:21:23,456 DEBUG [c.c.d.FirstFitPlanner]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Searching all possible resources
under this Zone: 1
2014-09-01 17:21:23,457 DEBUG [c.c.d.FirstFitPlanner]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Listing clusters in order of
aggregate capacity, that have (atleast one host with) enough CPU and RAM
capacity under this Zone: 1
2014-09-01 17:21:23,459 DEBUG [c.c.d.FirstFitPlanner]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Removing from the clusterId list
these clusters from avoid set: []
2014-09-01 17:21:23,463 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Checking resources in Cluster: 1
under Pod: 1
2014-09-01 17:21:23,463 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) Looking for
hosts in dc: 1 pod:1 cluster:1
2014-09-01 17:21:23,465 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator)
FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
2014-09-01 17:21:23,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) Found 1
hosts for allocation after prioritization: [Host[-1-Routing]]
2014-09-01 17:21:23,466 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) Looking for
speed=1000Mhz, Ram=1024
2014-09-01 17:21:23,469 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) Host: 1 has
cpu capability (cpu:4, speed:2801) to support requested CPU: 1 and requested
speed: 1000
2014-09-01 17:21:23,469 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) Checking if
host: 1 has enough capacity for requested CPU: 1000 and requested RAM:
1073741824 , cpuOverprovisioningFactor: 1.0
2014-09-01 17:21:23,471 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) Hosts's
actual total CPU: 11204 and CPU after applying overprovisioning: 11204
2014-09-01 17:21:23,471 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) Free CPU:
10204 , Requested CPU: 1000
2014-09-01 17:21:23,471 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) Free RAM:
15086501888 , Requested RAM: 1073741824
2014-09-01 17:21:23,471 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) Host has
enough CPU and RAM available
2014-09-01 17:21:23,471 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) STATS: Can
alloc CPU from host: 1, used: 1000, reserved: 0, actual total: 11204, total
with overprovisioning: 11204; requested cpu:1000,alloc_from_last_host?:false
,considerReservedCapacity?: true
2014-09-01 17:21:23,471 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) STATS: Can
alloc MEM from host: 1, used: 1610612736, reserved: 0, total: 16697114624;
requested mem: 1073741824,alloc_from_last_host?:false
,considerReservedCapacity?: true
2014-09-01 17:21:23,471 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) Found a
suitable host, adding to list: 1
2014-09-01 17:21:23,471 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336 FirstFitRoutingAllocator) Host
Allocator returning 1 suitable hosts
2014-09-01 17:21:23,472 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Checking suitable pools for volume
(Id, Type): (5,ROOT)
2014-09-01 17:21:23,472 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) We need to allocate new storagepool
for this volume
2014-09-01 17:21:23,473 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Calling StoragePoolAllocators to
find suitable pools
2014-09-01 17:21:23,473 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) LocalStoragePoolAllocator trying to
find storage pool to fit the vm
2014-09-01 17:21:23,474 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) ClusterScopeStoragePoolAllocator
looking for storage pool
2014-09-01 17:21:23,474 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Looking for pools in dc: 1 pod:1
cluster:1
2014-09-01 17:21:23,475 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Found pools matching tags: []
2014-09-01 17:21:23,475 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) No storage pools available for
shared volume allocation, returning
2014-09-01 17:21:23,475 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) ZoneWideStoragePoolAllocator to find
storage pool
2014-09-01 17:21:23,477 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Removing pool
Pool[1|NetworkFilesystem] from avoid set, must have been inserted when
searching for another disk's tag
2014-09-01 17:21:23,480 DEBUG [c.c.s.StorageManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Checking pool 1 for storage,
totalSize: 455581106176, usedBytes: 12836667392, usedPct: 0.028176470046676918,
disable threshold: 0.85
2014-09-01 17:21:23,482 DEBUG [c.c.s.StorageManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Checking pool: 1 for volume
allocation [Vol[5|vm=6|ROOT]], maxSize : 911162212352, totalAllocatedSize : 0,
askingSize : 107374182400, allocated disable threshold: 0.85
2014-09-01 17:21:23,482 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Trying to find a potenial host and
associated storage pools from the suitable host/pool lists for this VM
2014-09-01 17:21:23,482 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Checking if host: 1 can access any
suitable storage pool for volume: ROOT
2014-09-01 17:21:23,483 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Host: 1 can access pool: 1
2014-09-01 17:21:23,483 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Found a potential host id: 1 name:
ubuntu.movingtoclouds.com and associated storage pools for this VM
2014-09-01 17:21:23,484 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) 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(1)-Storage(Volume(5|ROOT-->Pool(1))]
2014-09-01 17:21:23,580 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) 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-09-01 17:21:23,580 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Successfully transitioned to start
state for VM[User|ubuntu-12-04-64bit-admin-Instance] reservation id =
ae334dd1-2b6a-41eb-952d-8c8f0742cc52
2014-09-01 17:21:23,666 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Trying to deploy VM, vm has dcId: 1
and podId: null
2014-09-01 17:21:23,666 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) advanceStart: DeploymentPlan is
provided, using dcId:1, podId: 1, clusterId: 1, hostId: 1, poolId: null
2014-09-01 17:21:23,666 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Deploy avoids pods: null, clusters:
null, hosts: null
2014-09-01 17:21:23,670 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Deploy avoids pods: [], clusters:
[], hosts: []
2014-09-01 17:21:23,671 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) DeploymentPlanner allocation
algorithm: com.cloud.deploy.FirstFitPlanner@7c4a754a
2014-09-01 17:21:23,671 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Trying to allocate a host and
storage pools from dc:1, pod:1,cluster:1, requested cpu: 1000, requested ram:
1073741824
2014-09-01 17:21:23,671 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Is ROOT volume READY (pool already
allocated)?: No
2014-09-01 17:21:23,671 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) DeploymentPlan has host_id
specified, choosing this host and making no checks on this host: 1
2014-09-01 17:21:23,672 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Looking for suitable pools for this
host under zone: 1, pod: 1, cluster: 1
2014-09-01 17:21:23,673 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Checking suitable pools for volume
(Id, Type): (5,ROOT)
2014-09-01 17:21:23,673 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) We need to allocate new storagepool
for this volume
2014-09-01 17:21:23,673 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Calling StoragePoolAllocators to
find suitable pools
2014-09-01 17:21:23,673 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) LocalStoragePoolAllocator trying to
find storage pool to fit the vm
2014-09-01 17:21:23,673 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) ClusterScopeStoragePoolAllocator
looking for storage pool
2014-09-01 17:21:23,673 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Looking for pools in dc: 1 pod:1
cluster:1
2014-09-01 17:21:23,674 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Found pools matching tags: []
2014-09-01 17:21:23,674 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) No storage pools available for
shared volume allocation, returning
2014-09-01 17:21:23,674 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) ZoneWideStoragePoolAllocator to find
storage pool
2014-09-01 17:21:23,676 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Removing pool
Pool[1|NetworkFilesystem] from avoid set, must have been inserted when
searching for another disk's tag
2014-09-01 17:21:23,677 DEBUG [c.c.s.StorageManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Checking pool 1 for storage,
totalSize: 455581106176, usedBytes: 12836667392, usedPct: 0.028176470046676918,
disable threshold: 0.85
2014-09-01 17:21:23,680 DEBUG [c.c.s.StorageManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Checking pool: 1 for volume
allocation [Vol[5|vm=6|ROOT]], maxSize : 911162212352, totalAllocatedSize : 0,
askingSize : 107374182400, allocated disable threshold: 0.85
2014-09-01 17:21:23,680 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Trying to find a potenial host and
associated storage pools from the suitable host/pool lists for this VM
2014-09-01 17:21:23,680 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Checking if host: 1 can access any
suitable storage pool for volume: ROOT
2014-09-01 17:21:23,681 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Host: 1 can access pool: 1
2014-09-01 17:21:23,681 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Found a potential host id: 1 name:
ubuntu.movingtoclouds.com and associated storage pools for this VM
2014-09-01 17:21:23,681 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) 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(1)-Storage(Volume(5|ROOT-->Pool(1))]
2014-09-01 17:21:23,681 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Deployment found -
P0=VM[User|ubuntu-12-04-64bit-admin-Instance],
P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
: Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(5|ROOT-->Pool(1))]
2014-09-01 17:21:23,832 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) VM state transitted from :Starting
to Starting with event: OperationRetryvm's original host id: null new host id:
1 host id before state transition: null
2014-09-01 17:21:23,840 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Hosts's actual total CPU: 11204 and
CPU after applying overprovisioning: 11204
2014-09-01 17:21:23,840 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) We are allocating VM, increasing the
used capacity of this host:1
2014-09-01 17:21:23,840 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Current Used CPU: 1000 , Free
CPU:10204 ,Requested CPU: 1000
2014-09-01 17:21:23,840 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Current Used RAM: 1610612736 , Free
RAM:15086501888 ,Requested RAM: 1073741824
2014-09-01 17:21:23,840 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) CPU STATS after allocation: for
host: 1, old used: 1000, old reserved: 0, actual total: 11204, total with
overprovisioning: 11204; new used:2000, reserved:0; requested
cpu:1000,alloc_from_last:false
2014-09-01 17:21:23,840 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) RAM STATS after allocation: for
host: 1, old used: 1610612736, old reserved: 0, total: 16697114624; new used:
2684354560, reserved: 0; requested mem: 1073741824,alloc_from_last:false
2014-09-01 17:21:23,949 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) VM is being created in podId: 1
2014-09-01 17:21:23,954 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Lock is acquired for network id 204
as a part of network implement
2014-09-01 17:21:23,954 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Asking ExternalGuestNetworkGuru to
implement Ntwk[204|Guest|8]
2014-09-01 17:21:24,062 DEBUG [c.c.u.d.T.Transaction]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Rolling back the transaction: Time =
1 Name = Job-Executor-6; called by
-TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:35-ReflectiveMethodInvocation.proceed:161-ExposeInvocationInterceptor.invoke:91-ReflectiveMethodInvocation.proceed:172-JdkDynamicAopProxy.invoke:204-$Proxy35.take:-1-DataCenterDaoImpl.allocateVnet:212-NativeMethodAccessorImpl.invoke0:-2-NativeMethodAccessorImpl.invoke:57
2014-09-01 17:21:24,063 INFO [c.c.u.e.CSExceptionErrorCode]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Could not find exception:
com.cloud.exception.InsufficientVirtualNetworkCapcityException in error code
list for exceptions
2014-09-01 17:21:24,063 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Cleaning up because we're unable to
implement the network Ntwk[204|Guest|8]
2014-09-01 17:21:24,196 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Lock is acquired for network
Ntwk[204|Guest|8] as a part of network shutdown
2014-09-01 17:21:24,252 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Releasing 0 port forwarding rules
for network id=204 as a part of shutdownNetworkRules
2014-09-01 17:21:24,252 DEBUG [c.c.n.f.FirewallManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) There are no rules to forward to the
network elements
2014-09-01 17:21:24,253 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Releasing 0 static nat rules for
network id=204 as a part of shutdownNetworkRules
2014-09-01 17:21:24,253 DEBUG [c.c.n.f.FirewallManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) There are no rules to forward to the
network elements
2014-09-01 17:21:24,253 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Revoking 0 Public load balancing
rules for network id=204
2014-09-01 17:21:24,254 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) There are no Load Balancing Rules to
forward to the network elements
2014-09-01 17:21:24,254 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Revoking 0 Internal load balancing
rules for network id=204
2014-09-01 17:21:24,254 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) There are no Load Balancing Rules to
forward to the network elements
2014-09-01 17:21:24,255 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Releasing 0 firewall ingress rules
for network id=204 as a part of shutdownNetworkRules
2014-09-01 17:21:24,255 DEBUG [c.c.n.f.FirewallManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) There are no rules to forward to the
network elements
2014-09-01 17:21:24,256 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Releasing 0 firewall egress rules
for network id=204 as a part of shutdownNetworkRules
2014-09-01 17:21:24,258 DEBUG [c.c.n.f.FirewallManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) applying default firewall egress
rules
2014-09-01 17:21:24,265 DEBUG [c.c.n.e.VirtualRouterElement]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Virtual router elemnt doesn't need
to apply firewall rules on the backend; virtual router doesn't exist in the
network 204
2014-09-01 17:21:24,265 DEBUG [c.c.n.f.FirewallManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) There are no rules to forward to the
network elements
2014-09-01 17:21:24,265 DEBUG [c.c.n.r.RulesManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Found 0 static nat rules to apply
for network id 204
2014-09-01 17:21:24,269 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Sending network shutdown to
VirtualRouter
2014-09-01 17:21:24,270 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Network id=204 is shutdown
successfully, cleaning up corresponding resources now.
2014-09-01 17:21:24,459 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Lock is released for network
Ntwk[204|Guest|8] as a part of network shutdown
2014-09-01 17:21:24,460 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Lock is released for network id 204
as a part of network implement
2014-09-01 17:21:24,460 INFO [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Insufficient capacity
2014-09-01 17:21:24,559 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Cleaning up resources for the vm
VM[User|ubuntu-12-04-64bit-admin-Instance] in Starting state
2014-09-01 17:21:24,562 DEBUG [c.c.a.t.Request] (Job-Executor-6:ctx-d1e72afb
ctx-21bde336) Seq 1-1238433898: Sending { Cmd , MgmtId: 279278805451282, via:
1(ubuntu.movingtoclouds.com), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-2-6-VM","wait":0}}]
}
2014-09-01 17:21:24,753 DEBUG [c.c.a.t.Request] (Job-Executor-6:ctx-d1e72afb
ctx-21bde336) Seq 1-1238433898: Received: { Ans: , MgmtId: 279278805451282,
via: 1, Ver: v1, Flags: 10, { StopAnswer } }
2014-09-01 17:21:24,760 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Successfully released network
resources for the vm VM[User|ubuntu-12-04-64bit-admin-Instance]
2014-09-01 17:21:24,760 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Successfully cleanued up resources
for the vm VM[User|ubuntu-12-04-64bit-admin-Instance] in Starting state
2014-09-01 17:21:24,768 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Deploy avoids pods: [], clusters:
[], hosts: [1]
2014-09-01 17:21:24,768 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) DataCenter id = '1' provided is in
avoid set, DeploymentPlanner cannot allocate the VM, returning.
2014-09-01 17:21:25,009 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) VM state transitted from :Starting
to Stopped with event: OperationFailedvm's original host id: null new host id:
null host id before state transition: 1
2014-09-01 17:21:25,016 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Hosts's actual total CPU: 11204 and
CPU after applying overprovisioning: 11204
2014-09-01 17:21:25,017 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Hosts's actual total RAM:
16697114624 and RAM after applying overprovisioning: 16697114624
2014-09-01 17:21:25,017 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) release cpu from host: 1, old used:
2000,reserved: 0, actual total: 11204, total with overprovisioning: 11204; new
used: 1000,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-09-01 17:21:25,017 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) release mem from host: 1, old used:
2684354560,reserved: 0, total: 16697114624; new used: 1610612736,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2014-09-01 17:21:25,274 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) 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-09-01 17:21:25,274 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Successfully transitioned to start
state for VM[User|ubuntu-12-04-64bit-admin-Instance] reservation id =
1c817c5f-dfc2-4328-9f90-5d6e99060f12
2014-09-01 17:21:25,360 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Trying to deploy VM, vm has dcId: 1
and podId: 1
2014-09-01 17:21:25,361 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Deploy avoids pods: [], clusters:
[], hosts: [1]
2014-09-01 17:21:25,370 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Deploy avoids pods: [], clusters:
[], hosts: [1]
2014-09-01 17:21:25,370 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) DataCenter id = '1' provided is in
avoid set, DeploymentPlanner cannot allocate the VM, returning.
2014-09-01 17:21:25,536 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) VM state transitted from :Starting
to Stopped with event: OperationFailedvm's original host id: null new host id:
null host id before state transition: null
2014-09-01 17:21:25,630 DEBUG [c.c.v.UserVmManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) Destroying vm
VM[User|ubuntu-12-04-64bit-admin-Instance] as it failed to create on Host with
Id:null
2014-09-01 17:21:25,719 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-6:ctx-d1e72afb ctx-21bde336) 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-09-01 17:21:26,080 WARN [o.a.c.alerts] (Job-Executor-6:ctx-d1e72afb
ctx-21bde336) alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId::
null // message:: Failed to deploy Vm with Id: 6, on Host with Id: null
2014-09-01 17:21:26,733 ERROR [c.c.a.ApiAsyncJobDispatcher]
(Job-Executor-6:ctx-d1e72afb) Unexpected exception while executing
org.apache.cloudstack.api.command.user.vm.DeployVMCmd
2014-09-01 17:21:26,736 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Job-Executor-6:ctx-d1e72afb) Complete async job-27, jobStatus: FAILED,
resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable
to start a VM due to insufficient capacity"}
2014-09-01 17:21:26,840 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Job-Executor-6:ctx-d1e72afb) Done executing
org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-27
2014-09-01 17:21:26,890 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Job-Executor-6:ctx-d1e72afb) Remove job-27 from job monitoring
________________________________
From: ilya musayev <[email protected]>
To: [email protected]
Sent: Wednesday, 3 September 2014 8:10 AM
Subject: Re: Unable to start a VM due to insufficient capacity
grep ctx-d1e72afb /var/log/cloudstack/management-server.log
Read through to see what happens, or post here...
On 9/1/14, 9:23 AM, abhisek basu wrote:
> You may want to review entire flow for job-27, which is related to this
> deployment failure. There are multiple possibilities for this insufficient
> capacity error.
>
> Sent from my iPhone
>
>> On 1 Sep 2014, at 6:49 pm, "Giri Prasad" <[email protected]> wrote:
>>
>> Hello,
>>
>> I have installed cs 4.3 on Ubuntu 14.04 LTS.
>>
>>
>> Created the usual infra, registered a couple of ISO's, and tried to created
>> a instance using the ISO, via the gui. Comes out with some error. Any ideas
>> on how to fix this?
>>
>> Thanks & Regards,
>> Giri
>> 2014-09-01 17:21:26,551 DEBUG [c.c.a.ApiServlet]
>> (catalina-exec-6:ctx-703486f7 ctx-ee65bd67) ===END=== XXX.XXX.XXX.5 -- GET
>> command=queryAsyncJobResult&jobId=1b7d53c6-256a-4721-b69c-d68c1f6d7d42&response=json&sessionkey=e6F89zbOUS4dR2%2FmrkznQBxeQ%2BM%3D&_=1409572286355
>> 2014-09-01 17:21:26,733 ERROR [c.c.a.ApiAsyncJobDispatcher]
>> (Job-Executor-6:ctx-d1e72afb) Unexpected exception while executing
>> org.apache.cloudstack.api.command.user.vm.DeployVMCmd
>> com.cloud.utils.exception.CloudRuntimeException: Unable to start a VM due to
>> insufficient capacity
>> at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:605)
>> at
>> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
>> at
>> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:207)
>> at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3581)
>> at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3161)
>> at
>> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3147)
>> 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.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)
>> Caused by: com.cloud.exception.InsufficientServerCapacityException: Unable
>> to create a deployment for
>> VM[User|ubuntu-12-04-64bit-admin-Instance]Scope=interface
>> com.cloud.dc.DataCenter; id=1
>> at
>> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:921)
>> at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:761)
>> at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:601)
>> ... 38 more
>> 2014-09-01 17:21:26,736 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (Job-Executor-6:ctx-d1e72afb) Complete async job-27, jobStatus: FAILED,
>> resultCode: 530, result:
>> org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable
>> to start a VM due to insufficient capacity"}
