Community
 
 
 

CloudPlatform 3.x

343 followers
 
Avatar
Administrator

Unable to add Instances

Avatar

Unable to add Instances

I am unable to add instances, getting following error,

"Unable to create a deployment for VM[User|i-2-8-VM]"

My Environment Details :
RHEL x64
CloudStack 3.0.0-1
XenServer 6.0

Secondary Storage : NFS Share 10 GB (OpenFiler Server)
Primary Storage : iSCSI 3* 10GB LUN (OpenFiler Server)

Log:
--------
2013-08-25 23:10:38,991 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-16:null) Access granted to Acct[2-admin] to Domain:1/ by DomainChecker
2013-08-25 23:10:45,982 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2013-08-25 23:10:46,139 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
2013-08-25 23:10:46,689 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers.
2013-08-25 23:10:49,702 DEBUG [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-24:null) Access granted to Acct[2-admin] to zone:1 by DomainChecker
2013-08-25 23:10:49,703 DEBUG [cloud.configuration.ConfigurationManagerImpl] (catalina-exec-24:null) Access granted to Acct[2-admin] to zone:1 by DomainChecker
2013-08-25 23:10:49,719 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-24:null) Allocating in the DB for vm
2013-08-25 23:10:49,719 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-24:null) Allocating entries for VM: VM[User|i-2-8-VM]
2013-08-25 23:10:49,723 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-24:null) Allocating nics for VM[User|i-2-8-VM]
2013-08-25 23:10:49,732 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-24:null) Allocaing disks for VM[User|i-2-8-VM]
2013-08-25 23:10:49,738 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-24:null) Allocation completed for VM: VM[User|i-2-8-VM]
2013-08-25 23:10:49,738 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-24:null) Successfully allocated DB entry for VM[User|i-2-8-VM]
2013-08-25 23:10:49,940 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-24:null) submit async job-19, details: AsyncJobVO {id:19, userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine, instanceId: 8, cmd: com.cloud.api.commands.DeployVMCmd, cmdOriginator: null, cmdInfo: {"id":"8","response":"json","templateId":"eaf1ae51-649b-4269-99f5-1b89130e5a60","sessionkey":"3bTlCpT9xfqEnfFsLLXwZ9D7Up8\u003d","ctxUserId":"2","hypervisor":"XenServer","serviceOfferingId":"46868cd8-fae6-4f08-97e2-699c5ab10c42","_":"1377461451328","securitygroupids":"48b6faa0-7b6c-4bf3-aed3-20d62a0ef128","ctxAccountId":"2","ctxStartEventId":"203","displayname":"MyVM01","zoneId":"f484c790-e41c-47c7-a8fc-d592d27cb164"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 8796756729983, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-08-25 23:10:49,945 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-5:job-19) Executing com.cloud.api.commands.DeployVMCmd for job-19
2013-08-25 23:10:50,015 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-5:job-19) 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-08-25 23:10:50,015 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-5:job-19) Successfully transitioned to start state for VM[User|i-2-8-VM] reservation id = 9b70e921-6ea1-48f3-8989-3e5e2621ffe3
2013-08-25 23:10:50,090 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-5:job-19) Trying to deploy VM, vm has dcId: 1 and podId: null
2013-08-25 23:10:50,091 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-5:job-19) Deploy avoids pods: null, clusters: null, hosts: null
2013-08-25 23:10:50,092 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) DeploymentPlanner allocation algorithm: random
2013-08-25 23:10:50,092 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1048576000
2013-08-25 23:10:50,092 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) Is ROOT volume READY (pool already allocated)?: No
2013-08-25 23:10:50,092 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) Searching all possible resources under this Zone: 1
2013-08-25 23:10:50,094 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1
2013-08-25 23:10:50,095 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) CPUOverprovisioningFactor considered: 1.0
2013-08-25 23:10:50,104 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) Checking resources in Cluster: 1 under Pod: 1
2013-08-25 23:10:50,104 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) Calling HostAllocators to find suitable hosts
2013-08-25 23:10:50,104 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-5:job-19 FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2013-08-25 23:10:50,105 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-5:job-19 FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-2-Routing]]
2013-08-25 23:10:50,108 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-5:job-19 FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-2-Routing]]
2013-08-25 23:10:50,108 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-5:job-19 FirstFitRoutingAllocator) Looking for speed=1000Mhz, Ram=1000
2013-08-25 23:10:50,109 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-5:job-19 FirstFitRoutingAllocator) Checking if host: 2 has enough capacity for requested CPU: 1000 and requested RAM: 1048576000 , cpuOverprovisioningFactor: 1.0
2013-08-25 23:10:50,112 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-5:job-19 FirstFitRoutingAllocator) Hosts's actual total CPU: 23408 and CPU after applying overprovisioning: 23408
2013-08-25 23:10:50,112 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-5:job-19 FirstFitRoutingAllocator) Free CPU: 22408 , Requested CPU: 1000
2013-08-25 23:10:50,112 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-5:job-19 FirstFitRoutingAllocator) Free RAM: 6565643200 , Requested RAM: 1048576000
2013-08-25 23:10:50,112 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-5:job-19 FirstFitRoutingAllocator) Host has enough CPU and RAM available
2013-08-25 23:10:50,112 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-5:job-19 FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 2, used: 1000, reserved: 0, actual total: 23408, total with overprovisioning: 23408; requested cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-08-25 23:10:50,112 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-5:job-19 FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 2, used: 1342177280, reserved: 0, total: 7907820480; requested mem: 1048576000,alloc_from_last_host?:false ,considerReservedCapacity?: true
2013-08-25 23:10:50,112 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-5:job-19 FirstFitRoutingAllocator) Found a suitable host, adding to list: 2
2013-08-25 23:10:50,112 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-5:job-19 FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts

--------------------
Continued in reply


ISMAIL SHAREEF MOHAMMED MEMBERS
3 comments
0

Please sign in to leave a comment.

 
 

Previous 3 comments

Avatar
Administrator
Avatar

Unable to add Instances

Log Continued :
-----------------------

2013-08-25 23:10:50,113 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) Checking suitable pools for volume (Id, Type): (11,ROOT)
2013-08-25 23:10:50,113 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) We need to allocate new storagepool for this volume
2013-08-25 23:10:50,113 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) Calling StoragePoolAllocators to find suitable pools
2013-08-25 23:10:50,115 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-5:job-19) Looking for pools in dc: 1 pod:1 cluster:1
2013-08-25 23:10:50,116 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-5:job-19) FirstFitStoragePoolAllocator has 3 pools to check for allocation
2013-08-25 23:10:50,116 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Checking if storage pool is suitable, name: MyPriStorage02 ,poolId: 202
2013-08-25 23:10:50,116 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Is localStorageAllocationNeeded? false
2013-08-25 23:10:50,116 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Is storage pool shared? true
2013-08-25 23:10:50,117 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Attempting to look for pool 202 for storage, totalSize: 10221518848, usedBytes: 8388608, usedPct: 8.206811653672548E-4, disable threshold: 0.85
2013-08-25 23:10:50,118 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Attempting to look for pool 202 for storage, maxSize : 10221518848, totalAllocatedSize : 0, askingSize : 21474836480, allocated disable threshold: 0.85
2013-08-25 23:10:50,119 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Cannot allocate this pool 202 for storage since its allocated percentage: 2.1009437833401723 has crossed the allocated pool.storage.allocated.capacity.disablethreshold: 0.85, skipping this pool
2013-08-25 23:10:50,119 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Checking if storage pool is suitable, name: MyPriStorage01 ,poolId: 201
2013-08-25 23:10:50,119 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Is localStorageAllocationNeeded? false
2013-08-25 23:10:50,119 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Is storage pool shared? true
2013-08-25 23:10:50,120 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Attempting to look for pool 201 for storage, totalSize: 10221518848, usedBytes: 4903141376, usedPct: 0.47968814115716046, disable threshold: 0.85
2013-08-25 23:10:50,122 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Attempting to look for pool 201 for storage, maxSize : 10221518848, totalAllocatedSize : 4861198336, askingSize : 21474836480, allocated disable threshold: 0.85
2013-08-25 23:10:50,122 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Cannot allocate this pool 201 for storage since its allocated percentage: 2.5765285186704965 has crossed the allocated pool.storage.allocated.capacity.disablethreshold: 0.85, skipping this pool
2013-08-25 23:10:50,122 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Checking if storage pool is suitable, name: MyPriStorage03 ,poolId: 203
2013-08-25 23:10:50,122 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Is localStorageAllocationNeeded? false
2013-08-25 23:10:50,122 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Is storage pool shared? true
2013-08-25 23:10:50,123 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Attempting to look for pool 203 for storage, totalSize: 10221518848, usedBytes: 8388608, usedPct: 8.206811653672548E-4, disable threshold: 0.85
2013-08-25 23:10:50,124 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Attempting to look for pool 203 for storage, maxSize : 10221518848, totalAllocatedSize : 0, askingSize : 21474836480, allocated disable threshold: 0.85
2013-08-25 23:10:50,124 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-5:job-19) Cannot allocate this pool 203 for storage since its allocated percentage: 2.1009437833401723 has crossed the allocated pool.storage.allocated.capacity.disablethreshold: 0.85, skipping this pool
2013-08-25 23:10:50,124 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-5:job-19) FirstFitStoragePoolAllocator returning 0 suitable storage pools
2013-08-25 23:10:50,124 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) No suitable pools found for volume: Vol[11|vm=8|ROOT] under cluster: 1
2013-08-25 23:10:50,124 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) No suitable pools found
2013-08-25 23:10:50,124 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) No suitable storagePools found under this Cluster: 1
2013-08-25 23:10:50,124 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-5:job-19) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2013-08-25 23:10:50,223 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-5:job-19) 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
2013-08-25 23:10:50,382 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-5:job-19) 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-08-25 23:10:50,975 INFO [api.commands.DeployVMCmd] (Job-Executor-5:job-19) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|i-2-8-VM]Scope=interface com.cloud.dc.DataCenter; id=1
2013-08-25 23:10:50,975 WARN [cloud.api.ApiDispatcher] (Job-Executor-5:job-19) class com.cloud.api.ServerApiException : Unable to create a deployment for VM[User|i-2-8-VM]
2013-08-25 23:10:50,978 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-5:job-19) Complete async job-19, jobStatus: 2, resultCode: 530, result: com.cloud.api.response.ExceptionResponse@62486398
2013-08-25 23:10:55,149 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-4:null) Async job-19 completed

----------
END OF LOG


ISMAIL SHAREEF MOHAMMED MEMBERS
Comment actions Permalink
Avatar
Erik Godin

Based on logging you provided, it looks like the problem is related to the storage pools:

_*Attempting to look for pool 202*_ for storage, maxSize : 10221518848, totalAllocatedSize : 0, askingSize : 21474836480, allocated disable threshold: 0.85
2013-08-25 23:10:50,119 DEBUG http://storage.allocator.AbstractStoragePoolAllocator (Job-Executor-5:job-19) Cannot allocate this pool 202 for storage since its allocated percentage: 2.1009437833401723 has crossed the allocated pool.storage.allocated.capacity.disablethreshold: 0.85, skipping this pool

The above message is repeated for pool 201, 202 and 203 (MyPriStorage01, MyPriStorage02 and MyPriStorage03 respectively). The message alludes to the fact that 2.10% of the Storage Pool is used while the limit is currently set to 0.85. Based on that information, I'm assuming the intention was to limit use of the Primary Storage to 85% used. My conclusion is that the param "pool.storage.allocated.capacity.disablethreshold" might need to be defined as "85" instead of "0.85".

Please rate if my reply helped or answered your question, thanks!

Regards,

Erik Godin

Please rate if my reply helps or answers your question. Thank you!

Erik Godin


Comment actions Permalink
Avatar
Administrator
Avatar

Dear Erik,

Thanks a lot for the reply, i forgot to update that i fixed it after studying the logs correctly yesterday. It was the same problem of Insufficient Storage Pool. As soon i increased the pool it started working.

Thanks again.


ISMAIL SHAREEF MOHAMMED MEMBERS
Comment actions Permalink

Top Contributors