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.
