cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Mueller, Udo" <Udo.Muel...@plath.de>
Subject CS 4.9.2: System VMs not starting
Date Mon, 06 May 2019 08:28:46 GMT
Hi all,

recently we had a crash in our cloudstack.

Cloudstack runs inside a pcs cluster which share a direct attached storage. Cluster is running
fine, storage is mounted, CS agents are running. Virtualization is run in KVM, project VMs
can be started fine.
Our installed version is 4.9.2 and we currently cant update to current.

But:

The system VM cannot be started. Neither console proxy nor secondary storage VM.

Log output on CS management when trying to start console proxy vm manually:

2019-05-06 08:22:58,865 DEBUG [c.c.a.ApiServlet] (catalina-exec-5:ctx-26cf8ba3) (logid:d5797b2d)
===START===  172.16.192.180 -- GET  command=startSystemVm&id=4803e585-78d3-45b8-8d8a-49944f05e5fa&response=json&projectid=53824f26-bf1d-4f3d-8f5c-d25a045e4abe&_=1557130978863
2019-05-06 08:22:58,878 WARN  [c.c.a.d.ParamGenericValidationWorker] (catalina-exec-5:ctx-26cf8ba3
ctx-31d5912e) (logid:d5797b2d) Received unknown parameters for command startSystemVm. Unknown
parameters : projectid
2019-05-06 08:22:58,928 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-63:ctx-c57ad4d3
job-122099) (logid:97ae8562) Add job-122099 into job monitoring
2019-05-06 08:22:58,944 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-5:ctx-26cf8ba3
ctx-31d5912e) (logid:d5797b2d) submit async job-122099, details: AsyncJobVO {id:122099, userId:
16, accountId: 2, instanceType: SystemVm, instanceId: 4448, cmd: org.apache.cloudstack.api.command.admin.systemvm.StartSystemVMCmd,
cmdInfo: {"response":"json","id":"4803e585-78d3-45b8-8d8a-49944f05e5fa","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"4803e585-78d3-45b8-8d8a-49944f05e5fa\"}","cmdEventType":"PROXY.START","ctxUserId":"16","httpmethod":"GET","_":"1557130978863","projectid":"53824f26-bf1d-4f3d-8f5c-d25a045e4abe","uuid":"4803e585-78d3-45b8-8d8a-49944f05e5fa","ctxAccountId":"2","ctxStartEventId":"108673"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
101543520292, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2019-05-06 08:22:58,945 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-c57ad4d3
job-122099) (logid:4706bea3) Executing AsyncJobVO {id:122099, userId: 16, accountId: 2, instanceType:
SystemVm, instanceId: 4448, cmd: org.apache.cloudstack.api.command.admin.systemvm.StartSystemVMCmd,
cmdInfo: {"response":"json","id":"4803e585-78d3-45b8-8d8a-49944f05e5fa","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"4803e585-78d3-45b8-8d8a-49944f05e5fa\"}","cmdEventType":"PROXY.START","ctxUserId":"16","httpmethod":"GET","_":"1557130978863","projectid":"53824f26-bf1d-4f3d-8f5c-d25a045e4abe","uuid":"4803e585-78d3-45b8-8d8a-49944f05e5fa","ctxAccountId":"2","ctxStartEventId":"108673"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
101543520292, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2019-05-06 08:22:58,945 DEBUG [c.c.a.ApiServlet] (catalina-exec-5:ctx-26cf8ba3 ctx-31d5912e)
(logid:d5797b2d) ===END===  172.16.192.180 -- GET  command=startSystemVm&id=4803e585-78d3-45b8-8d8a-49944f05e5fa&response=json&projectid=53824f26-bf1d-4f3d-8f5c-d25a045e4abe&_=1557130978863
2019-05-06 08:22:58,952 WARN  [c.c.a.d.ParamGenericValidationWorker] (API-Job-Executor-63:ctx-c57ad4d3
job-122099 ctx-fb498807) (logid:4706bea3) Received unknown parameters for command startSystemVm.
Unknown parameters : projectid
2019-05-06 08:22:59,011 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-c57ad4d3
job-122099 ctx-fb498807) (logid:4706bea3) Sync job-122100 execution on object VmWorkJobQueue.4448
2019-05-06 08:23:00,135 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-7a6dfcef)
(logid:6c3cd4ad) Execute sync-queue item: SyncQueueItemVO {id:33420, queueId: 49000, contentType:
AsyncJob, contentId: 122100, lastProcessMsid: 101543520292, lastprocessNumber: 16673, lastProcessTime:
Mon May 06 08:23:00 UTC 2019, created: Mon May 06 08:22:59 UTC 2019}
2019-05-06 08:23:00,136 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-7a6dfcef)
(logid:6c3cd4ad) Schedule queued job-122100
2019-05-06 08:23:00,156 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100) (logid:b2ab9409) Add job-122100 into job monitoring
2019-05-06 08:23:00,170 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100) (logid:4706bea3) Executing AsyncJobVO {id:122100, userId: 16, accountId:
2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAABAAAAAAAAARYHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
101543520292, completeMsid: null, lastUpdated: null, lastPolled: null, created: Mon May 06
08:22:59 UTC 2019}
2019-05-06 08:23:00,170 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100) (logid:4706bea3) Run VM work job: com.cloud.vm.VmWorkStart for VM 4448,
job origin: 122099
2019-05-06 08:23:00,171 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Execute VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":16,"accountId":2,"vmId":4448,"handlerName":"VirtualMachineManagerImpl"}
2019-05-06 08:23:00,181 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) VM state transitted from :Stopped to
Starting with event: StartRequestedvm's original host id: null new host id: null host id before
state transition: null
2019-05-06 08:23:00,181 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Successfully transitioned to start state
for VM[ConsoleProxy|v-4448-VM] reservation id = d5d5581b-c7f6-47a0-88c4-cfe16d06b1fd
2019-05-06 08:23:00,195 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Trying to deploy VM, vm has dcId: 2 and
podId: null
2019-05-06 08:23:00,195 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Deploy avoids pods: null, clusters: null,
hosts: null
2019-05-06 08:23:00,198 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Deploy avoids pods: null, clusters: null,
hosts: null
2019-05-06 08:23:00,199 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) DeploymentPlanner allocation algorithm:
com.cloud.deploy.FirstFitPlanner@4d829b98
2019-05-06 08:23:00,199 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Trying to allocate a host and storage
pools from dc:2, pod:null,cluster:null, requested cpu: 500, requested ram: 1073741824
2019-05-06 08:23:00,199 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Is ROOT volume READY (pool already allocated)?:
No
2019-05-06 08:23:00,199 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100
ctx-49eae88f) (logid:4706bea3) Searching all possible resources under this Zone: 2
2019-05-06 08:23:00,200 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-56:ctx-8bc110ba job-122099/job-122100
ctx-49eae88f) (logid:4706bea3) Listing clusters in order of aggregate capacity, that have
(atleast one host with) enough CPU and RAM capacity under this Zone: 2
2019-05-06 08:23:00,204 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Checking resources in Cluster: 2 under
Pod: 2
2019-05-06 08:23:00,205 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Looking for
hosts in dc: 2  pod:2  cluster:2
2019-05-06 08:23:00,207 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) FirstFitAllocator
has 8 hosts to check for allocation: [Host[-62-Routing], Host[-61-Routing], Host[-60-Routing],
Host[-59-Routing], Host[-57-Routing], Host[-56-Routing], Host[-58-Routing], Host[-54-Routing]]
2019-05-06 08:23:00,216 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Found 8 hosts
for allocation after prioritization: [Host[-62-Routing], Host[-61-Routing], Host[-60-Routing],
Host[-59-Routing], Host[-57-Routing], Host[-56-Routing], Host[-58-Routing], Host[-54-Routing]]
2019-05-06 08:23:00,216 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Looking for
speed=500Mhz, Ram=1024
2019-05-06 08:23:00,221 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host: 62 has
cpu capability (cpu:8, speed:2400) to support requested CPU: 1 and requested speed: 500
2019-05-06 08:23:00,221 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Checking if
host: 62 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor:
2.5
2019-05-06 08:23:00,222 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual
total CPU: 19200 and CPU after applying overprovisioning: 48000
2019-05-06 08:23:00,222 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 28000
, Requested CPU: 500
2019-05-06 08:23:00,222 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 284000190464
, Requested RAM: 1073741824
2019-05-06 08:23:00,223 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host has enough
CPU and RAM available
2019-05-06 08:23:00,223 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
CPU from host: 62, used: 20000, reserved: 0, actual total: 19200, total with overprovisioning:
48000; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2019-05-06 08:23:00,223 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
MEM from host: 62, used: 51539607552, reserved: 0, total: 335539798016; requested mem: 1073741824,alloc_from_last_host?:false
,considerReservedCapacity?: true
2019-05-06 08:23:00,223 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable
host, adding to list: 62
2019-05-06 08:23:00,227 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host: 61 has
cpu capability (cpu:8, speed:2400) to support requested CPU: 1 and requested speed: 500
2019-05-06 08:23:00,227 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Checking if
host: 61 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor:
2.5
2019-05-06 08:23:00,229 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual
total CPU: 19200 and CPU after applying overprovisioning: 48000
2019-05-06 08:23:00,229 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 0
, Requested CPU: 500
2019-05-06 08:23:00,229 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 571339177984
, Requested RAM: 1073741824
2019-05-06 08:23:00,229 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Failed
to alloc resource from host: 61 reservedCpu: 0, used cpu: 48000, requested cpu: 500, actual
total cpu: 19200, total cpu with overprovisioning: 48000, reservedMem: 0, used Mem: 103079215104,
requested mem: 1073741824, total Mem:674418393088 ,considerReservedCapacity?: true
2019-05-06 08:23:00,229 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host does not
have enough CPU available, cannot allocate to this host.
2019-05-06 08:23:00,229 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Not using host
61; host has cpu capability? true, host has capacity?false
2019-05-06 08:23:00,234 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host: 60 has
cpu capability (cpu:80, speed:2394) to support requested CPU: 1 and requested speed: 500
2019-05-06 08:23:00,234 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Checking if
host: 60 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor:
2.5
2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual
total CPU: 191520 and CPU after applying overprovisioning: 478800
2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 438704
, Requested CPU: 500
2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 519020019712
, Requested RAM: 1073741824
2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host has enough
CPU and RAM available
2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
CPU from host: 60, used: 40096, reserved: 0, actual total: 191520, total with overprovisioning:
478800; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2019-05-06 08:23:00,236 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
MEM from host: 60, used: 154618822656, reserved: 0, total: 673638842368; requested mem: 1073741824,alloc_from_last_host?:false
,considerReservedCapacity?: true
2019-05-06 08:23:00,236 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable
host, adding to list: 60
2019-05-06 08:23:00,240 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host: 59 has
cpu capability (cpu:8, speed:2400) to support requested CPU: 1 and requested speed: 500
2019-05-06 08:23:00,241 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Checking if
host: 59 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor:
2.5
2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual
total CPU: 19200 and CPU after applying overprovisioning: 48000
2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 24000
, Requested CPU: 500
2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 622878785536
, Requested RAM: 1073741824
2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host has enough
CPU and RAM available
2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
CPU from host: 59, used: 24000, reserved: 0, actual total: 19200, total with overprovisioning:
48000; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2019-05-06 08:23:00,242 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
MEM from host: 59, used: 51539607552, reserved: 0, total: 674418393088; requested mem: 1073741824,alloc_from_last_host?:false
,considerReservedCapacity?: true
2019-05-06 08:23:00,242 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable
host, adding to list: 59
2019-05-06 08:23:00,248 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host: 57 has
cpu capability (cpu:32, speed:2400) to support requested CPU: 1 and requested speed: 500
2019-05-06 08:23:00,248 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Checking if
host: 57 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor:
2.5
2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual
total CPU: 76800 and CPU after applying overprovisioning: 192000
2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 144000
, Requested CPU: 500
2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 62793105408
, Requested RAM: 1073741824
2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host has enough
CPU and RAM available
2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
CPU from host: 57, used: 48000, reserved: 0, actual total: 76800, total with overprovisioning:
192000; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2019-05-06 08:23:00,250 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
MEM from host: 57, used: 103079215104, reserved: 0, total: 165872320512; requested mem: 1073741824,alloc_from_last_host?:false
,considerReservedCapacity?: true
2019-05-06 08:23:00,250 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable
host, adding to list: 57
2019-05-06 08:23:00,255 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host: 56 has
cpu capability (cpu:8, speed:2400) to support requested CPU: 1 and requested speed: 500
2019-05-06 08:23:00,255 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Checking if
host: 56 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor:
2.5
2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual
total CPU: 19200 and CPU after applying overprovisioning: 48000
2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 20000
, Requested CPU: 500
2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 351539953664
, Requested RAM: 1073741824
2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host has enough
CPU and RAM available
2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
CPU from host: 56, used: 28000, reserved: 0, actual total: 19200, total with overprovisioning:
48000; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2019-05-06 08:23:00,257 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
MEM from host: 56, used: 68719476736, reserved: 0, total: 420259430400; requested mem: 1073741824,alloc_from_last_host?:false
,considerReservedCapacity?: true
2019-05-06 08:23:00,257 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable
host, adding to list: 56
2019-05-06 08:23:00,262 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host: 58 has
cpu capability (cpu:32, speed:2400) to support requested CPU: 1 and requested speed: 500
2019-05-06 08:23:00,262 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Checking if
host: 58 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor:
2.5
2019-05-06 08:23:00,263 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual
total CPU: 76800 and CPU after applying overprovisioning: 192000
2019-05-06 08:23:00,263 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 144000
, Requested CPU: 500
2019-05-06 08:23:00,263 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 41614508032
, Requested RAM: 1073741824
2019-05-06 08:23:00,264 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host has enough
CPU and RAM available
2019-05-06 08:23:00,264 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
CPU from host: 58, used: 48000, reserved: 0, actual total: 76800, total with overprovisioning:
192000; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2019-05-06 08:23:00,264 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Can alloc
MEM from host: 58, used: 103079215104, reserved: 0, total: 144693723136; requested mem: 1073741824,alloc_from_last_host?:false
,considerReservedCapacity?: true
2019-05-06 08:23:00,264 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Found a suitable
host, adding to list: 58
2019-05-06 08:23:00,268 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host: 54 has
cpu capability (cpu:8, speed:2400) to support requested CPU: 1 and requested speed: 500
2019-05-06 08:23:00,269 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Checking if
host: 54 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor:
2.5
2019-05-06 08:23:00,270 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Hosts's actual
total CPU: 19200 and CPU after applying overprovisioning: 48000
2019-05-06 08:23:00,270 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free CPU: 0
, Requested CPU: 500
2019-05-06 08:23:00,270 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Free RAM: 147740983296
, Requested RAM: 1073741824
2019-05-06 08:23:00,270 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) STATS: Failed
to alloc resource from host: 54 reservedCpu: 0, used cpu: 48000, requested cpu: 500, actual
total cpu: 19200, total cpu with overprovisioning: 48000, reservedMem: 0, used Mem: 103079215104,
requested mem: 1073741824, total Mem:250820198400 ,considerReservedCapacity?: true
2019-05-06 08:23:00,270 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host does not
have enough CPU available, cannot allocate to this host.
2019-05-06 08:23:00,270 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Not using host
54; host has cpu capability? true, host has capacity?false
2019-05-06 08:23:00,270 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f FirstFitRoutingAllocator) (logid:4706bea3) Host Allocator
returning 6 suitable hosts
2019-05-06 08:23:00,313 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) VM state transitted from :Starting to
Stopped with event: OperationFailedvm's original host id: null new host id: null host id before
state transition: null
2019-05-06 08:23:00,313 INFO  [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Caught CloudRuntimeException, returning
job failed
2019-05-06 08:23:00,313 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":16,"accountId":2,"vmId":4448,"handlerName":"VirtualMachineManagerImpl"}
2019-05-06 08:23:00,313 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Complete async job-122100, jobStatus:
FAILED, resultCode: 0, result: null
2019-05-06 08:23:00,314 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Publish async job-122100 complete on
message bus
2019-05-06 08:23:00,314 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Wake up jobs related to job-122100
2019-05-06 08:23:00,314 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Update db status for job-122100
2019-05-06 08:23:00,315 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100 ctx-49eae88f) (logid:4706bea3) Wake up jobs joined with job-122100 and
disjoin all subjobs created from job- 122100
2019-05-06 08:23:00,339 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100) (logid:4706bea3) Done with run of VM work job: com.cloud.vm.VmWorkStart
for VM 4448, job origin: 122099
2019-05-06 08:23:00,339 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100) (logid:4706bea3) Done executing com.cloud.vm.VmWorkStart for job-122100
2019-05-06 08:23:00,341 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-56:ctx-8bc110ba
job-122099/job-122100) (logid:4706bea3) Remove job-122100 from job monitoring
2019-05-06 08:23:00,394 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-c57ad4d3
job-122099 ctx-fb498807) (logid:4706bea3) Complete async job-122099, jobStatus: SUCCEEDED,
resultCode: 0, result: org.apache.cloudstack.api.response.SystemVmResponse/systemvm/{"id":"4803e585-78d3-45b8-8d8a-49944f05e5fa","systemvmtype":"consoleproxy","zoneid":"978f1e08-8650-424f-b527-a1afd74305e9","zonename":"Intsys","dns1":"10.252.34.10","name":"v-4448-VM","templateid":"367b6a82-1471-4fa3-a3b9-c194213c27d6","created":"2019-04-30T13:26:56+0000","state":"Stopped","activeviewersessions":0}
2019-05-06 08:23:00,395 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-c57ad4d3
job-122099 ctx-fb498807) (logid:4706bea3) Publish async job-122099 complete on message bus
2019-05-06 08:23:00,395 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-c57ad4d3
job-122099 ctx-fb498807) (logid:4706bea3) Wake up jobs related to job-122099
2019-05-06 08:23:00,395 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-c57ad4d3
job-122099 ctx-fb498807) (logid:4706bea3) Update db status for job-122099
2019-05-06 08:23:00,396 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-c57ad4d3
job-122099 ctx-fb498807) (logid:4706bea3) Wake up jobs joined with job-122099 and disjoin
all subjobs created from job- 122099
2019-05-06 08:23:00,418 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-c57ad4d3
job-122099) (logid:4706bea3) Done executing org.apache.cloudstack.api.command.admin.systemvm.StartSystemVMCmd
for job-122099
2019-05-06 08:23:00,418 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-63:ctx-c57ad4d3
job-122099) (logid:4706bea3) Remove job-122099 from job monitoring
2019-05-06 08:23:01,951 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-ec250e8c) (logid:862cd473)
===START===  172.16.192.180 -- GET  command=queryAsyncJobResult&jobId=4706bea3-a1fc-4f2b-8521-c296c2c46c4b&response=json&projectid=53824f26-bf1d-4f3d-8f5c-d25a045e4abe&_=1557130981948
2019-05-06 08:23:01,958 WARN  [c.c.a.d.ParamGenericValidationWorker] (catalina-exec-18:ctx-ec250e8c
ctx-05f46862) (logid:862cd473) Received unknown parameters for command queryAsyncJobResult.
Unknown parameters : projectid
2019-05-06 08:23:01,983 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-ec250e8c ctx-05f46862)
(logid:862cd473) ===END===  172.16.192.180 -- GET  command=queryAsyncJobResult&jobId=4706bea3-a1fc-4f2b-8521-c296c2c46c4b&response=json&projectid=53824f26-bf1d-4f3d-8f5c-d25a045e4abe&_=1557130981948

CS management reports that start system VM was successful.

But I cant see any connect/instruction in the agent logfile  of the connected servers. The
agents alos log in DEBUG mode.

Is there anyone out there who can give help or guidance?

Regards Udo
Mit freundlichen Gr??en
Best regards

Udo Mueller
Senior System Engineer

PLATH GmbH
Gotenstrasse 18
20097 Hamburg
Germany

Tel: +49 40 237 34-235
Fax: +49 40 237 34-222
Email: Udo.Mueller@plath.de


[http://www.plathgroup.com/banner/aeo-logo.jpg]
Directorate General Customs and
Taxation (c) European Union, 2007-2017



----------------------------
www.plath.de  |  www.plathgroup.com
District Court Hamburg HRB 7401
Authorised representatives:
Nico Scharfe (CEO), Hinrich Brueggmann (CEO)

The information transmitted and any documents, files or previous email messages attached to
it contains strictly confidential information that is legally privileged and intended only
for the person or entity to which it is addressed. Any review, retransmission, dissemination
or other use of, or taking of any action in reliance upon, this information by persons or
entities other than the intended recipient is prohibited.
If you have received this message in error, please advise the sender immediately by reply
e-mail and delete the original message and any copies from your computer system. This notice
also applies to future messages.


Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message