Hi,
I am running CloudStack with XenServer 6.0.2. The setup was working fine
till yesterday when I started getting this when trying to restart stopped
instances. (The host is not overutilized and there is plenty of RAM/HDD
space available - Local Storage 40% utilized, Memory 2GB/14.6GB utilized)
"""Unable to create a deployment for VM[User|i-2-13-VM]"""
I have copy/pasted management-server.log and this seems to be the issue
"""
2013-06-03 18:09:07,380 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Is ROOT volume READY (pool already allocated)?: No
2013-06-03 18:09:07,380 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) This VM has last host_id specified, trying to choose
the same host: 1
2013-06-03 18:09:07,382 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) The last host of this VM is in avoid set
2013-06-03 18:09:07,382 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Cannot choose the last host to deploy this VM
"""
I have searched online for solutions but I hav'nt found anything to help.
How do I go about removing the host from the avoid set?
Thanks,
Adi
2013-06-03 18:09:11,524 DEBUG [cloud.server.StatsCollector]
(StatsCollector-1:null) HostStatsCollector is running...
2013-06-03 18:09:11,879 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) StorageCollector is running...
2013-06-03 18:09:11,883 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) There is no secondary storage VM for secondary
storage host nfs://192.168.124.40/export/secondary
2013-06-03 18:09:11,942 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-6:null) Async job-8 completed
2013-06-03 18:09:26,932 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is not ready to launch secondary storage VM yet
2013-06-03 18:09:27,086 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2013-06-03 18:09:27,949 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2013-06-03 18:09:56,932 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is not ready to launch secondary storage VM yet
2013-06-03 18:09:57,086 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2013-06-03 18:09:57,949 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
^C
[root@cloudmaster ~]# less /var/log/cloud/management/management-server.log
[root@cloudmaster ~]# tail -100
/var/log/cloud/management/management-server.log
2013-06-03 18:08:11,872 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) StorageCollector is running...
2013-06-03 18:08:11,875 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) There is no secondary storage VM for secondary
storage host nfs://192.168.124.40/export/secondary
2013-06-03 18:08:26,932 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is not ready to launch secondary storage VM yet
2013-06-03 18:08:27,086 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2013-06-03 18:08:27,949 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2013-06-03 18:08:56,932 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is not ready to launch secondary storage VM yet
2013-06-03 18:08:57,086 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2013-06-03 18:08:57,949 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2013-06-03 18:09:06,907 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-7:null) submit async job-8, details: AsyncJobVO {id:8,
userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine,
instanceId: 13, cmd: com.cloud.api.commands.StartVMCmd, cmdOriginator: null,
cmdInfo:
{"id":"92500bf9-4db3-433a-a0d3-9a1c15d0068c","response":"json","sessionkey":
"B88CuPPzO1VbDvvlI1A1yPc16g8\u003d","ctxUserId":"2","_":"1370263145909","ctx
AccountId":"2","ctxStartEventId":"879"}, cmdVersion: 0, callbackType: 0,
callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result:
null, initMsid: 114130174762, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null}
2013-06-03 18:09:06,910 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-1:job-8) Executing com.cloud.api.commands.StartVMCmd for job-8
2013-06-03 18:09:07,163 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-1:job-8) VM state transitted from :Stopped to Starting with
event: StartRequestedvm's original host id: 1 new host id: null host id
before state transition: null
2013-06-03 18:09:07,163 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-1:job-8) Successfully transitioned to start state for
VM[User|i-2-13-VM] reservation id = 46a6492b-804d-4f00-bfc2-8958fefb275f
2013-06-03 18:09:07,362 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-1:job-8) Trying to deploy VM, vm has dcId: 1 and podId: 1
2013-06-03 18:09:07,363 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-1:job-8) Deploy avoids pods: null, clusters: null, hosts: null
2013-06-03 18:09:07,365 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-1:job-8) Root volume is ready, need to place VM in volume's
cluster
2013-06-03 18:09:07,366 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-1:job-8) Vol[15|vm=13|ROOT] is READY, changing deployment plan
to use this pool's dcId: 1 , podId: 1 , and clusterId: 1
2013-06-03 18:09:07,366 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) DeploymentPlanner allocation algorithm: random
2013-06-03 18:09:07,367 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Trying to allocate a host and storage pools from
dc:1, pod:1,cluster:1, requested cpu: 1024, requested ram: 2147483648
2013-06-03 18:09:07,367 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Is ROOT volume READY (pool already allocated)?: Yes
2013-06-03 18:09:07,367 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) This VM has last host_id specified, trying to choose
the same host: 1
2013-06-03 18:09:07,368 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) The last host of this VM is not UP or is not enabled,
host status is: Alert, host resource state is: Enabled
2013-06-03 18:09:07,368 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Cannot choose the last host to deploy this VM
2013-06-03 18:09:07,369 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Searching resources only under specified Cluster: 1
2013-06-03 18:09:07,375 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Checking resources in Cluster: 1 under Pod: 1
2013-06-03 18:09:07,375 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Calling HostAllocators to find suitable hosts
2013-06-03 18:09:07,375 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-1:job-8 FirstFitRoutingAllocator) Looking for hosts in dc: 1
pod:1 cluster:1
2013-06-03 18:09:07,377 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-1:job-8 FirstFitRoutingAllocator) FirstFitAllocator has 0
hosts to check for allocation: []
2013-06-03 18:09:07,378 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-1:job-8 FirstFitRoutingAllocator) Found 0 hosts for allocation
after prioritization: []
2013-06-03 18:09:07,379 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-1:job-8 FirstFitRoutingAllocator) Looking for speed=1024Mhz,
Ram=2048
2013-06-03 18:09:07,379 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-1:job-8 FirstFitRoutingAllocator) Host Allocator returning 0
suitable hosts
2013-06-03 18:09:07,379 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) No suitable hosts found
2013-06-03 18:09:07,379 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) No suitable hosts found under this Cluster: 1
2013-06-03 18:09:07,379 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Could not find suitable Deployment Destination for
this VM under any clusters, returning.
2013-06-03 18:09:07,380 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) DeploymentPlanner allocation algorithm: random
2013-06-03 18:09:07,380 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Trying to allocate a host and storage pools from
dc:1, pod:1,cluster:null, requested cpu: 1024, requested ram: 2147483648
2013-06-03 18:09:07,380 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Is ROOT volume READY (pool already allocated)?: No
2013-06-03 18:09:07,380 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) This VM has last host_id specified, trying to choose
the same host: 1
2013-06-03 18:09:07,382 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) The last host of this VM is in avoid set
2013-06-03 18:09:07,382 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Cannot choose the last host to deploy this VM
2013-06-03 18:09:07,382 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Searching resources only under specified Pod: 1
2013-06-03 18:09:07,383 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Listing clusters in order of aggregate capacity, that
have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2013-06-03 18:09:07,384 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) CPUOverprovisioningFactor considered: 1.0
2013-06-03 18:09:07,386 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) Removing from the clusterId list these clusters from
avoid set: [1]
2013-06-03 18:09:07,386 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-1:job-8) No clusters found after removing disabled clusters
and clusters in avoid list, returning.
2013-06-03 18:09:07,682 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-1:job-8) VM state transitted from :Starting to Stopped with
event: OperationFailedvm's original host id: 1 new host id: null host id
before state transition: null
2013-06-03 18:09:07,767 INFO [cloud.api.ApiDispatcher]
(Job-Executor-1:job-8) Unable to create a deployment for VM[User|i-2-13-VM]
2013-06-03 18:09:07,768 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-1:job-8) Complete async job-8, jobStatus: 2, resultCode: 530,
result: com.cloud.api.response.ExceptionResponse@73cee4bb
2013-06-03 18:09:11,523 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) VmStatsCollector is running...
2013-06-03 18:09:11,524 DEBUG [cloud.server.StatsCollector]
(StatsCollector-1:null) HostStatsCollector is running...
2013-06-03 18:09:11,879 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) StorageCollector is running...
2013-06-03 18:09:11,883 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) There is no secondary storage VM for secondary
storage host nfs://192.168.124.40/export/secondary
2013-06-03 18:09:11,942 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-6:null) Async job-8 completed
2013-06-03 18:09:26,932 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is not ready to launch secondary storage VM yet
2013-06-03 18:09:27,086 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2013-06-03 18:09:27,949 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2013-06-03 18:09:56,932 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is not ready to launch secondary storage VM yet
2013-06-03 18:09:57,086 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2013-06-03 18:09:57,949 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2013-06-03 18:10:11,526 DEBUG [cloud.server.StatsCollector]
(StatsCollector-1:null) VmStatsCollector is running...
2013-06-03 18:10:11,526 DEBUG [cloud.server.StatsCollector]
(StatsCollector-2:null) HostStatsCollector is running...
2013-06-03 18:10:11,886 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) StorageCollector is running...
2013-06-03 18:10:11,890 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) There is no secondary storage VM for secondary
storage host nfs://192.168.124.40/export/secondary
2013-06-03 18:10:26,932 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is not ready to launch secondary storage VM yet
2013-06-03 18:10:27,086 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2013-06-03 18:10:27,949 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2013-06-03 18:10:56,932 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is not ready to launch secondary storage VM yet
2013-06-03 18:10:57,086 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2013-06-03 18:10:57,625 DEBUG [storage.snapshot.SnapshotSchedulerImpl]
(SnapshotPollTask:null) Snapshot scheduler.poll is being called at
2013-06-03 12:40:57 GMT
2013-06-03 18:10:57,627 DEBUG [storage.snapshot.SnapshotSchedulerImpl]
(SnapshotPollTask:null) Got 0 snapshots to be executed at 2013-06-03
12:40:57 GMT
2013-06-03 18:10:57,946 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null)
Found 0 running routers.
2013-06-03 18:10:57,948 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2013-06-03 18:10:58,128 DEBUG
[cloud.network.ExternalLoadBalancerUsageManagerImpl]
(ExternalNetworkMonitor-1:null) External load balancer devices stats
collector is running...
2013-06-03 18:11:11,528 DEBUG [cloud.server.StatsCollector]
(StatsCollector-2:null) VmStatsCollector is running...
2013-06-03 18:11:11,529 DEBUG [cloud.server.StatsCollector]
(StatsCollector-1:null) HostStatsCollector is running...
2013-06-03 18:11:11,893 DEBUG [cloud.server.StatsCollector]
(StatsCollector-1:null) StorageCollector is running...
2013-06-03 18:11:11,897 DEBUG [cloud.server.StatsCollector]
(StatsCollector-1:null) There is no secondary storage VM for secondary
storage host nfs://192.168.124.40/export/secondary
2013-06-03 18:11:26,932 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is not ready to launch secondary storage VM yet
2013-06-03 18:11:27,086 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2013-06-03 18:11:27,607 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Running Capacity Checker ...
2013-06-03 18:11:27,607 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) recalculating system capacity
2013-06-03 18:11:27,607 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Executing cpu/ram capacity update
2013-06-03 18:11:27,614 DEBUG [cloud.capacity.CapacityManagerImpl]
(CapacityChecker:null) Found 0 VMs on host 1
2013-06-03 18:11:27,623 DEBUG [cloud.capacity.CapacityManagerImpl]
(CapacityChecker:null) Found 11 VM, not running on host 1
2013-06-03 18:11:27,626 DEBUG [cloud.capacity.CapacityManagerImpl]
(CapacityChecker:null) Calibrate reserved cpu for host: 1 old
reservedCpu:500 new reservedCpu:1524
2013-06-03 18:11:27,626 DEBUG [cloud.capacity.CapacityManagerImpl]
(CapacityChecker:null) Calibrate reserved memory for host: 1 old
reservedMem:134217728 new reservedMem:2281701376
2013-06-03 18:11:27,949 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2013-06-03 18:11:28,085 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done executing cpu/ram capacity update
2013-06-03 18:11:28,085 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Executing storage capacity update
2013-06-03 18:11:28,189 DEBUG [cloud.storage.StorageManagerImpl]
(CapacityChecker:null) Successfully set Capacity - 315054096384 for capacity
type - 3 , DataCenterId - 1, HostOrPoolId - 200, PodId 1
2013-06-03 18:11:28,272 DEBUG [cloud.storage.StorageManagerImpl]
(CapacityChecker:null) Successfully set Capacity - 449968521216 for capacity
type - 9 , DataCenterId - 1, HostOrPoolId - 201, PodId 1
2013-06-03 18:11:28,272 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done executing storage capacity update
2013-06-03 18:11:28,272 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Executing capacity updates for public ip and Vlans
2013-06-03 18:11:28,278 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done capacity updates for public ip and Vlans
2013-06-03 18:11:28,279 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Executing capacity updates for private ip
2013-06-03 18:11:28,284 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done executing capacity updates for private ip
2013-06-03 18:11:28,284 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done recalculating system capacity
2013-06-03 18:11:28,303 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done running Capacity Checker ...
2013-06-03 18:11:56,934 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is not ready to launch secondary storage VM yet
2013-06-03 18:11:57,086 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
2013-06-03 18:11:57,949 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
