cc20110101 opened a new issue, #7935:
URL: https://github.com/apache/cloudstack/issues/7935
<!--
Verify first that your issue/request is not already reported on GitHub.
Also test if the latest release and main branch are affected too.
Always add information AFTER of these HTML comments, but no need to delete
the comments.
-->
##### ISSUE TYPE
<!-- Pick one below and delete the rest -->
* Bug Report
* Improvement Request
* Enhancement Request
* Feature Idea
* Documentation Report
* Other
##### COMPONENT NAME
<!--
Categorize the issue, e.g. API, VR, VPN, UI, etc.
-->
~~~
[
[CloudStack高级网络.pdf](https://github.com/apache/cloudstack/files/12504424/CloudStack.pdf)
](url)
~~~
##### CLOUDSTACK VERSION
<!--
New line separated list of affected versions, commit ID for issues on main
branch.
-->
4.18.0
~~~
~~~
##### CONFIGURATION
<!--
Information about the configuration if relevant, e.g. basic network,
advanced networking, etc. N/A otherwise
-->
##### OS / ENVIRONMENT
<!--
Information about the environment if relevant, N/A otherwise
-->
CentOS Linux release 7.9.2009 (Core)
SA5112M4 818498931 64G cpu2*8core
##### SUMMARY
<!-- Explain the problem/feature briefly -->
use Advanced networking, but system vm not work
cloudstack-management log:
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-2e62d742) (logid:cc558161)
No stopped console proxy is available, need to allocate a new console proxy
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-0b5a87ad)
(logid:0fdd0f27) No running secondary storage vms found in datacenter id=1,
starting one
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-0b5a87ad)
(logid:0fdd0f27) No stopped secondary storage VM is available, need to allocate
a new secondary storage VM.
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[c.c.v.VirtualMachineManagerImpl] (consoleproxy-1:ctx-2e62d742)
(logid:cc558161) allocating virtual machine from
template:38b04570-6690-485b-8a82-be847a54c205 with hostname:v-57-VM and 3
networks
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[o.a.c.e.o.VolumeOrchestrator] (consoleproxy-1:ctx-2e62d742 ctx-731e32f7)
(logid:cc558161) Adding disk object [ROOT-57] to VM [VM instance
{"id":57,"instanceName":"v-57-VM","type":"ConsoleProxy","uuid":"4c981454-40b9-4d76-948d-891f6e09f766"}]
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[o.a.c.a.DynamicRoleBasedAPIAccessChecker] (qtp504858437-32:ctx-2171a0d8
ctx-9aa4c7b7) (logid:0ed34c17) Account [Account
[{"accountName":"admin","id":2,"uuid":"6be33dee-49aa-11ee-81b7-6c92bfa2cc24"}]]
is Root Admin or Domain Admin, all APIs are allowed.
Sep 03 01:12:00 management1.inspur.com java[2720]: WARN
[o.a.c.a.ProjectRoleBasedApiAccessChecker] (qtp504858437-32:ctx-2171a0d8
ctx-9aa4c7b7) (logid:0ed34c17) Project is null,
ProjectRoleBasedApiAccessChecker only applies to projects, returning API
[listSystemVms] for user [User
{"username":"admin","uuid":"6be42c0e-49aa-11ee-81b7-6c92bfa2cc24"}.] as allowed.
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-49:ctx-8efcf390
job-139/job-188) (logid:87b4eee9) Add job-188 into job monitoring
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-0b5a87ad) (logid:0fdd0f27)
allocating virtual machine from template:38b04570-6690-485b-8a82-be847a54c205
with hostname:s-58-VM and 3 networks
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-49:ctx-8efcf390
job-139/job-188 ctx-6c890d3d FirstFitRoutingAllocator) (logid:37be6c0b) Guest
VM is requested with Custom[UEFI] Boot Type false
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-49:ctx-8efcf390
job-139/job-188 ctx-6c890d3d) (logid:37be6c0b) Re-ordering hosts [Host
{"id":1,"name":"management2.inspur.com","type":"Routing","uuid":"dcc0f417-7260-4d48-ad7c-7372bd144fa3"}]
by priorities {}
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-49:ctx-8efcf390
job-139/job-188 ctx-6c890d3d) (logid:37be6c0b) Hosts after re-ordering are:
[Host
{"id":1,"name":"management2.inspur.com","type":"Routing","uuid":"dcc0f417-7260-4d48-ad7c-7372bd144fa3"}]
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[c.c.s.StorageManagerImpl] (Work-Job-Executor-49:ctx-8efcf390 job-139/job-188
ctx-6c890d3d) (logid:37be6c0b) Storage pool Primary1 (1) does not supply IOPS
capacity, assuming enough capacity
Sep 03 01:12:00 management1.inspur.com java[2720]: INFO
[o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-0b5a87ad ctx-7bd1abbf)
(logid:0fdd0f27) Adding disk object [ROOT-58] to VM [VM instance
{"id":58,"instanceName":"s-58-VM","type":"SecondaryStorageVm","uuid":"45bf5234-6359-4b9f-8116-d377f01b9d98"}]
Sep 03 01:12:02 management1.inspur.com java[2720]: INFO
[o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-50:ctx-b90a4c84 job-2/job-189)
(logid:4c0d9f18) Add job-189 into job monitoring
Sep 03 01:12:02 management1.inspur.com java[2720]: INFO
[c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-50:ctx-b90a4c84
job-2/job-189 ctx-30f5e928 FirstFitRoutingAllocator) (logid:cfdb0635) Guest VM
is requested with Custom[UEFI] Boot Type false
Sep 03 01:12:02 management1.inspur.com java[2720]: INFO
[c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-50:ctx-b90a4c84
job-2/job-189 ctx-30f5e928) (logid:cfdb0635) Re-ordering hosts [Host
{"id":1,"name":"management2.inspur.com","type":"Routing","uuid":"dcc0f417-7260-4d48-ad7c-7372bd144fa3"}]
by priorities {}
Sep 03 01:12:02 management1.inspur.com java[2720]: INFO
[c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-50:ctx-b90a4c84
job-2/job-189 ctx-30f5e928) (logid:cfdb0635) Hosts after re-ordering are: [Host
{"id":1,"name":"management2.inspur.com","type":"Routing","uuid":"dcc0f417-7260-4d48-ad7c-7372bd144fa3"}]
Sep 03 01:12:02 management1.inspur.com java[2720]: INFO
[c.c.s.StorageManagerImpl] (Work-Job-Executor-50:ctx-b90a4c84 job-2/job-189
ctx-30f5e928) (logid:cfdb0635) Storage pool Primary1 (1) does not supply IOPS
capacity, assuming enough capacity
Sep 03 01:12:02 management1.inspur.com java[2720]: INFO
[c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-49:ctx-8efcf390
job-139/job-188 ctx-6c890d3d) (logid:37be6c0b) Unable to start VM on Host
{"id":1,"name":"management2.inspur.com","type":"Routing","uuid":"dcc0f417-7260-4d48-ad7c-7372bd144fa3"}
due to internal error: process exited while connecting to monitor:
2023-09-02T17:12:02.525160Z qemu-kvm: -chardev
socket,id=charchannel0,path=/home/cloudstack-agent/libvirt/qemu/v-57-VM.org.qemu.guest_agent.0,server,nowait:
Failed to bind socket: No such file or directory
Sep 03 01:12:02 management1.inspur.com java[2720]:
2023-09-02T17:12:02.525231Z qemu-kvm: -chardev
socket,id=charchannel0,path=/home/cloudstack-agent/libvirt/qemu/v-57-VM.org.qemu.guest_agent.0,server,nowait:
chardev: opening backend "socket" failed
Sep 03 01:12:04 management1.inspur.com java[2720]: INFO
[o.a.c.s.SecondaryStorageManagerImpl] (Work-Job-Executor-50:ctx-b90a4c84
job-2/job-189 ctx-30f5e928) (logid:cfdb0635) Using [192.168.221.107] as address
of secondary storage of SSVM [s-58-VM].
Sep 03 01:12:04 management1.inspur.com java[2720]: INFO
[c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-50:ctx-b90a4c84
job-2/job-189 ctx-30f5e928) (logid:cfdb0635) Unable to start VM on Host
{"id":1,"name":"management2.inspur.com","type":"Routing","uuid":"dcc0f417-7260-4d48-ad7c-7372bd144fa3"}
due to internal error: process exited while connecting to monitor:
2023-09-02T17:12:04.518664Z qemu-kvm: -chardev
socket,id=charchannel0,path=/home/cloudstack-agent/libvirt/qemu/s-58-VM.org.qemu.guest_agent.0,server,nowait:
Failed to bind socket: No such file or directory
Sep 03 01:12:04 management1.inspur.com java[2720]:
2023-09-02T17:12:04.518742Z qemu-kvm: -chardev
socket,id=charchannel0,path=/home/cloudstack-agent/libvirt/qemu/s-58-VM.org.qemu.guest_agent.0,server,nowait:
chardev: opening backend "socket" failed
Sep 03 01:12:08 management1.inspur.com java[2720]: INFO
[c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-50:ctx-b90a4c84
job-2/job-189 ctx-30f5e928 FirstFitRoutingAllocator) (logid:cfdb0635) Guest VM
is requested with Custom[UEFI] Boot Type false
Sep 03 01:12:08 management1.inspur.com java[2720]: INFO
[c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-50:ctx-b90a4c84
job-2/job-189 ctx-30f5e928) (logid:cfdb0635) Re-ordering hosts [] by priorities
{}
Sep 03 01:12:08 management1.inspur.com java[2720]: INFO
[c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-50:ctx-b90a4c84
job-2/job-189 ctx-30f5e928) (logid:cfdb0635) Hosts after re-ordering are: []
Sep 03 01:12:08 management1.inspur.com java[2720]: ERROR
[c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-50:ctx-b90a4c84 job-2/job-189
ctx-30f5e928) (logid:cfdb0635) Invocation exception, caused by:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM instance
{"id":58,"instanceName":"s-58-VM","type":"SecondaryStorageVm","uuid":"45bf5234-6359-4b9f-8116-d377f01b9d98"}Scope=interface
com.cloud.dc.DataCenter; id=1
Sep 03 01:12:08 management1.inspur.com java[2720]: INFO
[c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-50:ctx-b90a4c84 job-2/job-189
ctx-30f5e928) (logid:cfdb0635) Rethrow exception
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM instance
{"id":58,"instanceName":"s-58-VM","type":"SecondaryStorageVm","uuid":"45bf5234-6359-4b9f-8116-d377f01b9d98"}Scope=interface
com.cloud.dc.DataCenter; id=1
Sep 03 01:12:08 management1.inspur.com java[2720]: ERROR
[c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-50:ctx-b90a4c84 job-2/job-189)
(logid:cfdb0635) Unable to complete AsyncJobVO: {id:189, userId: 1, accountId:
1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart,
cmdInfo:
rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAAOnQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null,
initMsid: 195927833637058, completeMsid: null, lastUpdated: null, lastPolled:
null, created: Sun Sep 03 01:12:00 CST 2023, removed: null}, job origin:2
Sep 03 01:12:08 management1.inspur.com java[2720]:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM instance
{"id":58,"instanceName":"s-58-VM","type":"SecondaryStorageVm","uuid":"45bf5234-6359-4b9f-8116-d377f01b9d98"}Scope=interface
com.cloud.dc.DataCenter; id=1
Sep 03 01:12:08 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1166)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5351)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
jdk.internal.reflect.GeneratedMethodAccessor210.invoke(Unknown Source)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.lang.reflect.Method.invoke(Method.java:566)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5475)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.lang.Thread.run(Thread.java:829)
Sep 03 01:12:08 management1.inspur.com java[2720]: INFO
[o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-50:ctx-b90a4c84 job-2/job-189)
(logid:cfdb0635) Remove job-189 from job monitoring
Sep 03 01:12:08 management1.inspur.com java[2720]: WARN
[o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-0b5a87ad)
(logid:0fdd0f27) Unable to start secondary storage VM [58] due to [Unable to
create a deployment for VM instance
{"id":58,"instanceName":"s-58-VM","type":"SecondaryStorageVm","uuid":"45bf5234-6359-4b9f-8116-d377f01b9d98"}].
Sep 03 01:12:08 management1.inspur.com java[2720]:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM instance
{"id":58,"instanceName":"s-58-VM","type":"SecondaryStorageVm","uuid":"45bf5234-6359-4b9f-8116-d377f01b9d98"}Scope=interface
com.cloud.dc.DataCenter; id=1
Sep 03 01:12:08 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1166)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5351)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
jdk.internal.reflect.GeneratedMethodAccessor210.invoke(Unknown Source)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.lang.reflect.Method.invoke(Method.java:566)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5475)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
Sep 03 01:12:08 management1.inspur.com java[2720]: at
java.base/java.lang.Thread.run(Thread.java:829)
Sep 03 01:12:08 management1.inspur.com java[2720]: INFO
[o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-0b5a87ad)
(logid:0fdd0f27) Unable to start secondary storage VM [58] for standby
capacity, it will be recycled and will start a new one.
Sep 03 01:12:08 management1.inspur.com java[2720]: WARN
[c.c.a.AlertManagerImpl] (secstorage-1:ctx-0b5a87ad) (logid:0fdd0f27)
alertType=[19] dataCenterId=[1] podId=[null] clusterId=[null]
message=[Secondary Storage Vm creation failure. zone: Zone1, error details:
null].
Sep 03 01:12:08 management1.inspur.com java[2720]: WARN
[c.c.a.AlertManagerImpl] (secstorage-1:ctx-0b5a87ad) (logid:0fdd0f27) No
recipients set in global setting 'alert.email.addresses', skipping sending
alert with subject [Secondary Storage Vm creation failure. zone: Zone1, error
details: null] and content [Secondary Storage Vm creation failure (zone Zone1)].
Sep 03 01:12:08 management1.inspur.com java[2720]: INFO
[o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-0b5a87ad)
(logid:0fdd0f27) Primary secondary storage is not even started, wait until next
turn
Sep 03 01:12:09 management1.inspur.com java[2720]: INFO
[c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-49:ctx-8efcf390
job-139/job-188 ctx-6c890d3d FirstFitRoutingAllocator) (logid:37be6c0b) Guest
VM is requested with Custom[UEFI] Boot Type false
Sep 03 01:12:09 management1.inspur.com java[2720]: INFO
[c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-49:ctx-8efcf390
job-139/job-188 ctx-6c890d3d) (logid:37be6c0b) Re-ordering hosts [] by
priorities {}
Sep 03 01:12:09 management1.inspur.com java[2720]: INFO
[c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-49:ctx-8efcf390
job-139/job-188 ctx-6c890d3d) (logid:37be6c0b) Hosts after re-ordering are: []
Sep 03 01:12:09 management1.inspur.com java[2720]: ERROR
[c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-49:ctx-8efcf390
job-139/job-188 ctx-6c890d3d) (logid:37be6c0b) Invocation exception, caused by:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM instance
{"id":57,"instanceName":"v-57-VM","type":"ConsoleProxy","uuid":"4c981454-40b9-4d76-948d-891f6e09f766"}Scope=interface
com.cloud.dc.DataCenter; id=1
Sep 03 01:12:09 management1.inspur.com java[2720]: INFO
[c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-49:ctx-8efcf390
job-139/job-188 ctx-6c890d3d) (logid:37be6c0b) Rethrow exception
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM instance
{"id":57,"instanceName":"v-57-VM","type":"ConsoleProxy","uuid":"4c981454-40b9-4d76-948d-891f6e09f766"}Scope=interface
com.cloud.dc.DataCenter; id=1
Sep 03 01:12:09 management1.inspur.com java[2720]: ERROR
[c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-49:ctx-8efcf390 job-139/job-188)
(logid:37be6c0b) Unable to complete AsyncJobVO: {id:188, userId: 1, accountId:
1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart,
cmdInfo:
rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAAOXQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null
, initMsid: 195927833637058, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Sun Sep 03 01:12:00 CST 2023, removed: null}, job
origin:139
Sep 03 01:12:09 management1.inspur.com java[2720]:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM instance
{"id":57,"instanceName":"v-57-VM","type":"ConsoleProxy","uuid":"4c981454-40b9-4d76-948d-891f6e09f766"}Scope=interface
com.cloud.dc.DataCenter; id=1
Sep 03 01:12:09 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1166)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5351)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
jdk.internal.reflect.GeneratedMethodAccessor210.invoke(Unknown Source)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.lang.reflect.Method.invoke(Method.java:566)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5475)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.lang.Thread.run(Thread.java:829)
Sep 03 01:12:09 management1.inspur.com java[2720]: INFO
[o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-49:ctx-8efcf390
job-139/job-188) (logid:37be6c0b) Remove job-188 from job monitoring
Sep 03 01:12:09 management1.inspur.com java[2720]: WARN
[c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-2e62d742) (logid:cc558161)
Unable to start proxy [57] due to [Unable to create a deployment for VM
instance
{"id":57,"instanceName":"v-57-VM","type":"ConsoleProxy","uuid":"4c981454-40b9-4d76-948d-891f6e09f766"}].
Sep 03 01:12:09 management1.inspur.com java[2720]:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM instance
{"id":57,"instanceName":"v-57-VM","type":"ConsoleProxy","uuid":"4c981454-40b9-4d76-948d-891f6e09f766"}Scope=interface
com.cloud.dc.DataCenter; id=1
Sep 03 01:12:09 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1166)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5351)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
jdk.internal.reflect.GeneratedMethodAccessor210.invoke(Unknown Source)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.lang.reflect.Method.invoke(Method.java:566)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5475)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
Sep 03 01:12:09 management1.inspur.com java[2720]: at
java.base/java.lang.Thread.run(Thread.java:829)
Sep 03 01:12:09 management1.inspur.com java[2720]: INFO
[c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-2e62d742) (logid:cc558161)
Unable to start console proxy vm for standby capacity, vm id : 57, will recycle
it and start a new one
Sep 03 01:12:09 management1.inspur.com java[2720]: WARN
[c.c.a.AlertManagerImpl] (consoleproxy-1:ctx-2e62d742) (logid:cc558161)
alertType=[10] dataCenterId=[1] podId=[null] clusterId=[null] message=[Console
proxy creation failure. zone: Zone1, error details: null].
Sep 03 01:12:09 management1.inspur.com java[2720]: WARN
[c.c.a.AlertManagerImpl] (consoleproxy-1:ctx-2e62d742) (logid:cc558161) No
recipients set in global setting 'alert.email.addresses', skipping sending
alert with subject [Console proxy creation failure. zone: Zone1, error details:
null] and content [Console proxy creation failure (zone Zone1)].
Sep 03 01:12:09 management1.inspur.com java[2720]: INFO
[c.c.s.StatsCollector] (StatsCollector-3:ctx-4d948c2f) (logid:adcdd786) system
memory from /proc: 67235295232
Sep 03 01:12:09 management1.inspur.com java[2720]: INFO
[c.c.s.StatsCollector] (StatsCollector-3:ctx-4d948c2f) (logid:adcdd786) free
memory from /proc: 61416931328
Sep 03 01:12:09 management1.inspur.com java[2720]: INFO
[c.c.s.StatsCollector] (StatsCollector-3:ctx-4d948c2f) (logid:adcdd786) used
memory from /proc: 1615768
##### STEPS TO REPRODUCE
<!--
For bugs, show exactly how to reproduce the problem, using a minimal
test-case. Use Screenshots if accurate.
For new features, show how the feature would be used.
-->
<!-- Paste example playbooks or commands between quotes below -->
~~~
~~~
<!-- You can also paste gist.github.com links for larger files -->
##### EXPECTED RESULTS
<!-- What did you expect to happen when running the steps above? -->
~~~
~~~
##### ACTUAL RESULTS
<!-- What actually happened? -->
<!-- Paste verbatim command output between quotes below -->
~~~
~~~
--
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]
