GitHub user w1a2n3o4 created a discussion: Can't start the virtual machine
[CloudStack 4.22.1.0 | XCP-NG 8.2.1]
Hello, everyone.
I can't start the VM. Please help me figure out the reason.
I'm getting the following errors in the CloudStack log files:
```
2026-07-27 09:26:50,229 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp253011924-2880087:[ctx-f45dc4b6, ctx-58cd3baa]) (logid:e54306c5) submit
async job-155216, details: AsyncJob
{"accountId":287,"cmd":"org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin","cmdInfo":"{\"considerlasthost\":\"false\",\"response\":\"json\",\"ctxUserId\":\"358\",\"sessionkey\":\"eCUiEdubqAJMYlxPMMw6oF-aDU4\",\"httpmethod\":\"POST\",\"ctxStartEventId\":\"2797130\",\"id\":\"d81f6675-9f75-4b28-bf89-bbee9c4c4432\",\"ctxDetails\":\"{\\\"interface
com.cloud.vm.VirtualMachine\\\":\\\"d81f6675-9f75-4b28-bf89-bbee9c4c4432\\\"}\",\"ctxAccountId\":\"287\",\"uuid\":\"d81f6675-9f75-4b28-bf89-bbee9c4c4432\",\"cmdEventType\":\"VM.START\"}","cmdVersion":0,"completeMsid":null,"created":null,"id":155216,"initMsid":108597816265214,"instanceId":8711,"instanceType":"VirtualMachine","lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":358,"uuid
":"262d47ad-5dc5-499a-9cb8-b5d29d46e27e"}
2026-07-27 09:26:50,290 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-64:[ctx-841aeb04, job-155216, ctx-17c953d4]) (logid:262d47ad)
Trying to allocate a host and storage pools ... with requested CPU [4000] and
requested RAM [(8.00 GB) 8589934592].
2026-07-27 09:26:50,335 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] ... Hosts
with tag 'cluster5' are:[Host {"id":77351,...}, Host {"id":77352,...}, Host
{"id":77353,...}, Host {"id":77354,...}, Host {"id":77355,...}, Host
{"id":77356,...}, Host {"id":77357,...}, Host {"id":77358,...}, Host
{"id":77359,...}, Host {"id":77360,...}, Host {"id":77361,...}, Host
{"id":77362,...}]
2026-07-27 09:26:50,442 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] ... Host
Allocator returning 12 suitable hosts
2026-07-27 09:26:50,546 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl]
(API-Job-Executor-64:[ctx-841aeb04, job-155216, ctx-17c953d4]) ... start
parameter value of enterHardwareSetup == <very null> during processing of
queued job
2026-07-27 09:26:50,556 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-64:[ctx-841aeb04, job-155216, ctx-17c953d4]) ... Sync
job-155217 execution on object VmWorkJobQueue.8711
2026-07-27 09:26:50,876 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5]
(Work-Job-Executor-11:[ctx-6556245f, job-155216/job-155217]) ... Executing
AsyncJob ... com.cloud.vm.VmWorkStart ...
2026-07-27 09:26:50,880 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Trying to start VM ["d81f6675-9f75-4b28-bf89-bbee9c4c4432"] using plan
[{"_dcId":7,"_podId":9,"_clusterId":14,"_hostId":77360,...}] and planner [null].
2026-07-27 09:26:50,907 DEBUG [c.c.c.CapacityManagerImpl] ... VM instance ...
state transited from [Stopped] to [Starting] with event [StartRequested].
2026-07-27 09:26:50,908 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Successfully transitioned to start state ... reservation id =
bcfb76e0-32a9-4a62-b7aa-bb228b8b0f02
2026-07-27 09:26:50,940 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Instance start attempt #1
2026-07-27 09:26:50,941 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Root volume is ready, need to place VM in volume's cluster
2026-07-27 09:26:50,961 DEBUG [c.c.d.DeploymentPlanningManagerImpl] ...
DeploymentPlan [DataCenterDeployment] has specified host [77360] without HA
flag. Choosing this host to deploy VM ...
2026-07-27 09:26:50,967 DEBUG [c.c.d.DeploymentPlanningManagerImpl] ... Volume
[Volume {"id":10031,...}] ... has pool [StoragePool {"id":71,...}] already
specified. No need to reallocate a pool for this volume.
2026-07-27 09:26:50,985 DEBUG [c.c.d.DeploymentPlanningManagerImpl] ...
Returning Deployment Destination:
Dest[Zone(7)-Pod(9)-Cluster(14)-Host(77360)-Storage()]
2026-07-27 09:26:51,000 DEBUG [c.c.c.CapacityManagerImpl] ... VM instance ...
state transited from [Starting] to [Starting] with event [OperationRetry]. VM's
original host: Host {"id":77359,...}, new host: Host {"id":77360,...}
2026-07-27 09:26:51,007 DEBUG [c.c.c.CapacityManagerImpl] ... We are allocating
VM, increasing the used capacity of this host:Host {"id":77360,...}
2026-07-27 09:26:51,012 DEBUG [c.c.c.CapacityManagerImpl] ... We need to
allocate to the last host again, so checking if there is enough reserved
capacity ... Reserved CPU: 0 , Requested CPU: 4000 ... Host does not have
enough reserved CPU available, cannot allocate to this host.
2026-07-27 09:26:51,023 DEBUG [o.a.c.e.o.NetworkOrchestrator] ... Network
Network {"id": 1814, ...} is already implemented
2026-07-27 09:26:51,039 DEBUG [o.a.c.e.o.NetworkOrchestrator] ... Changing
active number of NICs for Network ID=Network ... on 1
2026-07-27 09:26:51,047 DEBUG [o.a.c.e.o.NetworkOrchestrator] ... Asking
VpcVirtualRouter to prepare for Nic ...
2026-07-27 09:26:51,051 INFO [c.c.n.e.VpcVirtualRouterElement] ... Adding VPC
routers to Guest Network: 1 to be added!
2026-07-27 09:26:51,062 DEBUG [o.a.c.n.t.BasicNetworkTopology] ... CONFIG DHCP
FOR SUBNETS RULES
2026-07-27 09:26:51,072 DEBUG [o.a.c.n.t.BasicNetworkTopology] ... Applying
dhcp entry in network ...
2026-07-27 09:26:51,080 DEBUG [c.c.a.t.Request] ... Seq
77361-801359258695289998: Sending { Cmd , ... DhcpEntryCommand ...}
2026-07-27 09:26:51,081 DEBUG [c.c.a.r.v.VirtualRoutingResource] ...
Transforming com.cloud.agent.api.routing.DhcpEntryCommand to ConfigItems
2026-07-27 09:26:51,085 DEBUG [c.c.h.x.r.XenServer650Resource] ... Copying VR
with IP 169.254.148.58 config file into host 10.1.4.22
2026-07-27 09:26:51,736 DEBUG [c.c.a.r.v.VirtualRoutingResource] ... Processing
FileConfigItem, copying 279 characters ... took 655ms
2026-07-27 09:26:51,736 DEBUG [c.c.h.x.r.XenServer650Resource] ... Executing
command in VR: /opt/cloud/bin/router_proxy.sh update_config.py ...
2026-07-27 09:26:52,336 DEBUG [c.c.a.r.v.VirtualRoutingResource] ... Processing
ScriptConfigItem ... took 600ms
2026-07-27 09:26:52,337 DEBUG [c.c.a.t.Request] ... Seq
77361-801359258695289998: Received GroupAnswer result:"true"
2026-07-27 09:26:52,350 DEBUG [o.a.c.n.t.BasicNetworkTopology] ... Applying
userdata and password entry in network ...
2026-07-27 09:26:52,367 DEBUG [c.c.a.t.Request] ... Seq
77361-801359258695289999: Sending { Cmd , ... VmDataCommand ...}
2026-07-27 09:26:52,367 DEBUG [c.c.a.r.v.VirtualRoutingResource] ...
Transforming ... VmDataCommand to ConfigItems
2026-07-27 09:26:52,370 DEBUG [c.c.h.x.r.XenServer650Resource] ... Copying VR
with IP 169.254.148.58 config file into host 10.1.4.22
2026-07-27 09:26:52,950 DEBUG [c.c.a.r.v.VirtualRoutingResource] ... Processing
FileConfigItem, copying 722 characters ... took 583ms
2026-07-27 09:26:53,544 DEBUG [c.c.a.r.v.VirtualRoutingResource] ... Processing
ScriptConfigItem ... took 594ms
2026-07-27 09:26:53,544 DEBUG [c.c.a.t.Request] ... Seq
77361-801359258695289999: Received GroupAnswer result:"true"
2026-07-27 09:26:53,556 DEBUG [o.a.c.e.o.VolumeOrchestrator] ... No need to
recreate the volume [ROOT] ... already has assigned pool: [STR_21]. Adding disk
to the VM.
2026-07-27 09:26:53,696 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Orchestrating VM reboot for 'i-354-8711-VM' ...
2026-07-27 09:26:53,738 DEBUG [c.c.a.t.Request] ... Seq
77360-6129962042804675914: Sending StartCommand ...
2026-07-27 09:26:53,747 DEBUG [c.c.h.x.r.w.x.CitrixStartCommandWrapper] ... 1.
The VM i-354-8711-VM is in Starting state.
2026-07-27 09:26:53,757 DEBUG [c.c.h.x.r.XcpServer83Resource] ... Created
Instance 4c344de5-5499-3389-a0ef-a9486e992732 for i-354-8711-VM
2026-07-27 09:26:53,764 DEBUG [c.c.h.x.r.XcpServer83Resource] ... Setting
boottype=BIOS and bootmode=null for VM: ...
2026-07-27 09:26:53,773 WARN [c.c.h.x.r.w.x.CitrixStartCommandWrapper] ...
Catch Exception: class com.xensource.xenapi.Types$UuidInvalid due to The uuid
you supplied was invalid.
2026-07-27 09:26:53,773 WARN [c.c.h.x.r.XcpServer83Resource] ... Unable to
start i-354-8711-VM due to The uuid you supplied was invalid.
2026-07-27 09:26:53,783 DEBUG [c.c.a.t.Request] ... Seq 77360-... Received
StartAnswer result:"false","details":"Unable to start i-354-8711-VM due to "
2026-07-27 09:26:53,788 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Unable to start VM on Host {"id":77360,...} due to Unable to start
i-354-8711-VM due to com.cloud.utils.exception.ExecutionException: ...
2026-07-27 09:26:53,791 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Cleaning up resources for the vm VM instance ... in Starting state
2026-07-27 09:26:53,851 DEBUG [c.c.a.t.Request] ... Seq 77360-... Sending
StopCommand ...
2026-07-27 09:26:53,927 DEBUG [c.c.a.t.Request] ... Seq 77360-... Received
StopAnswer result:"true","details":"VM does not exist"
2026-07-27 09:26:53,946 DEBUG [o.a.c.e.o.NetworkOrchestrator] ... The nic ...
was released ...
2026-07-27 09:26:53,967 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Instance start attempt #2
2026-07-27 09:26:53,971 DEBUG [c.c.d.DeploymentPlanningManagerImpl] ... Trying
to deploy VM ... avoid list
[{"_podIds":[],"_clusterIds":[],"_hostIds":[77360]}] ...
2026-07-27 09:26:53,986 DEBUG [c.c.d.DeploymentPlanningManagerImpl] ... Cannot
deploy VM ... to host [Host {"id":77360,...}] because this host is in the avoid
set.
2026-07-27 09:26:54,024 DEBUG [c.c.c.CapacityManagerImpl] ... VM instance ...
state transited from [Starting] to [Stopped] with event [OperationFailed]. VM's
original host: Host {"id":77359,...}, new host: null, host before state
transition: Host {"id":77360,...}
2026-07-27 09:26:54,048 ERROR [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Unable to orchestrate start VM instance ... due to [Unable to create a
deployment for VM instance ... after 2 attempts ... Last known error: Unable to
start VM on Host {"id":77360,...} due to Unable to start i-354-8711-VM due to ].
2026-07-27 09:26:54,051 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] ... Complete
async job-155217, jobStatus: FAILED, result: ...
2026-07-27 09:26:54,076 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-64:[ctx-841aeb04, job-155216, ctx-17c953d4]) ... Sync
job-155218 execution on object VmWorkJobQueue.8711
2026-07-27 09:26:54,872 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5]
(Work-Job-Executor-12:[ctx-87ece019, job-155216/job-155218]) ... Executing
AsyncJob ... com.cloud.vm.VmWorkStart ...
2026-07-27 09:26:54,875 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Trying to start VM ... using plan [null] and planner [null].
2026-07-27 09:26:54,891 DEBUG [c.c.c.CapacityManagerImpl] ... VM instance ...
state transited from [Stopped] to [Starting] with event [StartRequested].
2026-07-27 09:26:54,896 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Instance start attempt #1
2026-07-27 09:26:54,897 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Root volume is ready, need to place VM in volume's cluster
2026-07-27 09:26:54,916 DEBUG [c.c.d.DeploymentPlanningManagerImpl] ... VM's
last host is Host {"id":77359,...}, trying to choose the same host ...
2026-07-27 09:26:54,929 DEBUG [c.c.d.DeploymentPlanningManagerImpl] ... Last
host [Host {"id":77359,...}] of VM ... is UP and has enough capacity.
2026-07-27 09:26:54,946 DEBUG [c.c.d.DeploymentPlanningManagerImpl] ...
Returning Deployment Destination:
Dest[Zone(7)-Pod(9)-Cluster(14)-Host(77359)-Storage()]
2026-07-27 09:26:54,957 DEBUG [c.c.c.CapacityManagerImpl] ... VM instance ...
state transited from [Starting] to [Starting] with event [OperationRetry]. VM's
original host: Host {"id":77359,...}, new host: Host {"id":77359,...}
2026-07-27 09:26:54,957 DEBUG [c.c.c.CapacityManagerImpl] ... VM starting again
on the last host it was stopped on
2026-07-27 09:26:54,969 DEBUG [c.c.c.CapacityManagerImpl] ... We need to
allocate to the last host again ... Reserved CPU: 0 , Requested CPU: 4000 ...
Host does not have enough reserved CPU available
2026-07-27 09:26:54,980 DEBUG [o.a.c.e.o.NetworkOrchestrator] ... Network
Network {"id": 1814, ...} is already implemented
2026-07-27 09:26:55,028 DEBUG [c.c.a.t.Request] ... Seq
77361-801359258695290001: Sending DhcpEntryCommand ...
2026-07-27 09:26:56,202 DEBUG [c.c.a.t.Request] ... Seq
77361-801359258695290001: Received GroupAnswer result:"true"
2026-07-27 09:26:56,223 DEBUG [c.c.a.t.Request] ... Seq
77361-801359258695290002: Sending VmDataCommand ...
2026-07-27 09:26:57,369 DEBUG [c.c.a.t.Request] ... Seq
77361-801359258695290002: Received GroupAnswer result:"true"
2026-07-27 09:26:57,378 DEBUG [o.a.c.e.o.VolumeOrchestrator] ... No need to
recreate the volume [ROOT] ... already has assigned pool: [STR_21]. Adding disk
to the VM.
2026-07-27 09:26:57,464 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Orchestrating VM reboot for 'i-354-8711-VM' ...
2026-07-27 09:26:57,501 DEBUG [c.c.a.t.Request] ... Seq
77359-9189876514626252962: Sending StartCommand ...
2026-07-27 09:26:57,511 DEBUG [c.c.h.x.r.XenServer650Resource] ... no guest OS
type, start it as HVM guest
2026-07-27 09:26:57,523 DEBUG [c.c.h.x.r.XenServer650Resource] ... Created
Instance fb1bee53-abf1-24ec-3076-5ae29642b354 for i-354-8711-VM
2026-07-27 09:26:57,537 WARN [c.c.h.x.r.w.x.CitrixStartCommandWrapper] ...
Catch Exception: class com.xensource.xenapi.Types$UuidInvalid due to The uuid
you supplied was invalid.
2026-07-27 09:26:57,537 WARN [c.c.h.x.r.XenServer650Resource] ... Unable to
start i-354-8711-VM due to The uuid you supplied was invalid.
2026-07-27 09:26:57,545 DEBUG [c.c.a.t.Request] ... Seq 77359-... Received
StartAnswer result:"false","details":"Unable to start i-354-8711-VM due to "
2026-07-27 09:26:57,550 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Unable to start VM on Host {"id":77359,...} due to Unable to start
i-354-8711-VM due to ...
2026-07-27 09:26:57,554 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Cleaning up resources ...
2026-07-27 09:26:57,569 DEBUG [c.c.a.t.Request] ... Seq 77359-... Sending
StopCommand ...
2026-07-27 09:26:57,574 DEBUG [c.c.a.t.Request] ... Seq 77359-... Received
StopAnswer result:"true","details":"VM does not exist"
2026-07-27 09:26:57,588 DEBUG [o.a.c.e.o.NetworkOrchestrator] ... The nic ...
was released ...
2026-07-27 09:26:57,604 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Instance start attempt #2
2026-07-27 09:26:57,608 DEBUG [c.c.d.DeploymentPlanningManagerImpl] ... Trying
to deploy VM ... avoid list
[{"_podIds":[],"_clusterIds":[],"_hostIds":[77359]}] ...
2026-07-27 09:26:57,625 WARN [c.c.d.DeploymentPlanningManagerImpl] ... The
last host [Host {"id":77359,...}] is in the avoid set. Skipping ...
2026-07-27 09:26:57,628 WARN [c.c.d.DeploymentPlanningManagerImpl] ... VM last
host ID: 77359 belongs to zone ID: 7 for which config -
migrate.vm.across.clusters is false ... adding all other clusters except ID: 14
from this zone to avoid list
2026-07-27 09:26:57,630 DEBUG [c.c.d.FirstFitPlanner] ... Searching resources
only under specified Cluster: Cluster {id: "14", ...}
2026-07-27 09:26:57,650 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] ...
Looking for hosts in zone [7], pod [9], cluster [14]
2026-07-27 09:26:57,679 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] ... Found
12 hosts for allocation ...
2026-07-27 09:26:57,683 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] ... Host:
Host {"id":77360,...} is in avoid set, skipping ...
2026-07-27 09:26:57,702 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] ... Host:
Host {"id":77359,...} is in avoid set, skipping ...
2026-07-27 09:26:57,710 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] ... Found
a suitable host, adding to list: Host {"id":77354,...}
2026-07-27 09:26:57,722 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] ... Found
a suitable host, adding to list: Host {"id":77358,...}
2026-07-27 09:26:57,742 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] ... Host
Allocator returning 10 suitable hosts
2026-07-27 09:26:57,774 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Deployment found - Attempt #2 - ...
Dest[Zone(7)-Pod(9)-Cluster(14)-Host(77353)-Storage()]
2026-07-27 09:27:24,474 ERROR [c.c.v.ClusteredVirtualMachineManagerImpl] ...
Unable to orchestrate start VM instance
{"id":8711,"instanceName":"i-354-8711-VM","state":"Stopped","type":"User","uuid":"d81f6675-9f75-4b28-bf89-bbee9c4c4432"}
due to [Unable to start Instance 'neliub-cluster5-backup-VM04'
(d81f6675-9f75-4b28-bf89-bbee9c4c4432): Unable to start VM on Host
{"id":77352,...} due to Unable to start i-354-8711-VM due to ].
2026-07-27 09:27:24,502 ERROR [c.c.a.ApiAsyncJobDispatcher] ... Unexpected
exception while executing ... com.cloud.utils.exception.CloudRuntimeException:
Unable to orchestrate the start of VM instance ...
2026-07-27 09:27:24,502 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] ... Complete
async job-155216, jobStatus: FAILED, resultCode: 530, errortext:"Unable to
orchestrate the start of VM instance
{"instanceName":"i-354-8711-VM","uuid":"d81f6675-9f75-4b28-bf89-bbee9c4c4432"}.
```
GitHub link: https://github.com/apache/cloudstack/discussions/13717
----
This is an automatically sent email for [email protected].
To unsubscribe, please send an email to: [email protected]
