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: asen...@testlabs.com.au [mailto:asen...@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.anapa...@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.muel...@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.muel...@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. >> >>
