I cannot delete Volumes from CloudStack. #12235
Description
problem
I cannot delete Volumes from CloudStack.
The virtual machines have been deleted, but the Volumes remain in Destroy status.
When I try to delete a Volume, I get the following error:
Failed to expunge the volume Volume {“id”:8174,“instanceId”:6893,‘name’:“ROOT-6893”," uuid“:”0cac74bc-7664-4ee9-aca9-43184ce317e9“,‘volumeType’:”ROOT"} in Primary data store : The uuid you supplied was invalid.
I get the following log:
2025-12-10 17:00:46,283 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (API-Job-Executor-77:[ctx-d9412154, job-124772]) (logid:599b0554) Executing AsyncJob {"accountId":335,"cmd":"org.apache.cloudstack.api.command.user.vm.DestroyVMCmd","cmdInfo":"{\"response\":\"json\",\"ctxUserId\":\"449\",\"sessionkey\":\"YkOY1BhGxW80BV4jYRVHvhZWl4M\",\"expunge\":\"true\",\"httpmethod\":\"POST\",\"ctxStartEventId\":\"2486568\",\"id\":\"92d53367-b11a-4545-81aa-ee9d45a523fa\",\"ctxDetails\":\"{\\\"interface com.cloud.vm.VirtualMachine\\\":\\\"92d53367-b11a-4545-81aa-ee9d45a523fa\\\"}\",\"ctxAccountId\":\"335\",\"uuid\":\"92d53367-b11a-4545-81aa-ee9d45a523fa\",\"cmdEventType\":\"VM.DESTROY\"}","cmdVersion":0,"completeMsid":null,"created":null,"id":124772,"initMsid":108597816265214,"instanceId":6893,"instanceType":"VirtualMachine","lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":449,"uuid":"599b0554-8206-49b0-9110-6320256b1e69"}
2025-12-10 17:00:46,289 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Access to Account [{"accountName":"IVCS-DEPESHA-TEST-RESTORE","id":335,"uuid":"5443f76a-dc36-4c8d-9134-287836c6e0b8"}] granted to Account [{"accountName":"IVCS-DEPESHA-TEST-RESTORE","id":335,"uuid":"5443f76a-dc36-4c8d-9134-287836c6e0b8"}] by DomainChecker on behalf of user IVCS-DEPESHA-TEST-RESTORE
2025-12-10 17:00:46,292 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Access to VM {"id":6893,"instanceName":"i-335-6893-VM","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} granted to Account [{"accountName":"IVCS-DEPESHA-TEST-RESTORE","id":335,"uuid":"5443f76a-dc36-4c8d-9134-287836c6e0b8"}] by DomainChecker on behalf of user IVCS-DEPESHA-TEST-RESTORE
2025-12-10 17:00:46,299 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Account [Account [{"accountName":"IVCS-DEPESHA-TEST-RESTORE","id":335,"uuid":"5443f76a-dc36-4c8d-9134-287836c6e0b8"}]] has access to resource.
2025-12-10 17:00:46,339 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Checking if [Account [{"accountName":"IVCS-DEPESHA-TEST-RESTORE","id":335,"uuid":"5443f76a-dc36-4c8d-9134-287836c6e0b8"}]] has permission for expunging VMs.
2025-12-10 17:00:46,347 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) RoleService is enabled. We will use it instead of StaticRoleBasedAPIAccessChecker.
2025-12-10 17:00:46,358 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Checking if there are any ongoing snapshots on the ROOT volumes associated with VM VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Running","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}
2025-12-10 17:00:46,359 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Found 1 no. of volumes of type ROOT for vm with VM ID VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Running","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}
2025-12-10 17:00:46,360 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Checking status of snapshots for Volume: Volume {"id":8174,"instanceId":6893,"name":"ROOT-6893","uuid":"0cac74bc-7664-4ee9-aca9-43184ce317e9","volumeType":"ROOT"}
2025-12-10 17:00:46,369 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) The count of ongoing Snapshots for VM VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Running","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} and disk type ROOT is 0
2025-12-10 17:00:46,370 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Found no ongoing snapshots on volume of type ROOT, for the vm VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Running","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}
2025-12-10 17:00:46,425 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Sync job-124788 execution on object VmWorkJobQueue.6893
2025-12-10 17:00:47,989 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788]) (logid:599b0554) Executing AsyncJob {"accountId":335,"cmd":"com.cloud.vm.VmWorkStop","cmdInfo":"rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAFPAAAAAAAAAcEAAAAAAAAa7XQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwB","cmdVersion":0,"completeMsid":null,"created":"Wed Dec 10 17:00:46 MSK 2025","id":124788,"initMsid":108597816265214,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":449,"uuid":"8db3b8a0-49cd-4edc-8951-d4b23383475e"}
2025-12-10 17:00:47,989 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788]) (logid:599b0554) Run VM work job: com.cloud.vm.VmWorkStop for VM 6893, job origin: 124772
2025-12-10 17:00:47,990 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":true,"userId":449,"accountId":335,"vmId":6893,"handlerName":"VirtualMachineManagerImpl"}
2025-12-10 17:00:48,008 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Stopping","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} state transited from [Running] to [Stopping] with event [StopRequested]. VM's original host: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}, new host: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}, host before state transition: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}
2025-12-10 17:00:48,021 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Stopping","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} is a [User], returning null for control Nic IP.
2025-12-10 17:00:48,021 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Wait time setting on com.cloud.agent.api.StopCommand is 1800 seconds
2025-12-10 17:00:48,022 DEBUG [c.c.a.m.ClusteredDirectAgentAttache] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Seq 77392-5272026313790597402: Routed from 108597816265214
2025-12-10 17:00:48,022 DEBUG [c.c.a.t.Request] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Seq 77359-5272026313790597402: Sending { Cmd , MgmtId: 108597816265214, via: 77359(xcp-sr247-u1112.aisrp.local), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","forceStop":"true","vlanToPersistenceMap":{"2010":"true"},"expungeVM":"false","volumesToDisconnect":[],"vmName":"i-335-6893-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2025-12-10 17:00:48,022 DEBUG [c.c.a.t.Request] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Seq 77359-5272026313790597402: Executing: { Cmd , MgmtId: 108597816265214, via: 77359(xcp-sr247-u1112.aisrp.local), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","forceStop":"true","vlanToPersistenceMap":{"2010":"true"},"expungeVM":"false","volumesToDisconnect":[],"vmName":"i-335-6893-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2025-12-10 17:00:50,386 DEBUG [c.c.h.x.r.w.x.CitrixStopCommandWrapper] (DirectAgent-391:[ctx-b7f71a99]) (logid:599b0554) 9. The VM i-335-6893-VM is in Stopping state
2025-12-10 17:01:09,021 DEBUG [c.c.h.x.r.w.x.CitrixStopCommandWrapper] (DirectAgent-391:[ctx-b7f71a99]) (logid:599b0554) 10. The VM i-335-6893-VM is in Stopped state
2025-12-10 17:01:09,021 DEBUG [c.c.a.m.D.Task] (DirectAgent-391:[ctx-b7f71a99]) (logid:599b0554) Seq 77392-5272026313790597402: Response Received:
2025-12-10 17:01:09,021 DEBUG [c.c.a.t.Request] (DirectAgent-391:[ctx-b7f71a99]) (logid:599b0554) Seq 77359-5272026313790597402: Processing: { Ans: , MgmtId: 108597816265214, via: 77359(xcp-sr247-u1112.aisrp.local), Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"platform":"device-model:qemu-upstream-compat;apic:true;viridian:true;timeoffset:0;pae:true;acpi:1;hpet:true;secureboot:false;nx:true","result":"true","details":"Stop VM i-335-6893-VM Succeed","wait":"0","bypassHostMaintenance":"false"}}] }
2025-12-10 17:01:09,021 DEBUG [c.c.a.t.Request] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Seq 77359-5272026313790597402: Received: { Ans: , MgmtId: 108597816265214, via: 77359(xcp-sr247-u1112.aisrp.local), Ver: v1, Flags: 10, { StopAnswer } }
2025-12-10 17:01:09,044 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Stopping","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} is stopped on the host. Proceeding to release resource held.
2025-12-10 17:01:09,060 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Service SecurityGroup is not supported in the network Network {"id": 1714, "name": "depesha-network", "uuid": "d0011524-14b3-4b0c-9ab8-898a5e40f644", "networkofferingid": 38}
2025-12-10 17:01:09,063 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) The nic Nic {"broadcastUri":"vlan:\/\/2010","deviceId":0,"iPv4Address":"10.40.40.51","id":10174,"instanceId":6893,"reservationId":"9fd2fc22-13e9-4485-a465-cd0fa7c7f7f1","uuid":"1410d500-553d-40e7-9668-c29575ae4e26"} on NicProfile {"broadcastUri":null,"deviceId":0,"iPv4Address":"10.40.40.51","id":10174,"reservationId":"9fd2fc22-13e9-4485-a465-cd0fa7c7f7f1","uuid":"1410d500-553d-40e7-9668-c29575ae4e26","vmId":6893} was released according to VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Stopping","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} by guru com.cloud.network.guru.ExternalGuestNetworkGuru@4f57a8e2, now updating record.
2025-12-10 17:01:09,064 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Changing active number of nics for network id=Network {"id": 1714, "name": "depesha-network", "uuid": "d0011524-14b3-4b0c-9ab8-898a5e40f644", "networkofferingid": 38} on -1
2025-12-10 17:01:09,072 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Asking VirtualRouter to release NicProfile {"broadcastUri":null,"deviceId":0,"iPv4Address":"10.40.40.51","id":10174,"reservationId":"9fd2fc22-13e9-4485-a465-cd0fa7c7f7f1","uuid":"1410d500-553d-40e7-9668-c29575ae4e26","vmId":6893}
2025-12-10 17:01:09,072 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Successfully released network resources for the VM VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Stopping","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} in Stopping state
2025-12-10 17:01:09,076 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Successfully released storage resources for the VM VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Stopping","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} in Stopping state
2025-12-10 17:01:09,077 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Successfully cleaned up resources for the VM VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Stopping","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} in Stopping state
2025-12-10 17:01:09,081 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Stopped","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} state transited from [Stopping] to [Stopped] with event [OperationSucceeded]. VM's original host: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}, new host: null, host before state transition: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}
2025-12-10 17:01:09,112 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Hosts's actual total CPU: 358400 and CPU after applying overprovisioning: 1433600
2025-12-10 17:01:09,113 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Hosts's actual total RAM: (480.03 GB) 515430248448 and RAM after applying overprovisioning: (960.06 GB) 1030860505088
2025-12-10 17:01:09,113 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) release cpu from host: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}, old used: 397600, reserved: 11200, actual total: 358400, total with overprovisioning: 1433600; new used: 330400,reserved:78400; movedfromreserved: false,moveToReservered: true
2025-12-10 17:01:09,113 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) release mem from host: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}, old used: (234.00 GB) 251255586816, reserved: (8.00 GB) 8589934592, total: (960.06 GB) 1030860505088; new used: (202.00 GB) 216895848448, reserved: (40.00 GB) 42949672960; movedfromreserved: false, moveToReservered: true
2025-12-10 17:01:09,162 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Service SecurityGroup is not supported in the network Network {"id": 1714, "name": "depesha-network", "uuid": "d0011524-14b3-4b0c-9ab8-898a5e40f644", "networkofferingid": 38}
2025-12-10 17:01:09,165 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Service SecurityGroup is not supported in the network Network {"id": 1714, "name": "depesha-network", "uuid": "d0011524-14b3-4b0c-9ab8-898a5e40f644", "networkofferingid": 38}
2025-12-10 17:01:09,184 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":true,"userId":449,"accountId":335,"vmId":6893,"handlerName":"VirtualMachineManagerImpl"}
2025-12-10 17:01:09,184 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Complete async job-124788, jobStatus: SUCCEEDED, resultCode: 0, result: null
2025-12-10 17:01:09,185 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Publish async job-124788 complete on message bus
2025-12-10 17:01:09,185 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Wake up jobs related to job-124788
2025-12-10 17:01:09,185 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Update db status for job-124788
2025-12-10 17:01:09,186 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788, ctx-eb41c0eb]) (logid:599b0554) Wake up jobs joined with job-124788 and disjoin all subjobs created from job- 124788
2025-12-10 17:01:09,195 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788]) (logid:599b0554) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 6893, job origin: 124772
2025-12-10 17:01:09,195 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788]) (logid:599b0554) Done executing com.cloud.vm.VmWorkStop for job-124788
2025-12-10 17:01:09,201 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-10:[ctx-63f5898e, job-124772/job-124788]) (logid:599b0554) Remove job-124788 from job monitoring
2025-12-10 17:01:09,235 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Destroying vm VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Stopped","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}, expunge flag on
2025-12-10 17:01:09,244 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Sync job-124868 execution on object VmWorkJobQueue.6893
2025-12-10 17:01:09,707 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868]) (logid:599b0554) Executing AsyncJob {"accountId":335,"cmd":"com.cloud.vm.VmWorkStop","cmdInfo":"rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAFPAAAAAAAAAcEAAAAAAAAa7XQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwB","cmdVersion":0,"completeMsid":null,"created":"Wed Dec 10 17:01:09 MSK 2025","id":124868,"initMsid":108597816265214,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":449,"uuid":"8c9d34ac-26d6-485e-9c9c-26391952c078"}
2025-12-10 17:01:09,707 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868]) (logid:599b0554) Run VM work job: com.cloud.vm.VmWorkStop for VM 6893, job origin: 124772
2025-12-10 17:01:09,708 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868, ctx-fe38760a]) (logid:599b0554) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":true,"userId":449,"accountId":335,"vmId":6893,"handlerName":"VirtualMachineManagerImpl"}
2025-12-10 17:01:09,710 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868, ctx-fe38760a]) (logid:599b0554) VM is already stopped: VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Stopped","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}
2025-12-10 17:01:09,710 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868, ctx-fe38760a]) (logid:599b0554) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":true,"userId":449,"accountId":335,"vmId":6893,"handlerName":"VirtualMachineManagerImpl"}
2025-12-10 17:01:09,710 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868, ctx-fe38760a]) (logid:599b0554) Complete async job-124868, jobStatus: SUCCEEDED, resultCode: 0, result: null
2025-12-10 17:01:09,710 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868, ctx-fe38760a]) (logid:599b0554) Publish async job-124868 complete on message bus
2025-12-10 17:01:09,711 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868, ctx-fe38760a]) (logid:599b0554) Wake up jobs related to job-124868
2025-12-10 17:01:09,711 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868, ctx-fe38760a]) (logid:599b0554) Update db status for job-124868
2025-12-10 17:01:09,713 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868, ctx-fe38760a]) (logid:599b0554) Wake up jobs joined with job-124868 and disjoin all subjobs created from job- 124868
2025-12-10 17:01:09,757 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868]) (logid:599b0554) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 6893, job origin: 124772
2025-12-10 17:01:09,757 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868]) (logid:599b0554) Done executing com.cloud.vm.VmWorkStop for job-124868
2025-12-10 17:01:09,766 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-67:[ctx-e3407351, job-124772/job-124868]) (logid:599b0554) Remove job-124868 from job monitoring
2025-12-10 17:01:09,785 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Sync job-124872 execution on object VmWorkJobQueue.6893
2025-12-10 17:01:11,676 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872]) (logid:599b0554) Executing AsyncJob {"accountId":335,"cmd":"com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots","cmdInfo":"rO0ABXNyADBjb20uY2xvdWQudm0uc25hcHNob3QuVm1Xb3JrRGVsZXRlQWxsVk1TbmFwc2hvdHOsl-VRajf8cAIAAUwABHR5cGV0ACdMY29tL2Nsb3VkL3ZtL3NuYXBzaG90L1ZNU25hcHNob3QkVHlwZTt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAABTwAAAAAAAAHBAAAAAAAAGu10ABVWTVNuYXBzaG90TWFuYWdlckltcGxw","cmdVersion":0,"completeMsid":null,"created":"Wed Dec 10 17:01:09 MSK 2025","id":124872,"initMsid":108597816265214,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":449,"uuid":"ec6cef98-2cf9-41fe-8d4e-00942bab703b"}
2025-12-10 17:01:11,676 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872]) (logid:599b0554) Run VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 6893, job origin: 124772
2025-12-10 17:01:11,677 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872, ctx-7e854d1a]) (logid:599b0554) Execute VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":449,"accountId":335,"vmId":6893,"handlerName":"VMSnapshotManagerImpl"}
2025-12-10 17:01:11,678 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872, ctx-7e854d1a]) (logid:599b0554) Done executing VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":449,"accountId":335,"vmId":6893,"handlerName":"VMSnapshotManagerImpl"}
2025-12-10 17:01:11,678 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872, ctx-7e854d1a]) (logid:599b0554) Complete async job-124872, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE
2025-12-10 17:01:11,678 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872, ctx-7e854d1a]) (logid:599b0554) Publish async job-124872 complete on message bus
2025-12-10 17:01:11,678 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872, ctx-7e854d1a]) (logid:599b0554) Wake up jobs related to job-124872
2025-12-10 17:01:11,678 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872, ctx-7e854d1a]) (logid:599b0554) Update db status for job-124872
2025-12-10 17:01:11,679 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872, ctx-7e854d1a]) (logid:599b0554) Wake up jobs joined with job-124872 and disjoin all subjobs created from job- 124872
2025-12-10 17:01:11,698 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872]) (logid:599b0554) Done with run of VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 6893, job origin: 124772
2025-12-10 17:01:11,698 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872]) (logid:599b0554) Done executing com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for job-124872
2025-12-10 17:01:11,705 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-71:[ctx-1b244e96, job-124772/job-124872]) (logid:599b0554) Remove job-124872 from job monitoring
2025-12-10 17:01:11,740 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Destroyed","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} state transited from [Stopped] to [Destroyed] with event [DestroyRequested]. VM's original host: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}, new host: null, host before state transition: null
2025-12-10 17:01:11,793 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Hosts's actual total CPU: 358400 and CPU after applying overprovisioning: 1433600
2025-12-10 17:01:11,793 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Hosts's actual total RAM: (480.03 GB) 515430248448 and RAM after applying overprovisioning: (960.06 GB) 1030860505088
2025-12-10 17:01:11,793 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) release cpu from host: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}, old used: 319200, reserved: 78400, actual total: 358400, total with overprovisioning: 1433600; new used: 319200,reserved:11200; movedfromreserved: true,moveToReservered: false
2025-12-10 17:01:11,793 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) release mem from host: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}, old used: (198.00 GB) 212600881152, reserved: (36.00 GB) 38654705664, total: (960.06 GB) 1030860505088; new used: (198.00 GB) 212600881152, reserved: (4.00 GB) 4294967296; movedfromreserved: true, moveToReservered: false
2025-12-10 17:01:11,809 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} state transited from [Destroyed] to [Expunging] with event [ExpungeOperation]. VM's original host: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}, new host: null, host before state transition: null
2025-12-10 17:01:11,824 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Updating resource Type = user_vm count for Account with id = 335 Operation = decreasing Amount = 1
2025-12-10 17:01:11,838 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Updating resource Type = cpu count for Account with id = 335 Operation = decreasing Amount = 24
2025-12-10 17:01:11,847 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Updating resource Type = memory count for Account with id = 335 Operation = decreasing Amount = 32768
2025-12-10 17:01:11,893 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Sync job-124881 execution on object VmWorkJobQueue.6893
2025-12-10 17:01:13,713 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881]) (logid:599b0554) Executing AsyncJob {"accountId":335,"cmd":"com.cloud.vm.VmWorkStop","cmdInfo":"rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAFPAAAAAAAAAcEAAAAAAAAa7XQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwB","cmdVersion":0,"completeMsid":null,"created":"Wed Dec 10 17:01:11 MSK 2025","id":124881,"initMsid":108597816265214,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":449,"uuid":"3419262f-6b3a-47cf-adb5-6f410f68396f"}
2025-12-10 17:01:13,714 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881]) (logid:599b0554) Run VM work job: com.cloud.vm.VmWorkStop for VM 6893, job origin: 124772
2025-12-10 17:01:13,717 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881, ctx-0fe24c26]) (logid:599b0554) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":true,"userId":449,"accountId":335,"vmId":6893,"handlerName":"VirtualMachineManagerImpl"}
2025-12-10 17:01:13,720 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881, ctx-0fe24c26]) (logid:599b0554) Stopped called on VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} but the state is Expunging
2025-12-10 17:01:13,720 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881, ctx-0fe24c26]) (logid:599b0554) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":true,"userId":449,"accountId":335,"vmId":6893,"handlerName":"VirtualMachineManagerImpl"}
2025-12-10 17:01:13,720 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881, ctx-0fe24c26]) (logid:599b0554) Complete async job-124881, jobStatus: SUCCEEDED, resultCode: 0, result: null
2025-12-10 17:01:13,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881, ctx-0fe24c26]) (logid:599b0554) Publish async job-124881 complete on message bus
2025-12-10 17:01:13,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881, ctx-0fe24c26]) (logid:599b0554) Wake up jobs related to job-124881
2025-12-10 17:01:13,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881, ctx-0fe24c26]) (logid:599b0554) Update db status for job-124881
2025-12-10 17:01:13,722 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881, ctx-0fe24c26]) (logid:599b0554) Wake up jobs joined with job-124881 and disjoin all subjobs created from job- 124881
2025-12-10 17:01:13,742 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881]) (logid:599b0554) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 6893, job origin: 124772
2025-12-10 17:01:13,742 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881]) (logid:599b0554) Done executing com.cloud.vm.VmWorkStop for job-124881
2025-12-10 17:01:13,748 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-79:[ctx-f0148949, job-124772/job-124881]) (logid:599b0554) Remove job-124881 from job monitoring
2025-12-10 17:01:13,768 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} state transited from [Expunging] to [Expunging] with event [ExpungeOperation]. VM's original host: Host {"id":77359,"name":"xcp-sr247-u1112.aisrp.local","type":"Routing","uuid":"8b7c7a2e-63c4-41c1-bf44-de047b763ec9"}, new host: null, host before state transition: null
2025-12-10 17:01:13,776 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Expunging vm VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}
2025-12-10 17:01:13,777 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Cleaning up NICS [] of VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}.
2025-12-10 17:01:13,777 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Cleaning network for vm: VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}
2025-12-10 17:01:13,791 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) REMOVE VPC DHCP ENTRY RULES
2025-12-10 17:01:13,792 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Applying dhcp entry in network Network {"id": 1714, "name": "depesha-network", "uuid": "d0011524-14b3-4b0c-9ab8-898a5e40f644", "networkofferingid": 38}
2025-12-10 17:01:13,803 DEBUG [c.c.u.s.Script] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Looking for vms/cloud-scripts.tgz in the classpath
2025-12-10 17:01:13,803 DEBUG [c.c.u.s.Script] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) System resource: file:/usr/share/cloudstack-common/vms/cloud-scripts.tgz
2025-12-10 17:01:13,803 DEBUG [c.c.u.s.Script] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Absolute path = /usr/share/cloudstack-common/vms/cloud-scripts.tgz
2025-12-10 17:01:13,804 DEBUG [c.c.n.r.NetworkHelperImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Router requires upgrade. Unable to send command to router: VM instance {"id":6820,"instanceName":"r-6820-VM","state":"Running","type":"DomainRouter","uuid":"48b990ee-4744-441f-8220-075613d7cf60"}, router template version: Cloudstack Release 4.19.1 Mon 08 Jul 2024 08:19:20 AM UTC, minimal required version: 4.22.0
2025-12-10 17:01:13,804 ERROR [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Failed to remove dhcp-dns entry due to: com.cloud.exception.ResourceUnavailableException: Resource [VirtualRouter:6820] is unreachable: Unable to send command. Router requires upgrade
2025-12-10 17:01:13,812 DEBUG [c.c.n.NetworkModelImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Service SecurityGroup is not supported in the network Network {"id": 1714, "name": "depesha-network", "uuid": "d0011524-14b3-4b0c-9ab8-898a5e40f644", "networkofferingid": 38}
2025-12-10 17:01:13,818 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Removed nic Nic {"broadcastUri":null,"deviceId":0,"iPv4Address":"10.40.40.51","id":10174,"instanceId":6893,"reservationId":"9fd2fc22-13e9-4485-a465-cd0fa7c7f7f1","uuid":"1410d500-553d-40e7-9668-c29575ae4e26"}
2025-12-10 17:01:13,820 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Revoving nic secondary ip entry ...
2025-12-10 17:01:13,821 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage. Data from VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}.
2025-12-10 17:01:13,830 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Cleaning storage for VM [VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}].
2025-12-10 17:01:13,857 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959, ctx-e479c7e6]) (logid:599b0554) Updating resource Type = volume count for Account with id = 335 Operation = decreasing Amount = 1
2025-12-10 17:01:13,875 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959, ctx-e479c7e6]) (logid:599b0554) Updating resource Type = primary_storage count for Account with id = 335 Operation = decreasing Amount = (1000.00 GB) 1073741824000
2025-12-10 17:01:13,935 DEBUG [c.c.h.XenServerGuru] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) We are returning the default host to execute commands because the command is not of Copy type.
2025-12-10 17:01:13,935 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Wait time setting on org.apache.cloudstack.storage.command.DeleteCommand is 1800 seconds
2025-12-10 17:01:13,936 DEBUG [c.c.a.m.ClusteredDirectAgentAttache] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Seq 77392-5547027366036914016: Routed from 108597816265214
2025-12-10 17:01:13,937 DEBUG [c.c.a.t.Request] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Seq 77360-5547027366036914016: Sending { Cmd , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"0cac74bc-7664-4ee9-aca9-43184ce317e9","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"SR2410_U10_DM7100F_21","name":"cluster5-SR2410_U10_DM7100F_21","id":"71","poolType":"PreSetup","host":"localhost","path":"/SR2410_U10_DM7100F_21","port":"0","url":"PreSetup://localhost/SR2410_U10_DM7100F_21/?ROLE=Primary&STOREUUID=SR2410_U10_DM7100F_21","isManaged":"false"}},"name":"ROOT-6893","size":"(1000.00 GB) 1073741824000","path":"893dbeb2-074a-4cee-b7f0-98516f9df125","volumeId":"8174","vmName":"i-335-6893-VM","accountId":"335","format":"VHD","provisioningType":"THIN","poolId":"71","id":"8174","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","checkpointPaths":[],"checkpointImageStoreUrls":[],"followRedirects":"true"}},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-12-10 17:01:13,937 DEBUG [c.c.a.t.Request] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Seq 77360-5547027366036914016: Executing: { Cmd , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"0cac74bc-7664-4ee9-aca9-43184ce317e9","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"SR2410_U10_DM7100F_21","name":"cluster5-SR2410_U10_DM7100F_21","id":"71","poolType":"PreSetup","host":"localhost","path":"/SR2410_U10_DM7100F_21","port":"0","url":"PreSetup://localhost/SR2410_U10_DM7100F_21/?ROLE=Primary&STOREUUID=SR2410_U10_DM7100F_21","isManaged":"false"}},"name":"ROOT-6893","size":"(1000.00 GB) 1073741824000","path":"893dbeb2-074a-4cee-b7f0-98516f9df125","volumeId":"8174","vmName":"i-335-6893-VM","accountId":"335","format":"VHD","provisioningType":"THIN","poolId":"71","id":"8174","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","checkpointPaths":[],"checkpointImageStoreUrls":[],"followRedirects":"true"}},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-12-10 17:01:13,937 DEBUG [c.c.s.r.StorageSubsystemCommandHandlerBase] (DirectAgent-500:[ctx-bbff2f26]) (logid:599b0554) Executing command DeleteCommand: [{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"0cac74bc-7664-4ee9-aca9-43184ce317e9","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"SR2410_U10_DM7100F_21","name":"cluster5-SR2410_U10_DM7100F_21","id":71,"poolType":"PreSetup","host":"localhost","path":"/SR2410_U10_DM7100F_21","port":0,"url":"PreSetup://localhost/SR2410_U10_DM7100F_21/?ROLE=Primary&STOREUUID=SR2410_U10_DM7100F_21","isManaged":false}},"name":"ROOT-6893","size":1073741824000,"path":"893dbeb2-074a-4cee-b7f0-98516f9df125","volumeId":8174,"vmName":"i-335-6893-VM","accountId":335,"format":"VHD","provisioningType":"THIN","poolId":71,"id":8174,"deviceId":0,"cacheMode":"NONE","hypervisorType":"XenServer","directDownload":false,"deployAsIs":false,"checkpointPaths":[],"checkpointImageStoreUrls":[],"followRedirects":true}},"wait":0,"bypassHostMaintenance":false}].
2025-12-10 17:02:44,019 DEBUG [c.c.h.x.r.XenServerConnectionPool] (DirectAgent-500:[ctx-bbff2f26]) (logid:599b0554) XmlRpcException for method: VDI.destroy due to org.apache.xmlrpc.XmlRpcException: Failed to create input stream: Read timed out
2025-12-10 17:02:44,019 DEBUG [c.c.h.x.r.Xenserver625StorageProcessor] (DirectAgent-500:[ctx-bbff2f26]) (logid:599b0554) Failed to delete volume org.apache.xmlrpc.XmlRpcException: Failed to create input stream: Read timed out
2025-12-10 17:02:44,019 DEBUG [c.c.a.m.D.Task] (DirectAgent-500:[ctx-bbff2f26]) (logid:599b0554) Seq 77392-5547027366036914016: Response Received:
2025-12-10 17:02:44,019 DEBUG [c.c.a.t.Request] (DirectAgent-500:[ctx-bbff2f26]) (logid:599b0554) Seq 77360-5547027366036914016: Processing: { Ans: , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":"false","details":"org.apache.xmlrpc.XmlRpcException: Failed to create input stream: Read timed out","wait":"0","bypassHostMaintenance":"false"}}] }
2025-12-10 17:02:44,019 DEBUG [c.c.a.t.Request] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Seq 77360-5547027366036914016: Received: { Ans: , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 10, { Answer } }
2025-12-10 17:02:44,030 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Wait time setting on com.cloud.agent.api.CleanupVMCommand is 1800 seconds
2025-12-10 17:02:44,031 DEBUG [c.c.a.m.ClusteredDirectAgentAttache] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Seq 77392-5272026313790597423: Routed from 108597816265214
2025-12-10 17:02:44,031 DEBUG [c.c.a.t.Request] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Seq 77359-5272026313790597423: Waiting for Seq 5272026313790597422 Scheduling: { Cmd , MgmtId: 108597816265214, via: 77359(xcp-sr247-u1112.aisrp.local), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.CleanupVMCommand":{"vmName":"i-335-6893-VM","executeInSequence":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2025-12-10 17:02:44,076 DEBUG [c.c.a.m.D.Task] (DirectAgent-67:[ctx-7317093d]) (logid:599b0554) Seq 77392-5272026313790597423: Response Received:
2025-12-10 17:02:44,076 DEBUG [c.c.a.t.Request] (DirectAgent-67:[ctx-7317093d]) (logid:599b0554) Seq 77359-5272026313790597423: Processing: { Ans: , MgmtId: 108597816265214, via: 77359(xcp-sr247-u1112.aisrp.local), Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2025-12-10 17:02:44,076 DEBUG [c.c.a.m.ClusteredDirectAgentAttache] (DirectAgent-67:[ctx-7317093d]) (logid:599b0554) Seq 77392-5272026313790597424: Sending now. is current sequence.
2025-12-10 17:02:44,076 DEBUG [c.c.a.t.Request] (DirectAgent-67:[ctx-7317093d]) (logid:599b0554) Seq 77359-5272026313790597424: Executing: { Cmd , MgmtId: 108597816265214, via: 77359(xcp-sr247-u1112.aisrp.local), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.CleanupVMCommand":{"vmName":"i-335-6829-VM","executeInSequence":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2025-12-10 17:02:44,076 DEBUG [c.c.a.t.Request] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Seq 77359-5272026313790597423: Received: { Ans: , MgmtId: 108597816265214, via: 77359(xcp-sr247-u1112.aisrp.local), Ver: v1, Flags: 110, { Answer } }
2025-12-10 17:02:44,076 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Expunged VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}
2025-12-10 17:02:44,077 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Starting cleaning up vm VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} resources...
2025-12-10 17:02:44,091 DEBUG [c.c.n.f.FirewallManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) No firewall rules are found for vm: VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}
2025-12-10 17:02:44,100 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Firewall rules are removed successfully as a part of vm VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} expunge
2025-12-10 17:02:44,103 DEBUG [c.c.n.r.RulesManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) No port forwarding rules are found for vm VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"}
2025-12-10 17:02:44,104 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Port forwarding rules are removed successfully as a part of vm VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} expunge
2025-12-10 17:02:44,104 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Removed vm VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} from all load balancers as a part of expunge process
2025-12-10 17:02:44,105 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Successfully cleaned up vm VM instance {"id":6893,"instanceName":"i-335-6893-VM","state":"Expunging","type":"User","uuid":"92d53367-b11a-4545-81aa-ee9d45a523fa"} resources as a part of expunge process
2025-12-10 17:02:44,133 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Complete async job-124772, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.UserVmResponse/virtualmachine/{"securitygroup":[],"nic":[],"affinitygroup":[],"deleteprotection":"false","tags":[]}
2025-12-10 17:02:44,133 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Publish async job-124772 complete on message bus
2025-12-10 17:02:44,133 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Wake up jobs related to job-124772
2025-12-10 17:02:44,133 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Update db status for job-124772
2025-12-10 17:02:44,134 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Wake up jobs joined with job-124772 and disjoin all subjobs created from job- 124772
2025-12-10 17:02:44,139 DEBUG [c.c.a.ApiServer] (API-Job-Executor-77:[ctx-d9412154, job-124772, ctx-2f5d6959]) (logid:599b0554) Retrieved cmdEventType from job info: VM.DESTROY
2025-12-10 17:02:44,142 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (API-Job-Executor-77:[ctx-d9412154, job-124772]) (logid:599b0554) Done executing org.apache.cloudstack.api.command.user.vm.DestroyVMCmd for job-124772
2025-12-10 17:02:44,142 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-77:[ctx-d9412154, job-124772]) (logid:599b0554) Remove job-124772 from job monitoring
Please advise how I can correctly delete the volume.
versions
CloudStack version: 4.22.0.0
XCP-ng 8.21
The steps to reproduce the bug
...
What to do about it?
No response