This is the error:
2020-06-24 17:26:03,566 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Unable to start VM on Host[-6-Routing]
due to XML error: Non-empty feature list specified without CPU model
what that means I'm afraid I don’t know. Do you know if you've added something
to the defaults?
paul.an...@shapeblue.com
www.shapeblue.com
3 London Bridge Street, 3rd floor, News Building, London SE1 9SGUK
@shapeblue
-----Original Message-----
From: marcos <vend4...@gmail.com>
Sent: 24 June 2020 21:32
To: users@cloudstack.apache.org
Subject: Error Create VM 4.13.1
When I try to create a VM I am getting the error according to the LOGs below.
I have resources left on the KVM server
SSVMs working perfectly
Computational offer - Local
Disco Offer - Location
Can anyone save me?
2020-06-24 17:26:03,557 DEBUG [c.c.a.t.Request] (AgentManager-Handler-11:null)
(logid:) Seq 6-5149866173898163465: Processing: { Ans: , MgmtId:
8796761733588, via: 6, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StartAnswer":{"vm":{"id":31,"name":"i-2-31-VM","state":"Starting","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"CentOS
7.2","platformEmulator":"CentOS
7.2","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"yR6FxxzHBSibiwQcMQQOcA","vncAddr":"172.26.0.222","params":{"deployvm":"true"},"uuid":"76edbaeb-6a45-405b-a932-961e12e98cc3","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"5a49cd33-0581-405c-8aa0-dd76193cec94","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"fdf04200-8e76-4fd6-9045-18c1f7b8924a","id":2,"poolType":"Filesystem","host":"172.26.0.222","path":"/var/lib/libvirt/images","port":0,"url":"Filesystem://172.26.0.222/var/lib/libvirt/images/?ROLE=Primary&STOREUUID=fdf04200-8e76-4fd6-9045-18c1f7b8924a","isManaged":false}},"name":"ROOT-31","size":5368709120,"path":"5a49cd33-0581-405c-8aa0-dd76193cec94","volumeId":33,"vmName":"i-2-31-VM","accountId":2,"format":"QCOW2","provisioningType":"THIN","id":33,"deviceId":0,"bytesReadRate":0,"bytesWriteRate":0,"iopsReadRate":0,"iopsWriteRate":0,"hypervisorType":"KVM"}},"diskSeq":0,"path":"5a49cd33-0581-405c-8aa0-dd76193cec94","type":"ROOT","_details":{"storageHost":"172.26.0.222","managed":"false","storagePort":"0","volumeSize":"5368709120"}},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/204/204-2-1e647bf1-04d0-3541-a0ab-dc27bde551c0.iso","origUrl":"http://mirror.ufam.edu.br/centos/7.8.2003/isos/x86_64/CentOS-7-x86_64-Minimal-2003.iso","uuid":"b0b0c779-43d0-40a7-a31f-33bceb91250b","id":204,"format":"ISO","accountId":2,"checksum":"{SHA-512}c56aba0a569ef605118c642a03529206befac3a5baca329bdf27d1e5578e036dc93952e9ea602897bfb72ded66991f57cea258aa90f12665cde92770c135373a","hvm":true,"displayText":"Centos7Minimal","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://172.26.0.222/export/secondary","_role":"Image"}},"name":"204-2-1e647bf1-04d0-3541-a0ab-dc27bde551c0","guestOsType":"CentOS
7.2","size":1085276160,"hypervisorType":"None","bootable":false,"uniqueName":"204-2-1e647bf1-04d0-3541-a0ab-dc27bde551c0","directDownload":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":false,"nicUuid":"13df0849-9c60-4def-b124-0a4485629ba1","details":{"ForgedTransmits":"true","PromiscuousMode":"false","MacAddressChanges":"true"},"dpdkEnabled":false,"uuid":"ae49270a-9617-4a07-ae61-72aa58dfec69","ip":"10.1.3.134","netmask":"255.255.255.0","gateway":"10.1.3.1","mac":"02:00:05:76:00:08","dns1":"172.26.0.1","dns2":"","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://571","isolationUri":"vlan://571","isSecurityGroupEnabled":false,"name":"cloudbr1"}],"guestOsDetails":{},"extraConfig":{}},"result":false,"details":"XML
error: Non-empty feature list specified without CPU model","wait":0}}] }
2020-06-24 17:26:03,558 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Seq 6-5149866173898163465: Received: { Ans: , MgmtId:
8796761733588, via: 6(kvm-lab-01), Ver: v1, Flags: 10, { StartAnswer } }
2020-06-24 17:26:03,566 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Unable to start VM on Host[-6-Routing] due to XML error:
Non-empty feature list specified without CPU model
2020-06-24 17:26:03,575 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Cleaning up resources for the vm VM[User|i-2-31-VM] in
Starting state
2020-06-24 17:26:03,579 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Seq 6-5149866173898163466: Sending { Cmd , MgmtId:
8796761733588, via: 6(kvm-lab-01), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"forceStop":false,"volumesToDisconnect":[],"vmName":"i-2-31-VM","executeInSequence":false,"wait":0}}]
}
2020-06-24 17:26:03,684 DEBUG [c.c.a.ApiServlet] (qtp540585569-20:ctx-0fe0afac)
(logid:b04b428e) ===START=== 172.26.0.190 -- GET
command=queryAsyncJobResult&jobId=1ee79ed4-5ba5-411c-8b8c-9eb085adb578&response=json&_=1593028561934
2020-06-24 17:26:03,691 DEBUG [c.c.a.ApiServer] (qtp540585569-20:ctx-0fe0afac
ctx-87505e06) (logid:b04b428e) CIDRs from which account
'Acct[980fd937-9a2a-11ea-8d4e-080027e76427-admin]' is allowed to perform API
calls: 0.0.0.0/0,::/0
2020-06-24 17:26:03,706 DEBUG [c.c.a.ApiServlet] (qtp540585569-20:ctx-0fe0afac
ctx-87505e06) (logid:b04b428e) ===END=== 172.26.0.190 -- GET
command=queryAsyncJobResult&jobId=1ee79ed4-5ba5-411c-8b8c-9eb085adb578&response=json&_=1593028561934
2020-06-24 17:26:03,800 DEBUG [c.c.a.t.Request] (AgentManager-Handler-12:null)
(logid:) Seq 6-5149866173898163466: Processing: { Ans: , MgmtId:
8796761733588, via: 6, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2020-06-24 17:26:03,800 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Seq 6-5149866173898163466: Received: { Ans: , MgmtId:
8796761733588, via: 6(kvm-lab-01), Ver: v1, Flags: 10, { StopAnswer } }
2020-06-24 17:26:03,806 DEBUG [c.c.n.NetworkModelImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Service SecurityGroup is not supported in the network id=211
2020-06-24 17:26:03,809 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Changing active number of nics for network id=211 on -1
2020-06-24 17:26:03,830 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Asking VirtualRouter to release
NicProfile[78-31-dd21999b-d77e-46fd-a722-e9733f119a1b-10.1.3.134-null
2020-06-24 17:26:03,830 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Successfully released network resources for the vm
VM[User|i-2-31-VM]
2020-06-24 17:26:03,830 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Successfully cleaned up resources for the VM
VM[User|i-2-31-VM] in Starting state
2020-06-24 17:26:03,831 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Root volume is ready, need to place VM in volume's cluster
2020-06-24 17:26:03,837 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) DeploymentPlanner allocation algorithm: null
2020-06-24 17:26:03,837 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Trying to allocate a host and storage pools from dc:3,
pod:2,cluster:2, requested cpu: 500, requested ram: 536870912
2020-06-24 17:26:03,837 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Is ROOT volume READY (pool already allocated)?: Yes
2020-06-24 17:26:03,838 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) DeploymentPlan has host_id specified, choosing this host and
making no checks on this host: 6
2020-06-24 17:26:03,838 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) The specified host is in avoid set
2020-06-24 17:26:03,838 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Cannot deploy to specified host, returning.
2020-06-24 17:26:03,890 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) VM state transitted from :Starting to Stopped with event:
OperationFailedvm's original host id: null new host id: null host id before
state transition: 6
2020-06-24 17:26:03,899 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Hosts's actual total CPU: 12400 and CPU after applying
overprovisioning: 12400
2020-06-24 17:26:03,899 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Hosts's actual total RAM: 7115472896 and RAM after applying
overprovisioning: 7115472896
2020-06-24 17:26:03,899 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) release cpu from host: 6, old used: 2500,reserved: 0, actual
total: 12400, total with overprovisioning: 12400; new used: 2000,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2020-06-24 17:26:03,899 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) release mem from host: 6, old used: 2684354560,reserved: 0,
total: 7115472896; new used: 2147483648,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2020-06-24 17:26:03,935 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Invocation exception, caused by:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-31-VM]Scope=interface com.cloud.dc.DataCenter; id=3
2020-06-24 17:26:03,935 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212 ctx-1cf4ef5a)
(logid:1ee79ed4) Rethrow exception
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-31-VM]Scope=interface com.cloud.dc.DataCenter; id=3
2020-06-24 17:26:03,936 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212) (logid:1ee79ed4) Done with
run of VM work job: com.cloud.vm.VmWorkStart for VM 31, job origin: 211
2020-06-24 17:26:03,936 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212) (logid:1ee79ed4) Unable to
complete AsyncJobVO {id:212, userId: 2, accountId: 2, instanceType: null,
instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAH3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAA3BzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAAAJzcQB-AAgAAAAAAAAABnBwcHEAfgAKcHNyABFqYXZhLnV0aWwuSGFzaE1hcAUH2sHDFmDRAwACRgAKbG9hZEZhY3RvckkACXRocmVzaG9sZHhwP0AAAAAAAAx3CAAAABAAAAABdAAKVm1QYXNzd29yZHQAHHJPMEFCWFFBRG5OaGRtVmtYM0JoYzNOM2IzSmt4cA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 8796761733588, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Wed Jun 24 17:25:15 BRT 2020, removed: null}, job
origin:211
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-31-VM]Scope=interface com.cloud.dc.DataCenter; id=3
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1067)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5143)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5306)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:603)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:551)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2020-06-24 17:26:03,957 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212) (logid:1ee79ed4) Complete
async job-212, jobStatus: FAILED, resultCode: 0, result:
rO0ABXNyADdjb20uY2xvdWQuZXhjZXB0aW9uLkluc3VmZmljaWVudFNlcnZlckNhcGFjaXR5RXhjZXB0aW9uAAAAAFZNT3ACAAFaABVhZmZpbml0eUdyb3Vwc0FwcGxpZWR4cgAxY29tLmNsb3VkLmV4Y2VwdGlvbi5JbnN1ZmZpY2llbnRDYXBhY2l0eUV4Y2VwdGlvbgAAAABWTU91AgACTAACaWR0ABBMamF2YS9sYW5nL0xvbmc7TAAFc2NvcGV0ABFMamF2YS9sYW5nL0NsYXNzO3hyACJjb20uY2xvdWQuZXhjZXB0aW9uLkNsb3VkRXhjZXB0aW9ueeiOG_HkRMcCAAJMAAtjc0Vycm9yQ29kZXQAE0xqYXZhL2xhbmcvSW50ZWdlcjtMAAZpZExpc3R0ABVMamF2YS91dGlsL0FycmF5TGlzdDt4cgATamF2YS5sYW5nLkV4Y2VwdGlvbtD9Hz4aOxzEAgAAeHIAE2phdmEubGFuZy5UaHJvd2FibGXVxjUnOXe4ywMABEwABWNhdXNldAAVTGphdmEvbGFuZy9UaHJvd2FibGU7TAANZGV0YWlsTWVzc2FnZXQAEkxqYXZhL2xhbmcvU3RyaW5nO1sACnN0YWNrVHJhY2V0AB5bTGphdmEvbGFuZy9TdGFja1RyYWNlRWxlbWVudDtMABRzdXBwcmVzc2VkRXhjZXB0aW9uc3QAEExqYXZhL3V0aWwvTGlzdDt4cHEAfgANdAA0VW5hYmxlIHRvIGNyZWF0ZSBhIGRlcGxveW1lbnQgZm9yIFZNW1VzZXJ8aS0yLTMxLVZNXXVyAB5bTGphdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudDsCRio8PP0iOQIAAHhwAAAAFXNyABtqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnRhCcWaJjbdhQIABEkACmxpbmVOdW1iZXJMAA5kZWNsYXJpbmdDbGFzc3EAfgAKTAAIZmlsZU5hbWVxAH4ACkwACm1ldGhvZE5hbWVxAH4ACnhwAAAEK3QAJmNvbS5jbG91ZC52bS5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsdAAeVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbC5qYXZhdAAQb3JjaGVzdHJhdGVTdGFydHNxAH4AEQAAFBdxAH4AE3EAfgAUcQB-ABVzcQB-ABH____-dAAkc3VuLnJlZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpbnZva2Uwc3EAfgARAAAAPnEAfgAYcQB-ABl0AAZpbnZva2VzcQB-ABEAAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAcc3EAfgARAAAB8nQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-ABxzcQB-ABEAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EAfgARAAAUunEAfgATcQB-ABRxAH4AJnNxAH4AEQAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4AEQAAAlt0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-ABEAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-ABEAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgARAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4ANnQAD2NhbGxXaXRoQ29udGV4dHNxAH4AEQAAADVxAH4AOXEAfgA2dAAOcnVuV2l0aENvbnRleHRzcQB-ABEAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ADJxAH4AM3NxAH4AEQAAAidxAH4ALXEAfgAucQB-ADNzcQB-ABEAAAH_dAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ADdzcQB-ABEAAAEKdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAzc3EAfgARAAAEfXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgARAAACcHQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4ASHEAfgAzc3EAfgARAAAC7HQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAzc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAx4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AVHhzcgARamF2YS5sYW5nLkludGVnZXIS4qCk94GHOAIAAUkABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAQ73NxAH4AUwAAAAB3BAAAAAB4c3IADmphdmEubGFuZy5Mb25nO4vkkMyPI98CAAFKAAV2YWx1ZXhxAH4AVgAAAAAAAAADdnIAF2NvbS5jbG91ZC5kYy5EYXRhQ2VudGVyU-gkGtLTtlwCAAB4cAA
2020-06-24 17:26:03,958 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212) (logid:1ee79ed4) Publish
async job-212 complete on message bus
2020-06-24 17:26:03,958 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212) (logid:1ee79ed4) Wake up
jobs related to job-212
2020-06-24 17:26:03,958 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212) (logid:1ee79ed4) Update db
status for job-212
2020-06-24 17:26:03,959 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212) (logid:1ee79ed4) Wake up
jobs joined with job-212 and disjoin all subjobs created from job- 212
2020-06-24 17:26:03,970 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212) (logid:1ee79ed4) Done
executing com.cloud.vm.VmWorkStart for job-212
2020-06-24 17:26:03,974 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-35:ctx-620bd39c job-211/job-212) (logid:1ee79ed4) Remove
job-212 from job monitoring
2020-06-24 17:26:03,983 ERROR [c.c.v.UserVmManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211 ctx-501a7875) (logid:1ee79ed4) VM
VM[User|i-2-31-VM] unexpectedly went to Stopped state
2020-06-24 17:26:03,984 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211 ctx-501a7875) (logid:1ee79ed4)
Destroying vm VM[User|i-2-31-VM] as it failed to create on Host with Id:6
2020-06-24 17:26:04,024 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211 ctx-501a7875) (logid:1ee79ed4) VM
state transitted from :Stopped to Error with event: OperationFailedToErrorvm's
original host id: null new host id: null host id before state transition: null
2020-06-24 17:26:04,092 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211 ctx-501a7875) (logid:1ee79ed4)
Updating resource Type = volume count for Account = 2 Operation = decreasing
Amount = 1
2020-06-24 17:26:04,103 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211 ctx-501a7875) (logid:1ee79ed4)
Updating resource Type = primary_storage count for Account = 2 Operation =
decreasing Amount = 5368709120
2020-06-24 17:26:04,122 WARN [c.c.a.AlertManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211 ctx-501a7875) (logid:1ee79ed4)
AlertType:: 8 | dataCenterId:: 3 | podId:: 2 | clusterId:: null | message::
Failed to deploy Vm with Id: 31, on Host with Id: 6
2020-06-24 17:26:04,133 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211 ctx-501a7875) (logid:1ee79ed4)
Updating resource Type = user_vm count for Account = 2 Operation = decreasing
Amount = 1
2020-06-24 17:26:04,145 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211 ctx-501a7875) (logid:1ee79ed4)
Updating resource Type = cpu count for Account = 2 Operation = decreasing
Amount = 1
2020-06-24 17:26:04,152 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211 ctx-501a7875) (logid:1ee79ed4)
Updating resource Type = memory count for Account = 2 Operation = decreasing
Amount = 512
2020-06-24 17:26:04,188 WARN [o.a.c.a.c.a.v.DeployVMCmdByAdmin]
(API-Job-Executor-18:ctx-cbb64e2f job-211 ctx-501a7875) (logid:1ee79ed4)
Exception:
com.cloud.exception.ConcurrentOperationException: Failed to deploy VM
VM[User|i-2-31-VM]
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4242)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4224)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy190.startVirtualMachine(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin.execute(DeployVMCmdByAdmin.java:67)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:156)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:603)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:551)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2020-06-24 17:26:04,202 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211) (logid:1ee79ed4) Complete async
job-211, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed
to deploy VM VM[User|i-2-31-VM]"}
2020-06-24 17:26:04,203 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211) (logid:1ee79ed4) Publish async
job-211 complete on message bus
2020-06-24 17:26:04,203 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211) (logid:1ee79ed4) Wake up jobs
related to job-211
2020-06-24 17:26:04,203 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211) (logid:1ee79ed4) Update db status
for job-211
2020-06-24 17:26:04,204 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211) (logid:1ee79ed4) Wake up jobs joined
with job-211 and disjoin all subjobs created from job- 211
2020-06-24 17:26:04,212 DEBUG [c.c.a.ApiServer]
(API-Job-Executor-18:ctx-cbb64e2f job-211) (logid:1ee79ed4) Retrieved
cmdEventType from job info: VM.CREATE
2020-06-24 17:26:04,220 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-18:ctx-cbb64e2f job-211) (logid:1ee79ed4) Done executing
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin for job-211
2020-06-24 17:26:04,220 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-18:ctx-cbb64e2f job-211) (logid:1ee79ed4) Remove job-211 from
job monitoring
2020-06-24 17:26:04,230 DEBUG [c.c.a.ApiServlet] (qtp540585569-11:ctx-9130e9a3)
(logid:54744f8a) ===START=== 186.237.59.161 -- GET
apiKey=kyairaeSm9tJ8AUT4MnSbFz8DM2WoS8ms3EYcYE0PEg5dk44Wc5G2QQXjZFS_iuvcZ3veHFpqVTKjexObgj7Jg&command=queryAsyncJobResult&jobId=1ee79ed4-5ba5-411c-8b8c-9eb085adb578&response=json&signature=Yjnyb7O31B44%2F5JOHXuV8q2JNv8%3D
2020-06-24 17:26:04,232 DEBUG [c.c.a.ApiServer] (qtp540585569-11:ctx-9130e9a3
ctx-93ca96cb) (logid:54744f8a) apiKey does not map to a valid user -- ignoring
request, apiKey:
kyairaeSm9tJ8AUT4MnSbFz8DM2WoS8ms3EYcYE0PEg5dk44Wc5G2QQXjZFS_iuvcZ3veHFpqVTKjexObgj7Jg
2020-06-24 17:26:04,232 DEBUG [c.c.a.ApiServlet] (qtp540585569-11:ctx-9130e9a3
ctx-93ca96cb) (logid:54744f8a) ===END=== 186.237.59.161 -- GET
apiKey=kyairaeSm9tJ8AUT4MnSbFz8DM2WoS8ms3EYcYE0PEg5dk44Wc5G2QQXjZFS_iuvcZ3veHFpqVTKjexObgj7Jg&command=queryAsyncJobResult&jobId=1ee79ed4-5ba5-411c-8b8c-9eb085adb578&response=json&signature=Yjnyb7O31B44%2F5JOHXuV8q2JNv8%3D
2020-06-24 17:26:06,681 DEBUG [c.c.a.ApiServlet] (qtp540585569-17:ctx-6a9b3a91)
(logid:bdb454ea) ===START=== 172.26.0.190 -- GET
command=queryAsyncJobResult&jobId=1ee79ed4-5ba5-411c-8b8c-9eb085adb578&response=json&_=1593028561935
2020-06-24 17:26:06,686 DEBUG [c.c.a.ApiServer] (qtp540585569-17:ctx-6a9b3a91
ctx-da6293a3) (logid:bdb454ea) CIDRs from which account
'Acct[980fd937-9a2a-11ea-8d4e-080027e76427-admin]' is allowed to perform API
calls: 0.0.0.0/0,::/0
2020-06-24 17:26:06,702 DEBUG [c.c.a.ApiServlet] (qtp540585569-17:ctx-6a9b3a91
ctx-da6293a3) (logid:bdb454ea) ===END=== 172.26.0.190 -- GET
command=queryAsyncJobResult&jobId=1ee79ed4-5ba5-411c-8b8c-9eb085adb578&response=json&_=1593028561935
2020-06-24 17:26:06,709 DEBUG [c.c.a.ApiServlet] (qtp540585569-19:ctx-84fafbe8)
(logid:08355159) ===START=== 172.26.0.190 -- GET
command=listVirtualMachines&id=76edbaeb-6a45-405b-a932-961e12e98cc3&response=json&_=1593028561936
2020-06-24 17:26:06,714 DEBUG [c.c.a.ApiServer] (qtp540585569-19:ctx-84fafbe8
ctx-436c28b9) (logid:08355159) CIDRs from which account
'Acct[980fd937-9a2a-11ea-8d4e-080027e76427-admin]' is allowed to perform API
calls: 0.0.0.0/0,::/0
2020-06-24 17:26:06,728 DEBUG [c.c.a.ApiServlet] (qtp540585569-19:ctx-84fafbe8
ctx-436c28b9) (logid:08355159) ===END=== 172.26.0.190 -- GET
command=listVirtualMachines&id=76edbaeb-6a45-405b-a932-961e12e98cc3&response=json&_=1593028561936
2020-06-24 17:26:08,995 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-08f3052c) (logid:e798324a) Begin cleanup expired
async-jobs
2020-06-24 17:26:08,999 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-08f3052c) (logid:e798324a) End cleanup expired
async-jobs
