xuanyuanaosheng opened a new issue, #6635:
URL: https://github.com/apache/cloudstack/issues/6635
##### ISSUE TYPE
* Bug Report
##### CLOUDSTACK VERSION
1. CloudStack:4.15.2.0
2. ceph version:15.2.16
3. cloudstack agent os version: Oracle Linux Server 8.3
4.
The cloudstack env is **using the Ceph RBD and local storage as cloudstack
cluster primary storage.**
The cloudstack cluster TEST work node is eno49 and eno50 to bond0.
```
- bond0 ---> bond0.1935 ---> cloudbr0
-------> VLAN 1115
- bond0 ---> cloudbr1 -
-------> VLAN 1118
```
The libvirt version:
```
# rpm -qa | grep libvirt*
libvirt-daemon-driver-storage-rbd-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-client-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-glib-3.0.0-1.el8.x86_64
libvirt-daemon-driver-storage-disk-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-nodedev-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-storage-iscsi-direct-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-devel-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-storage-core-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-qemu-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-storage-mpath-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-wireshark-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-nwfilter-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-storage-logical-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-lock-sanlock-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-docs-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-secret-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-config-network-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-storage-scsi-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-kvm-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-interface-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-config-nwfilter-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-gobject-3.0.0-1.el8.x86_64
libvirt-daemon-driver-storage-gluster-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-gconfig-3.0.0-1.el8.x86_64
libvirt-dbus-1.3.0-2.module+el8.6.0+20659+3dcf7c70.x86_64
libvirt-libs-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-storage-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
python3-libvirt-6.0.0-1.module+el8.3.0+7860+a7792d29.x86_64
libvirt-daemon-driver-network-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-daemon-driver-storage-iscsi-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
libvirt-nss-8.0.0-5.2.0.1.module+el8.6.0+20722+b0f1ae3c.x86_64
```
The Cloudstack manager error log
```
2022-08-12 12:32:08,563 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Seq 76-8001207687977107472: Received: { Ans: , MgmtId:
345052215515, via: 76(whdckvm006.cn.prod), Ver: v1, Flags: 10, { StopAnswer } }
2022-08-12 12:32:08,583 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Changing active number of nics for network id=234 on -1
2022-08-12 12:32:08,597 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Successfully released network resources for the vm
VM[User|i-2-25947-VM]
2022-08-12 12:32:08,597 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Successfully cleaned up resources for the VM
VM[User|i-2-25947-VM] in Starting state
2022-08-12 12:32:08,601 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Root volume is ready, need to place VM in volume's cluster
2022-08-12 12:32:08,614 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) DeploymentPlanner allocation algorithm: null
2022-08-12 12:32:08,614 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Trying to allocate a host and storage pools from dc:8,
pod:7,cluster:8, requested cpu: 4096, requested ram: (7.91 GB) 8489271296
2022-08-12 12:32:08,614 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Is ROOT volume READY (pool already allocated)?: Yes
2022-08-12 12:32:08,614 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) DeploymentPlan has host_id specified, choosing this host and
making no checks on this host: 76
2022-08-12 12:32:08,616 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) The specified host is in avoid set
2022-08-12 12:32:08,616 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Cannot deploy to specified host, returning.
2022-08-12 12:32:08,632 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) VM state transitted from :Starting to Stopped with event:
OperationFailedvm's original host id: null new host id: null host id before
state transition: 76
2022-08-12 12:32:08,636 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-15:null) (logid:) Ping from 18(s-286-VM)
2022-08-12 12:32:08,647 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Hosts's actual total CPU: 184800 and CPU after applying
overprovisioning: 1108800
2022-08-12 12:32:08,647 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Hosts's actual total RAM: (502.83 GB) 539906072576 and RAM
after applying overprovisioning: (2.9463 TB) 3239436615680
2022-08-12 12:32:08,647 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) release cpu from host: 76, old used: 4096,reserved: 0, actual
total: 184800, total with overprovisioning: 1108800; new used: 0,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2022-08-12 12:32:08,647 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) release mem from host: 76, old used: (7.91 GB)
8489271296,reserved: (0 bytes) 0, total: (2.9463 TB) 3239436615680; new used:
(0 bytes) 0,reserved:(0 bytes) 0; movedfromreserved: false,moveToReserveredfalse
2022-08-12 12:32:08,674 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Invocation exception, caused by:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-25947-VM]Scope=interface com.cloud.dc.DataCenter;
id=8
2022-08-12 12:32:08,674 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365 ctx-d0ce22e0)
(logid:a4efa0f1) Rethrow exception
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-25947-VM]Scope=interface com.cloud.dc.DataCenter;
id=8
2022-08-12 12:32:08,674 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365) (logid:a4efa0f1) Done
with run of VM work job: com.cloud.vm.VmWorkStart for VM 25947, job origin:
86364
2022-08-12 12:32:08,674 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365) (logid:a4efa0f1) Unable
to complete AsyncJobVO {id:86365, userId: 2, accountId: 2, instanceType: null,
instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAABlW3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAACHBzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAAAhzcQB-AAgAAAAA
AAAATHBwcHNxAH4ACAAAAAAAAAAHcHNyABFqYXZhLnV0aWwuSGFzaE1hcAUH2sHDFmDRAwACRgAKbG9hZEZhY3RvckkACXRocmVzaG9sZHhwP0AAAAAAAAx3CAAAABAAAAABdAAKVm1QYXNzd29yZHQAHHJPMEFCWFFBRG5OaGRtVmtYM0JoYzNOM2IzSmt4cA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 345052215515, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Fri Aug 12 12:32:04 CST 2022, removed: null}, job
origin:86364
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|i-2-25947-VM]Scope=interface com.cloud.dc.DataCenter;
id=8
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1119)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5502)
at jdk.internal.reflect.GeneratedMethodAccessor1415.invoke(Unknown
Source)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5669)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
2022-08-12 12:32:08,684 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365) (logid:a4efa0f1)
Complete async job-86365, jobStatus: FAILED, resultCode: 0, result:
rO0ABXNyADdjb20uY2xvdWQuZXhjZXB0aW9uLkluc3VmZmljaWVudFNlcnZlckNhcGFjaXR5RXhjZXB0aW9uAAAAAFZNT3ACAAFaABVhZmZpbml0eUdyb3Vwc0FwcGxpZWR4cgAxY29tLmNsb3VkLmV4Y2VwdGlvbi5JbnN1ZmZpY2llbnRDYXBhY2l0eUV4Y2VwdGlvbgAAAABWTU91AgACTAACaWR0ABBMamF2YS9sYW5nL0xvbmc7TAAFc2NvcGV0ABFMamF2YS9sYW5nL0NsYXNzO3hyACJjb20uY2xvdWQuZXhjZXB0aW9uLkNsb3VkRXhjZXB0aW9ueeiOG_HkRMcCAAJMAAtjc0Vycm9yQ29kZXQAE0xqYXZhL2xhbmcvSW50ZWdlcjtMAAZpZExpc3R0ABVMamF2YS91dGlsL0FycmF5TGlzdDt4cgATamF2YS5sYW5nLkV4Y2VwdGlvbtD9Hz4aOxzEAgAAeHIAE2phdmEubGFuZy5UaHJvd2FibGXVxjUnOXe4ywMABEwABWNhdXNldAAVTGphdmEvbGFuZy9UaHJvd2FibGU7TAANZGV0YWlsTWVzc2FnZXQAEkxqYXZhL2xhbmcvU3RyaW5nO1sACnN0YWNrVHJhY2V0AB5bTGphdmEvbGFuZy9TdGFja1RyYWNlRWxlbWVudDtMABRzdXBwcmVzc2VkRXhjZXB0aW9uc3QAEExqYXZhL3V0aWwvTGlzdDt4cHEAfgANdAA3VW5hYmxlIHRvIGNyZWF0ZSBhIGRlcGxveW
1lbnQgZm9yIFZNW1VzZXJ8aS0yLTI1OTQ3LVZNXXVyAB5bTGphdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudDsCRio8PP0iOQIAAHhwAAAAFHNyABtqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnRhCcWaJjbdhQIACEIABmZvcm1hdEkACmxpbmVOdW1iZXJMAA9jbGFzc0xvYWRlck5hbWVxAH4ACkwADmRlY2xhcmluZ0NsYXNzcQB-AApMAAhmaWxlTmFtZXEAfgAKTAAKbWV0aG9kTmFtZXEAfgAKTAAKbW9kdWxlTmFtZXEAfgAKTAANbW9kdWxlVmVyc2lvbnEAfgAKeHABAAAEX3QAA2FwcHQAJmNvbS5jbG91ZC52bS5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsdAAeVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbC5qYXZhdAAQb3JjaGVzdHJhdGVTdGFydHBwc3EAfgARAQAAFX5xAH4AE3EAfgAUcQB-ABVxAH4AFnBwc3EAfgARAP____9wdAAwamRrLmludGVybmFsLnJlZmxlY3QuR2VuZXJhdGVkTWV0aG9kQWNjZXNzb3IxNDE1cHQABmludm9rZXBwc3EAfgARAgAAACtwdAAxamRrLmludGVybmFsLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAadAAJamF2YS5iYXNldAAHMTEuMC4xMHNxAH4AEQIAAAI2cHQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-ABpxAH4AHnEAfgAfc3EAfgARAQAAAGtxAH4AE3QAImNvbS5jbG91ZC52bS5WbVdvcmtKb2JIYW5kbGVyUHJveHl0ABpWbVdvcmtKb2JIYW5kbGVyUHJ
veHkuamF2YXQAD2hhbmRsZVZtV29ya0pvYnBwc3EAfgARAQAAFiVxAH4AE3EAfgAUcQB-ABVxAH4AJnBwc3EAfgARAQAAAGZxAH4AE3QAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXNwYXRjaGVydAAYVm1Xb3JrSm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9icHBzcQB-ABEBAAACbHEAfgATdAA_b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmZyYW1ld29yay5qb2JzLmltcGwuQXN5bmNKb2JNYW5hZ2VySW1wbCQ1dAAYQXN5bmNKb2JNYW5hZ2VySW1wbC5qYXZhdAAMcnVuSW5Db250ZXh0cHBzcQB-ABEBAAAAMHEAfgATdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5wcHNxAH4AEQEAAAA3cQB-ABN0AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbGxwcHNxAH4AEQEAAABmcQB-ABN0AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0cQB-ADZ0AA9jYWxsV2l0aENvbnRleHRwcHNxAH4AEQEAAAA0cQB-ABNxAH4AOXEAfgA2dAAOcnVuV2l0aENvbnRleHRwcHNxAH4AEQEAAAAtcQB-ABN0ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFi
bGVxAH4AMnEAfgAzcHBzcQB-ABEBAAACOHEAfgATcQB-AC1xAH4ALnEAfgAzcHBzcQB-ABECAAACA3B0AC5qYXZhLnV0aWwuY29uY3VycmVudC5FeGVjdXRvcnMkUnVubmFibGVBZGFwdGVydAAORXhlY3V0b3JzLmphdmFxAH4AN3EAfgAecQB-AB9zcQB-ABECAAABCHB0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrdAAPRnV0dXJlVGFzay5qYXZhcQB-ADNxAH4AHnEAfgAfc3EAfgARAgAABGhwdAAnamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9ydAAXVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmF0AAlydW5Xb3JrZXJxAH4AHnEAfgAfc3EAfgARAgAAAnRwdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9yJFdvcmtlcnEAfgBIcQB-ADNxAH4AHnEAfgAfc3EAfgARAgAAA0JwdAAQamF2YS5sYW5nLlRocmVhZHQAC1RocmVhZC5qYXZhcQB-ADNxAH4AHnEAfgAfc3IAH2phdmEudXRpbC5Db2xsZWN0aW9ucyRFbXB0eUxpc3R6uBe0PKee3gIAAHhweHNyABFqYXZhLmxhbmcuSW50ZWdlchLioKT3gYc4AgABSQAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAABDvc3IAE2phdmEudXRpbC5BcnJheUxpc3R4gdIdmcdhnQMAAUkABHNpemV4cAAAAAB3BAAAAAB4c3IADmphdmEubGFuZy5Mb25nO4vkkMyPI98CAAFKAAV2YWx1ZXhxAH4AUgAAAAAAAAAIdnIAF2NvbS5jbG91ZC5kYy5EYXRhQ2VudGVyU-gkGtLTtlwCAAB4cAA
2022-08-12 12:32:08,686 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365) (logid:a4efa0f1)
Publish async job-86365 complete on message bus
2022-08-12 12:32:08,686 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365) (logid:a4efa0f1) Wake
up jobs related to job-86365
2022-08-12 12:32:08,686 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365) (logid:a4efa0f1) Update
db status for job-86365
2022-08-12 12:32:08,689 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365) (logid:a4efa0f1) Wake
up jobs joined with job-86365 and disjoin all subjobs created from job- 86365
2022-08-12 12:32:08,700 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365) (logid:a4efa0f1) Done
executing com.cloud.vm.VmWorkStart for job-86365
2022-08-12 12:32:08,704 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-71:ctx-c5d11def job-86364/job-86365) (logid:a4efa0f1) Remove
job-86365 from job monitoring
2022-08-12 12:32:08,718 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364 ctx-13ec6414) (logid:a4efa0f1)
Destroying vm VM[User|i-2-25947-VM] as it failed to create on Host with Id:76
2022-08-12 12:32:08,726 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364 ctx-13ec6414) (logid:a4efa0f1) 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
2022-08-12 12:32:08,779 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364 ctx-13ec6414) (logid:a4efa0f1)
Updating resource Type = volume count for Account = 2 Operation = decreasing
Amount = 1
2022-08-12 12:32:08,787 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364 ctx-13ec6414) (logid:a4efa0f1)
Updating resource Type = primary_storage count for Account = 2 Operation =
decreasing Amount = (40.00 GB) 42949672960
2022-08-12 12:32:08,804 WARN [c.c.a.AlertManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364 ctx-13ec6414) (logid:a4efa0f1)
AlertType:: 8 | dataCenterId:: 8 | podId:: 7 | clusterId:: null | message::
Failed to deploy Vm with Id: 25947, on Host with Id: 76
2022-08-12 12:32:08,806 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-12:null) (logid:) Ping from Routing host
5(scnbe013.cn.prod)
2022-08-12 12:32:08,807 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-12:null) (logid:) Process host VM state report from ping
process. host: 5
2022-08-12 12:32:08,813 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364 ctx-13ec6414) (logid:a4efa0f1)
Updating resource Type = user_vm count for Account = 2 Operation = decreasing
Amount = 1
2022-08-12 12:32:08,827 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364 ctx-13ec6414) (logid:a4efa0f1)
Updating resource Type = cpu count for Account = 2 Operation = decreasing
Amount = 4
2022-08-12 12:32:08,830 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-12:null) (logid:) Process VM state report. host: 5,
number of records in report: 6
2022-08-12 12:32:08,830 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-12:null) (logid:) VM state report. host: 5, vm id: 25824,
power state: PowerOn
2022-08-12 12:32:08,833 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-12:null) (logid:) VM state report. host: 5, vm id: 25825,
power state: PowerOn
2022-08-12 12:32:08,836 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-12:null) (logid:) VM state report. host: 5, vm id: 25826,
power state: PowerOn
2022-08-12 12:32:08,837 DEBUG [c.c.r.ResourceLimitManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364 ctx-13ec6414) (logid:a4efa0f1)
Updating resource Type = memory count for Account = 2 Operation = decreasing
Amount = 8096
2022-08-12 12:32:08,839 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-12:null) (logid:) VM state report. host: 5, vm id: 25827,
power state: PowerOn
2022-08-12 12:32:08,842 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-12:null) (logid:) VM state report. host: 5, vm id: 25933,
power state: PowerOn
2022-08-12 12:32:08,845 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-12:null) (logid:) VM state report. host: 5, vm id: 110,
power state: PowerOn
2022-08-12 12:32:08,852 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-12:null) (logid:) Done with process of VM state report.
host: 5
2022-08-12 12:32:08,854 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364) (logid:a4efa0f1) Unexpected
exception while executing
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin
com.cloud.utils.exception.CloudRuntimeException: Unable to start a VM due to
insufficient capacity
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:751)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:243)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:214)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4938)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4464)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4453)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
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:175)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
at com.sun.proxy.$Proxy127.startVirtualMachine(Unknown Source)
at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:686)
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:620)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: com.cloud.exception.InsufficientServerCapacityException: Unable
to create a deployment for VM[User|i-2-25947-VM]Scope=interface
com.cloud.dc.DataCenter; id=8
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1119)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5502)
at jdk.internal.reflect.GeneratedMethodAccessor1415.invoke(Unknown
Source)
... 17 more
2022-08-12 12:32:08,857 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364) (logid:a4efa0f1) Complete async
job-86364, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":"530","errortext":"Unable
to start a VM due to insufficient capacity"}
2022-08-12 12:32:08,858 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364) (logid:a4efa0f1) Publish async
job-86364 complete on message bus
2022-08-12 12:32:08,859 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364) (logid:a4efa0f1) Wake up jobs
related to job-86364
2022-08-12 12:32:08,859 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364) (logid:a4efa0f1) Update db status
for job-86364
2022-08-12 12:32:08,860 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364) (logid:a4efa0f1) Wake up jobs
joined with job-86364 and disjoin all subjobs created from job- 86364
2022-08-12 12:32:08,867 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364) (logid:a4efa0f1) Done executing
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin for job-86364
2022-08-12 12:32:08,868 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-40:ctx-5a8d5b0a job-86364) (logid:a4efa0f1) Remove job-86364
from job monitoring
2022-08-12 12:32:09,348 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-6:null) (logid:) Ping from 69(s-25919-VM)
2022-08-12 12:32:09,587 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-3:null) (logid:) Ping from 71(v-25920-VM)
2022-08-12 12:32:10,043 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-1:null) (logid:) SeqA 72-10974: Processing Seq 72-10974:
{ Cmd , MgmtId: -1, via: 72, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"25921","_loadInfo":"{
"connections": [
{
"id": 6,
"clientInfo": "",
"host": "10.26.246.11",
"port": 5906,
"tag": "ec3c81f6-4701-4276-8fdb-8cf34d610ddb",
"createTime": 1660274781795,
"lastUsedTime": 1660278669208
},
{
"id": 7,
"clientInfo": "",
"host": "10.26.246.11",
"port": 5904,
"tag": "0e65d2af-8e29-4c50-b2d0-170afcdb9a16",
"createTime": 1660274912073,
"lastUsedTime": 1660278669182
}
]
}","wait":"0","bypassHostMaintenance":"false"}}] }
2022-08-12 12:32:10,050 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-1:null) (logid:) SeqA 72-10974: Sending Seq 72-10974: {
Ans: , MgmtId: 345052215515, via: 72, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
```
The cloudstack agent error log:
```
2022-08-12 12:29:04,107 INFO [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-4:null) (logid:14eb27c4) Trying to fetch storage pool
0edb0e58-6b90-3be
e-8e7b-13007b0f7bf9 from libvirt
2022-08-12 12:29:04,317 INFO [cloud.agent.Agent]
(agentRequest-Handler-4:null) (logid:14eb27c4) Processing agent ready command,
agent id = 76
2022-08-12 12:29:04,318 INFO [cloud.agent.Agent]
(agentRequest-Handler-4:null) (logid:14eb27c4) Set agent id 76
2022-08-12 12:29:04,325 INFO [cloud.agent.Agent]
(agentRequest-Handler-4:null) (logid:14eb27c4) Ready command is processed for
agent id = 76
2022-08-12 12:29:04,382 INFO [cloud.agent.Agent]
(agentRequest-Handler-5:null) (logid:14eb27c4) Processing agent ready command,
agent id = 76
2022-08-12 12:29:04,382 INFO [cloud.agent.Agent]
(agentRequest-Handler-5:null) (logid:14eb27c4) Set agent id 76
2022-08-12 12:29:04,385 INFO [cloud.agent.Agent]
(agentRequest-Handler-5:null) (logid:14eb27c4) Processed new management server
list: 10.25.2.173@static
2022-08-12 12:29:04,385 INFO [cloud.agent.Agent]
(agentRequest-Handler-5:null) (logid:14eb27c4) Ready command is processed for
agent id = 76
2022-08-12 12:34:33,836 INFO [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-3:null) (logid:a4efa0f1) Trying to fetch storage pool
0edb0e58-6b90-3bee-8e7b-13007b0f7bf9 from libvirt
2022-08-12 12:34:34,217 INFO [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-3:null) (logid:a4efa0f1) Trying to fetch storage pool
0edb0e58-6b90-3be
e-8e7b-13007b0f7bf9 from libvirt
2022-08-12 12:34:34,673 WARN [kvm.resource.LibvirtKvmAgentHook]
(agentRequest-Handler-3:null) (logid:a4efa0f1) Groovy script
'/etc/cloudstack/agent/hooks/libv
irt-vm-xml-transformer.groovy' is not available. Transformations will not be
applied.
2022-08-12 12:34:34,674 WARN [kvm.resource.LibvirtKvmAgentHook]
(agentRequest-Handler-3:null) (logid:a4efa0f1) Groovy scripting engine is not
initialized. Dat
a transformation skipped.
2022-08-12 12:34:34,687 WARN [resource.wrapper.LibvirtStartCommandWrapper]
(agentRequest-Handler-3:null) (logid:a4efa0f1) LibvirtException
org.libvirt.LibvirtException: unsupported configuration: VNC password is 22
characters long, only 8 permitted
at org.libvirt.ErrorHandler.processError(Unknown Source)
at org.libvirt.ErrorHandler.processError(Unknown Source)
at org.libvirt.Connect.domainCreateXML(Unknown Source)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.startVM(LibvirtComputingResource.java:1616)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtStartCommandWrapper.execute(LibvirtStartCommandWrapper.java:85)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtStartCommandWrapper.execute(LibvirtStartCommandWrapper.java:45)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1648)
at com.cloud.agent.Agent.processRequest(Agent.java:661)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1079)
at com.cloud.utils.nio.Task.call(Task.java:83)
at com.cloud.utils.nio.Task.call(Task.java:29)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
2022-08-12 12:34:34,825 INFO [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-3:null) (logid:a4efa0f1) Trying to fetch storage pool
0edb0e58-6b90-3be
e-8e7b-13007b0f7bf9 from libvirt
2022-08-12 12:34:34,878 INFO [kvm.resource.LibvirtConnection]
(agentRequest-Handler-4:null) (logid:a4efa0f1) No existing libvirtd connection
found. Opening a
new one
2022-08-12 12:34:34,884 WARN [kvm.resource.LibvirtConnection]
(agentRequest-Handler-4:null) (logid:a4efa0f1) Can not find a connection for
Instance i-2-25947-
VM. Assuming the default connection.
2022-08-12 12:34:35,272 WARN [kvm.resource.LibvirtKvmAgentHook]
(agentRequest-Handler-4:null) (logid:a4efa0f1) Groovy script
'/etc/cloudstack/agent/hooks/libv
irt-vm-state-change.groovy' is not available. Transformations will not be
applied.
2022-08-12 12:34:35,273 WARN [kvm.resource.LibvirtKvmAgentHook]
(agentRequest-Handler-4:null) (logid:a4efa0f1) Groovy scripting engine is not
initialized. Dat
a transformation skipped.
```
Information already queried:
1. https://www.mail-archive.com/[email protected]/msg69138.html
2.
https://lists.ovirt.org/archives/list/[email protected]/thread/JU3EGBZWSITTDJSLX3WZBBYZ7MEXZQM7/
Could you please give some advices?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
