Can't start the virtual machine [CloudStack 4.22.1.0 | XCP-NG 8.2.1]

[w1a2n3o4]

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"}.