cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Mueller, Udo" <Udo.Muel...@plath.de>
Subject AW: AW: CS 4.9.2: System VMs not starting
Date Tue, 07 May 2019 11:46:33 GMT
Hi Adrian,

yes it was. I think below message results from minimizing the CS Cluster to have a better overview over the agent log files.
I apologize for that.

See 

https://www.file-upload.net/download-13596521/management-server.log.html

where the cluster is fully populated again with  20 hosts and enough resources.

-----Urspr√ľngliche Nachricht-----
Von: asender@testlabs.com.au [mailto:asender@testlabs.com.au] 
Gesendet: Dienstag, 7. Mai 2019 02:16
An: users@cloudstack.apache.org
Cc: Mueller, Udo
Betreff: Re: AW: CS 4.9.2: System VMs not starting

Was it ever working, looks like a resource issue. I used to run KVM + 
CLVM with gfs successfully.

Adrian Sender


FirstFitRoutingAllocator) (logid:4706bea3) STATS: Failed to alloc 
resource
from host: 54 reservedCpu: 0, used cpu: 48000, requested cpu: 500, 
actual
total cpu: 19200, total cpu with overprovisioning: 48000, reservedMem: 
0,
used Mem: 103079215104, requested mem: 1073741824, total 
Mem:250820198400
,considerReservedCapacity?: true
2019-05-06 08:23:00,270 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
FirstFitRoutingAllocator) (logid:4706bea3) Host does not have enough CPU
available, cannot allocate to this host.


On 2019-05-07 00:14, Mueller, Udo wrote:
> Hi Suresh,
> 
> thanks for your reply!
> 
> Zone, Pod, Cluster and hosts are all up and enabled.
> Primary storage is online and enabled.
> 
> I changed  vm.deployment.planner to UserDispersingPlanner
> 
> Nothing changed:
> 
> 2019-05-06 14:04:20,466 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-723640c1) (logid:0fb29055) Zone 2 is ready to launch
> secondary storage VM
> 2019-05-06 14:04:20,469 INFO
> [o.a.c.s.PremiumSecondaryStorageManagerImpl]
> (secstorage-1:ctx-723640c1) (logid:0fb29055) No running secondary
> storage vms found in datacenter id=2, starting one
> 2019-05-06 14:04:20,472 TRACE [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-723640c1) (logid:0fb29055) Allocate secondary
> storage vm standby capacity for data center : 2
> 2019-05-06 14:04:20,474 INFO  [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-723640c1) (logid:0fb29055) Found a stopped secondary
> storage vm, starting it. Vm id : 4464
> 2019-05-06 14:04:20,509 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (secstorage-1:ctx-723640c1) (logid:0fb29055) Sync job-123639 execution
> on object VmWorkJobQueue.4464
> 2019-05-06 14:04:22,359 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
> (secstorage-1:ctx-723640c1) (logid:0fb29055) received secondary
> storage vm alert
> 2019-05-06 14:04:22,359 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
> (secstorage-1:ctx-723640c1) (logid:0fb29055) Secondary Storage Vm is
> up, zone: Intsys, secStorageVm: s-4464-VM, public IP: null, private
> IP: null
> 2019-05-06 14:04:22,360 WARN  [o.a.c.alerts]
> (secstorage-1:ctx-723640c1) (logid:0fb29055)  alertType:: 19 //
> dataCenterId:: 2 // podId:: null // clusterId:: null // message::
> Secondary Storage Vm up in zone: Intsys, secStorageVm: s-4464-VM,
> public IP: null, private IP: N/A
> 2019-05-06 14:04:22,392 INFO  [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-723640c1) (logid:0fb29055) Secondary storage vm
> s-4464-VM is started
> 2019-05-06 14:04:22,392 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
> (secstorage-1:ctx-723640c1) (logid:0fb29055) received secondary
> storage vm alert
> 2019-05-06 14:04:22,392 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
> (secstorage-1:ctx-723640c1) (logid:0fb29055) Secondary Storage Vm
> creation failure, zone: Intsys
> 2019-05-06 14:04:22,393 WARN  [o.a.c.alerts]
> (secstorage-1:ctx-723640c1) (logid:0fb29055)  alertType:: 19 //
> dataCenterId:: 2 // podId:: null // clusterId:: null // message::
> Secondary Storage Vm creation failure. zone: Intsys, error details:
> null
> 2019-05-06 14:04:22,412 INFO
> [o.a.c.s.PremiumSecondaryStorageManagerImpl]
> (secstorage-1:ctx-723640c1) (logid:0fb29055) Primary secondary storage
> is not even started, wait until next turn
> 
> Manual start of VM results in "System VM started" by web ui.
> 
> I changed  vm.deployment.planner to UserConcentratedPodPlanner
> 
> Nothing changed
> 
> 2019-05-06 14:13:44,824 DEBUG [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-2825c38c) (logid:64c127ac) Zone 2 is ready to
> launch console proxy
> 2019-05-06 14:13:44,824 DEBUG [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-2825c38c) (logid:64c127ac) Expand console proxy
> standby capacity for zone Intsys
> 2019-05-06 14:13:44,826 INFO  [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-2825c38c) (logid:64c127ac) Found a stopped console
> proxy, starting it. Vm id : 4463
> 2019-05-06 14:13:44,860 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (consoleproxy-1:ctx-2825c38c) (logid:64c127ac) Sync job-123671
> execution on object VmWorkJobQueue.4463
> 2019-05-06 14:13:46,816 INFO  [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-2825c38c) (logid:64c127ac) Console proxy v-4463-VM
> is started
> 2019-05-06 14:13:46,817 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
> (consoleproxy-1:ctx-2825c38c) (logid:64c127ac) received console proxy
> alert
> 2019-05-06 14:13:46,817 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
> (consoleproxy-1:ctx-2825c38c) (logid:64c127ac) Console proxy is up,
> zone: Intsys, proxy: v-4463-VM, public IP: null, private IP: null
> 2019-05-06 14:13:46,818 WARN  [o.a.c.alerts]
> (consoleproxy-1:ctx-2825c38c) (logid:64c127ac)  alertType:: 10 //
> dataCenterId:: 2 // podId:: null // clusterId:: null // message::
> Console proxy up in zone: Intsys, proxy: v-4463-VM, public IP: null,
> private IP: N/A
> 2019-05-06 14:13:46,840 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
> (consoleproxy-1:ctx-2825c38c) (logid:64c127ac) received console proxy
> alert
> 2019-05-06 14:13:46,840 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
> (consoleproxy-1:ctx-2825c38c) (logid:64c127ac) Console proxy creation
> failure, zone: Intsys
> 2019-05-06 14:13:46,841 WARN  [o.a.c.alerts]
> (consoleproxy-1:ctx-2825c38c) (logid:64c127ac)  alertType:: 10 //
> dataCenterId:: 2 // podId:: null // clusterId:: null // message::
> Console proxy creation failure. zone: Intsys, error details: null
> 
> Regards Udo
> 
> -----Urspr√ľngliche Nachricht-----
> Von: Suresh Kumar Anaparti [mailto:sureshkumar.anaparti@gmail.com]
> Gesendet: Montag, 6. Mai 2019 11:34
> An: users@cloudstack.apache.org
> Betreff: Re: CS 4.9.2: System VMs not starting
> 
> Hi Udo,
> 
> As per the log in the email, the System VM deployment failed 
> immediately
> after finding suitable hosts by the Deployment Planner 
> (FirstFitPlanner).
> Once suitable hosts are found in the cluster, CS should check for 
> suitable
> storage pools for finalizing the complete deployment destination (Zone,
> Pod, Cluster, Host, Storage). It seems there is some unlogged error 
> after
> finding suitable hosts and the deployment failed immediately with Event
> OperationFailed. Check the pools accessibilty. and also try with a
> different Deployment Planner (change the global config parameter
> "vm.deployment.planner")
> 
> - Suresh
> 
> On Mon, May 6, 2019 at 1:59 PM Mueller, Udo <Udo.Mueller@plath.de> 
> wrote:
> 
>> Hi all,
>> 
>> recently we had a crash in our cloudstack.
>> 
>> Cloudstack runs inside a pcs cluster which share a direct attached
>> storage. Cluster is running fine, storage is mounted, CS agents are
>> running. Virtualization is run in KVM, project VMs can be started 
>> fine.
>> Our installed version is 4.9.2 and we currently cant update to 
>> current.
>> 
>> But:
>> 
>> The system VM cannot be started. Neither console proxy nor secondary
>> storage VM.
>> 
>> Log output on CS management when trying to start console proxy vm 
>> manually:
>> 
>> 2019-05-06 08:22:58,865 DEBUG [c.c.a.ApiServlet]
>> (catalina-exec-5:ctx-26cf8ba3) (logid:d5797b2d) ===START===  
>> 172.16.192.180
>> -- GET
>> command=startSystemVm&id=4803e585-78d3-45b8-8d8a-49944f05e5fa&response=json&projectid=53824f26-bf1d-4f3d-8f5c-d25a045e4abe&_=1557130978863
>> 2019-05-06 08:22:58,878 WARN  [c.c.a.d.ParamGenericValidationWorker]
>> (catalina-exec-5:ctx-26cf8ba3 ctx-31d5912e) (logid:d5797b2d) Received
>> unknown parameters for command startSystemVm. Unknown parameters : 
>> projectid
>> 2019-05-06 08:22:58,928 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
>> (API-Job-Executor-63:ctx-c57ad4d3 job-122099) (logid:97ae8562) Add
>> job-122099 into job monitoring
>> 2019-05-06 08:22:58,944 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (catalina-exec-5:ctx-26cf8ba3 ctx-31d5912e) (logid:d5797b2d) submit 
>> async
>> job-122099, details: AsyncJobVO {id:122099, userId: 16, accountId: 2,
>> instanceType: SystemVm, instanceId: 4448, cmd:
>> org.apache.cloudstack.api.command.admin.systemvm.StartSystemVMCmd, 
>> cmdInfo:
>> {"response":"json","id":"4803e585-78d3-45b8-8d8a-49944f05e5fa","ctxDetails":"{\"interface
>> com.cloud.vm.VirtualMachine\":\"4803e585-78d3-45b8-8d8a-49944f05e5fa\"}","cmdEventType":"PROXY.START","ctxUserId":"16","httpmethod":"GET","_":"1557130978863","projectid":"53824f26-bf1d-4f3d-8f5c-d25a045e4abe","uuid":"4803e585-78d3-45b8-8d8a-49944f05e5fa","ctxAccountId":"2","ctxStartEventId":"108673"},
>> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
>> result: null, initMsid: 101543520292, completeMsid: null, lastUpdated:
>> null, lastPolled: null, created: null}
>> 2019-05-06 08:22:58,945 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (API-Job-Executor-63:ctx-c57ad4d3 job-122099) (logid:4706bea3) 
>> Executing
>> AsyncJobVO {id:122099, userId: 16, accountId: 2, instanceType: 
>> SystemVm,
>> instanceId: 4448, cmd:
>> org.apache.cloudstack.api.command.admin.systemvm.StartSystemVMCmd, 
>> cmdInfo:
>> {"response":"json","id":"4803e585-78d3-45b8-8d8a-49944f05e5fa","ctxDetails":"{\"interface
>> com.cloud.vm.VirtualMachine\":\"4803e585-78d3-45b8-8d8a-49944f05e5fa\"}","cmdEventType":"PROXY.START","ctxUserId":"16","httpmethod":"GET","_":"1557130978863","projectid":"53824f26-bf1d-4f3d-8f5c-d25a045e4abe","uuid":"4803e585-78d3-45b8-8d8a-49944f05e5fa","ctxAccountId":"2","ctxStartEventId":"108673"},
>> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
>> result: null, initMsid: 101543520292, completeMsid: null, lastUpdated:
>> null, lastPolled: null, created: null}
>> 2019-05-06 08:22:58,945 DEBUG [c.c.a.ApiServlet]
>> (catalina-exec-5:ctx-26cf8ba3 ctx-31d5912e) (logid:d5797b2d) ===END===
>> 172.16.192.180 -- GET
>> command=startSystemVm&id=4803e585-78d3-45b8-8d8a-49944f05e5fa&response=json&projectid=53824f26-bf1d-4f3d-8f5c-d25a045e4abe&_=1557130978863
>> 2019-05-06 08:22:58,952 WARN  [c.c.a.d.ParamGenericValidationWorker]
>> (API-Job-Executor-63:ctx-c57ad4d3 job-122099 ctx-fb498807) 
>> (logid:4706bea3)
>> Received unknown parameters for command startSystemVm. Unknown 
>> parameters :
>> projectid
>> 2019-05-06 08:22:59,011 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (API-Job-Executor-63:ctx-c57ad4d3 job-122099 ctx-fb498807) 
>> (logid:4706bea3)
>> Sync job-122100 execution on object VmWorkJobQueue.4448
>> 2019-05-06 08:23:00,135 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (AsyncJobMgr-Heartbeat-1:ctx-7a6dfcef) (logid:6c3cd4ad) Execute 
>> sync-queue
>> item: SyncQueueItemVO {id:33420, queueId: 49000, contentType: 
>> AsyncJob,
>> contentId: 122100, lastProcessMsid: 101543520292, lastprocessNumber: 
>> 16673,
>> lastProcessTime: Mon May 06 08:23:00 UTC 2019, created: Mon May 06 
>> 08:22:59
>> UTC 2019}
>> 2019-05-06 08:23:00,136 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (AsyncJobMgr-Heartbeat-1:ctx-7a6dfcef) (logid:6c3cd4ad) Schedule 
>> queued
>> job-122100
>> 2019-05-06 08:23:00,156 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100) 
>> (logid:b2ab9409)
>> Add job-122100 into job monitoring
>> 2019-05-06 08:23:00,170 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100) 
>> (logid:4706bea3)
>> Executing AsyncJobVO {id:122100, userId: 16, accountId: 2, 
>> instanceType:
>> null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
>> rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAABAAAAAAAAARYHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA,
>> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
>> result: null, initMsid: 101543520292, completeMsid: null, lastUpdated:
>> null, lastPolled: null, created: Mon May 06 08:22:59 UTC 2019}
>> 2019-05-06 08:23:00,170 DEBUG [c.c.v.VmWorkJobDispatcher]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100) 
>> (logid:4706bea3)
>> Run VM work job: com.cloud.vm.VmWorkStart for VM 4448, job origin: 
>> 122099
>> 2019-05-06 08:23:00,171 DEBUG [c.c.v.VmWorkJobHandlerProxy]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Execute VM work job:
>> com.cloud.vm.VmWorkStart{"dcId":0,"userId":16,"accountId":2,"vmId":4448,"handlerName":"VirtualMachineManagerImpl"}
>> 2019-05-06 08:23:00,181 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) VM state transitted from :Stopped to Starting with 
>> event:
>> StartRequestedvm's original host id: null new host id: null host id 
>> before
>> state transition: null
>> 2019-05-06 08:23:00,181 DEBUG [c.c.v.VirtualMachineManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Successfully transitioned to start state for
>> VM[ConsoleProxy|v-4448-VM] reservation id =
>> d5d5581b-c7f6-47a0-88c4-cfe16d06b1fd
>> 2019-05-06 08:23:00,195 DEBUG [c.c.v.VirtualMachineManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Trying to deploy VM, vm has dcId: 2 and podId: null
>> 2019-05-06 08:23:00,195 DEBUG [c.c.v.VirtualMachineManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Deploy avoids pods: null, clusters: null, hosts: null
>> 2019-05-06 08:23:00,198 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Deploy avoids pods: null, clusters: null, hosts: null
>> 2019-05-06 08:23:00,199 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) DeploymentPlanner allocation algorithm:
>> com.cloud.deploy.FirstFitPlanner@4d829b98
>> 2019-05-06 08:23:00,199 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Trying to allocate a host and storage pools from 
>> dc:2,
>> pod:null,cluster:null, requested cpu: 500, requested ram: 1073741824
>> 2019-05-06 08:23:00,199 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Is ROOT volume READY (pool already allocated)?: No
>> 2019-05-06 08:23:00,199 DEBUG [c.c.d.FirstFitPlanner]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Searching all possible resources under this Zone: 2
>> 2019-05-06 08:23:00,200 DEBUG [c.c.d.FirstFitPlanner]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Listing clusters in order of aggregate capacity, that 
>> have
>> (atleast one host with) enough CPU and RAM capacity under this Zone: 2
>> 2019-05-06 08:23:00,204 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Checking resources in Cluster: 2 under Pod: 2
>> 2019-05-06 08:23:00,205 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Looking for hosts in dc: 2
>> pod:2  cluster:2
>> 2019-05-06 08:23:00,207 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) FirstFitAllocator has 8 
>> hosts to
>> check for allocation: [Host[-62-Routing], Host[-61-Routing],
>> Host[-60-Routing], Host[-59-Routing], Host[-57-Routing], 
>> Host[-56-Routing],
>> Host[-58-Routing], Host[-54-Routing]]
>> 2019-05-06 08:23:00,216 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Found 8 hosts for 
>> allocation
>> after prioritization: [Host[-62-Routing], Host[-61-Routing],
>> Host[-60-Routing], Host[-59-Routing], Host[-57-Routing], 
>> Host[-56-Routing],
>> Host[-58-Routing], Host[-54-Routing]]
>> 2019-05-06 08:23:00,216 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Looking for speed=500Mhz,
>> Ram=1024
>> 2019-05-06 08:23:00,221 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host: 62 has cpu capability
>> (cpu:8, speed:2400) to support requested CPU: 1 and requested speed: 
>> 500
>> 2019-05-06 08:23:00,221 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Checking if host: 62 has 
>> enough
>> capacity for requested CPU: 500 and requested RAM: 1073741824 ,
>> cpuOverprovisioningFactor: 2.5
>> 2019-05-06 08:23:00,222 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual total CPU: 
>> 19200
>> and CPU after applying overprovisioning: 48000
>> 2019-05-06 08:23:00,222 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 28000 , Requested 
>> CPU:
>> 500
>> 2019-05-06 08:23:00,222 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 284000190464 ,
>> Requested RAM: 1073741824
>> 2019-05-06 08:23:00,223 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host has enough CPU and RAM
>> available
>> 2019-05-06 08:23:00,223 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc CPU from 
>> host:
>> 62, used: 20000, reserved: 0, actual total: 19200, total with
>> overprovisioning: 48000; requested cpu:500,alloc_from_last_host?:false
>> ,considerReservedCapacity?: true
>> 2019-05-06 08:23:00,223 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc MEM from 
>> host:
>> 62, used: 51539607552, reserved: 0, total: 335539798016; requested 
>> mem:
>> 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: 
>> true
>> 2019-05-06 08:23:00,223 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable host, 
>> adding to
>> list: 62
>> 2019-05-06 08:23:00,227 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host: 61 has cpu capability
>> (cpu:8, speed:2400) to support requested CPU: 1 and requested speed: 
>> 500
>> 2019-05-06 08:23:00,227 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Checking if host: 61 has 
>> enough
>> capacity for requested CPU: 500 and requested RAM: 1073741824 ,
>> cpuOverprovisioningFactor: 2.5
>> 2019-05-06 08:23:00,229 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual total CPU: 
>> 19200
>> and CPU after applying overprovisioning: 48000
>> 2019-05-06 08:23:00,229 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 0 , Requested 
>> CPU: 500
>> 2019-05-06 08:23:00,229 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 571339177984 ,
>> Requested RAM: 1073741824
>> 2019-05-06 08:23:00,229 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Failed to alloc 
>> resource
>> from host: 61 reservedCpu: 0, used cpu: 48000, requested cpu: 500, 
>> actual
>> total cpu: 19200, total cpu with overprovisioning: 48000, reservedMem: 
>> 0,
>> used Mem: 103079215104, requested mem: 1073741824, total 
>> Mem:674418393088
>> ,considerReservedCapacity?: true
>> 2019-05-06 08:23:00,229 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host does not have enough 
>> CPU
>> available, cannot allocate to this host.
>> 2019-05-06 08:23:00,229 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Not using host 61; host has 
>> cpu
>> capability? true, host has capacity?false
>> 2019-05-06 08:23:00,234 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host: 60 has cpu capability
>> (cpu:80, speed:2394) to support requested CPU: 1 and requested speed: 
>> 500
>> 2019-05-06 08:23:00,234 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Checking if host: 60 has 
>> enough
>> capacity for requested CPU: 500 and requested RAM: 1073741824 ,
>> cpuOverprovisioningFactor: 2.5
>> 2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual total CPU: 
>> 191520
>> and CPU after applying overprovisioning: 478800
>> 2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 438704 , 
>> Requested
>> CPU: 500
>> 2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 519020019712 ,
>> Requested RAM: 1073741824
>> 2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host has enough CPU and RAM
>> available
>> 2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc CPU from 
>> host:
>> 60, used: 40096, reserved: 0, actual total: 191520, total with
>> overprovisioning: 478800; requested 
>> cpu:500,alloc_from_last_host?:false
>> ,considerReservedCapacity?: true
>> 2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc MEM from 
>> host:
>> 60, used: 154618822656, reserved: 0, total: 673638842368; requested 
>> mem:
>> 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: 
>> true
>> 2019-05-06 08:23:00,236 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable host, 
>> adding to
>> list: 60
>> 2019-05-06 08:23:00,240 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host: 59 has cpu capability
>> (cpu:8, speed:2400) to support requested CPU: 1 and requested speed: 
>> 500
>> 2019-05-06 08:23:00,241 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Checking if host: 59 has 
>> enough
>> capacity for requested CPU: 500 and requested RAM: 1073741824 ,
>> cpuOverprovisioningFactor: 2.5
>> 2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual total CPU: 
>> 19200
>> and CPU after applying overprovisioning: 48000
>> 2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 24000 , Requested 
>> CPU:
>> 500
>> 2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 622878785536 ,
>> Requested RAM: 1073741824
>> 2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host has enough CPU and RAM
>> available
>> 2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc CPU from 
>> host:
>> 59, used: 24000, reserved: 0, actual total: 19200, total with
>> overprovisioning: 48000; requested cpu:500,alloc_from_last_host?:false
>> ,considerReservedCapacity?: true
>> 2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc MEM from 
>> host:
>> 59, used: 51539607552, reserved: 0, total: 674418393088; requested 
>> mem:
>> 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: 
>> true
>> 2019-05-06 08:23:00,242 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable host, 
>> adding to
>> list: 59
>> 2019-05-06 08:23:00,248 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host: 57 has cpu capability
>> (cpu:32, speed:2400) to support requested CPU: 1 and requested speed: 
>> 500
>> 2019-05-06 08:23:00,248 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Checking if host: 57 has 
>> enough
>> capacity for requested CPU: 500 and requested RAM: 1073741824 ,
>> cpuOverprovisioningFactor: 2.5
>> 2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual total CPU: 
>> 76800
>> and CPU after applying overprovisioning: 192000
>> 2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 144000 , 
>> Requested
>> CPU: 500
>> 2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 62793105408 ,
>> Requested RAM: 1073741824
>> 2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host has enough CPU and RAM
>> available
>> 2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc CPU from 
>> host:
>> 57, used: 48000, reserved: 0, actual total: 76800, total with
>> overprovisioning: 192000; requested 
>> cpu:500,alloc_from_last_host?:false
>> ,considerReservedCapacity?: true
>> 2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc MEM from 
>> host:
>> 57, used: 103079215104, reserved: 0, total: 165872320512; requested 
>> mem:
>> 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: 
>> true
>> 2019-05-06 08:23:00,250 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable host, 
>> adding to
>> list: 57
>> 2019-05-06 08:23:00,255 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host: 56 has cpu capability
>> (cpu:8, speed:2400) to support requested CPU: 1 and requested speed: 
>> 500
>> 2019-05-06 08:23:00,255 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Checking if host: 56 has 
>> enough
>> capacity for requested CPU: 500 and requested RAM: 1073741824 ,
>> cpuOverprovisioningFactor: 2.5
>> 2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual total CPU: 
>> 19200
>> and CPU after applying overprovisioning: 48000
>> 2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 20000 , Requested 
>> CPU:
>> 500
>> 2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 351539953664 ,
>> Requested RAM: 1073741824
>> 2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host has enough CPU and RAM
>> available
>> 2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc CPU from 
>> host:
>> 56, used: 28000, reserved: 0, actual total: 19200, total with
>> overprovisioning: 48000; requested cpu:500,alloc_from_last_host?:false
>> ,considerReservedCapacity?: true
>> 2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc MEM from 
>> host:
>> 56, used: 68719476736, reserved: 0, total: 420259430400; requested 
>> mem:
>> 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: 
>> true
>> 2019-05-06 08:23:00,257 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable host, 
>> adding to
>> list: 56
>> 2019-05-06 08:23:00,262 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host: 58 has cpu capability
>> (cpu:32, speed:2400) to support requested CPU: 1 and requested speed: 
>> 500
>> 2019-05-06 08:23:00,262 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Checking if host: 58 has 
>> enough
>> capacity for requested CPU: 500 and requested RAM: 1073741824 ,
>> cpuOverprovisioningFactor: 2.5
>> 2019-05-06 08:23:00,263 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual total CPU: 
>> 76800
>> and CPU after applying overprovisioning: 192000
>> 2019-05-06 08:23:00,263 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 144000 , 
>> Requested
>> CPU: 500
>> 2019-05-06 08:23:00,263 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 41614508032 ,
>> Requested RAM: 1073741824
>> 2019-05-06 08:23:00,264 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host has enough CPU and RAM
>> available
>> 2019-05-06 08:23:00,264 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc CPU from 
>> host:
>> 58, used: 48000, reserved: 0, actual total: 76800, total with
>> overprovisioning: 192000; requested 
>> cpu:500,alloc_from_last_host?:false
>> ,considerReservedCapacity?: true
>> 2019-05-06 08:23:00,264 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc MEM from 
>> host:
>> 58, used: 103079215104, reserved: 0, total: 144693723136; requested 
>> mem:
>> 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: 
>> true
>> 2019-05-06 08:23:00,264 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable host, 
>> adding to
>> list: 58
>> 2019-05-06 08:23:00,268 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host: 54 has cpu capability
>> (cpu:8, speed:2400) to support requested CPU: 1 and requested speed: 
>> 500
>> 2019-05-06 08:23:00,269 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Checking if host: 54 has 
>> enough
>> capacity for requested CPU: 500 and requested RAM: 1073741824 ,
>> cpuOverprovisioningFactor: 2.5
>> 2019-05-06 08:23:00,270 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual total CPU: 
>> 19200
>> and CPU after applying overprovisioning: 48000
>> 2019-05-06 08:23:00,270 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 0 , Requested 
>> CPU: 500
>> 2019-05-06 08:23:00,270 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 147740983296 ,
>> Requested RAM: 1073741824
>> 2019-05-06 08:23:00,270 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) STATS: Failed to alloc 
>> resource
>> from host: 54 reservedCpu: 0, used cpu: 48000, requested cpu: 500, 
>> actual
>> total cpu: 19200, total cpu with overprovisioning: 48000, reservedMem: 
>> 0,
>> used Mem: 103079215104, requested mem: 1073741824, total 
>> Mem:250820198400
>> ,considerReservedCapacity?: true
>> 2019-05-06 08:23:00,270 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host does not have enough 
>> CPU
>> available, cannot allocate to this host.
>> 2019-05-06 08:23:00,270 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Not using host 54; host has 
>> cpu
>> capability? true, host has capacity?false
>> 2019-05-06 08:23:00,270 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f
>> FirstFitRoutingAllocator) (logid:4706bea3) Host Allocator returning 6
>> suitable hosts
>> 2019-05-06 08:23:00,313 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) VM state transitted from :Starting to Stopped with 
>> event:
>> OperationFailedvm's original host id: null new host id: null host id 
>> before
>> state transition: null
>> 2019-05-06 08:23:00,313 INFO  [c.c.v.VirtualMachineManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Caught CloudRuntimeException, returning job failed
>> 2019-05-06 08:23:00,313 DEBUG [c.c.v.VmWorkJobHandlerProxy]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Done executing VM work job:
>> com.cloud.vm.VmWorkStart{"dcId":0,"userId":16,"accountId":2,"vmId":4448,"handlerName":"VirtualMachineManagerImpl"}
>> 2019-05-06 08:23:00,313 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Complete async job-122100, jobStatus: FAILED, 
>> resultCode:
>> 0, result: null
>> 2019-05-06 08:23:00,314 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Publish async job-122100 complete on message bus
>> 2019-05-06 08:23:00,314 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Wake up jobs related to job-122100
>> 2019-05-06 08:23:00,314 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Update db status for job-122100
>> 2019-05-06 08:23:00,315 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100 ctx-49eae88f)
>> (logid:4706bea3) Wake up jobs joined with job-122100 and disjoin all
>> subjobs created from job- 122100
>> 2019-05-06 08:23:00,339 DEBUG [c.c.v.VmWorkJobDispatcher]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100) 
>> (logid:4706bea3)
>> Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 4448, 
>> job
>> origin: 122099
>> 2019-05-06 08:23:00,339 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100) 
>> (logid:4706bea3)
>> Done executing com.cloud.vm.VmWorkStart for job-122100
>> 2019-05-06 08:23:00,341 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
>> (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100) 
>> (logid:4706bea3)
>> Remove job-122100 from job monitoring
>> 2019-05-06 08:23:00,394 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (API-Job-Executor-63:ctx-c57ad4d3 job-122099 ctx-fb498807) 
>> (logid:4706bea3)
>> Complete async job-122099, jobStatus: SUCCEEDED, resultCode: 0, 
>> result:
>> org.apache.cloudstack.api.response.SystemVmResponse/systemvm/{"id":"4803e585-78d3-45b8-8d8a-49944f05e5fa","systemvmtype":"consoleproxy","zoneid":"978f1e08-8650-424f-b527-a1afd74305e9","zonename":"Intsys","dns1":"10.252.34.10","name":"v-4448-VM","templateid":"367b6a82-1471-4fa3-a3b9-c194213c27d6","created":"2019-04-30T13:26:56+0000","state":"Stopped","activeviewersessions":0}
>> 2019-05-06 08:23:00,395 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (API-Job-Executor-63:ctx-c57ad4d3 job-122099 ctx-fb498807) 
>> (logid:4706bea3)
>> Publish async job-122099 complete on message bus
>> 2019-05-06 08:23:00,395 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (API-Job-Executor-63:ctx-c57ad4d3 job-122099 ctx-fb498807) 
>> (logid:4706bea3)
>> Wake up jobs related to job-122099
>> 2019-05-06 08:23:00,395 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (API-Job-Executor-63:ctx-c57ad4d3 job-122099 ctx-fb498807) 
>> (logid:4706bea3)
>> Update db status for job-122099
>> 2019-05-06 08:23:00,396 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (API-Job-Executor-63:ctx-c57ad4d3 job-122099 ctx-fb498807) 
>> (logid:4706bea3)
>> Wake up jobs joined with job-122099 and disjoin all subjobs created 
>> from
>> job- 122099
>> 2019-05-06 08:23:00,418 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>> (API-Job-Executor-63:ctx-c57ad4d3 job-122099) (logid:4706bea3) Done
>> executing 
>> org.apache.cloudstack.api.command.admin.systemvm.StartSystemVMCmd
>> for job-122099
>> 2019-05-06 08:23:00,418 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
>> (API-Job-Executor-63:ctx-c57ad4d3 job-122099) (logid:4706bea3) Remove
>> job-122099 from job monitoring
>> 2019-05-06 08:23:01,951 DEBUG [c.c.a.ApiServlet]
>> (catalina-exec-18:ctx-ec250e8c) (logid:862cd473) ===START===
>> 172.16.192.180 -- GET
>> command=queryAsyncJobResult&jobId=4706bea3-a1fc-4f2b-8521-c296c2c46c4b&response=json&projectid=53824f26-bf1d-4f3d-8f5c-d25a045e4abe&_=1557130981948
>> 2019-05-06 08:23:01,958 WARN  [c.c.a.d.ParamGenericValidationWorker]
>> (catalina-exec-18:ctx-ec250e8c ctx-05f46862) (logid:862cd473) Received
>> unknown parameters for command queryAsyncJobResult. Unknown parameters 
>> :
>> projectid
>> 2019-05-06 08:23:01,983 DEBUG [c.c.a.ApiServlet]
>> (catalina-exec-18:ctx-ec250e8c ctx-05f46862) (logid:862cd473) 
>> ===END===
>> 172.16.192.180 -- GET
>> command=queryAsyncJobResult&jobId=4706bea3-a1fc-4f2b-8521-c296c2c46c4b&response=json&projectid=53824f26-bf1d-4f3d-8f5c-d25a045e4abe&_=1557130981948
>> 
>> CS management reports that start system VM was successful.
>> 
>> But I cant see any connect/instruction in the agent logfile  of the
>> connected servers. The agents alos log in DEBUG mode.
>> 
>> Is there anyone out there who can give help or guidance?
>> 
>> Regards Udo
>> Mit freundlichen Gr??en
>> Best regards
>> 
>> Udo Mueller
>> Senior System Engineer
>> 
>> PLATH GmbH
>> Gotenstrasse 18
>> 20097 Hamburg
>> Germany
>> 
>> Tel: +49 40 237 34-235
>> Fax: +49 40 237 34-222
>> Email: Udo.Mueller@plath.de
>> 
>> 
>> [http://www.plathgroup.com/banner/aeo-logo.jpg]
>> Directorate General Customs and
>> Taxation (c) European Union, 2007-2017
>> 
>> 
>> 
>> ----------------------------
>> www.plath.de  |  www.plathgroup.com
>> District Court Hamburg HRB 7401
>> Authorised representatives:
>> Nico Scharfe (CEO), Hinrich Brueggmann (CEO)
>> 
>> The information transmitted and any documents, files or previous email
>> messages attached to it contains strictly confidential information 
>> that is
>> legally privileged and intended only for the person or entity to which 
>> it
>> is addressed. Any review, retransmission, dissemination or other use 
>> of, or
>> taking of any action in reliance upon, this information by persons or
>> entities other than the intended recipient is prohibited.
>> If you have received this message in error, please advise the sender
>> immediately by reply e-mail and delete the original message and any 
>> copies
>> from your computer system. This notice also applies to future 
>> messages.
>> 
>> 
Mime
View raw message