Marcus Sorensen created CLOUDSTACK-2281:
-------------------------------------------
Summary: VM fails to deploy due to planner selecting deleted pool
Key: CLOUDSTACK-2281
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2281
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Management Server
Affects Versions: 4.1.0
Reporter: Marcus Sorensen
Priority: Blocker
Fix For: 4.1.0
Having trouble tracking this down. Here's what I did:
Created a 4.1 advanced zone
added primary storage A
deployed a template
deployed vms
added new primary storages
migrated VMs from primary storage A to others
removed initial primary storage A
try to deploy new vm from template, not working. It looks like the allocator
correctly finds and decides to use pool id 204, but somehow deployment is
actually attempted on deleted pool 202. See "Returning Deployment Destination"
and "DeploymentPlan is provided":
2013-04-29 13:25:49,293 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-10:job-9908 FirstFitRoutingAllocator) Found a suitable host,
adding to list: 19
2013-04-29 13:25:49,294 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-10:job-9908 FirstFitRoutingAllocator) Host Allocator returning 4
suitable hosts
2013-04-29 13:25:49,297 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) Checking suitable pools for volume (Id, Type):
(10663,ROOT)
2013-04-29 13:25:49,297 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) We need to allocate new storagepool for this volume
2013-04-29 13:25:49,299 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) Calling StoragePoolAllocators to find suitable pools
2013-04-29 13:25:49,302 DEBUG [storage.allocator.FirstFitStoragePoolAllocator]
(Job-Executor-10:job-9908) Looking for pools in dc: 1 pod:1 cluster:1
2013-04-29 13:25:49,304 DEBUG [storage.allocator.FirstFitStoragePoolAllocator]
(Job-Executor-10:job-9908) FirstFitStoragePoolAllocator has 1 pools to check
for allocation
2013-04-29 13:25:49,304 DEBUG [storage.allocator.AbstractStoragePoolAllocator]
(Job-Executor-10:job-9908) Checking if storage pool is suitable, name:
sansrv-row2-rack0 ,poolId: 204
2013-04-29 13:25:49,304 DEBUG [storage.allocator.AbstractStoragePoolAllocator]
(Job-Executor-10:job-9908) Is localStorageAllocationNeeded? false
2013-04-29 13:25:49,305 DEBUG [storage.allocator.AbstractStoragePoolAllocator]
(Job-Executor-10:job-9908) Is storage pool shared? true
2013-04-29 13:25:49,309 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-10:job-9908) Checking pool 204 for storage, totalSize:
11984676742758, usedBytes: 879609302221, usedPct: 0.07339449541286318, disable
threshold: 0.85
2013-04-29 13:25:49,327 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-10:job-9908) Checking pool: 204 for volume allocation
[Vol[10663|vm=6189|ROOT]], maxSize : 11984676742758, totalAllocatedSize :
588879744000, askingSize : 8589934592, allocated disable threshold: 0.85
2013-04-29 13:25:49,327 DEBUG [storage.allocator.FirstFitStoragePoolAllocator]
(Job-Executor-10:job-9908) FirstFitStoragePoolAllocator returning 1 suitable
storage pools
2013-04-29 13:25:49,327 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) Trying to find a potenial host and associated
storage pools from the suitable host/pool lists for this VM
2013-04-29 13:25:49,327 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) Checking if host: 17 can access any suitable storage
pool for volume: ROOT
2013-04-29 13:25:49,330 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) Host: 17 can access pool: 204
2013-04-29 13:25:49,330 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) Found a potential host id: 17 name: ksrv2-000 and
associated storage pools for this VM
2013-04-29 13:25:49,332 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) 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(17)-Storage(Volume(10663|ROOT-->Pool(204))]
2013-04-29 13:25:49,370 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-10:job-9908) 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-04-29 13:25:49,370 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-10:job-9908) Successfully transitioned to start state for
VM[User|marcus-deleteme] reservation id = dd7783f0-800a-481a-a407-88ec5262a397
2013-04-29 13:25:49,387 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-10:job-9908) Trying to deploy VM, vm has dcId: 1 and podId: null
2013-04-29 13:25:49,387 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-10:job-9908) advanceStart: DeploymentPlan is provided, using
dcId:1, podId: 1, clusterId: 1, hostId: 17, poolId: 202
2013-04-29 13:25:49,387 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-10:job-9908) Deploy avoids pods: null, clusters: null, hosts: null
2013-04-29 13:25:49,389 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) DeploymentPlanner allocation algorithm: random
2013-04-29 13:25:49,390 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) Trying to allocate a host and storage pools from
dc:1, pod:1,cluster:1, requested cpu: 2200, requested ram: 1073741824
2013-04-29 13:25:49,390 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) Is ROOT volume READY (pool already allocated)?: Yes
2013-04-29 13:25:49,390 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) DeploymentPlan has host_id specified, making no
checks on this host, looks like admin test: 17
2013-04-29 13:25:49,391 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) Looking for suitable pools for this host under zone:
1, pod: 1, cluster: 1
2013-04-29 13:25:49,393 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) Checking suitable pools for volume (Id, Type):
(10663,ROOT)
2013-04-29 13:25:49,393 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-10:job-9908) Volume has pool already allocated, checking if pool
can be reused, poolId: null
2013-04-29 13:25:49,411 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-10:job-9908) 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-04-29 13:25:49,417 DEBUG [cloud.vm.UserVmManagerImpl]
(Job-Executor-10:job-9908) Destroying vm VM[User|marcus-deleteme] as it failed
to create on Host with Id:null
2013-04-29 13:25:49,438 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-10:job-9908) 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-04-29 13:25:49,528 ERROR [cloud.async.AsyncJobManagerImpl]
(Job-Executor-10:job-9908) Unexpected exception while executing
org.apache.cloudstack.api.command.user.vm.DeployVMCmd
java.lang.NullPointerException
at
com.cloud.deploy.FirstFitPlanner.findSuitablePoolsForVolumes(FirstFitPlanner.java:758)
at com.cloud.deploy.FirstFitPlanner.plan(FirstFitPlanner.java:174)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:709)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:212)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3873)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3466)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3452)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:385)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:162)
at
com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)
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)
--
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
