You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Caleb Call <ca...@me.com> on 2013/07/18 22:24:28 UTC
Console Proxy not starting
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
Re: Console Proxy not starting
Posted by David Comerford <da...@gmail.com>.
Can't say I'd support a separate log for each ssvm but a different log for
each zone isn't a bad idea.
Could be worth a feature request!
Best regards,
David Comerford
------------------------
Tel: +353 87 1238295
Email: davestyle@gmail.com
Website: http://dave.ie
GPG key: http://gpg.dave.ie
On 24 July 2013 00:11, Caleb Call <ca...@me.com> wrote:
> Yep, still no new console proxy vm. I'll have to take a look at the logs
> to see what's going on.
>
> side note: I wish each zone would log to a separate log, or system vm
> activity would log to a separate log from the user instances.
>
> On Jul 23, 2013, at 2:40 PM, David Comerford <da...@gmail.com> wrote:
>
> > Yeah, should be a couple of minutes at most.
> > If you don't have it yet it's time to examine the logs.
> >
> >
> > Best regards,
> > David Comerford
> > ------------------------
> > Tel: +353 87 1238295
> > Email: davestyle@gmail.com
> > Website: http://dave.ie
> > GPG key: http://gpg.dave.ie
> >
> >
> > On 23 July 2013 19:35, Dean Kamali <de...@gmail.com> wrote:
> >
> >> I destroyed proxy vm few days ago, and in about 30 seconds or so I saw
> the
> >> new one getting created and started in about 1 -2 min.
> >>
> >> environment: cs 4.1 xenserver 6.0.2
> >>
> >>
> >> On Tue, Jul 23, 2013 at 12:12 PM, Caleb Call <ca...@me.com> wrote:
> >>
> >>> That's odd because of all my zones, this is the only one I haven't
> moved
> >> a
> >>> hypervisor in or out of since being built.
> >>>
> >>> I destroyed the Console Proxy VM, how long should it take before CS
> spins
> >>> a new one up?
> >>>
> >>> Thanks
> >>>
> >>> On Jul 22, 2013, at 10:26 PM, Ahmad Emneina <ae...@gmail.com>
> wrote:
> >>>
> >>>> Hey Caleb, looks like the host the console proxy used to live on is
> >> gone.
> >>>> see:
> >>>> 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
> >>>>
> >>>> what I would do is nuke (destroy) the console proxy vm, and allow
> >>>> cloudstack to spin up a new one.
> >>>>
> >>>>
> >>>> On Mon, Jul 22, 2013 at 8:56 AM, Caleb Call <ca...@me.com> wrote:
> >>>>
> >>>>> Primary storage is not in maintenance mode and is available. I have
> a
> >>>>> couple dozen VMs running from this same primary storage and the SSVM
> >> and
> >>>>> router VM are both running from this same storage. Only the console
> >>> proxy
> >>>>> seems to be having a problem.
> >>>>>
> >>>>> $ ./cloudAPI.pl -c listStoragePools -p
> >>>>> clusterid=f200c92f-5937-43c7-8bf5-6593f7311400
> >>>>>
> >>>>>
> >>>
> >>
> https://cloud.overstock.com/client/api?apiKey=xxxxxxxxxxxxxxxxx&clusterid=f200c92f-5937-43c7-8bf5-6593f7311400&command=listStoragePools&response=json&signature=xxxxxxxxxxxxx{
> >>>>> "liststoragepoolsresponse" : {
> >>>>> "storagepool" : [
> >>>>> {
> >>>>> "clusterid" : "f200c92f-5937-43c7-8bf5-6593f7311400",
> >>>>> "zonename" : "Offshore",
> >>>>> "state" : "Up",
> >>>>> "disksizeallocated" : 359196000256,
> >>>>> "podid" : "20eff451-3edd-4366-8ab2-60f2390e5134",
> >>>>> "podname" : "Offshore",
> >>>>> "id" : "OFFSHORE_FC_LUN01",
> >>>>> "clustername" : "Offshore",
> >>>>> "zoneid" : "8e1c49fc-a5b3-44bb-9d54-932b0047eed0",
> >>>>> "name" : "OFFSHORE_FC_LUN01",
> >>>>> "disksizeused" : 360047443968,
> >>>>> "path" : "/OFFSHORE_FC_LUN01",
> >>>>> "disksizetotal" : 1099499044864,
> >>>>> "tags" : "",
> >>>>> "created" : "2013-06-08T15:45:05-0600",
> >>>>> "type" : "PreSetup",
> >>>>> "ipaddress" : "localhost"
> >>>>> }
> >>>>> ],
> >>>>> "count" : 1
> >>>>> }
> >>>>> }
> >>>>>
> >>>>>
> >>>>>
> >>>>> On Jul 20, 2013, at 5:06 PM, David Comerford <da...@gmail.com>
> >>> wrote:
> >>>>>
> >>>>>>> For some reason I was thinking the system VMs lived on the
> secondary
> >>>>>> storage, but I'm probably wrong on that.
> >>>>>> The templates for the system VM's live on secondary storage, then
> >> they
> >>>>> are
> >>>>>> deployed to primary storage.
> >>>>>>
> >>>>>> Allocator seems happy enough to use host id 51 but theres no primary
> >>>>>> storage available in cluster id 9.
> >>>>>> Is it in maintenance mode or anything?
> >>>>>>
> >>>>>> 'list storagepools' in cloudmonkey might shed some light.
> >>>>>>
> >>>>>> Best regards,
> >>>>>> David Comerford
> >>>>>> ------------------------
> >>>>>> Tel: +353 87 1238295
> >>>>>> Email: davestyle@gmail.com
> >>>>>> Website: http://dave.ie
> >>>>>> GPG key: http://gpg.dave.ie <http://pgp.dave.ie>
> >>>>>>
> >>>>>>
> >>>>>> On 18 July 2013 21:27, Bradley Hieber <me...@gmail.com> wrote:
> >>>>>>
> >>>>>>> pastebin please
> >>>>>>>
> >>>>>>>
> >>>>>>> On Thu, Jul 18, 2013 at 4:24 PM, Caleb Call <ca...@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
> >>>>>>>
> >>>>>
> >>>>>
> >>>
> >>>
> >>
>
>
Re: Console Proxy not starting
Posted by Caleb Call <ca...@me.com>.
Yep, still no new console proxy vm. I'll have to take a look at the logs to see what's going on.
side note: I wish each zone would log to a separate log, or system vm activity would log to a separate log from the user instances.
On Jul 23, 2013, at 2:40 PM, David Comerford <da...@gmail.com> wrote:
> Yeah, should be a couple of minutes at most.
> If you don't have it yet it's time to examine the logs.
>
>
> Best regards,
> David Comerford
> ------------------------
> Tel: +353 87 1238295
> Email: davestyle@gmail.com
> Website: http://dave.ie
> GPG key: http://gpg.dave.ie
>
>
> On 23 July 2013 19:35, Dean Kamali <de...@gmail.com> wrote:
>
>> I destroyed proxy vm few days ago, and in about 30 seconds or so I saw the
>> new one getting created and started in about 1 -2 min.
>>
>> environment: cs 4.1 xenserver 6.0.2
>>
>>
>> On Tue, Jul 23, 2013 at 12:12 PM, Caleb Call <ca...@me.com> wrote:
>>
>>> That's odd because of all my zones, this is the only one I haven't moved
>> a
>>> hypervisor in or out of since being built.
>>>
>>> I destroyed the Console Proxy VM, how long should it take before CS spins
>>> a new one up?
>>>
>>> Thanks
>>>
>>> On Jul 22, 2013, at 10:26 PM, Ahmad Emneina <ae...@gmail.com> wrote:
>>>
>>>> Hey Caleb, looks like the host the console proxy used to live on is
>> gone.
>>>> see:
>>>> 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
>>>>
>>>> what I would do is nuke (destroy) the console proxy vm, and allow
>>>> cloudstack to spin up a new one.
>>>>
>>>>
>>>> On Mon, Jul 22, 2013 at 8:56 AM, Caleb Call <ca...@me.com> wrote:
>>>>
>>>>> Primary storage is not in maintenance mode and is available. I have a
>>>>> couple dozen VMs running from this same primary storage and the SSVM
>> and
>>>>> router VM are both running from this same storage. Only the console
>>> proxy
>>>>> seems to be having a problem.
>>>>>
>>>>> $ ./cloudAPI.pl -c listStoragePools -p
>>>>> clusterid=f200c92f-5937-43c7-8bf5-6593f7311400
>>>>>
>>>>>
>>>
>> https://cloud.overstock.com/client/api?apiKey=xxxxxxxxxxxxxxxxx&clusterid=f200c92f-5937-43c7-8bf5-6593f7311400&command=listStoragePools&response=json&signature=xxxxxxxxxxxxx{
>>>>> "liststoragepoolsresponse" : {
>>>>> "storagepool" : [
>>>>> {
>>>>> "clusterid" : "f200c92f-5937-43c7-8bf5-6593f7311400",
>>>>> "zonename" : "Offshore",
>>>>> "state" : "Up",
>>>>> "disksizeallocated" : 359196000256,
>>>>> "podid" : "20eff451-3edd-4366-8ab2-60f2390e5134",
>>>>> "podname" : "Offshore",
>>>>> "id" : "OFFSHORE_FC_LUN01",
>>>>> "clustername" : "Offshore",
>>>>> "zoneid" : "8e1c49fc-a5b3-44bb-9d54-932b0047eed0",
>>>>> "name" : "OFFSHORE_FC_LUN01",
>>>>> "disksizeused" : 360047443968,
>>>>> "path" : "/OFFSHORE_FC_LUN01",
>>>>> "disksizetotal" : 1099499044864,
>>>>> "tags" : "",
>>>>> "created" : "2013-06-08T15:45:05-0600",
>>>>> "type" : "PreSetup",
>>>>> "ipaddress" : "localhost"
>>>>> }
>>>>> ],
>>>>> "count" : 1
>>>>> }
>>>>> }
>>>>>
>>>>>
>>>>>
>>>>> On Jul 20, 2013, at 5:06 PM, David Comerford <da...@gmail.com>
>>> wrote:
>>>>>
>>>>>>> For some reason I was thinking the system VMs lived on the secondary
>>>>>> storage, but I'm probably wrong on that.
>>>>>> The templates for the system VM's live on secondary storage, then
>> they
>>>>> are
>>>>>> deployed to primary storage.
>>>>>>
>>>>>> Allocator seems happy enough to use host id 51 but theres no primary
>>>>>> storage available in cluster id 9.
>>>>>> Is it in maintenance mode or anything?
>>>>>>
>>>>>> 'list storagepools' in cloudmonkey might shed some light.
>>>>>>
>>>>>> Best regards,
>>>>>> David Comerford
>>>>>> ------------------------
>>>>>> Tel: +353 87 1238295
>>>>>> Email: davestyle@gmail.com
>>>>>> Website: http://dave.ie
>>>>>> GPG key: http://gpg.dave.ie <http://pgp.dave.ie>
>>>>>>
>>>>>>
>>>>>> On 18 July 2013 21:27, Bradley Hieber <me...@gmail.com> wrote:
>>>>>>
>>>>>>> pastebin please
>>>>>>>
>>>>>>>
>>>>>>> On Thu, Jul 18, 2013 at 4:24 PM, Caleb Call <ca...@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
>>>>>>>
>>>>>
>>>>>
>>>
>>>
>>
Re: Console Proxy not starting
Posted by David Comerford <da...@gmail.com>.
Yeah, should be a couple of minutes at most.
If you don't have it yet it's time to examine the logs.
Best regards,
David Comerford
------------------------
Tel: +353 87 1238295
Email: davestyle@gmail.com
Website: http://dave.ie
GPG key: http://gpg.dave.ie
On 23 July 2013 19:35, Dean Kamali <de...@gmail.com> wrote:
> I destroyed proxy vm few days ago, and in about 30 seconds or so I saw the
> new one getting created and started in about 1 -2 min.
>
> environment: cs 4.1 xenserver 6.0.2
>
>
> On Tue, Jul 23, 2013 at 12:12 PM, Caleb Call <ca...@me.com> wrote:
>
> > That's odd because of all my zones, this is the only one I haven't moved
> a
> > hypervisor in or out of since being built.
> >
> > I destroyed the Console Proxy VM, how long should it take before CS spins
> > a new one up?
> >
> > Thanks
> >
> > On Jul 22, 2013, at 10:26 PM, Ahmad Emneina <ae...@gmail.com> wrote:
> >
> > > Hey Caleb, looks like the host the console proxy used to live on is
> gone.
> > > see:
> > > 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
> > >
> > > what I would do is nuke (destroy) the console proxy vm, and allow
> > > cloudstack to spin up a new one.
> > >
> > >
> > > On Mon, Jul 22, 2013 at 8:56 AM, Caleb Call <ca...@me.com> wrote:
> > >
> > >> Primary storage is not in maintenance mode and is available. I have a
> > >> couple dozen VMs running from this same primary storage and the SSVM
> and
> > >> router VM are both running from this same storage. Only the console
> > proxy
> > >> seems to be having a problem.
> > >>
> > >> $ ./cloudAPI.pl -c listStoragePools -p
> > >> clusterid=f200c92f-5937-43c7-8bf5-6593f7311400
> > >>
> > >>
> >
> https://cloud.overstock.com/client/api?apiKey=xxxxxxxxxxxxxxxxx&clusterid=f200c92f-5937-43c7-8bf5-6593f7311400&command=listStoragePools&response=json&signature=xxxxxxxxxxxxx{
> > >> "liststoragepoolsresponse" : {
> > >> "storagepool" : [
> > >> {
> > >> "clusterid" : "f200c92f-5937-43c7-8bf5-6593f7311400",
> > >> "zonename" : "Offshore",
> > >> "state" : "Up",
> > >> "disksizeallocated" : 359196000256,
> > >> "podid" : "20eff451-3edd-4366-8ab2-60f2390e5134",
> > >> "podname" : "Offshore",
> > >> "id" : "OFFSHORE_FC_LUN01",
> > >> "clustername" : "Offshore",
> > >> "zoneid" : "8e1c49fc-a5b3-44bb-9d54-932b0047eed0",
> > >> "name" : "OFFSHORE_FC_LUN01",
> > >> "disksizeused" : 360047443968,
> > >> "path" : "/OFFSHORE_FC_LUN01",
> > >> "disksizetotal" : 1099499044864,
> > >> "tags" : "",
> > >> "created" : "2013-06-08T15:45:05-0600",
> > >> "type" : "PreSetup",
> > >> "ipaddress" : "localhost"
> > >> }
> > >> ],
> > >> "count" : 1
> > >> }
> > >> }
> > >>
> > >>
> > >>
> > >> On Jul 20, 2013, at 5:06 PM, David Comerford <da...@gmail.com>
> > wrote:
> > >>
> > >>>> For some reason I was thinking the system VMs lived on the secondary
> > >>> storage, but I'm probably wrong on that.
> > >>> The templates for the system VM's live on secondary storage, then
> they
> > >> are
> > >>> deployed to primary storage.
> > >>>
> > >>> Allocator seems happy enough to use host id 51 but theres no primary
> > >>> storage available in cluster id 9.
> > >>> Is it in maintenance mode or anything?
> > >>>
> > >>> 'list storagepools' in cloudmonkey might shed some light.
> > >>>
> > >>> Best regards,
> > >>> David Comerford
> > >>> ------------------------
> > >>> Tel: +353 87 1238295
> > >>> Email: davestyle@gmail.com
> > >>> Website: http://dave.ie
> > >>> GPG key: http://gpg.dave.ie <http://pgp.dave.ie>
> > >>>
> > >>>
> > >>> On 18 July 2013 21:27, Bradley Hieber <me...@gmail.com> wrote:
> > >>>
> > >>>> pastebin please
> > >>>>
> > >>>>
> > >>>> On Thu, Jul 18, 2013 at 4:24 PM, Caleb Call <ca...@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
> > >>>>
> > >>
> > >>
> >
> >
>
Re: Console Proxy not starting
Posted by Dean Kamali <de...@gmail.com>.
I destroyed proxy vm few days ago, and in about 30 seconds or so I saw the
new one getting created and started in about 1 -2 min.
environment: cs 4.1 xenserver 6.0.2
On Tue, Jul 23, 2013 at 12:12 PM, Caleb Call <ca...@me.com> wrote:
> That's odd because of all my zones, this is the only one I haven't moved a
> hypervisor in or out of since being built.
>
> I destroyed the Console Proxy VM, how long should it take before CS spins
> a new one up?
>
> Thanks
>
> On Jul 22, 2013, at 10:26 PM, Ahmad Emneina <ae...@gmail.com> wrote:
>
> > Hey Caleb, looks like the host the console proxy used to live on is gone.
> > see:
> > 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
> >
> > what I would do is nuke (destroy) the console proxy vm, and allow
> > cloudstack to spin up a new one.
> >
> >
> > On Mon, Jul 22, 2013 at 8:56 AM, Caleb Call <ca...@me.com> wrote:
> >
> >> Primary storage is not in maintenance mode and is available. I have a
> >> couple dozen VMs running from this same primary storage and the SSVM and
> >> router VM are both running from this same storage. Only the console
> proxy
> >> seems to be having a problem.
> >>
> >> $ ./cloudAPI.pl -c listStoragePools -p
> >> clusterid=f200c92f-5937-43c7-8bf5-6593f7311400
> >>
> >>
> https://cloud.overstock.com/client/api?apiKey=xxxxxxxxxxxxxxxxx&clusterid=f200c92f-5937-43c7-8bf5-6593f7311400&command=listStoragePools&response=json&signature=xxxxxxxxxxxxx{
> >> "liststoragepoolsresponse" : {
> >> "storagepool" : [
> >> {
> >> "clusterid" : "f200c92f-5937-43c7-8bf5-6593f7311400",
> >> "zonename" : "Offshore",
> >> "state" : "Up",
> >> "disksizeallocated" : 359196000256,
> >> "podid" : "20eff451-3edd-4366-8ab2-60f2390e5134",
> >> "podname" : "Offshore",
> >> "id" : "OFFSHORE_FC_LUN01",
> >> "clustername" : "Offshore",
> >> "zoneid" : "8e1c49fc-a5b3-44bb-9d54-932b0047eed0",
> >> "name" : "OFFSHORE_FC_LUN01",
> >> "disksizeused" : 360047443968,
> >> "path" : "/OFFSHORE_FC_LUN01",
> >> "disksizetotal" : 1099499044864,
> >> "tags" : "",
> >> "created" : "2013-06-08T15:45:05-0600",
> >> "type" : "PreSetup",
> >> "ipaddress" : "localhost"
> >> }
> >> ],
> >> "count" : 1
> >> }
> >> }
> >>
> >>
> >>
> >> On Jul 20, 2013, at 5:06 PM, David Comerford <da...@gmail.com>
> wrote:
> >>
> >>>> For some reason I was thinking the system VMs lived on the secondary
> >>> storage, but I'm probably wrong on that.
> >>> The templates for the system VM's live on secondary storage, then they
> >> are
> >>> deployed to primary storage.
> >>>
> >>> Allocator seems happy enough to use host id 51 but theres no primary
> >>> storage available in cluster id 9.
> >>> Is it in maintenance mode or anything?
> >>>
> >>> 'list storagepools' in cloudmonkey might shed some light.
> >>>
> >>> Best regards,
> >>> David Comerford
> >>> ------------------------
> >>> Tel: +353 87 1238295
> >>> Email: davestyle@gmail.com
> >>> Website: http://dave.ie
> >>> GPG key: http://gpg.dave.ie <http://pgp.dave.ie>
> >>>
> >>>
> >>> On 18 July 2013 21:27, Bradley Hieber <me...@gmail.com> wrote:
> >>>
> >>>> pastebin please
> >>>>
> >>>>
> >>>> On Thu, Jul 18, 2013 at 4:24 PM, Caleb Call <ca...@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
> >>>>
> >>
> >>
>
>
Re: Console Proxy not starting
Posted by Caleb Call <ca...@me.com>.
That's odd because of all my zones, this is the only one I haven't moved a hypervisor in or out of since being built.
I destroyed the Console Proxy VM, how long should it take before CS spins a new one up?
Thanks
On Jul 22, 2013, at 10:26 PM, Ahmad Emneina <ae...@gmail.com> wrote:
> Hey Caleb, looks like the host the console proxy used to live on is gone.
> see:
> 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
>
> what I would do is nuke (destroy) the console proxy vm, and allow
> cloudstack to spin up a new one.
>
>
> On Mon, Jul 22, 2013 at 8:56 AM, Caleb Call <ca...@me.com> wrote:
>
>> Primary storage is not in maintenance mode and is available. I have a
>> couple dozen VMs running from this same primary storage and the SSVM and
>> router VM are both running from this same storage. Only the console proxy
>> seems to be having a problem.
>>
>> $ ./cloudAPI.pl -c listStoragePools -p
>> clusterid=f200c92f-5937-43c7-8bf5-6593f7311400
>>
>> https://cloud.overstock.com/client/api?apiKey=xxxxxxxxxxxxxxxxx&clusterid=f200c92f-5937-43c7-8bf5-6593f7311400&command=listStoragePools&response=json&signature=xxxxxxxxxxxxx{
>> "liststoragepoolsresponse" : {
>> "storagepool" : [
>> {
>> "clusterid" : "f200c92f-5937-43c7-8bf5-6593f7311400",
>> "zonename" : "Offshore",
>> "state" : "Up",
>> "disksizeallocated" : 359196000256,
>> "podid" : "20eff451-3edd-4366-8ab2-60f2390e5134",
>> "podname" : "Offshore",
>> "id" : "OFFSHORE_FC_LUN01",
>> "clustername" : "Offshore",
>> "zoneid" : "8e1c49fc-a5b3-44bb-9d54-932b0047eed0",
>> "name" : "OFFSHORE_FC_LUN01",
>> "disksizeused" : 360047443968,
>> "path" : "/OFFSHORE_FC_LUN01",
>> "disksizetotal" : 1099499044864,
>> "tags" : "",
>> "created" : "2013-06-08T15:45:05-0600",
>> "type" : "PreSetup",
>> "ipaddress" : "localhost"
>> }
>> ],
>> "count" : 1
>> }
>> }
>>
>>
>>
>> On Jul 20, 2013, at 5:06 PM, David Comerford <da...@gmail.com> wrote:
>>
>>>> For some reason I was thinking the system VMs lived on the secondary
>>> storage, but I'm probably wrong on that.
>>> The templates for the system VM's live on secondary storage, then they
>> are
>>> deployed to primary storage.
>>>
>>> Allocator seems happy enough to use host id 51 but theres no primary
>>> storage available in cluster id 9.
>>> Is it in maintenance mode or anything?
>>>
>>> 'list storagepools' in cloudmonkey might shed some light.
>>>
>>> Best regards,
>>> David Comerford
>>> ------------------------
>>> Tel: +353 87 1238295
>>> Email: davestyle@gmail.com
>>> Website: http://dave.ie
>>> GPG key: http://gpg.dave.ie <http://pgp.dave.ie>
>>>
>>>
>>> On 18 July 2013 21:27, Bradley Hieber <me...@gmail.com> wrote:
>>>
>>>> pastebin please
>>>>
>>>>
>>>> On Thu, Jul 18, 2013 at 4:24 PM, Caleb Call <ca...@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
>>>>
>>
>>
Re: Console Proxy not starting
Posted by Ahmad Emneina <ae...@gmail.com>.
Hey Caleb, looks like the host the console proxy used to live on is gone.
see:
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
what I would do is nuke (destroy) the console proxy vm, and allow
cloudstack to spin up a new one.
On Mon, Jul 22, 2013 at 8:56 AM, Caleb Call <ca...@me.com> wrote:
> Primary storage is not in maintenance mode and is available. I have a
> couple dozen VMs running from this same primary storage and the SSVM and
> router VM are both running from this same storage. Only the console proxy
> seems to be having a problem.
>
> $ ./cloudAPI.pl -c listStoragePools -p
> clusterid=f200c92f-5937-43c7-8bf5-6593f7311400
>
> https://cloud.overstock.com/client/api?apiKey=xxxxxxxxxxxxxxxxx&clusterid=f200c92f-5937-43c7-8bf5-6593f7311400&command=listStoragePools&response=json&signature=xxxxxxxxxxxxx{
> "liststoragepoolsresponse" : {
> "storagepool" : [
> {
> "clusterid" : "f200c92f-5937-43c7-8bf5-6593f7311400",
> "zonename" : "Offshore",
> "state" : "Up",
> "disksizeallocated" : 359196000256,
> "podid" : "20eff451-3edd-4366-8ab2-60f2390e5134",
> "podname" : "Offshore",
> "id" : "OFFSHORE_FC_LUN01",
> "clustername" : "Offshore",
> "zoneid" : "8e1c49fc-a5b3-44bb-9d54-932b0047eed0",
> "name" : "OFFSHORE_FC_LUN01",
> "disksizeused" : 360047443968,
> "path" : "/OFFSHORE_FC_LUN01",
> "disksizetotal" : 1099499044864,
> "tags" : "",
> "created" : "2013-06-08T15:45:05-0600",
> "type" : "PreSetup",
> "ipaddress" : "localhost"
> }
> ],
> "count" : 1
> }
> }
>
>
>
> On Jul 20, 2013, at 5:06 PM, David Comerford <da...@gmail.com> wrote:
>
> >> For some reason I was thinking the system VMs lived on the secondary
> > storage, but I'm probably wrong on that.
> > The templates for the system VM's live on secondary storage, then they
> are
> > deployed to primary storage.
> >
> > Allocator seems happy enough to use host id 51 but theres no primary
> > storage available in cluster id 9.
> > Is it in maintenance mode or anything?
> >
> > 'list storagepools' in cloudmonkey might shed some light.
> >
> > Best regards,
> > David Comerford
> > ------------------------
> > Tel: +353 87 1238295
> > Email: davestyle@gmail.com
> > Website: http://dave.ie
> > GPG key: http://gpg.dave.ie <http://pgp.dave.ie>
> >
> >
> > On 18 July 2013 21:27, Bradley Hieber <me...@gmail.com> wrote:
> >
> >> pastebin please
> >>
> >>
> >> On Thu, Jul 18, 2013 at 4:24 PM, Caleb Call <ca...@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
> >>
>
>
Re: Console Proxy not starting
Posted by Caleb Call <ca...@me.com>.
Primary storage is not in maintenance mode and is available. I have a couple dozen VMs running from this same primary storage and the SSVM and router VM are both running from this same storage. Only the console proxy seems to be having a problem.
$ ./cloudAPI.pl -c listStoragePools -p clusterid=f200c92f-5937-43c7-8bf5-6593f7311400
https://cloud.overstock.com/client/api?apiKey=xxxxxxxxxxxxxxxxx&clusterid=f200c92f-5937-43c7-8bf5-6593f7311400&command=listStoragePools&response=json&signature=xxxxxxxxxxxxx{
"liststoragepoolsresponse" : {
"storagepool" : [
{
"clusterid" : "f200c92f-5937-43c7-8bf5-6593f7311400",
"zonename" : "Offshore",
"state" : "Up",
"disksizeallocated" : 359196000256,
"podid" : "20eff451-3edd-4366-8ab2-60f2390e5134",
"podname" : "Offshore",
"id" : "OFFSHORE_FC_LUN01",
"clustername" : "Offshore",
"zoneid" : "8e1c49fc-a5b3-44bb-9d54-932b0047eed0",
"name" : "OFFSHORE_FC_LUN01",
"disksizeused" : 360047443968,
"path" : "/OFFSHORE_FC_LUN01",
"disksizetotal" : 1099499044864,
"tags" : "",
"created" : "2013-06-08T15:45:05-0600",
"type" : "PreSetup",
"ipaddress" : "localhost"
}
],
"count" : 1
}
}
On Jul 20, 2013, at 5:06 PM, David Comerford <da...@gmail.com> wrote:
>> For some reason I was thinking the system VMs lived on the secondary
> storage, but I'm probably wrong on that.
> The templates for the system VM's live on secondary storage, then they are
> deployed to primary storage.
>
> Allocator seems happy enough to use host id 51 but theres no primary
> storage available in cluster id 9.
> Is it in maintenance mode or anything?
>
> 'list storagepools' in cloudmonkey might shed some light.
>
> Best regards,
> David Comerford
> ------------------------
> Tel: +353 87 1238295
> Email: davestyle@gmail.com
> Website: http://dave.ie
> GPG key: http://gpg.dave.ie <http://pgp.dave.ie>
>
>
> On 18 July 2013 21:27, Bradley Hieber <me...@gmail.com> wrote:
>
>> pastebin please
>>
>>
>> On Thu, Jul 18, 2013 at 4:24 PM, Caleb Call <ca...@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
>>
Re: Console Proxy not starting
Posted by David Comerford <da...@gmail.com>.
> For some reason I was thinking the system VMs lived on the secondary
storage, but I'm probably wrong on that.
The templates for the system VM's live on secondary storage, then they are
deployed to primary storage.
Allocator seems happy enough to use host id 51 but theres no primary
storage available in cluster id 9.
Is it in maintenance mode or anything?
'list storagepools' in cloudmonkey might shed some light.
Best regards,
David Comerford
------------------------
Tel: +353 87 1238295
Email: davestyle@gmail.com
Website: http://dave.ie
GPG key: http://gpg.dave.ie <http://pgp.dave.ie>
On 18 July 2013 21:27, Bradley Hieber <me...@gmail.com> wrote:
> pastebin please
>
>
> On Thu, Jul 18, 2013 at 4:24 PM, Caleb Call <ca...@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
>
Re: Console Proxy not starting
Posted by Bradley Hieber <me...@gmail.com>.
pastebin please
On Thu, Jul 18, 2013 at 4:24 PM, Caleb Call <ca...@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