w1a2n3o4 opened a new issue, #12235:
URL: https://github.com/apache/cloudstack/issues/12235
### 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-6320256b1
e69"}
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","provisioningTy
pe":"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":[],"fol
lowRedirects":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
1.
2.
3.
...
### What to do about it?
_No response_
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
