Dedicated Cluster - No destination found for a deployment for VM instance

[wverleger]

Hi,

I was wondering how to troubleshoot the following scenario:

ACS 4.19.2.0
Linstor primary storage
NFS secondary storage
2 cluster à 3 hosts
On the primary storage os template and systemvm template is available.

1 cluster with host tags: "benchmark" dedicated to specific domain

1 compute offering with host tags: "benchmark" (without storage tag)

On instance creation:

MGMT logs:

2025-05-22 17:24:24,452 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Adding pods to avoid lists for non-explicit VM deployment: []
2025-05-22 17:24:24,453 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Adding clusters to avoid lists for non-explicit VM deployment: [2]
2025-05-22 17:24:24,453 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Adding hosts to avoid lists for non-explicit VM deployment: []
2025-05-22 17:24:24,453 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) DeploymentPlanner allocation algorithm: null
2025-05-22 17:24:24,453 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 8000, requested ram: (8.00 GB) 8589934592
2025-05-22 17:24:24,453 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Is ROOT volume READY (pool already allocated)?: No
2025-05-22 17:24:24,470 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Deploy avoids pods: [], clusters: [2], hosts: []
2025-05-22 17:24:24,470 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Deploy hosts with priorities {} , hosts have NORMAL priority by default
2025-05-22 17:24:24,473 DEBUG [c.c.d.FirstFitPlanner] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Searching all possible resources under this Zone: 1
2025-05-22 17:24:24,477 DEBUG [c.c.d.FirstFitPlanner] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Listing clusters in order of aggregate capacity, that have (at least one host with) enough CPU and RAM capacity under this Zone: 1
2025-05-22 17:24:24,488 DEBUG [c.c.d.FirstFitPlanner] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Removing from the clusterId list these clusters from avoid set: [2]
2025-05-22 17:24:24,515 DEBUG [c.c.d.FirstFitPlanner] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) The clusterId list for the given offering tag: []
2025-05-22 17:24:24,515 DEBUG [c.c.d.FirstFitPlanner] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2025-05-22 17:24:24,524 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Destroying vm VM instance {"id":276,"instanceName":"i-4-276-VM","type":"User","uuid":"dbc37987-8dcf-4d07-af77-f407bcfb44ab"} as it failed to create on Host with Id:null
2025-05-22 17:24:24,546 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) VM instance {"id":276,"instanceName":"i-4-276-VM","type":"User","uuid":"dbc37987-8dcf-4d07-af77-f407bcfb44ab"} state transited from [Stopped] to [Error] with event [OperationFailedToError]. VM's original host: null, new host: null, host before state transition: null
2025-05-22 17:24:24,571 DEBUG [c.c.s.d.VolumeDaoImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Removing volume 239 from DB
2025-05-22 17:24:24,581 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) (logid:) SeqA 14-161999: Processing Seq 14-161999:  { Cmd , MgmtId: -1, via: 14, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"203","_loadInfo":"{
  "connections": [],
  "removedSessions": []
}","wait":"0","bypassHostMaintenance":"false"}}] }
2025-05-22 17:24:24,591 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) (logid:) SeqA 14-161999: Sending Seq 14-161999:  { Ans: , MgmtId: 206863100042711, via: 14, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2025-05-22 17:24:24,594 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Updating resource Type = volume count for Account = 4 Operation = decreasing Amount = 1
2025-05-22 17:24:24,612 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Updating resource Type = primary_storage count for Account = 4 Operation = decreasing Amount = (10.00 GB) 10737418240
2025-05-22 17:24:24,620 DEBUG [c.c.a.ApiServlet] (qtp364604394-343:ctx-d7319955) (logid:c2a20715) ===START===  10.0.2.6 -- GET  resourceids=baf9986a-bc94-4946-9b83-803476b9c02a&resourcetype=template&command=listResourceIcon&response=json&sessionkey=JkVAsy4QNQ80rJB0GLaoOhCxjls
2025-05-22 17:24:24,621 DEBUG [c.c.a.ApiServlet] (qtp364604394-343:ctx-d7319955) (logid:c2a20715) Two factor authentication is already verified for the user 5, so skipping
2025-05-22 17:24:24,622 DEBUG [c.c.a.ApiServlet] (qtp364604394-568:ctx-b11902ac) (logid:db83492a) ===START===  10.0.2.6 -- GET  listall=true&details=group,nics,secgrp,tmpl,servoff,diskoff,iso,volume,affgrp,backoff&isvnf=false&page=1&pagesize=20&showIcon=true&command=listVirtualMachines&response=json&sessionkey=JkVAsy4QNQ80rJB0GLaoOhCxjls
2025-05-22 17:24:24,622 DEBUG [c.c.a.ApiServlet] (qtp364604394-568:ctx-b11902ac) (logid:db83492a) Two factor authentication is already verified for the user 5, so skipping
2025-05-22 17:24:24,643 DEBUG [c.c.a.ApiServer] (qtp364604394-343:ctx-d7319955 ctx-65086e12) (logid:c2a20715) CIDRs from which account 'Account [{"accountName":"benchmark","id":4,"uuid":"17cbae37-de20-455b-91ee-9ffd098c9a26"}]' is allowed to perform API calls: 0.0.0.0/0,::/0
2025-05-22 17:24:24,644 DEBUG [c.c.a.ApiServer] (qtp364604394-568:ctx-b11902ac ctx-3a996edc) (logid:db83492a) CIDRs from which account 'Account [{"accountName":"benchmark","id":4,"uuid":"17cbae37-de20-455b-91ee-9ffd098c9a26"}]' is allowed to perform API calls: 0.0.0.0/0,::/0
2025-05-22 17:24:24,647 WARN  [c.c.a.AlertManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) alertType=[8] dataCenterId=[1] podId=[null] clusterId=[null] message=[Failed to deploy Vm with Id: 276, on Host with Id: null].
2025-05-22 17:24:24,660 WARN  [c.c.a.AlertManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Failed to deploy Vm with Id: 276, on Host with Id: null] and content [Failed to deploy Vm with Id: 276, on Host with Id: null].
2025-05-22 17:24:24,662 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker] (qtp364604394-343:ctx-d7319955 ctx-65086e12) (logid:c2a20715) RoleService is enabled. We will use it instead of StaticRoleBasedAPIAccessChecker.
2025-05-22 17:24:24,663 DEBUG [o.a.c.r.ApiRateLimitServiceImpl] (qtp364604394-343:ctx-d7319955 ctx-65086e12) (logid:c2a20715) API rate limiting is disabled. We will not use ApiRateLimitService.
2025-05-22 17:24:24,663 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker] (qtp364604394-568:ctx-b11902ac ctx-3a996edc) (logid:db83492a) RoleService is enabled. We will use it instead of StaticRoleBasedAPIAccessChecker.
2025-05-22 17:24:24,665 DEBUG [o.a.c.r.ApiRateLimitServiceImpl] (qtp364604394-568:ctx-b11902ac ctx-3a996edc) (logid:db83492a) API rate limiting is disabled. We will not use ApiRateLimitService.
2025-05-22 17:24:24,666 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Updating resource Type = user_vm count for Account = 4 Operation = decreasing Amount = 1
2025-05-22 17:24:24,666 DEBUG [c.c.a.ApiServlet] (qtp364604394-343:ctx-d7319955 ctx-65086e12) (logid:c2a20715) ===END===  10.0.2.6 -- GET  resourceids=baf9986a-bc94-4946-9b83-803476b9c02a&resourcetype=template&command=listResourceIcon&response=json&sessionkey=JkVAsy4QNQ80rJB0GLaoOhCxjls
2025-05-22 17:24:24,667 DEBUG [o.a.c.a.BaseCmd] (qtp364604394-568:ctx-b11902ac ctx-3a996edc) (logid:db83492a) Ignoring parameter displayvm as the caller is not authorized to pass it in
2025-05-22 17:24:24,668 DEBUG [o.a.c.a.BaseCmd] (qtp364604394-568:ctx-b11902ac ctx-3a996edc) (logid:db83492a) Ignoring parameter displayvm as the caller is not authorized to pass it in
2025-05-22 17:24:24,684 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Updating resource Type = cpu count for Account = 4 Operation = decreasing Amount = 4
2025-05-22 17:24:24,703 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) Updating resource Type = memory count for Account = 4 Operation = decreasing Amount = 8192
2025-05-22 17:24:24,719 DEBUG [c.c.a.ApiServlet] (qtp364604394-568:ctx-b11902ac ctx-3a996edc) (logid:db83492a) ===END===  10.0.2.6 -- GET  listall=true&details=group,nics,secgrp,tmpl,servoff,diskoff,iso,volume,affgrp,backoff&isvnf=false&page=1&pagesize=20&showIcon=true&command=listVirtualMachines&response=json&sessionkey=JkVAsy4QNQ80rJB0GLaoOhCxjls
2025-05-22 17:24:24,732 DEBUG [c.c.a.ApiServlet] (qtp364604394-14:ctx-6103f450) (logid:fe405d52) ===START===  10.0.2.6 -- GET  resourceids=db2b752c-8e7c-466a-9254-7a64426830de&resourcetype=zone&command=listResourceIcon&response=json&sessionkey=JkVAsy4QNQ80rJB0GLaoOhCxjls
2025-05-22 17:24:24,732 DEBUG [c.c.a.ApiServlet] (qtp364604394-14:ctx-6103f450) (logid:fe405d52) Two factor authentication is already verified for the user 5, so skipping
2025-05-22 17:24:24,738 INFO  [o.a.c.a.c.u.v.DeployVMCmd] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) No destination found for a deployment for VM instance {"id":276,"instanceName":"i-4-276-VM","type":"User","uuid":"dbc37987-8dcf-4d07-af77-f407bcfb44ab"}: No destination found for a deployment for VM instance {"id":276,"instanceName":"i-4-276-VM","type":"User","uuid":"dbc37987-8dcf-4d07-af77-f407bcfb44ab"}
2025-05-22 17:24:24,738 DEBUG [o.a.c.a.c.u.v.DeployVMCmd] (API-Job-Executor-24:ctx-4b9b5a87 job-1142 ctx-dbd7aa33) (logid:353a8273) No destination found for a deployment for VM instance {"id":276,"instanceName":"i-4-276-VM","type":"User","uuid":"dbc37987-8dcf-4d07-af77-f407bcfb44ab"}
com.cloud.exception.InsufficientServerCapacityException: No destination found for a deployment for VM instance {"id":276,"instanceName":"i-4-276-VM","type":"User","uuid":"dbc37987-8dcf-4d07-af77-f407bcfb44ab"}Scope=interface com.cloud.dc.DataCenter; id=1
        at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:228)
        at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:202)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:5454)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:5308)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4920)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4909)
        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:52)
        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.$Proxy186.startVirtualMachine(Unknown Source)
        at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:782)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:172)
        at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:112)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:654)
        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:602)
        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:829)

Adding clusters to avoid lists for non-explicit VM deployment: [2]

How can I check why the cluster is in avoid list / state?

Thank you!

[winterhazel]

How can I check why the cluster is in avoid list / state?

The reason will usually be included in the deployment process' logs.

In the logs, lines will contain a (logid:<something>) to identify a process, e.g.: (logid:353a8273) No clusters found after removing disabled clusters and clusters in avoid list, returning.. Could you try deploying a VM one more time, copying the logid:<something>, executing a grep 'logid:<something>' /var/log/cloudstack/management/management-server.log and sharing the full output?

[DaanHoogland]

@wverleger any updates?