Hi Udo, Can you share the complete debug log (uploaded link) and db records in tables *storage_pool* and *host*.
- Suresh On Mon, May 6, 2019 at 8:09 PM Mueller, Udo <udo.muel...@plath.de> 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. > > > > >
