You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by William Jiang <Wi...@manwin.com> on 2013/07/22 21:13:26 UTC
can't create VM after upgrade from 3.0.2 to 4,1. Error Code: 533
Error text: Unable to create a deployment for VM
Hi,
We just upgraded our cloudstack management server from 3.0.2 to 4.1, host xenserver from 6.0.2 to 6.1.
Everything looks fine but we have issue when we try to create a new VM, it showed me "Error Code: 533 Error text: Unable to create a deployment for VM "
the following is the detailed error log.
Any idea or comments will be greatly appreciated.
William
2013-07-22 13:51:37,884 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-17:null) submit async job-1036, details: AsyncJobVO {id:1036, userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine, instanceId: 176, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdOriginator: null, cmdInfo: {"sessionkey":"K5slfid24tK3AnhctgPy6HTidu4\u003d","ctxUserId":"2","serviceOfferingId":"c2bb9152-ca4b-4f19-8899-302df39df303","zoneId":"2e115e65-3a77-4a92-a01b-e61380b6e2fb","templateId":"f67d7b16-da53-4745-8871-4a35f9a0dc5f","response":"json","id":"176","hypervisor":"XenServer","name":"test0722-2","diskOfferingId":"678fb0dc-f055-4a48-9f17-0dca4049b9cf","_":"1374515893655","ctxAccountId":"2","ctxStartEventId":"9706","displayname":"test0722-2"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 110492071566, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-07-22 13:51:37,887 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-2:job-1036) Executing org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-1036
2013-07-22 13:51:37,893 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-2:job-1036) InfrastructureEntity name is:com.cloud.offering.ServiceOffering
2013-07-22 13:51:37,895 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-2:job-1036) ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
2013-07-22 13:51:37,897 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-2:job-1036) InfrastructureEntity name is:com.cloud.offering.DiskOffering
2013-07-22 13:51:37,956 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) DeploymentPlanner allocation algorithm: random
2013-07-22 13:51:37,957 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824
2013-07-22 13:51:37,957 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Is ROOT volume READY (pool already allocated)?: No
2013-07-22 13:51:37,957 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Searching all possible resources under this Zone: 1
2013-07-22 13:51:37,958 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2013-07-22 13:51:37,959 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) CPUOverprovisioningFactor considered: 1.0
2013-07-22 13:51:37,968 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Checking resources in Cluster: 1 under Pod: 1
2013-07-22 13:51:37,970 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2013-07-22 13:51:37,973 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) FirstFitAllocator has 4 hosts to check for allocation: [Host[-4-Routing], Host[-3-Routing], Host[-1-Routing], Host[-2-Routing]]
2013-07-22 13:51:37,977 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Found 4 hosts for allocation after prioritization: [Host[-4-Routing], Host[-3-Routing], Host[-1-Routing], Host[-2-Routing]]
2013-07-22 13:51:37,978 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Looking for speed=1000Mhz, Ram=1024
2013-07-22 13:51:37,984 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Checking if host: 4 has enough capacity for requested CPU: 1000 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2013-07-22 13:51:37,986 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 64000
2013-07-22 13:51:37,986 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Free CPU: 64000 , Requested CPU: 1000
2013-07-22 13:51:37,986 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Free RAM: 269593309440 , Requested RAM: 1073741824
2013-07-22 13:51:37,986 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Host has enough CPU and RAM available
2013-07-22 13:51:37,986 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 4, used: 0, reserved: 0, actual total: 64000, total with overprovisioning: 64000; requested cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-07-22 13:51:37,986 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 4, used: 0, reserved: 0, total: 269593309440; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-07-22 13:51:37,986 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Found a suitable host, adding to list: 4
2013-07-22 13:51:37,989 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Checking if host: 3 has enough capacity for requested CPU: 1000 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2013-07-22 13:51:37,990 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 64000
2013-07-22 13:51:37,990 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Free CPU: 25000 , Requested CPU: 1000
2013-07-22 13:51:37,990 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Free RAM: 214543069440 , Requested RAM: 1073741824
2013-07-22 13:51:37,990 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Host has enough CPU and RAM available
2013-07-22 13:51:37,991 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 3, used: 39000, reserved: 0, actual total: 64000, total with overprovisioning: 64000; requested cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-07-22 13:51:37,991 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 3, used: 55050240000, reserved: 0, total: 269593309440; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-07-22 13:51:37,991 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Found a suitable host, adding to list: 3
2013-07-22 13:51:37,992 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 1000 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2013-07-22 13:51:37,995 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 64000
2013-07-22 13:51:37,995 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Free CPU: 46500 , Requested CPU: 1000
2013-07-22 13:51:37,995 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Free RAM: 214698258688 , Requested RAM: 1073741824
2013-07-22 13:51:37,995 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Host has enough CPU and RAM available
2013-07-22 13:51:37,995 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 17500, reserved: 0, actual total: 64000, total with overprovisioning: 64000; requested cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-07-22 13:51:37,995 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 54895050752, reserved: 0, total: 269593309440; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-07-22 13:51:37,995 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2013-07-22 13:51:37,997 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Checking if host: 2 has enough capacity for requested CPU: 1000 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2013-07-22 13:51:37,999 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 64000
2013-07-22 13:51:37,999 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Free CPU: -5000 , Requested CPU: 1000
2013-07-22 13:51:37,999 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Free RAM: 214727618816 , Requested RAM: 1073741824
2013-07-22 13:51:37,999 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) STATS: Failed to alloc resource from host: 2 reservedCpu: 0, used cpu: 69000, requested cpu: 1000, actual total cpu: 64000, total cpu with overprovisioning: 64000, reservedMem: 0, used Mem: 54865690624, requested mem: 1073741824, total Mem:269593309440 ,considerReservedCapacity?: true
2013-07-22 13:51:37,999 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Host does not have enough CPU available, cannot allocate to this host.
2013-07-22 13:51:37,999 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Not using host 2; numCpusGood: true; cpuFreqGood: true, host has capacity?false
2013-07-22 13:51:37,999 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-2:job-1036 FirstFitRoutingAllocator) Host Allocator returning 3 suitable hosts
2013-07-22 13:51:38,001 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Checking suitable pools for volume (Id, Type): (218,ROOT)
2013-07-22 13:51:38,001 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) We need to allocate new storagepool for this volume
2013-07-22 13:51:38,002 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Calling StoragePoolAllocators to find suitable pools
2013-07-22 13:51:38,004 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) Looking for pools in dc: 1 pod:1 cluster:1
2013-07-22 13:51:38,006 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) FirstFitStoragePoolAllocator has 5 pools to check for allocation
2013-07-22 13:51:38,006 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: CloudStackPrimary ,poolId: 202
2013-07-22 13:51:38,006 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,006 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? true
2013-07-22 13:51:38,019 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Checking pool: 202 for volume allocation [Vol[218|vm=176|ROOT]], maxSize : 15536092086272, totalAllocatedSize : 3265472557568, askingSize : 21474836480, allocated disable threshold: 0.85
2013-07-22 13:51:38,019 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen4-cld.na.manwin.local Local Storage ,poolId: 206
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen1-cld.na.manwin.local Local Storage ,poolId: 204
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen2-cld.na.manwin.local Local Storage ,poolId: 207
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen3-cld.na.manwin.local Local Storage ,poolId: 208
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,020 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) FirstFitStoragePoolAllocator returning 1 suitable storage pools
2013-07-22 13:51:38,020 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Checking suitable pools for volume (Id, Type): (219,DATADISK)
2013-07-22 13:51:38,020 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) We need to allocate new storagepool for this volume
2013-07-22 13:51:38,021 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Calling StoragePoolAllocators to find suitable pools
2013-07-22 13:51:38,021 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) Looking for pools in dc: 1 pod:1 cluster:1
2013-07-22 13:51:38,023 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) FirstFitStoragePoolAllocator has 5 pools to check for allocation
2013-07-22 13:51:38,023 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen3-cld.na.manwin.local Local Storage ,poolId: 208
2013-07-22 13:51:38,023 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,023 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,023 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,023 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: CloudStackPrimary ,poolId: 202
2013-07-22 13:51:38,023 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,023 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? true
2013-07-22 13:51:38,030 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Checking pool: 202 for volume allocation [Vol[219|vm=176|DATADISK]], maxSize : 15536092086272, totalAllocatedSize : 3263713771520, askingSize : 16106127360, allocated disable threshold: 0.85
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen2-cld.na.manwin.local Local Storage ,poolId: 207
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen1-cld.na.manwin.local Local Storage ,poolId: 204
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen4-cld.na.manwin.local Local Storage ,poolId: 206
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,030 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,030 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) FirstFitStoragePoolAllocator returning 1 suitable storage pools
2013-07-22 13:51:38,030 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2013-07-22 13:51:38,031 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Checking if host: 4 can access any suitable storage pool for volume: ROOT
2013-07-22 13:51:38,033 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Host: 4 can access pool: 202
2013-07-22 13:51:38,043 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Checking pool: 202 for volume allocation [Vol[218|vm=176|ROOT]], maxSize : 15536092086272, totalAllocatedSize : 3265472557568, askingSize : 21474836480, allocated disable threshold: 0.85
2013-07-22 13:51:38,043 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Checking if host: 4 can access any suitable storage pool for volume: DATADISK
2013-07-22 13:51:38,045 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Host: 4 can access pool: 202
2013-07-22 13:51:38,054 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Checking pool: 202 for volume allocation [Vol[218|vm=176|ROOT], Vol[219|vm=176|DATADISK]], maxSize : 15536092086272, totalAllocatedSize : 3265472557568, askingSize : 37580963840, allocated disable threshold: 0.85
2013-07-22 13:51:38,054 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Found a potential host id: 4 name: xen3-cld.na.manwin.local and associated storage pools for this VM
2013-07-22 13:51:38,056 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) 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(4)-Storage(Volume(218|ROOT-->Pool(202), Volume(219|DATADISK-->Pool(202))]
2013-07-22 13:51:38,076 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) 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
2013-07-22 13:51:38,076 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-2:job-1036) Successfully transitioned to start state for VM[User|test0722-2] reservation id = 1efb74e4-0b9e-4cd5-97af-5018451e1ac9
2013-07-22 13:51:38,078 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-2:job-1036) Trying to deploy VM, vm has dcId: 1 and podId: null
2013-07-22 13:51:38,079 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-2:job-1036) advanceStart: DeploymentPlan is provided, using dcId:1, podId: 1, clusterId: 1, hostId: 4, poolId: null
2013-07-22 13:51:38,079 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-2:job-1036) Deploy avoids pods: null, clusters: null, hosts: null
2013-07-22 13:51:38,081 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) DeploymentPlanner allocation algorithm: random
2013-07-22 13:51:38,081 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 1000, requested ram: 1073741824
2013-07-22 13:51:38,081 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Is ROOT volume READY (pool already allocated)?: No
2013-07-22 13:51:38,081 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) DeploymentPlan has host_id specified, choosing this host and making no checks on this host: 4
2013-07-22 13:51:38,083 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Looking for suitable pools for this host under zone: 1, pod: 1, cluster: 1
2013-07-22 13:51:38,084 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Checking suitable pools for volume (Id, Type): (218,ROOT)
2013-07-22 13:51:38,084 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) We need to allocate new storagepool for this volume
2013-07-22 13:51:38,085 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Calling StoragePoolAllocators to find suitable pools
2013-07-22 13:51:38,085 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) Looking for pools in dc: 1 pod:1 cluster:1
2013-07-22 13:51:38,086 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) FirstFitStoragePoolAllocator has 5 pools to check for allocation
2013-07-22 13:51:38,087 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen2-cld.na.manwin.local Local Storage ,poolId: 207
2013-07-22 13:51:38,087 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,087 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,087 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,087 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen1-cld.na.manwin.local Local Storage ,poolId: 204
2013-07-22 13:51:38,087 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,087 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,087 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,087 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: CloudStackPrimary ,poolId: 202
2013-07-22 13:51:38,087 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,087 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? true
2013-07-22 13:51:38,096 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Checking pool: 202 for volume allocation [Vol[218|vm=176|ROOT]], maxSize : 15536092086272, totalAllocatedSize : 3265472557568, askingSize : 21474836480, allocated disable threshold: 0.85
2013-07-22 13:51:38,097 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen3-cld.na.manwin.local Local Storage ,poolId: 208
2013-07-22 13:51:38,097 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,097 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,097 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,097 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen4-cld.na.manwin.local Local Storage ,poolId: 206
2013-07-22 13:51:38,097 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,097 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,097 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,097 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) FirstFitStoragePoolAllocator returning 1 suitable storage pools
2013-07-22 13:51:38,097 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Checking suitable pools for volume (Id, Type): (219,DATADISK)
2013-07-22 13:51:38,097 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) We need to allocate new storagepool for this volume
2013-07-22 13:51:38,097 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Calling StoragePoolAllocators to find suitable pools
2013-07-22 13:51:38,097 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) Looking for pools in dc: 1 pod:1 cluster:1
2013-07-22 13:51:38,098 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) FirstFitStoragePoolAllocator has 5 pools to check for allocation
2013-07-22 13:51:38,098 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen1-cld.na.manwin.local Local Storage ,poolId: 204
2013-07-22 13:51:38,098 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,098 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,098 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,098 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen3-cld.na.manwin.local Local Storage ,poolId: 208
2013-07-22 13:51:38,099 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,099 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,099 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,099 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen4-cld.na.manwin.local Local Storage ,poolId: 206
2013-07-22 13:51:38,099 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,099 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,099 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,099 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: CloudStackPrimary ,poolId: 202
2013-07-22 13:51:38,099 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,099 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? true
2013-07-22 13:51:38,103 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Checking pool: 202 for volume allocation [Vol[219|vm=176|DATADISK]], maxSize : 15536092086272, totalAllocatedSize : 3263713771520, askingSize : 16106127360, allocated disable threshold: 0.85
2013-07-22 13:51:38,104 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen2-cld.na.manwin.local Local Storage ,poolId: 207
2013-07-22 13:51:38,104 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:51:38,104 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:51:38,104 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:51:38,104 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) FirstFitStoragePoolAllocator returning 1 suitable storage pools
2013-07-22 13:51:38,104 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2013-07-22 13:51:38,104 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Checking if host: 4 can access any suitable storage pool for volume: ROOT
2013-07-22 13:51:38,105 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Host: 4 can access pool: 202
2013-07-22 13:51:38,113 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Checking pool: 202 for volume allocation [Vol[218|vm=176|ROOT]], maxSize : 15536092086272, totalAllocatedSize : 3265472557568, askingSize : 21474836480, allocated disable threshold: 0.85
2013-07-22 13:51:38,113 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Checking if host: 4 can access any suitable storage pool for volume: DATADISK
2013-07-22 13:51:38,114 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Host: 4 can access pool: 202
2013-07-22 13:51:38,123 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Checking pool: 202 for volume allocation [Vol[218|vm=176|ROOT], Vol[219|vm=176|DATADISK]], maxSize : 15536092086272, totalAllocatedSize : 3265472557568, askingSize : 37580963840, allocated disable threshold: 0.85
2013-07-22 13:51:38,123 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Found a potential host id: 4 name: xen3-cld.na.manwin.local and associated storage pools for this VM
2013-07-22 13:51:38,124 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) 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(4)-Storage(Volume(218|ROOT-->Pool(202), Volume(219|DATADISK-->Pool(202))]
2013-07-22 13:51:38,125 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-2:job-1036) Deployment found - P0=VM[User|test0722-2], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(4)-Storage(Volume(218|ROOT-->Pool(202), Volume(219|DATADISK-->Pool(202))]
2013-07-22 13:51:38,132 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 4 host id before state transition: null
2013-07-22 13:51:38,140 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 64000
2013-07-22 13:51:38,140 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) We are allocating VM, increasing the used capacity of this host:4
2013-07-22 13:51:38,140 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) Current Used CPU: 0 , Free CPU:64000 ,Requested CPU: 1000
2013-07-22 13:51:38,140 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) Current Used RAM: 0 , Free RAM:269593309440 ,Requested RAM: 1073741824
2013-07-22 13:51:38,140 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) CPU STATS after allocation: for host: 4, old used: 0, old reserved: 0, actual total: 64000, total with overprovisioning: 64000; new used:1000, reserved:0; requested cpu:1000,alloc_from_last:false
2013-07-22 13:51:38,140 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) RAM STATS after allocation: for host: 4, old used: 0, old reserved: 0, total: 269593309440; new used: 1073741824, reserved: 0; requested mem: 1073741824,alloc_from_last:false
2013-07-22 13:51:38,142 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-2:job-1036) VM is being created in podId: 1
2013-07-22 13:51:38,147 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Lock is acquired for network id 204 as a part of network implement
2013-07-22 13:51:38,147 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Network id=204 is already implemented
2013-07-22 13:51:38,148 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Lock is released for network id 204 as a part of network implement
2013-07-22 13:51:38,184 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Changing active number of nics for network id=204 on 1
2013-07-22 13:51:38,192 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking NiciraNvp to prepare for Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:51:38,192 DEBUG [network.element.NiciraNvpElement] (Job-Executor-2:job-1036) Checking if NiciraNvpElement can handle service Connectivity on network guestNetworkForBasicZone
2013-07-22 13:51:38,196 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking JuniperSRX to prepare for Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:51:38,199 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking Netscaler to prepare for Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:51:38,202 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking F5BigIP to prepare for Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:51:38,206 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking CiscoNexus1000vVSM to prepare for Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:51:38,206 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking BigSwitchVnsElement to prepare for Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:51:38,206 DEBUG [network.element.BigSwitchVnsElement] (Job-Executor-2:job-1036) Checking if BigSwitchVnsElement can handle service Connectivity on network guestNetworkForBasicZone
2013-07-22 13:51:38,209 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking VirtualRouter to prepare for Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:51:38,225 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-2:job-1036) Lock is acquired for network id 204 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(4)-Storage(Volume(218|ROOT-->Pool(202), Volume(219|DATADISK-->Pool(202))]
2013-07-22 13:51:38,229 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-2:job-1036) Skipping VR deployment: Found a running or starting VR in Pod null id=1
2013-07-22 13:51:38,230 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-2:job-1036) Lock is released for network id 204 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(4)-Storage(Volume(218|ROOT-->Pool(202), Volume(219|DATADISK-->Pool(202))]
2013-07-22 13:51:38,241 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-2:job-1036) Applying dhcp entry in network Ntwk[204|Guest|5]
2013-07-22 13:51:38,262 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 1-761921545: Sending { Cmd , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 100111, [{"routing.DhcpEntryCommand":{"vmMac":"06:4d:74:00:00:23","vmIpAddress":"10.3.34.45","vmName":"test0722-2","defaultRouter":"10.3.34.1","defaultDns":"10.3.34.29","duid":"00:03:00:01:06:4d:74:00:00:23","isDefault":true,"accessDetails":{"router.guest.ip":"10.3.34.29","zone.network.type":"Basic","router.name":"r-4-VM","router.ip":"169.254.3.241"},"wait":0}}] }
2013-07-22 13:51:38,262 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 1-761921545: Executing: { Cmd , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 100111, [{"routing.DhcpEntryCommand":{"vmMac":"06:4d:74:00:00:23","vmIpAddress":"10.3.34.45","vmName":"test0722-2","defaultRouter":"10.3.34.1","defaultDns":"10.3.34.29","duid":"00:03:00:01:06:4d:74:00:00:23","isDefault":true,"accessDetails":{"router.guest.ip":"10.3.34.29","zone.network.type":"Basic","router.name":"r-4-VM","router.ip":"169.254.3.241"},"wait":0}}] }
2013-07-22 13:51:41,205 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 1-761921545: Received: { Ans: , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 110, { Answer } }
2013-07-22 13:51:41,215 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-2:job-1036) Applying userdata and password entry in network Ntwk[204|Guest|5]
2013-07-22 13:51:41,230 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 1-761921546: Sending { Cmd , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 100111, [{"routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"10.3.34.45","vmName":"test0722-2","accessDetails":{"router.guest.ip":"10.3.34.29","zone.network.type":"Basic","router.ip":"169.254.3.241","router.name":"r-4-VM"},"wait":0}},{"routing.VmDataCommand":{"vmIpAddress":"10.3.34.45","vmName":"test0722-2","accessDetails":{"router.guest.ip":"10.3.34.29","zone.network.type":"Basic","router.ip":"169.254.3.241","router.name":"r-4-VM"},"wait":0}}] }
2013-07-22 13:51:41,231 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 1-761921546: Executing: { Cmd , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 100111, [{"routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"10.3.34.45","vmName":"test0722-2","accessDetails":{"router.guest.ip":"10.3.34.29","zone.network.type":"Basic","router.ip":"169.254.3.241","router.name":"r-4-VM"},"wait":0}},{"routing.VmDataCommand":{"vmIpAddress":"10.3.34.45","vmName":"test0722-2","accessDetails":{"router.guest.ip":"10.3.34.29","zone.network.type":"Basic","router.ip":"169.254.3.241","router.name":"r-4-VM"},"wait":0}}] }
2013-07-22 13:51:59,315 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 1-761921546: Received: { Ans: , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 110, { Answer, Answer } }
2013-07-22 13:51:59,315 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking Ovs to prepare for Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:51:59,315 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking SecurityGroupProvider to prepare for Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:51:59,322 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking VpcVirtualRouter to prepare for Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:51:59,322 WARN [network.element.VpcVirtualRouterElement] (Job-Executor-2:job-1036) Network Ntwk[204|Guest|5] is not associated with any VPC
2013-07-22 13:51:59,328 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Checking if we need to prepare 2 volumes for VM[User|test0722-2]
2013-07-22 13:51:59,335 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Creating volume: Vol[218|vm=176|ROOT]
2013-07-22 13:51:59,336 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Trying to create in Pool[202|IscsiLUN]
2013-07-22 13:51:59,347 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-2:job-1036) Downloading template 5 to pool 202
2013-07-22 13:51:59,355 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-2:job-1036) Downloading 5 via 1
2013-07-22 13:51:59,358 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 1-761921547: Sending { Cmd , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 100111, [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolUuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolId":202,"primaryPool":{"id":202,"uuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","host":"10.3.34.5","path":"/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","port":3260,"type":"IscsiLUN"},"secondaryStorageUrl":"nfs://mgt-cld.na.manwin.local/home/secondary","primaryStorageUrl":"nfs://10.3.34.5/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","url":"nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/1/5//f208d740-0ad0-34fa-b6c4-5d1d961446d9.vhd","format":"VHD","accountId":1,"name":"centos56-x86_64-xen","wait":10800}}] }
2013-07-22 13:51:59,359 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 1-761921547: Executing: { Cmd , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 100111, [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolUuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolId":202,"primaryPool":{"id":202,"uuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","host":"10.3.34.5","path":"/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","port":3260,"type":"IscsiLUN"},"secondaryStorageUrl":"nfs://mgt-cld.na.manwin.local/home/secondary","primaryStorageUrl":"nfs://10.3.34.5/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","url":"nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/1/5//f208d740-0ad0-34fa-b6c4-5d1d961446d9.vhd","format":"VHD","accountId":1,"name":"centos56-x86_64-xen","wait":10800}}] }
2013-07-22 13:52:01,855 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 1-761921547: Received: { Ans: , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 110, { PrimaryStorageDownloadAnswer } }
2013-07-22 13:52:01,855 DEBUG [agent.manager.AgentManagerImpl] (Job-Executor-2:job-1036) Details from executing class com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:21870d6d-c300-4f6d-80c2-b4bedc7f1f25 for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/1/5//f208d740-0ad0-34fa-b6c4-5d1d961446d9.vhd due to com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 3bcca549-8365-35ce-8a87-17ac8768adc6
2013-07-22 13:52:01,855 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-2:job-1036) Template 5 download to pool 202 failed due to Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:21870d6d-c300-4f6d-80c2-b4bedc7f1f25 for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/1/5//f208d740-0ad0-34fa-b6c4-5d1d961446d9.vhd due to com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 3bcca549-8365-35ce-8a87-17ac8768adc6
2013-07-22 13:52:01,855 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-2:job-1036) Downloading 5 via 4
2013-07-22 13:52:01,859 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 4-1109524489: Sending { Cmd , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 100111, [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolUuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolId":202,"primaryPool":{"id":202,"uuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","host":"10.3.34.5","path":"/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","port":3260,"type":"IscsiLUN"},"secondaryStorageUrl":"nfs://mgt-cld.na.manwin.local/home/secondary","primaryStorageUrl":"nfs://10.3.34.5/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","url":"nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/1/5//f208d740-0ad0-34fa-b6c4-5d1d961446d9.vhd","format":"VHD","accountId":1,"name":"centos56-x86_64-xen","wait":10800}}] }
2013-07-22 13:52:01,859 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 4-1109524489: Executing: { Cmd , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 100111, [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolUuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolId":202,"primaryPool":{"id":202,"uuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","host":"10.3.34.5","path":"/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","port":3260,"type":"IscsiLUN"},"secondaryStorageUrl":"nfs://mgt-cld.na.manwin.local/home/secondary","primaryStorageUrl":"nfs://10.3.34.5/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","url":"nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/1/5//f208d740-0ad0-34fa-b6c4-5d1d961446d9.vhd","format":"VHD","accountId":1,"name":"centos56-x86_64-xen","wait":10800}}] }
2013-07-22 13:52:04,325 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 4-1109524489: Received: { Ans: , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 110, { PrimaryStorageDownloadAnswer } }
2013-07-22 13:52:04,325 DEBUG [agent.manager.AgentManagerImpl] (Job-Executor-2:job-1036) Details from executing class com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:114d6e75-82c1-47d4-af04-1c4192be11b9 for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/1/5//f208d740-0ad0-34fa-b6c4-5d1d961446d9.vhd due to com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 3bcca549-8365-35ce-8a87-17ac8768adc6
2013-07-22 13:52:04,325 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-2:job-1036) Template 5 download to pool 202 failed due to Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:114d6e75-82c1-47d4-af04-1c4192be11b9 for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/1/5//f208d740-0ad0-34fa-b6c4-5d1d961446d9.vhd due to com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 3bcca549-8365-35ce-8a87-17ac8768adc6
2013-07-22 13:52:04,326 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-2:job-1036) Template 5 is not found on and can not be downloaded to pool 202
2013-07-22 13:52:04,326 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-2:job-1036) Cannot use this pool Pool[202|IscsiLUN] because we can't propagate template Tmpl[5-VHD-centos56-x86_64-xen
2013-07-22 13:52:04,328 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-2:job-1036) Unable to contact resource.
2013-07-22 13:52:04,330 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-2:job-1036) Cleaning up resources for the vm VM[User|test0722-2] in Starting state
2013-07-22 13:52:04,332 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 4-1109524490: Sending { Cmd , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"i-2-176-VM","wait":0}}] }
2013-07-22 13:52:04,332 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 4-1109524490: Executing: { Cmd , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"i-2-176-VM","wait":0}}] }
2013-07-22 13:52:04,582 DEBUG [agent.transport.Request] (Job-Executor-2:job-1036) Seq 4-1109524490: Received: { Ans: , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 110, { StopAnswer } }
2013-07-22 13:52:04,589 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Changing active number of nics for network id=204 on -1
2013-07-22 13:52:04,590 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking NiciraNvp to release Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:52:04,590 DEBUG [network.element.NiciraNvpElement] (Job-Executor-2:job-1036) Checking if NiciraNvpElement can handle service Connectivity on network guestNetworkForBasicZone
2013-07-22 13:52:04,590 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking JuniperSRX to release Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:52:04,590 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking Netscaler to release Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:52:04,591 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking F5BigIP to release Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:52:04,591 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking CiscoNexus1000vVSM to release Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:52:04,591 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking BigSwitchVnsElement to release Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:52:04,591 DEBUG [network.element.BigSwitchVnsElement] (Job-Executor-2:job-1036) Checking if BigSwitchVnsElement can handle service Connectivity on network guestNetworkForBasicZone
2013-07-22 13:52:04,591 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking VirtualRouter to release Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:52:04,591 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking Ovs to release Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:52:04,591 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking SecurityGroupProvider to release Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:52:04,591 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-2:job-1036) Asking VpcVirtualRouter to release Nic[239-176-1efb74e4-0b9e-4cd5-97af-5018451e1ac9-10.3.34.45]
2013-07-22 13:52:04,591 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-2:job-1036) Successfully released network resources for the vm VM[User|test0722-2]
2013-07-22 13:52:04,591 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-2:job-1036) Successfully cleanued up resources for the vm VM[User|test0722-2] in Starting state
2013-07-22 13:52:04,592 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) DeploymentPlanner allocation algorithm: random
2013-07-22 13:52:04,592 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 1000, requested ram: 1073741824
2013-07-22 13:52:04,593 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Is ROOT volume READY (pool already allocated)?: No
2013-07-22 13:52:04,593 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) DeploymentPlan has host_id specified, choosing this host and making no checks on this host: 4
2013-07-22 13:52:04,594 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Looking for suitable pools for this host under zone: 1, pod: 1, cluster: 1
2013-07-22 13:52:04,595 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Checking suitable pools for volume (Id, Type): (218,ROOT)
2013-07-22 13:52:04,595 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) We need to allocate new storagepool for this volume
2013-07-22 13:52:04,595 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Calling StoragePoolAllocators to find suitable pools
2013-07-22 13:52:04,595 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) Looking for pools in dc: 1 pod:1 cluster:1
2013-07-22 13:52:04,597 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) FirstFitStoragePoolAllocator has 5 pools to check for allocation
2013-07-22 13:52:04,597 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen3-cld.na.manwin.local Local Storage ,poolId: 208
2013-07-22 13:52:04,597 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:52:04,597 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:52:04,597 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:52:04,597 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen4-cld.na.manwin.local Local Storage ,poolId: 206
2013-07-22 13:52:04,597 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:52:04,597 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:52:04,597 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:52:04,597 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen1-cld.na.manwin.local Local Storage ,poolId: 204
2013-07-22 13:52:04,597 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:52:04,598 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:52:04,598 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:52:04,598 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen2-cld.na.manwin.local Local Storage ,poolId: 207
2013-07-22 13:52:04,598 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
2013-07-22 13:52:04,598 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
2013-07-22 13:52:04,598 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool
2013-07-22 13:52:04,598 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: CloudStackPrimary ,poolId: 202
2013-07-22 13:52:04,598 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is in avoid set, skipping this pool
2013-07-22 13:52:04,598 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-2:job-1036) FirstFitStoragePoolAllocator returning 0 suitable storage pools
2013-07-22 13:52:04,598 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) No suitable pools found for volume: Vol[218|vm=176|ROOT] under cluster: 1
2013-07-22 13:52:04,598 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) No suitable pools found
2013-07-22 13:52:04,598 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-2:job-1036) Cannnot deploy to specified host, returning.
2013-07-22 13:52:04,601 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 4
2013-07-22 13:52:04,604 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 64000
2013-07-22 13:52:04,605 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) release cpu from host: 4, old used: 1000,reserved: 0, actual total: 64000, total with overprovisioning: 64000; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-07-22 13:52:04,605 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) release mem from host: 4, old used: 1073741824,reserved: 0, total: 269593309440; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-07-22 13:52:04,608 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-2:job-1036) Destroying vm VM[User|test0722-2] as it failed to create on Host with Id:null
2013-07-22 13:52:04,612 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-2:job-1036) 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
2013-07-22 13:52:04,669 INFO [user.vm.DeployVMCmd] (Job-Executor-2:job-1036) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test0722-2]Scope=interface com.cloud.dc.DataCenter; id=1
2013-07-22 13:52:04,669 INFO [user.vm.DeployVMCmd] (Job-Executor-2:job-1036) Unable to create a deployment for VM[User|test0722-2]
2013-07-22 13:52:04,670 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-2:job-1036) Complete async job-1036, jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable to create a deployment for VM[User|test0722-2]
2013-07-22 13:52:04,926 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-19:null) Async job-1036 completed
This e-mail may be privileged and/or confidential, and the sender does not waive any related rights and obligations. Any distribution, use or copying of this e-mail or the information it contains by other than an intended recipient is unauthorized. If you received this e-mail in error, please advise me (by return e-mail or otherwise) immediately. Ce courrier ?lectronique est confidentiel et prot?g?. L'exp?diteur ne renonce pas aux droits et obligations qui s'y rapportent. Toute diffusion, utilisation ou copie de ce message ou des renseignements qu'il contient par une personne autre que le (les) destinataire(s) d?sign?(s) est interdite. Si vous recevez ce courrier ?lectronique par erreur, veuillez m'en aviser imm?diatement, par retour de courrier ?lectronique ou par un autre moyen.
Re: can't create VM after upgrade from 3.0.2 to 4,1. Error Code: 533 Error text: Unable to create a deployment for VM
Posted by Ahmad Emneina <ae...@gmail.com>.
Hey William, it seems You only have local storage in your cloud... And Cloudstack is looking to deploy to a shared storage pool. You can either add shared storage or change the service offering you're using to use local storage.
Ahmad
On Jul 22, 2013, at 12:13 PM, William Jiang <Wi...@manwin.com> wrote:
> 2013-07-22 13:51:38,019 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Checking if storage pool is suitable, name: xen4-cld.na.manwin.local Local Storage ,poolId: 206
> 2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is localStorageAllocationNeeded? false
> 2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) Is storage pool shared? false
> 2013-07-22 13:51:38,020 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-2:job-1036) StoragePool is not of correct type, skipping this pool