nvazquez commented on issue #11764:
URL: https://github.com/apache/cloudstack/issues/11764#issuecomment-3354010903
Hi @weizhouapache for 4.21:
````
2025-09-30 12:03:04,171 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Trying to find suitable pools to allocate volume [Volume
{"id":3,"instanceId":3,"na
me":"ROOT-3","uuid":"d702b70c-26c9-47e1-b809-331aa95293c6","volumeType":"ROOT"}]
necessary to deploy VM [VM instance
{"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}],
us
ing StoragePoolAllocator: [LocalStoragePoolAllocator].
2025-09-30 12:03:04,171 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) LocalStoragePoolAllocator is returning null since the disk
profile does not use loc
al storage and bypassStorageTypeCheck is false.
2025-09-30 12:03:04,171 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Trying to find suitable pools to allocate volume [Volume
{"id":3,"instanceId":3,"na
me":"ROOT-3","uuid":"d702b70c-26c9-47e1-b809-331aa95293c6","volumeType":"ROOT"}]
necessary to deploy VM [VM instance
{"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}],
us
ing StoragePoolAllocator: [ClusterScopeStoragePoolAllocator].
2025-09-30 12:03:04,172 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Looking for pools in dc [1], pod [1] and cluster [1]. Disabled
pools will be
ignored.
2025-09-30 12:03:04,177 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Found pools [[StoragePool
{"id":1,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez
-kvm-pri1","poolType":"NetworkFilesystem","uuid":"e18412c1-7ca8-391e-a36c-bd2f1e17e0f9"}]]
that match with tags [[]].
2025-09-30 12:03:04,177 DEBUG [c.c.a.ApiServlet]
(qtp253011924-23:[ctx-33c4b4a5]) (logid:97086b9c) ===START=== 10.0.3.251 --
GET
jobId=b6c287d1-b670-444c-89b7-c739dbfe0ee5&command=queryAsyncJobResult&response=json&
2025-09-30 12:03:04,177 DEBUG [c.c.a.ApiServlet]
(qtp253011924-23:[ctx-33c4b4a5]) (logid:97086b9c) Two factor authentication is
already verified for the user 2, so skipping
2025-09-30 12:03:04,179 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Checking if storage pool [StoragePool
{"id":1,"name":"ref-trl-9583-k-Mr8-nic
olas-vazquez-kvm-pri1","poolType":"NetworkFilesystem","uuid":"e18412c1-7ca8-391e-a36c-bd2f1e17e0f9"}]
is suitable to disk [DskChr[ROOT|8589934592|]].
2025-09-30 12:03:04,179 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) StoragePool [StoragePool
{"id":1,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez-
kvm-pri1","poolType":"NetworkFilesystem","uuid":"e18412c1-7ca8-391e-a36c-bd2f1e17e0f9"}]
is in avoid set, skipping this pool to allocation of disk
[DskChr[ROOT|8589934592|]].
2025-09-30 12:03:04,179 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Adding storage pool [StoragePool
{"id":1,"name":"ref-trl-9583-k-Mr8-nicolas-
vazquez-kvm-pri1","poolType":"NetworkFilesystem","uuid":"e18412c1-7ca8-391e-a36c-bd2f1e17e0f9"}]
to avoid set during allocation of disk [DskChr[ROOT|8589934592|]].
2025-09-30 12:03:04,179 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) ClusterScopeStoragePoolAllocator is returning [0] suitable
storage pools [[]
].
2025-09-30 12:03:04,180 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Using volume allocation algorithm random to reorder pools.
2025-09-30 12:03:04,180 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Trying to find suitable pools to allocate volume [Volume
{"id":3,"instanceId":3,"na
me":"ROOT-3","uuid":"d702b70c-26c9-47e1-b809-331aa95293c6","volumeType":"ROOT"}]
necessary to deploy VM [VM instance
{"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}],
us
ing StoragePoolAllocator: [ZoneWideStoragePoolAllocator].
2025-09-30 12:03:04,183 DEBUG [c.c.a.ApiServer]
(qtp253011924-23:[ctx-33c4b4a5, ctx-7f911202]) (logid:97086b9c) CIDRs from
which account 'Account
[{"accountName":"admin","id":2,"uuid":"2d5b7d34-9df0-11f0-8b37-1e004c0003f2"}]'
is allowe
d to perform API calls: 0.0.0.0/0,::/0
2025-09-30 12:03:04,184 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Could not find any zone wide storage pool that matched with
any of the following
tags [[]].
2025-09-30 12:03:04,184 INFO [o.a.c.a.DynamicRoleBasedAPIAccessChecker]
(qtp253011924-23:[ctx-33c4b4a5, ctx-7f911202]) (logid:97086b9c) Account for
user id 2d5c2b80-9df0-11f0-8b37-1e004c0003f2 is Root Admin or Domain Admin, all
APIs a
re allowed.
2025-09-30 12:03:04,185 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker]
(qtp253011924-23:[ctx-33c4b4a5, ctx-7f911202]) (logid:97086b9c) RoleService is
enabled. We will use it instead of StaticRoleBasedAPIAccessChecker.
2025-09-30 12:03:04,185 DEBUG [o.a.c.r.ApiRateLimitServiceImpl]
(qtp253011924-23:[ctx-33c4b4a5, ctx-7f911202]) (logid:97086b9c) API rate
limiting is disabled. We will not use ApiRateLimitService.
2025-09-30 12:03:04,185 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) ZoneWideStoragePoolAllocator is returning [0] suitable storage
pools [[]].
2025-09-30 12:03:04,185 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Using volume allocation algorithm random to reorder pools.
2025-09-30 12:03:04,185 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) No suitable pools found for volume [Volume
{"id":3,"instanceId":3,"name":"ROOT-3","uuid":"d702b70c-26c9-47e1-b809-331aa95293c6","volumeType":"ROOT"}]
used by VM [VM instance
{"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}]
under cluster: [1].
2025-09-30 12:03:04,186 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) No suitable pools found
2025-09-30 12:03:04,186 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) No suitable storagePools found under this Cluster: Cluster
{id: "1", name: "p1-c1", uuid: "5eaa27b1-3e55-409f-ae27-36eadfc056d5"}
2025-09-30 12:03:04,189 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Could not find suitable Deployment Destination for this VM
under any clusters, returning.
2025-09-30 12:03:04,189 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Searching resources only under specified Pod: HostPod
{"id":1,"name":"Pod1","uuid":"34a2069d-5a73-4f2a-9911-ba8bf0f5e8b9"}
2025-09-30 12:03:04,190 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Listing clusters in order of aggregate capacity, that have (at
least one host with) enough CPU and RAM capacity under this Pod: 1
2025-09-30 12:03:04,192 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) CapacityType: CPU is used for Cluster ordering
2025-09-30 12:03:04,193 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Removing from the clusterId list these clusters from avoid
set: [1]
2025-09-30 12:03:04,193 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) No clusters found after removing disabled clusters and
clusters in avoid list, returning.
2025-09-30 12:03:04,198 DEBUG [c.c.a.ApiServlet]
(qtp253011924-23:[ctx-33c4b4a5, ctx-7f911202]) (logid:97086b9c) ===END===
10.0.3.251 -- GET
jobId=b6c287d1-b670-444c-89b7-c739dbfe0ee5&command=queryAsyncJobResult&response=json&
2025-09-30 12:03:04,207 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) VM instance
{"id":3,"instanceName":"i-2-3-VM","state":"Stopped","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}
state transited from [Starting] to [Stopped] with event [OperationFailed].
VM's original host: Host
{"id":2,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez-kvm2","type":"Routing","uuid":"98a1e36c-bb70-465d-a171-344fcda28a14"},
new host: null, host before state transition: Host
{"id":2,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez-kvm2","type":"Routing","uuid":"98a1e36c-bb70-465d-a171-344fcda28a14"}
2025-09-30 12:03:04,213 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Hosts's actual total CPU: 6300 and CPU after applying
overprovisioning: 12600
2025-09-30 12:03:04,213 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Hosts's actual total RAM: (6.59 GB) 7072067584 and RAM after
applying overprovisioning: (6.59 GB) 7072067584
2025-09-30 12:03:04,213 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) release cpu from host: Host
{"id":2,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez-kvm2","type":"Routing","uuid":"98a1e36c-bb70-465d-a171-344fcda28a14"},
old used: 2000, reserved: 0, actual total: 6300, total with overprovisioning:
12600; new used: 1500,reserved:0; movedfromreserved: false,moveToReservered:
false
2025-09-30 12:03:04,213 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) release mem from host: Host
{"id":2,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez-kvm2","type":"Routing","uuid":"98a1e36c-bb70-465d-a171-344fcda28a14"},
old used: (2.50 GB) 2684354560, reserved: (0 bytes) 0, total: (6.59 GB)
7072067584; new used: (2.00 GB) 2147483648, reserved: (0 bytes) 0;
movedfromreserved: false, moveToReservered: false
2025-09-30 12:03:04,225 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Invocation exception, caused by:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM instance
{"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}Scope=interface
com.cloud.dc.DataCenter; id=1
2025-09-30 12:03:04,225 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39])
(logid:849acb31) Rethrow exception
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM instance
{"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}Scope=interface
com.cloud.dc.DataCenter; id=1
2025-09-30 12:03:04,225 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50]) (logid:849acb31) Done with
run of VM work job: com.cloud.vm.VmWorkStart for VM 3, job origin: 49
2025-09-30 12:03:04,225 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-11:[ctx-9124964b, job-49/job-50]) (logid:849acb31) Unable to
complete AsyncJob
{"accountId":2,"cmd":"com.cloud.vm.VmWorkStart","cmdInfo":"rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAA3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA","cmdVersion":0,"completeMsid":null,"created":"Tue
Sep 30 11:57:59 UTC
2025","id":50,"initMsid":32986623902706,"instanceId":null,"instanceType":null,"lastPolled":nu
ll,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"ae190a75-a4bf-4e73-9ae0-866a8360b080"},
job origin: 49 com.cloud.exception.InsufficientServerCapacityException: Unable
to create a deployment for VM instance
{"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}Scope=interface
com.cloud.dc.DataCenter; id=1
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1451)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5827)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5951)
at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:689)
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:637)
at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
````
--
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]
