[
https://issues.apache.org/jira/browse/CLOUDSTACK-4042?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13728478#comment-13728478
]
Rajesh Battala commented on CLOUDSTACK-4042:
--------------------------------------------
please post kvm agent debug log and mgmt server log.
> [KVM][ZWPS] Failed to allocate storagepool when there are only zone wide
> primary storage pools
> ----------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-4042
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4042
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Storage Controller
> Affects Versions: 4.2.0
> Environment: KVM, Zone wide primary storage
> Reporter: Srikanteswararao Talluri
> Priority: Blocker
> Fix For: 4.2.0
>
>
> Steps to reproduce:
> ==============
> KVM zone with one cluster, one host and two zone wide primary storages (no
> cluster scoped primary storage is added)
> Scenario1:
> =======
> 1. try to deploy an instance.
> observation:
> ========
> unable to allocate storage pool for volume creation.
> Scenario2:
> =======
> 1. after doing scenario1 mentioned above, add a cluster scoped primary
> storage
> 2. now deploy a VM.
> Observation:
> =========
> management server log is flooded with resource allocation messages and it is
> never ending.
> ===START=== 10.101.255.7 -- GET
> command=deployVirtualMachine&zoneId=d61380f7-0317-43dc-a789-7fe2930eb918&templateId=a38a3426-fb8d-11e2-85e6-06dbcc000016&hypervisor=KVM&serviceOfferingId=1e987a1b-fbd8-40b9-90db-7d7e8ff9dce3&networkIds=67c86fc3-8ec1-4a02-9d5e-417761e215e5&displayname=zwps&name=zwps&response=json&sessionkey=PPS9ecULClNpbWM%2BzAATiCSw3rA%3D&_=1375443681861
> 2013-08-02 22:35:53,670 DEBUG [cloud.api.ApiDispatcher]
> (catalina-exec-24:null) InfrastructureEntity name
> is:com.cloud.offering.ServiceOffering
> 2013-08-02 22:35:53,673 DEBUG [cloud.api.ApiDispatcher]
> (catalina-exec-24:null) ControlledEntity name
> is:com.cloud.template.VirtualMachineTemplate
> 2013-08-02 22:35:53,679 DEBUG [cloud.api.ApiDispatcher]
> (catalina-exec-24:null) ControlledEntity name is:com.cloud.network.Network
> 2013-08-02 22:35:53,702 DEBUG [cloud.network.NetworkModelImpl]
> (catalina-exec-24:null) Service SecurityGroup is not supported in the network
> id=204
> 2013-08-02 22:35:53,729 DEBUG [cloud.vm.UserVmManagerImpl]
> (catalina-exec-24:null) Allocating in the DB for vm
> 2013-08-02 22:35:53,749 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-24:null) Allocating entries for VM: VM[User|zwps]
> 2013-08-02 22:35:53,752 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-24:null) Allocating nics for VM[User|zwps]
> 2013-08-02 22:35:53,754 DEBUG [cloud.network.NetworkManagerImpl]
> (catalina-exec-24:null) Allocating nic for vm VM[User|zwps] in network
> Ntwk[204|Guest|8] with requested profile NicProfile[0-0-null-null-null
> 2013-08-02 22:35:53,788 DEBUG [cloud.network.NetworkModelImpl]
> (catalina-exec-24:null) Service SecurityGroup is not supported in the network
> id=204
> 2013-08-02 22:35:53,791 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-24:null) Allocating disks for VM[User|zwps]
> 2013-08-02 22:35:53,813 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (catalina-exec-24:null) Allocation completed for VM: VM[User|zwps]
> 2013-08-02 22:35:53,813 DEBUG [cloud.vm.UserVmManagerImpl]
> (catalina-exec-24:null) Successfully allocated DB entry for VM[User|zwps]
> 2013-08-02 22:35:53,876 DEBUG [cloud.network.NetworkModelImpl]
> (catalina-exec-24:null) Service SecurityGroup is not supported in the network
> id=204
> 2013-08-02 22:35:53,884 DEBUG [cloud.network.NetworkModelImpl]
> (catalina-exec-24:null) Service SecurityGroup is not supported in the network
> id=204
> 2013-08-02 22:35:53,929 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-24:null) submit async job-16 = [
> 184a510c-4399-4e5c-9cfd-cdbfec3415da ], details: AsyncJobVO {id:16, userId:
> 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine, instanceId:
> 4, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd, cmdOriginator:
> null, cmdInfo:
> {"sessionkey":"PPS9ecULClNpbWM+zAATiCSw3rA\u003d","cmdEventType":"VM.CREATE","ctxUserId":"2","serviceOfferingId":"1e987a1b-fbd8-40b9-90db-7d7e8ff9dce3","httpmethod":"GET","zoneId":"d61380f7-0317-43dc-a789-7fe2930eb918","templateId":"a38a3426-fb8d-11e2-85e6-06dbcc000016","response":"json","id":"4","networkIds":"67c86fc3-8ec1-4a02-9d5e-417761e215e5","hypervisor":"KVM","name":"zwps","_":"1375443681861","ctxAccountId":"2","ctxStartEventId":"58","displayname":"zwps"},
> cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
> processStatus: 0, resultCode: 0, result: null, initMsid: 7541090156566,
> completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2013-08-02 22:35:53,933 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null)
> ===END=== 10.101.255.7 -- GET
> command=deployVirtualMachine&zoneId=d61380f7-0317-43dc-a789-7fe2930eb918&templateId=a38a3426-fb8d-11e2-85e6-06dbcc000016&hypervisor=KVM&serviceOfferingId=1e987a1b-fbd8-40b9-90db-7d7e8ff9dce3&networkIds=67c86fc3-8ec1-4a02-9d5e-417761e215e5&displayname=zwps&name=zwps&response=json&sessionkey=PPS9ecULClNpbWM%2BzAATiCSw3rA%3D&_=1375443681861
> 2013-08-02 22:35:53,936 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Executing
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-16 = [
> 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> 2013-08-02 22:35:53,946 DEBUG [cloud.api.ApiDispatcher]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ])
> InfrastructureEntity name is:com.cloud.offering.ServiceOffering
> 2013-08-02 22:35:53,950 DEBUG [cloud.api.ApiDispatcher]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ])
> ControlledEntity name is:com.cloud.template.VirtualMachineTemplate
> 2013-08-02 22:35:53,956 DEBUG [cloud.api.ApiDispatcher]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ])
> ControlledEntity name is:com.cloud.network.Network
> 2013-08-02 22:35:54,005 DEBUG [cloud.network.NetworkModelImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Service
> SecurityGroup is not supported in the network id=204
> 2013-08-02 22:35:54,013 DEBUG [cloud.network.NetworkModelImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Service
> SecurityGroup is not supported in the network id=204
> 2013-08-02 22:35:54,046 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Deploy
> avoids pods: null, clusters: null, hosts: null
> 2013-08-02 22:35:54,050 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ])
> DeploymentPlanner allocation algorithm:
> com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_962eb8f7@165051aa
> 2013-08-02 22:35:54,051 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Trying to
> allocate a host and storage pools from dc:1, pod:null,cluster:null, requested
> cpu: 500, requested ram: 536870912
> 2013-08-02 22:35:54,051 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Is ROOT
> volume READY (pool already allocated)?: No
> 2013-08-02 22:35:54,051 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Searching
> all possible resources under this Zone: 1
> 2013-08-02 22:35:54,053 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Listing
> clusters in order of aggregate capacity, that have (atleast one host with)
> enough CPU and RAM capacity under this Zone: 1
> 2013-08-02 22:35:54,072 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Checking
> resources in Cluster: 1 under Pod: 1
> 2013-08-02 22:35:54,077 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
> 2013-08-02 22:35:54,083 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for
> allocation: [Host[-1-Routing]]
> 2013-08-02 22:35:54,089 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization:
> [Host[-1-Routing]]
> 2013-08-02 22:35:54,089 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
> 2013-08-02 22:35:54,100 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for
> requested CPU: 500 and requested RAM: 536870912 , cpuOverprovisioningFactor:
> 1.0
> 2013-08-02 22:35:54,105 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) Hosts's actual total CPU: 12404 and CPU after
> applying overprovisioning: 12404
> 2013-08-02 22:35:54,106 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) Free CPU: 11404 , Requested CPU: 500
> 2013-08-02 22:35:54,106 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) Free RAM: 6785155072 , Requested RAM: 536870912
> 2013-08-02 22:35:54,106 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) Host has enough CPU and RAM available
> 2013-08-02 22:35:54,106 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 1000,
> reserved: 0, actual total: 12404, total with overprovisioning: 12404;
> requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
> 2013-08-02 22:35:54,106 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used:
> 1342177280, reserved: 0, total: 8127332352; requested mem:
> 536870912,alloc_from_last_host?:false ,considerReservedCapacity?: true
> 2013-08-02 22:35:54,107 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
> 2013-08-02 22:35:54,107 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]
> FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
> 2013-08-02 22:35:54,111 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Checking
> suitable pools for volume (Id, Type): (5,ROOT)
> 2013-08-02 22:35:54,112 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) We need
> to allocate new storagepool for this volume
> 2013-08-02 22:35:54,112 INFO [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Zone is
> currently disabled, cannot allocate to this zone: 1
> 2013-08-02 22:35:54,112 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Cannot
> allocate new storagepool for this volume in this cluster, allocation state is
> disabled
> 2013-08-02 22:35:54,112 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Cannot
> deploy to this specified plan, allocation state is disabled, returning.
> 2013-08-02 22:35:54,112 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) No
> suitable pools found
> 2013-08-02 22:35:54,113 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) No
> suitable storagePools found under this Cluster: 1
> 2013-08-02 22:35:54,119 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Could not
> find suitable Deployment Destination for this VM under any clusters,
> returning.
> 2013-08-02 22:35:54,119 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Searching
> all possible resources under this Zone: 1
> 2013-08-02 22:35:54,122 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Listing
> clusters in order of aggregate capacity, that have (atleast one host with)
> enough CPU and RAM capacity under this Zone: 1
> 2013-08-02 22:35:54,129 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Removing
> from the clusterId list these clusters from avoid set: [1]
> 2013-08-02 22:35:54,134 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) No
> clusters found after removing disabled clusters and clusters in avoid list,
> returning.
> 2013-08-02 22:35:54,144 DEBUG [cloud.vm.UserVmManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ])
> Destroying vm VM[User|zwps] as it failed to create on Host with Id:null
> 2013-08-02 22:35:54,175 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) 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-02 22:35:54,188 WARN [apache.cloudstack.alerts]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ])
> alertType:: 8 // dataCenterId:: 1 // podId:: null // clusterId:: null //
> message:: Failed to deploy Vm with Id: 4, on Host with Id: null
> 2013-08-02 22:35:54,267 INFO [user.vm.DeployVMCmd] (Job-Executor-16:job-16 =
> [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ])
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|zwps]Scope=interface com.cloud.dc.DataCenter; id=1
> 2013-08-02 22:35:54,268 INFO [user.vm.DeployVMCmd] (Job-Executor-16:job-16 =
> [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Unable to create a deployment for
> VM[User|zwps]
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|zwps]Scope=interface com.cloud.dc.DataCenter; id=1
> at
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:209)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:198)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3407)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2968)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2954)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at
> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> 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:679)
> 2013-08-02 22:35:54,273 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-16:job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ]) Complete
> async job-16 = [ 184a510c-4399-4e5c-9cfd-cdbfec3415da ], jobStatus: 2,
> resultCode: 530, result: Error Code: 533 Error text: Unable to create a
> deployment for VM[User|zwps]
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
