pastebin please
On Thu, Jul 18, 2013 at 4:24 PM, Caleb Call <calebc...@me.com> wrote:
> When trying to start the console proxy in one of my zones fails. I'm
> getting an error that says "no suitable storagePools for in this cluster".
> Which storage pool would this be? For some reason I was thinking the
> system VMs lived on the secondary storage, but I'm probably wrong on that.
> Either way, I have ~700GB of free space on my primary storage and ~500GB
> free in my secondary storage, what else is this looking for to be able to
> start this console proxy? I've included the logs around this event.
>
>
> 2013-07-18 14:02:40,031 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-13:null) ===START=== 10.4.108.254 -- GET
> command=startSystemVm&id=d10d7f57
>
> -8b1b-45b2-9875-8c18995ac37b&response=json&sessionkey=uMQLwJmB8uyPSQeSiSBXo04naus%3D&_=1374177759969
> 2013-07-18 14:02:40,033 DEBUG [ehcache.store.MemoryStore]
> (catalina-exec-13:null) UserDaoCache: UserDaoMemoryStore hit for 10
> 2013-07-18 14:02:40,112 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-13:null) submit async job-5916, details: AsyncJobVO
> {id:5916, use
> rId: 10, accountId: 7, sessionKey: null, instanceType: SystemVm,
> instanceId: 1024, cmd: com.cloud.api.commands.StartSystemVMCmd,
> cmdOriginator:
> null, cmdInfo:
> {"response":"json","id":"d10d7f57-8b1b-45b2-9875-8c18995ac37b","sessionkey":"uMQLwJmB8uyPSQeSiSBXo04naus\u003d","ctxUserId":"10",
> "_":"1374177759969","ctxAccountId":"7","ctxStartEventId":"18978"},
> cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
> processStat
> us: 0, resultCode: 0, result: null, initMsid: 145320940120008,
> completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2013-07-18 14:02:40,113 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-43:job-5916) Executing
> com.cloud.api.commands.StartSystemVMCmd for
> job-5916
> 2013-07-18 14:02:40,114 DEBUG [cloud.api.ApiServlet]
> (catalina-exec-13:null) ===END=== 10.4.108.254 -- GET
> command=startSystemVm&id=d10d7f57-8
>
> b1b-45b2-9875-8c18995ac37b&response=json&sessionkey=uMQLwJmB8uyPSQeSiSBXo04naus%3D&_=1374177759969
> 2013-07-18 14:02:40,125 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-43:job-5916) VM state transitted from :Stopped to Starting
> with
> event: StartRequestedvm's original host id: 25 new host id: null host id
> before state transition: null
> 2013-07-18 14:02:40,125 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-43:job-5916) Successfully transitioned to start state for
> VM[Co
> nsoleProxy|v-1024-VM] reservation id = c9a532cb-3976-4284-ab2e-17d7d5dca070
> 2013-07-18 14:02:40,138 DEBUG [ehcache.store.MemoryStore]
> (Job-Executor-43:job-5916) ServiceOfferingDaoCache:
> ServiceOfferingDaoMemoryStore hit
> for 8
> 2013-07-18 14:02:40,138 DEBUG [ehcache.store.MemoryStore]
> (Job-Executor-43:job-5916) VMTemplateDaoCache: VMTemplateDaoMemoryStore hit
> for 1
> 2013-07-18 14:02:40,138 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-43:job-5916) Trying to deploy VM, vm has dcId: 5 and podId: 8
> 2013-07-18 14:02:40,138 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-43:job-5916) Deploy avoids pods: null, clusters: null, hosts:
> n
> ull
> 2013-07-18 14:02:40,140 DEBUG [ehcache.store.MemoryStore]
> (Job-Executor-43:job-5916) DataCenterDaoCache: DataCenterDaoMemoryStore hit
> for 5
> 2013-07-18 14:02:40,141 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) DeploymentPlanner allocation algorithm: random
> 2013-07-18 14:02:40,141 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) Trying to allocate a host and storage pools from
> dc:5, p
> od:8,cluster:null, requested cpu: 500, requested ram: 1073741824
> 2013-07-18 14:02:40,141 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) Is ROOT volume READY (pool already allocated)?:
> No
> 2013-07-18 14:02:40,141 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) This VM has last host_id specified, trying to
> choose the
> same host: 25
> 2013-07-18 14:02:40,142 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) The last host of this VM cannot be found
> 2013-07-18 14:02:40,142 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) Cannot choose the last host to deploy this VM
> 2013-07-18 14:02:40,142 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) Searching resources only under specified Pod: 8
> 2013-07-18 14:02:40,142 DEBUG [ehcache.store.MemoryStore]
> (Job-Executor-43:job-5916) HostPodDaoCache: HostPodDaoMemoryStore hit for 8
> 2013-07-18 14:02:40,142 DEBUG [ehcache.store.MemoryStore]
> (Job-Executor-43:job-5916) DataCenterDaoCache: DataCenterDaoMemoryStore hit
> for 5
> 2013-07-18 14:02:40,143 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) Listing clusters in order of aggregate capacity,
> that ha
> ve (atleast one host with) enough CPU and RAM capacity under this Pod: 8
> 2013-07-18 14:02:40,143 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) CPUOverprovisioningFactor considered: 5.0
> 2013-07-18 14:02:40,150 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) Checking resources in Cluster: 9 under Pod: 8
> 2013-07-18 14:02:40,150 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) Calling HostAllocators to find suitable hosts
> 2013-07-18 14:02:40,150 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) Looking for hosts in
> dc: 5
> pod:8 cluster:9
> 2013-07-18 14:02:40,152 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) FirstFitAllocator has 1
> hos
> ts to check for allocation: [Host[-51-Routing]]
> 2013-07-18 14:02:40,154 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) Found 1 hosts for
> allocation after prioritization: [Host[-51-Routing]]
> 2013-07-18 14:02:40,154 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) Looking for
> speed=500Mhz, Ram=1024
> 2013-07-18 14:02:40,155 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) Checking if host: 51
> has enough capacity for requested CPU: 500 and requested RAM: 1073741824 ,
> cpuOverprovisioningFactor: 5.0
> 2013-07-18 14:02:40,157 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) Hosts's actual total
> CPU: 70400 and CPU after applying overprovisioning: 352000
> 2013-07-18 14:02:40,157 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) Free CPU: 303000 ,
> Requested CPU: 500
> 2013-07-18 14:02:40,157 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) Free RAM: 342436691072
> , Requested RAM: 1073741824
> 2013-07-18 14:02:40,157 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) Host has enough CPU and
> RAM available
> 2013-07-18 14:02:40,157 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) STATS: Can alloc CPU
> from host: 51, used: 49000, reserved: 0, actual total: 70400, total with
> overprovisioning: 352000; requested cpu:500,alloc_from_last_host?:false
> ,considerReservedCapacity?: true
> 2013-07-18 14:02:40,157 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) STATS: Can alloc MEM
> from host: 51, used: 62478352384, reserved: 0, total: 404915043456;
> requested mem: 1073741824,alloc_from_last_host?:false
> ,considerReservedCapacity?: true
> 2013-07-18 14:02:40,157 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) Found a suitable host,
> adding to list: 51
> 2013-07-18 14:02:40,157 DEBUG [allocator.impl.FirstFitAllocator]
> (Job-Executor-43:job-5916 FirstFitRoutingAllocator) Host Allocator
> returning 1 suitable hosts
> 2013-07-18 14:02:40,159 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) No suitable pools found
> 2013-07-18 14:02:40,159 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) No suitable storagePools found under this
> Cluster: 9
> 2013-07-18 14:02:40,159 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-43:job-5916) Could not find suitable Deployment Destination
> for this VM under any clusters, returning.
> 2013-07-18 14:02:40,186 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-43:job-5916) VM state transitted from :Starting to Stopped
> with event: OperationFailedvm's original host id: 25 new host id: null host
> id before state transition: null
> 2013-07-18 14:02:40,186 DEBUG [ehcache.store.MemoryStore]
> (Job-Executor-43:job-5916) ServiceOfferingDaoCache:
> ServiceOfferingDaoMemoryStore hit for 8
> 2013-07-18 14:02:40,188 WARN [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (Job-Executor-43:job-5916) Exception while trying to start console proxy
> com.cloud.exception.InsufficientServerCapacityException: Unable to create
> a deployment for VM[ConsoleProxy|v-1024-VM]Scope=interface
> com.cloud.dc.DataCenter; id=5
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:734)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
> at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
> at
> com.cloud.server.ManagementServerImpl.startConsoleProxy(ManagementServerImpl.java:1911)
> at
> com.cloud.server.ManagementServerImpl.startSystemVM(ManagementServerImpl.java:2728)
> at
> com.cloud.api.commands.StartSystemVMCmd.execute(StartSystemVMCmd.java:107)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
> at
> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432)
> 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-07-18 14:02:40,189 WARN [cloud.api.ApiDispatcher]
> (Job-Executor-43:job-5916) class com.cloud.api.ServerApiException : Fail to
> start system vm
> 2013-07-18 14:02:40,189 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-43:job-5916) Complete async job-5916, jobStatus: 2,
> resultCode: 530, result: Error Code: 530 Error text: Fail to start system vm
>
>
--
Brad
