Hi Udo, Can you share more details about your setup?
Still on version 4.9.2 ? By PCS you mean Pacemaker ? If so please describe your setup in more details - what is being clustered (shared resources, etc.) and why are you using it. How many CloudStack management servers? If possible, please restart management server and post logs from the beginning of the management server boot until the time you notice failure starting SSVM/CPVM - please upload log to pastebin or similar, so we can follow it more easily. Regards, Andrija andrija.pa...@shapeblue.com www.shapeblue.com Amadeus House, Floral Street, London WC2E 9DPUK @shapeblue -----Original Message----- From: Mueller, Udo <udo.muel...@plath.de> Sent: 06 May 2019 16:15 To: users@cloudstack.apache.org Subject: AW: CS 4.9.2: System VMs not starting 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","ctxDet > ails":"{\"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","ctxSt > artEventId":"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","ctxDet > ails":"{\"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","ctxSt > artEventId":"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: > rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAA > Zhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRl > TGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAA > tqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lk > cQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYX > dQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29t > LmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm > 1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAABAAAAAAAAARYHQAGVZp > cnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, > 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":444 > 8,"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":444 > 8,"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":"48 > 03e585-78d3-45b8-8d8a-49944f05e5fa","systemvmtype":"consoleproxy","zon > eid":"978f1e08-8650-424f-b527-a1afd74305e9","zonename":"Intsys","dns1" > :"10.252.34.10","name":"v-4448-VM","templateid":"367b6a82-1471-4fa3-a3 > b9-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&_=155713 > 0981948 > 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&_=155713 > 0981948 > > 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. > >
