CKS Firewall bug if port start is "ALL"

[baltazorbest]

problem

After creating a k8s cluster and adding an IP address with empty start and end ports, I’m unable to delete the cluster; I get the following error:

2025-09-29 16:58:45,581 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-24:[ctx-6070df23, job-6277]) (logid:7e48a51e) Unexpected exception while executing org.apache.cloudstack.api.command.user.kubernetes.cluster.DeleteKubernetesClusterCmd java.lang.NullPointerException: Cannot invoke "java.lang.Integer.intValue()" because the return value of "com.cloud.network.rules.FirewallRuleVO.getSourcePortStart()" is null
at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterResourceModifierActionWorker.removeSshFirewallRule(KubernetesClusterResourceModifierActionWorker.java:518)
at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterDestroyWorker.deleteKubernetesClusterIsolatedNetworkRules(KubernetesClusterDestroyWorker.java:160)
at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterDestroyWorker.deleteKubernetesClusterNetworkRules(KubernetesClusterDestroyWorker.java:197)
at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterDestroyWorker.checkForRulesToDelete(KubernetesClusterDestroyWorker.java:227)
at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterDestroyWorker.destroy(KubernetesClusterDestroyWorker.java:299)
at com.cloud.kubernetes.cluster.KubernetesClusterManagerImpl.destroyKubernetesCluster(KubernetesClusterManagerImpl.java:1923)
at com.cloud.kubernetes.cluster.KubernetesClusterManagerImpl.destroyKubernetesCluster(KubernetesClusterManagerImpl.java:1931)
at com.cloud.kubernetes.cluster.KubernetesClusterManagerImpl.deleteKubernetesCluster(KubernetesClusterManagerImpl.java:1598)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:105)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:52)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
at jdk.proxy3/jdk.proxy3.$Proxy517.deleteKubernetesCluster(Unknown Source)
at org.apache.cloudstack.api.command.user.kubernetes.cluster.DeleteKubernetesClusterCmd.execute(DeleteKubernetesClusterCmd.java:95)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:173)
at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:110)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

versions

CloudStack version is 4.20.1

The steps to reproduce the bug

1. Create a k8s cluster with an isolated network (IP subnet e.g. 192.168.1.0/24).
2. In the Firewall tab, remove all rules.
3. Add the following rules:

• 192.168.1.0/24, port start: 6443, port end: 6443
• 1.1.1.1/32, port start: (leave blank), port end: (leave blank)

4. Stop the k8s cluster.
5. Attempt to delete the k8s cluster → deletion fails.

Workaround that succeeds
Replace the second rule with:

1.1.1.1/32, port start: 1024, port end: 65534

What to do about it?

I would like to have the ability to create rules with blank fields.

[boring-cyborg]

Thanks for opening your first issue here! Be sure to follow the issue template!

[kiranchavala]

@baltazorbest

Did you remove the firewall rules on the source nat IP of the network and then try to delete the cks cluster ?

Also, could you mention the k8s version and the hypervisor you are using

Not able to reproduce the issue

Steps that I followed

1. Create a cks cluster in isolated network > cluster in running state

2. On the isolated network > source nat IP > delete the firewall for port 6443 and 2223

3. Add the firewall rules

3. Delete the cluster > cluster deleted successfully

[baltazorbest]

My env:
OS on management and hypervisor hosts: ubuntu 22.04
Libvirt version: 8.0.0-1ubuntu7.12
Storage: Ceph 19.2.3 RBD
K8S version: setup-v1.33.1-calico-x86_64.iso and setup-v1.31.1-calico-x86_64.iso

[baltazorbest]

I performed additional tests, and as I observed, the error occurs when I use a previously created network. If the “Network” field is left empty, everything works fine.

[kiranchavala]

@baltazorbest able to reproduce the issue

cc @weizhouapache

Logs

root@ref-trl-9522-k-Mol8-kiran-chavala-mgmt1 ~]# cat  /var/log/cloudstack/management/management-server.log |grep -i "logid:46b21a65"
2025-09-30 11:36:02,703 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (API-Job-Executor-7:[ctx-0806c5c6, job-700]) (logid:46b21a65) Executing AsyncJob {"accountId":2,"cmd":"org.apache.cloudstack.api.command.user.kubernetes.cluster.DeleteKubernetesClusterCmd","cmdInfo":"{\"response\":\"json\",\"ctxUserId\":\"2\",\"sessionkey\":\"GKJDBq74Zw6CDLqspk0tfiT6QRM\",\"httpmethod\":\"POST\",\"ctxStartEventId\":\"1540\",\"id\":\"746208c1-2b84-426d-92f4-f55bbc1e1ee6\",\"ctxDetails\":\"{\\\"interface com.cloud.kubernetes.cluster.KubernetesCluster\\\":\\\"746208c1-2b84-426d-92f4-f55bbc1e1ee6\\\"}\",\"ctxAccountId\":\"2\",\"uuid\":\"746208c1-2b84-426d-92f4-f55bbc1e1ee6\",\"cmdEventType\":\"KUBERNETES.CLUSTER.DELETE\"}","cmdVersion":0,"completeMsid":null,"created":null,"id":700,"initMsid":32987882193172,"instanceId":5,"instanceType":"KubernetesCluster","lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"46b21a65-0d60-4cd1-bfe0-e60ac8cd007c"}
2025-09-30 11:36:02,724 INFO  [c.c.k.c.a.KubernetesClusterDestroyWorker] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Destroying Kubernetes cluster : KubernetesCluster {"id":5,"name":"cks-exist-net","uuid":"746208c1-2b84-426d-92f4-f55bbc1e1ee6"}
2025-09-30 11:36:02,748 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Destroying vm VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Running","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"}, expunge flag on
2025-09-30 11:36:02,756 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Sync job-701 execution on object VmWorkJobQueue.51
2025-09-30 11:36:02,874 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701]) (logid:46b21a65) Executing AsyncJob {"accountId":2,"cmd":"com.cloud.vm.VmWorkStop","cmdInfo":"rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAM3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA","cmdVersion":0,"completeMsid":null,"created":"Tue Sep 30 11:36:02 UTC 2025","id":701,"initMsid":32987882193172,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"e422345c-ffdd-4871-808b-d220664ab84a"}
2025-09-30 11:36:02,875 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701]) (logid:46b21a65) Run VM work job: com.cloud.vm.VmWorkStop for VM 51, job origin: 700
2025-09-30 11:36:02,877 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":51,"handlerName":"VirtualMachineManagerImpl"}
2025-09-30 11:36:02,894 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Stopping","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} state transited from [Running] to [Stopping] with event [StopRequested]. VM's original host: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}, new host: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}, host before state transition: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}
2025-09-30 11:36:02,896 DEBUG [c.c.v.UserVmManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Collect vm disk statistics from host before stopping VM
2025-09-30 11:36:02,898 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.GetVmDiskStatsCommand is 1800 seconds
2025-09-30 11:36:02,899 DEBUG [c.c.a.m.ClusteredAgentAttache] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Seq 2-7890306547153114540: Routed from 32987882193172
2025-09-30 11:36:02,908 DEBUG [c.c.a.t.Request] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Seq 2-7890306547153114540: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 10, { GetVmDiskStatsAnswer } }
2025-09-30 11:36:02,908 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Details from executing class com.cloud.agent.api.GetVmDiskStatsCommand:
2025-09-30 11:36:02,910 DEBUG [c.c.v.UserVmManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Collect vm network statistics from host before stopping Vm
2025-09-30 11:36:02,911 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.GetVmNetworkStatsCommand is 1800 seconds
2025-09-30 11:36:02,912 DEBUG [c.c.a.m.ClusteredAgentAttache] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Seq 2-7890306547153114541: Routed from 32987882193172
2025-09-30 11:36:02,959 DEBUG [c.c.a.t.Request] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Seq 2-7890306547153114541: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 10, { GetVmNetworkStatsAnswer } }
2025-09-30 11:36:02,959 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Details from executing class com.cloud.agent.api.GetVmNetworkStatsCommand:
2025-09-30 11:36:02,974 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Stopping","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} is a [User], returning null for control Nic IP.
2025-09-30 11:36:02,975 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.StopCommand is 1800 seconds
2025-09-30 11:36:02,975 DEBUG [c.c.a.m.ClusteredAgentAttache] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Seq 2-7890306547153114542: Routed from 32987882193172
2025-09-30 11:36:02,975 DEBUG [c.c.a.t.Request] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Seq 2-7890306547153114542: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","forceStop":"false","vlanToPersistenceMap":{"3007":"true"},"expungeVM":"false","volumesToDisconnect":[],"vmName":"i-2-51-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:15,511 DEBUG [c.c.a.t.Request] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Seq 2-7890306547153114542: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 10, { StopAnswer } }
2025-09-30 11:36:15,522 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Stopping","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} is stopped on the host.  Proceeding to release resource held.
2025-09-30 11:36:15,529 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Service SecurityGroup is not supported in the network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:15,533 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) The nic Nic {"broadcastUri":"vlan:\/\/3007","deviceId":0,"iPv4Address":"10.1.1.254","id":77,"instanceId":51,"reservationId":"1f16b62a-5220-4568-8c5b-40449386c88b","uuid":"2db657ad-b07a-48a4-adb9-0899fa706809"} on NicProfile {"broadcastUri":null,"deviceId":0,"iPv4Address":"10.1.1.254","id":77,"reservationId":"1f16b62a-5220-4568-8c5b-40449386c88b","uuid":"2db657ad-b07a-48a4-adb9-0899fa706809","vmId":51} was released according to VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Stopping","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} by guru com.cloud.network.guru.ExternalGuestNetworkGuru@6ac5fdb, now updating record.
2025-09-30 11:36:15,535 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Changing active number of nics for network id=Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28} on -1
2025-09-30 11:36:15,559 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Asking VirtualRouter to release NicProfile {"broadcastUri":null,"deviceId":0,"iPv4Address":"10.1.1.254","id":77,"reservationId":"1f16b62a-5220-4568-8c5b-40449386c88b","uuid":"2db657ad-b07a-48a4-adb9-0899fa706809","vmId":51}
2025-09-30 11:36:15,559 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Successfully released network resources for the VM VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Stopping","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} in Stopping state
2025-09-30 11:36:15,567 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Found [0] snapshots [[]] that have checkpoints for volume with id [173].
2025-09-30 11:36:15,569 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Successfully released storage resources for the VM VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Stopping","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} in Stopping state
2025-09-30 11:36:15,569 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Successfully cleaned up resources for the VM VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Stopping","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} in Stopping state
2025-09-30 11:36:15,580 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Service SecurityGroup is not supported in the network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:15,583 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Service SecurityGroup is not supported in the network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:15,586 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Stopped","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} state transited from [Stopping] to [Stopped] with event [OperationSucceeded]. VM's original host: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}, new host: null, host before state transition: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}
2025-09-30 11:36:15,592 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Hosts's actual total CPU: 6300 and CPU after applying overprovisioning: 12600
2025-09-30 11:36:15,592 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Hosts's actual total RAM: (6.76 GB) 7259152384 and RAM after applying overprovisioning: (6.76 GB) 7259152384
2025-09-30 11:36:15,592 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) release cpu from host: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}, old used: 2500, reserved: 0, actual total: 6300, total with overprovisioning: 12600; new used: 500,reserved:2000; movedfromreserved: false,moveToReservered: true
2025-09-30 11:36:15,592 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) release mem from host: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}, old used: (2.50 GB) 2684354560, reserved: (0 bytes) 0, total: (6.76 GB) 7259152384; new used: (512.00 MB) 536870912, reserved: (2.00 GB) 2147483648; movedfromreserved: false, moveToReservered: true
2025-09-30 11:36:15,613 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":51,"handlerName":"VirtualMachineManagerImpl"}
2025-09-30 11:36:15,613 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Complete async job-701, jobStatus: SUCCEEDED, resultCode: 0, result: null
2025-09-30 11:36:15,614 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Publish async job-701 complete on message bus
2025-09-30 11:36:15,614 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Wake up jobs related to job-701
2025-09-30 11:36:15,614 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Update db status for job-701
2025-09-30 11:36:15,615 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701, ctx-0fb79ab5]) (logid:46b21a65) Wake up jobs joined with job-701 and disjoin all subjobs created from job- 701
2025-09-30 11:36:15,624 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701]) (logid:46b21a65) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 51, job origin: 700
2025-09-30 11:36:15,625 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701]) (logid:46b21a65) Done executing com.cloud.vm.VmWorkStop for job-701
2025-09-30 11:36:15,626 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-149:[ctx-9c04cd1e, job-700/job-701]) (logid:46b21a65) Remove job-701 from job monitoring
2025-09-30 11:36:15,642 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Sync job-702 execution on object VmWorkJobQueue.51
2025-09-30 11:36:16,867 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702]) (logid:46b21a65) Executing AsyncJob {"accountId":2,"cmd":"com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots","cmdInfo":"rO0ABXNyADBjb20uY2xvdWQudm0uc25hcHNob3QuVm1Xb3JrRGVsZXRlQWxsVk1TbmFwc2hvdHOsl-VRajf8cAIAAUwABHR5cGV0ACdMY29tL2Nsb3VkL3ZtL3NuYXBzaG90L1ZNU25hcHNob3QkVHlwZTt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAAAgAAAAAAAAACAAAAAAAAADN0ABVWTVNuYXBzaG90TWFuYWdlckltcGxw","cmdVersion":0,"completeMsid":null,"created":"Tue Sep 30 11:36:15 UTC 2025","id":702,"initMsid":32987882193172,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"0cc6cc01-2437-466f-8b35-8afc5130ec3c"}
2025-09-30 11:36:16,868 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702]) (logid:46b21a65) Run VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 51, job origin: 700
2025-09-30 11:36:16,869 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702, ctx-84804e44]) (logid:46b21a65) Execute VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":51,"handlerName":"VMSnapshotManagerImpl"}
2025-09-30 11:36:16,870 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702, ctx-84804e44]) (logid:46b21a65) Done executing VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":51,"handlerName":"VMSnapshotManagerImpl"}
2025-09-30 11:36:16,871 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702, ctx-84804e44]) (logid:46b21a65) Complete async job-702, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE
2025-09-30 11:36:16,871 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702, ctx-84804e44]) (logid:46b21a65) Publish async job-702 complete on message bus
2025-09-30 11:36:16,871 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702, ctx-84804e44]) (logid:46b21a65) Wake up jobs related to job-702
2025-09-30 11:36:16,871 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702, ctx-84804e44]) (logid:46b21a65) Update db status for job-702
2025-09-30 11:36:16,872 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702, ctx-84804e44]) (logid:46b21a65) Wake up jobs joined with job-702 and disjoin all subjobs created from job- 702
2025-09-30 11:36:16,878 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702]) (logid:46b21a65) Done with run of VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 51, job origin: 700
2025-09-30 11:36:16,879 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702]) (logid:46b21a65) Done executing com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for job-702
2025-09-30 11:36:16,879 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-150:[ctx-a3b02314, job-700/job-702]) (logid:46b21a65) Remove job-702 from job monitoring
2025-09-30 11:36:16,889 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Destroyed","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} state transited from [Stopped] to [Destroyed] with event [DestroyRequested]. VM's original host: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}, new host: null, host before state transition: null
2025-09-30 11:36:16,895 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Hosts's actual total CPU: 6300 and CPU after applying overprovisioning: 12600
2025-09-30 11:36:16,895 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Hosts's actual total RAM: (6.76 GB) 7259152384 and RAM after applying overprovisioning: (6.76 GB) 7259152384
2025-09-30 11:36:16,895 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) release cpu from host: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}, old used: 500, reserved: 2000, actual total: 6300, total with overprovisioning: 12600; new used: 500,reserved:0; movedfromreserved: true,moveToReservered: false
2025-09-30 11:36:16,895 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) release mem from host: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}, old used: (512.00 MB) 536870912, reserved: (2.00 GB) 2147483648, total: (6.76 GB) 7259152384; new used: (512.00 MB) 536870912, reserved: (0 bytes) 0; movedfromreserved: true, moveToReservered: false
2025-09-30 11:36:16,912 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} state transited from [Destroyed] to [Expunging] with event [ExpungeOperation]. VM's original host: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}, new host: null, host before state transition: null
2025-09-30 11:36:16,922 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Updating resource Type = user_vm count for Account with id = 2 Operation = decreasing Amount = 1
2025-09-30 11:36:16,925 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Updating resource Type = cpu count for Account with id = 2 Operation = decreasing Amount = 2
2025-09-30 11:36:16,927 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Updating resource Type = memory count for Account with id = 2 Operation = decreasing Amount = 2048
2025-09-30 11:36:16,955 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Sync job-703 execution on object VmWorkJobQueue.51
2025-09-30 11:36:18,870 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703]) (logid:46b21a65) Executing AsyncJob {"accountId":2,"cmd":"com.cloud.vm.VmWorkStop","cmdInfo":"rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAM3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA","cmdVersion":0,"completeMsid":null,"created":"Tue Sep 30 11:36:16 UTC 2025","id":703,"initMsid":32987882193172,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"5c7a8a0f-02ff-4996-84db-a222020d38fb"}
2025-09-30 11:36:18,870 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703]) (logid:46b21a65) Run VM work job: com.cloud.vm.VmWorkStop for VM 51, job origin: 700
2025-09-30 11:36:18,871 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703, ctx-9ee35ca8]) (logid:46b21a65) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":51,"handlerName":"VirtualMachineManagerImpl"}
2025-09-30 11:36:18,873 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703, ctx-9ee35ca8]) (logid:46b21a65) Stopped called on VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} but the state is Expunging
2025-09-30 11:36:18,873 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703, ctx-9ee35ca8]) (logid:46b21a65) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":51,"handlerName":"VirtualMachineManagerImpl"}
2025-09-30 11:36:18,874 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703, ctx-9ee35ca8]) (logid:46b21a65) Complete async job-703, jobStatus: SUCCEEDED, resultCode: 0, result: null
2025-09-30 11:36:18,874 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703, ctx-9ee35ca8]) (logid:46b21a65) Publish async job-703 complete on message bus
2025-09-30 11:36:18,874 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703, ctx-9ee35ca8]) (logid:46b21a65) Wake up jobs related to job-703
2025-09-30 11:36:18,874 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703, ctx-9ee35ca8]) (logid:46b21a65) Update db status for job-703
2025-09-30 11:36:18,875 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703, ctx-9ee35ca8]) (logid:46b21a65) Wake up jobs joined with job-703 and disjoin all subjobs created from job- 703
2025-09-30 11:36:18,883 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703]) (logid:46b21a65) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 51, job origin: 700
2025-09-30 11:36:18,883 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703]) (logid:46b21a65) Done executing com.cloud.vm.VmWorkStop for job-703
2025-09-30 11:36:18,887 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-151:[ctx-a7034e4f, job-700/job-703]) (logid:46b21a65) Remove job-703 from job monitoring
2025-09-30 11:36:18,896 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} state transited from [Expunging] to [Expunging] with event [ExpungeOperation]. VM's original host: Host {"id":2,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2","type":"Routing","uuid":"58376dc5-2296-470d-bed7-6a83125e12bf"}, new host: null, host before state transition: null
2025-09-30 11:36:18,899 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Expunging vm VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"}
2025-09-30 11:36:18,899 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Cleaning up NICS [] of VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"}.
2025-09-30 11:36:18,899 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Cleaning network for vm: VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"}
2025-09-30 11:36:18,910 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) REMOVE VPC DHCP ENTRY RULES
2025-09-30 11:36:18,910 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Applying dhcp entry in network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:18,920 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.routing.DhcpEntryCommand is 1800 seconds
2025-09-30 11:36:18,921 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114543: Routed from 32987882193172
2025-09-30 11:36:18,921 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114543: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"02:01:00:d2:00:02","vmIpAddress":"10.1.1.254","vmName":"cks-exist-net-control-1999a54a354","defaultRouter":"10.1.1.1","defaultDns":"10.1.1.1","duid":"00:03:00:01:02:01:00:d2:00:02","isDefault":"true","executeInSequence":"false","remove":"true","accessDetails":{"router.name":"r-50-VM","router.guest.ip":"10.1.1.1","router.ip":"169.254.166.44","zone.network.type":"Advanced"},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:19,950 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114543: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 10, { GroupAnswer } }
2025-09-30 11:36:19,956 DEBUG [c.c.n.NetworkModelImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Service SecurityGroup is not supported in the network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:19,962 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Removed nic Nic {"broadcastUri":null,"deviceId":0,"iPv4Address":"10.1.1.254","id":77,"instanceId":51,"reservationId":"1f16b62a-5220-4568-8c5b-40449386c88b","uuid":"2db657ad-b07a-48a4-adb9-0899fa706809"}
2025-09-30 11:36:19,964 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Revoving nic secondary ip entry ...
2025-09-30 11:36:19,964 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage. Data from VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"}.
2025-09-30 11:36:19,972 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Found [0] snapshots [[]] that have checkpoints for volume with id [173].
2025-09-30 11:36:19,975 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Cleaning storage for VM [VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"}].
2025-09-30 11:36:19,982 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e, ctx-3aa846d1]) (logid:46b21a65) Found [0] snapshots [[]] that have checkpoints for volume with id [173].
2025-09-30 11:36:19,996 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e, ctx-3aa846d1]) (logid:46b21a65) Updating resource Type = volume count for Account with id = 2 Operation = decreasing Amount = 1
2025-09-30 11:36:19,999 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e, ctx-3aa846d1]) (logid:46b21a65) Updating resource Type = primary_storage count for Account with id = 2 Operation = decreasing Amount = (8.00 GB) 8589934592
2025-09-30 11:36:20,010 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Found [0] snapshots [[]] that have checkpoints for volume with id [173].
2025-09-30 11:36:20,031 DEBUG [c.c.h.XenServerGuru] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) We are returning the default host to execute commands because the command is not of Copy type.
2025-09-30 11:36:20,031 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Wait time setting on org.apache.cloudstack.storage.command.DeleteCommand is 1800 seconds
2025-09-30 11:36:20,031 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114544: Routed from 32987882193172
2025-09-30 11:36:20,032 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114544: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"0c3fab9e-a810-4a37-9911-65a525ca4c27","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"5b4cbc1e-df84-423b-9038-b4f5a3017087","name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm2-local-5b4cbc1e","id":"5","poolType":"Filesystem","host":"10.0.33.218","path":"/var/lib/libvirt/images","port":"0","url":"Filesystem://10.0.33.218/var/lib/libvirt/images/?ROLE=Primary&STOREUUID=5b4cbc1e-df84-423b-9038-b4f5a3017087","isManaged":"false"}},"name":"ROOT-51","size":"(8.00 GB) 8589934592","path":"0c3fab9e-a810-4a37-9911-65a525ca4c27","volumeId":"173","vmName":"i-2-51-VM","accountId":"2","format":"QCOW2","provisioningType":"THIN","poolId":"5","id":"173","deviceId":"0","cacheMode":"NONE","hypervisorType":"KVM","directDownload":"false","deployAsIs":"false","checkpointPaths":[],"checkpointImageStoreUrls":[],"followRedirects":"false"}},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:21,074 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114544: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 10, { Answer } }
2025-09-30 11:36:21,083 INFO  [o.a.c.s.v.VolumeServiceImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Volume VolumeObject {"dataStore":"StoragePool {\"id\":5,\"name\":\"ref-trl-9522-k-Mol8-kiran-chavala-kvm2-local-5b4cbc1e\",\"poolType\":\"Filesystem\",\"uuid\":\"5b4cbc1e-df84-423b-9038-b4f5a3017087\"}","volumeVO":"Volume {\"id\":173,\"instanceId\":51,\"name\":\"ROOT-51\",\"uuid\":\"0c3fab9e-a810-4a37-9911-65a525ca4c27\",\"volumeType\":\"ROOT\"}"} is not referred anywhere, remove it from volumes table
2025-09-30 11:36:21,083 DEBUG [c.c.s.d.VolumeDaoImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Removing volume 173 from DB
2025-09-30 11:36:21,091 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Expunged VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"}
2025-09-30 11:36:21,092 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Starting cleaning up vm VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} resources...
2025-09-30 11:36:21,108 DEBUG [c.c.n.f.FirewallManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) No firewall rules are found for vm: VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"}
2025-09-30 11:36:21,115 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Firewall rules are removed successfully as a part of vm VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} expunge
2025-09-30 11:36:21,127 DEBUG [c.c.n.r.RulesManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Applying port forwarding rules for ip address id=4 as a part of vm expunge
2025-09-30 11:36:21,140 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) APPLYING FIREWALL RULES
2025-09-30 11:36:21,140 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Applying firewall rules in network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:21,145 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.routing.SetPortForwardingRulesCommand is 1800 seconds
2025-09-30 11:36:21,146 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114545: Routed from 32987882193172
2025-09-30 11:36:21,147 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114545: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100001, [{"com.cloud.agent.api.routing.SetPortForwardingRulesCommand":{"rules":[{"dstIp":"10.1.1.254","dstPortRange":["22","22"],"id":"29","srcIp":"10.0.59.124","protocol":"tcp","srcPortRange":["2222","2222"],"revoked":"true","alreadyAdded":"false","sourceCidrList":[],"purpose":"PortForwarding","defaultEgressPolicy":"false"},{"dstIp":"10.1.1.194","dstPortRange":["22","22"],"id":"30","srcIp":"10.0.59.124","protocol":"tcp","srcPortRange":["2223","2223"],"revoked":"false","alreadyAdded":"true","sourceCidrList":[],"purpose":"PortForwarding","defaultEgressPolicy":"false"}],"accessDetails":{"router.name":"r-50-VM","router.guest.ip":"10.1.1.1","router.ip":"169.254.166.44","zone.network.type":"Advanced"},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:22,164 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114545: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 0, { GroupAnswer } }
2025-09-30 11:36:22,172 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Port forwarding rules are removed successfully as a part of vm VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} expunge
2025-09-30 11:36:22,180 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Set load balancer rule for revoke: rule LoadBalancer {"name":"api-lb","id":31,"purpose":"LoadBalancing","state":"Active","uuid":"e0721e9e-e603-4d0b-945e-6972e9d99ca2"}, vm VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"}
2025-09-30 11:36:22,188 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Set load balancer rule for revoke: rule LoadBalancer {"name":"api-lb","id":31,"purpose":"LoadBalancing","state":"Add","uuid":"e0721e9e-e603-4d0b-945e-6972e9d99ca2"}, vm VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"}
2025-09-30 11:36:22,209 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) APPLYING IP RULES
2025-09-30 11:36:22,209 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Applying ip association in network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:22,235 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.routing.IpAssocCommand is 1800 seconds
2025-09-30 11:36:22,236 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114546: Routed from 32987882193172
2025-09-30 11:36:22,237 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114546: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100001, [{"com.cloud.agent.api.routing.IpAssocCommand":{"ipAddresses":[{"accountId":"2","publicIp":"10.0.59.124","sourceNat":"true","add":"true","oneToOneNat":"false","firstIP":"true","broadcastUri":"vlan://51","vlanGateway":"10.0.48.1","vlanNetmask":"255.255.240.0","vifMacAddress":"1e:00:fa:00:00:04","networkRate":"200","trafficType":"Public","networkName":"cloudbr1","newNic":"false","isPrivateGateway":"false","nicTO":{"deviceId":"0","networkRateMbps":"-1","defaultNic":"false","pxeDisable":"false","details":{"MacLearning":"false","ForgedTransmits":"true","PromiscuousMode":"false","MacAddressChanges":"true"},"dpdkEnabled":"false","gateway":"10.0.48.1","mac":"1e:00:fa:00:00:04","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://51","securityGroupEnabled":"false","name":"cloudbr1"},"mtu":"1500"}],"accessDetails":{"router.name":"r-50-VM","router.guest.ip":"10.0.59.124","network.public.last.ip":"false","router.ip":"169.254.166.44","zone.network.type":"Advanced"},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:23,173 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114546: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 0, { GroupAnswer } }
2025-09-30 11:36:23,180 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) APPLYING LOAD BALANCING RULES
2025-09-30 11:36:23,181 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Applying loadbalancing rules in network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:23,197 DEBUG [c.c.n.NetworkModelImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Service SecurityGroup is not supported in the network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:23,211 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.routing.LoadBalancerConfigCommand is 1800 seconds
2025-09-30 11:36:23,212 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114547: Routed from 32987882193172
2025-09-30 11:36:23,213 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114547: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100001, [{"com.cloud.agent.api.routing.LoadBalancerConfigCommand":{"loadBalancers":[{"uuid":"e0721e9e-e603-4d0b-945e-6972e9d99ca2","srcIp":"10.0.59.124","srcPort":"6443","protocol":"tcp","lbProtocol":"tcp","algorithm":"roundrobin","revoked":"false","alreadyAdded":"false","inline":"false","destinations":[{"destIp":"10.1.1.254","destPort":"6443","revoked":"true","alreadyAdded":"false"}]}],"lbStatsVisibility":"global","lbStatsPublicIP":"10.0.59.124","lbStatsPrivateIP":"169.254.166.44","lbStatsGuestIP":"10.1.1.1","lbStatsPort":"8081","lbStatsSrcCidrs":"0/0","lbStatsAuth":"admin1:AdMiN123","lbStatsUri":"/admin?stats","maxconn":"4096","keepAliveEnabled":"false","nic":{"deviceId":"0","networkRateMbps":"200","defaultNic":"false","pxeDisable":"true","nicUuid":"97c3b4d6-1ac8-4d44-bd32-62a5a12de029","details":{"MacLearning":"false","ForgedTransmits":"true","PromiscuousMode":"false","MacAddressChanges":"true"},"dpdkEnabled":"false","networkId":"210","networkSegmentName":"D1-A2-Z1-S210","uuid":"fcabd5c5-9614-4ae3-b99e-b10630f54b62","ip":"10.1.1.1","netmask":"255.255.255.0","mac":"02:01:00:d2:00:01","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://3007","isolationUri":"vlan://3007","securityGroupEnabled":"false","name":"cloudbr1"},"accessDetails":{"router.name":"r-50-VM","router.guest.ip":"10.1.1.1","router.ip":"169.254.166.44","zone.network.type":"Advanced"},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:24,830 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114547: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 0, { GroupAnswer } }
2025-09-30 11:36:24,845 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) APPLYING IP RULES
2025-09-30 11:36:24,846 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Applying ip association in network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:24,872 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.routing.IpAssocCommand is 1800 seconds
2025-09-30 11:36:24,872 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114548: Routed from 32987882193172
2025-09-30 11:36:24,873 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114548: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100001, [{"com.cloud.agent.api.routing.IpAssocCommand":{"ipAddresses":[{"accountId":"2","publicIp":"10.0.59.124","sourceNat":"true","add":"true","oneToOneNat":"false","firstIP":"true","broadcastUri":"vlan://51","vlanGateway":"10.0.48.1","vlanNetmask":"255.255.240.0","vifMacAddress":"1e:00:fa:00:00:04","networkRate":"200","trafficType":"Public","networkName":"cloudbr1","newNic":"false","isPrivateGateway":"false","nicTO":{"deviceId":"0","networkRateMbps":"-1","defaultNic":"false","pxeDisable":"false","details":{"MacLearning":"false","ForgedTransmits":"true","PromiscuousMode":"false","MacAddressChanges":"true"},"dpdkEnabled":"false","gateway":"10.0.48.1","mac":"1e:00:fa:00:00:04","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://51","securityGroupEnabled":"false","name":"cloudbr1"},"mtu":"1500"}],"accessDetails":{"router.name":"r-50-VM","router.guest.ip":"10.0.59.124","network.public.last.ip":"false","router.ip":"169.254.166.44","zone.network.type":"Advanced"},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:25,847 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Seq 2-7890306547153114548: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 0, { GroupAnswer } }
2025-09-30 11:36:25,848 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) LB rule LoadBalancer {"name":"api-lb","id":31,"purpose":"LoadBalancing","state":"Active","uuid":"e0721e9e-e603-4d0b-945e-6972e9d99ca2"} state is set to Active
2025-09-30 11:36:25,851 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Load balancer rule LoadBalancer {"name":"api-lb","id":31,"purpose":"LoadBalancing","state":"Active","uuid":"e0721e9e-e603-4d0b-945e-6972e9d99ca2"} is removed for vm 51 instance ip 10.1.1.254
2025-09-30 11:36:25,854 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) LB rule LoadBalancer {"name":"api-lb","id":31,"purpose":"LoadBalancing","state":"Add","uuid":"e0721e9e-e603-4d0b-945e-6972e9d99ca2"} state is set to Add as there are no more active LB-VM mappings
2025-09-30 11:36:25,860 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Removed vm VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} from all load balancers as a part of expunge process
2025-09-30 11:36:25,862 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Successfully cleaned up vm VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} resources as a part of expunge process
2025-09-30 11:36:25,873 INFO  [c.c.k.c.a.KubernetesClusterDestroyWorker] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-2d0bf92e]) (logid:46b21a65) Destroyed VM VM instance {"id":51,"instanceName":"i-2-51-VM","state":"Expunging","type":"User","uuid":"2c89d90b-efed-4e3f-a715-c44599b32c85"} as part of Kubernetes cluster : KubernetesCluster {"id":5,"name":"cks-exist-net","uuid":"746208c1-2b84-426d-92f4-f55bbc1e1ee6"} cleanup
2025-09-30 11:36:25,893 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Destroying vm VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Running","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"}, expunge flag on
2025-09-30 11:36:25,900 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Sync job-704 execution on object VmWorkJobQueue.52
2025-09-30 11:36:26,873 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704]) (logid:46b21a65) Executing AsyncJob {"accountId":2,"cmd":"com.cloud.vm.VmWorkStop","cmdInfo":"rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAANHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA","cmdVersion":0,"completeMsid":null,"created":"Tue Sep 30 11:36:25 UTC 2025","id":704,"initMsid":32987882193172,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"4ad15c17-9fef-4e01-8dd1-88044b557fb3"}
2025-09-30 11:36:26,873 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704]) (logid:46b21a65) Run VM work job: com.cloud.vm.VmWorkStop for VM 52, job origin: 700
2025-09-30 11:36:26,874 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":52,"handlerName":"VirtualMachineManagerImpl"}
2025-09-30 11:36:26,886 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Stopping","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} state transited from [Running] to [Stopping] with event [StopRequested]. VM's original host: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}, new host: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}, host before state transition: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}
2025-09-30 11:36:26,887 DEBUG [c.c.v.UserVmManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Collect vm disk statistics from host before stopping VM
2025-09-30 11:36:26,888 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.GetVmDiskStatsCommand is 1800 seconds
2025-09-30 11:36:26,888 DEBUG [c.c.a.m.ClusteredAgentAttache] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Seq 2-8469300574246936130: Routed from 32987882193172
2025-09-30 11:36:26,898 DEBUG [c.c.a.t.Request] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Seq 1-8469300574246936130: Received:  { Ans: , MgmtId: 32987882193172, via: 1(ref-trl-9522-k-Mol8-kiran-chavala-kvm1), Ver: v1, Flags: 10, { GetVmDiskStatsAnswer } }
2025-09-30 11:36:26,898 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Details from executing class com.cloud.agent.api.GetVmDiskStatsCommand:
2025-09-30 11:36:26,900 DEBUG [c.c.v.UserVmManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Collect vm network statistics from host before stopping Vm
2025-09-30 11:36:26,901 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.GetVmNetworkStatsCommand is 1800 seconds
2025-09-30 11:36:26,902 DEBUG [c.c.a.m.ClusteredAgentAttache] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Seq 2-8469300574246936131: Routed from 32987882193172
2025-09-30 11:36:26,908 DEBUG [c.c.a.t.Request] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Seq 1-8469300574246936131: Received:  { Ans: , MgmtId: 32987882193172, via: 1(ref-trl-9522-k-Mol8-kiran-chavala-kvm1), Ver: v1, Flags: 10, { GetVmNetworkStatsAnswer } }
2025-09-30 11:36:26,908 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Details from executing class com.cloud.agent.api.GetVmNetworkStatsCommand:
2025-09-30 11:36:26,921 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Stopping","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} is a [User], returning null for control Nic IP.
2025-09-30 11:36:26,921 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.StopCommand is 1800 seconds
2025-09-30 11:36:26,922 DEBUG [c.c.a.m.ClusteredAgentAttache] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Seq 2-8469300574246936132: Routed from 32987882193172
2025-09-30 11:36:26,922 DEBUG [c.c.a.t.Request] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Seq 1-8469300574246936132: Sending  { Cmd , MgmtId: 32987882193172, via: 1(ref-trl-9522-k-Mol8-kiran-chavala-kvm1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","forceStop":"false","vlanToPersistenceMap":{"3007":"true"},"expungeVM":"false","volumesToDisconnect":[],"vmName":"i-2-52-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:29,555 DEBUG [c.c.a.t.Request] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Seq 1-8469300574246936132: Received:  { Ans: , MgmtId: 32987882193172, via: 1(ref-trl-9522-k-Mol8-kiran-chavala-kvm1), Ver: v1, Flags: 10, { StopAnswer } }
2025-09-30 11:36:29,562 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Stopping","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} is stopped on the host.  Proceeding to release resource held.
2025-09-30 11:36:29,565 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Service SecurityGroup is not supported in the network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:29,567 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) The nic Nic {"broadcastUri":"vlan:\/\/3007","deviceId":0,"iPv4Address":"10.1.1.194","id":78,"instanceId":52,"reservationId":"7884af66-b28b-47c6-95a6-ebfea91a5f87","uuid":"a2a13645-79e8-41a6-afb8-4c1dd417444a"} on NicProfile {"broadcastUri":null,"deviceId":0,"iPv4Address":"10.1.1.194","id":78,"reservationId":"7884af66-b28b-47c6-95a6-ebfea91a5f87","uuid":"a2a13645-79e8-41a6-afb8-4c1dd417444a","vmId":52} was released according to VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Stopping","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} by guru com.cloud.network.guru.ExternalGuestNetworkGuru@6ac5fdb, now updating record.
2025-09-30 11:36:29,569 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Changing active number of nics for network id=Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28} on -1
2025-09-30 11:36:29,577 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Asking VirtualRouter to release NicProfile {"broadcastUri":null,"deviceId":0,"iPv4Address":"10.1.1.194","id":78,"reservationId":"7884af66-b28b-47c6-95a6-ebfea91a5f87","uuid":"a2a13645-79e8-41a6-afb8-4c1dd417444a","vmId":52}
2025-09-30 11:36:29,577 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Successfully released network resources for the VM VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Stopping","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} in Stopping state
2025-09-30 11:36:29,581 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Found [0] snapshots [[]] that have checkpoints for volume with id [174].
2025-09-30 11:36:29,582 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Successfully released storage resources for the VM VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Stopping","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} in Stopping state
2025-09-30 11:36:29,582 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Successfully cleaned up resources for the VM VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Stopping","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} in Stopping state
2025-09-30 11:36:29,591 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Service SecurityGroup is not supported in the network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:29,594 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Service SecurityGroup is not supported in the network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:29,596 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Stopped","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} state transited from [Stopping] to [Stopped] with event [OperationSucceeded]. VM's original host: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}, new host: null, host before state transition: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}
2025-09-30 11:36:29,602 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Hosts's actual total CPU: 6300 and CPU after applying overprovisioning: 12600
2025-09-30 11:36:29,602 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Hosts's actual total RAM: (6.76 GB) 7259152384 and RAM after applying overprovisioning: (6.76 GB) 7259152384
2025-09-30 11:36:29,602 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) release cpu from host: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}, old used: 3000, reserved: 500, actual total: 6300, total with overprovisioning: 12600; new used: 1000,reserved:2500; movedfromreserved: false,moveToReservered: true
2025-09-30 11:36:29,602 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) release mem from host: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}, old used: (3.50 GB) 3758096384, reserved: (512.00 MB) 536870912, total: (6.76 GB) 7259152384; new used: (1.50 GB) 1610612736, reserved: (2.50 GB) 2684354560; movedfromreserved: false, moveToReservered: true
2025-09-30 11:36:29,623 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":52,"handlerName":"VirtualMachineManagerImpl"}
2025-09-30 11:36:29,623 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Complete async job-704, jobStatus: SUCCEEDED, resultCode: 0, result: null
2025-09-30 11:36:29,624 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Publish async job-704 complete on message bus
2025-09-30 11:36:29,624 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Wake up jobs related to job-704
2025-09-30 11:36:29,624 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Update db status for job-704
2025-09-30 11:36:29,625 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704, ctx-202a7cbd]) (logid:46b21a65) Wake up jobs joined with job-704 and disjoin all subjobs created from job- 704
2025-09-30 11:36:29,633 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704]) (logid:46b21a65) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 52, job origin: 700
2025-09-30 11:36:29,633 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704]) (logid:46b21a65) Done executing com.cloud.vm.VmWorkStop for job-704
2025-09-30 11:36:29,634 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-152:[ctx-f982eef8, job-700/job-704]) (logid:46b21a65) Remove job-704 from job monitoring
2025-09-30 11:36:29,644 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Sync job-705 execution on object VmWorkJobQueue.52
2025-09-30 11:36:30,869 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705]) (logid:46b21a65) Executing AsyncJob {"accountId":2,"cmd":"com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots","cmdInfo":"rO0ABXNyADBjb20uY2xvdWQudm0uc25hcHNob3QuVm1Xb3JrRGVsZXRlQWxsVk1TbmFwc2hvdHOsl-VRajf8cAIAAUwABHR5cGV0ACdMY29tL2Nsb3VkL3ZtL3NuYXBzaG90L1ZNU25hcHNob3QkVHlwZTt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAAAgAAAAAAAAACAAAAAAAAADR0ABVWTVNuYXBzaG90TWFuYWdlckltcGxw","cmdVersion":0,"completeMsid":null,"created":"Tue Sep 30 11:36:29 UTC 2025","id":705,"initMsid":32987882193172,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"153b0706-4a5c-4073-96d1-d99a125dea8c"}
2025-09-30 11:36:30,870 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705]) (logid:46b21a65) Run VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 52, job origin: 700
2025-09-30 11:36:30,871 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705, ctx-bf2788a3]) (logid:46b21a65) Execute VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":52,"handlerName":"VMSnapshotManagerImpl"}
2025-09-30 11:36:30,872 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705, ctx-bf2788a3]) (logid:46b21a65) Done executing VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots{"userId":2,"accountId":2,"vmId":52,"handlerName":"VMSnapshotManagerImpl"}
2025-09-30 11:36:30,872 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705, ctx-bf2788a3]) (logid:46b21a65) Complete async job-705, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE
2025-09-30 11:36:30,872 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705, ctx-bf2788a3]) (logid:46b21a65) Publish async job-705 complete on message bus
2025-09-30 11:36:30,872 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705, ctx-bf2788a3]) (logid:46b21a65) Wake up jobs related to job-705
2025-09-30 11:36:30,873 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705, ctx-bf2788a3]) (logid:46b21a65) Update db status for job-705
2025-09-30 11:36:30,874 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705, ctx-bf2788a3]) (logid:46b21a65) Wake up jobs joined with job-705 and disjoin all subjobs created from job- 705
2025-09-30 11:36:30,883 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705]) (logid:46b21a65) Done with run of VM work job: com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for VM 52, job origin: 700
2025-09-30 11:36:30,883 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705]) (logid:46b21a65) Done executing com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots for job-705
2025-09-30 11:36:30,884 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-153:[ctx-0fc3e65d, job-700/job-705]) (logid:46b21a65) Remove job-705 from job monitoring
2025-09-30 11:36:30,894 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Destroyed","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} state transited from [Stopped] to [Destroyed] with event [DestroyRequested]. VM's original host: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}, new host: null, host before state transition: null
2025-09-30 11:36:30,901 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Hosts's actual total CPU: 6300 and CPU after applying overprovisioning: 12600
2025-09-30 11:36:30,901 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Hosts's actual total RAM: (6.76 GB) 7259152384 and RAM after applying overprovisioning: (6.76 GB) 7259152384
2025-09-30 11:36:30,901 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) release cpu from host: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}, old used: 1000, reserved: 2500, actual total: 6300, total with overprovisioning: 12600; new used: 1000,reserved:500; movedfromreserved: true,moveToReservered: false
2025-09-30 11:36:30,901 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) release mem from host: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}, old used: (1.50 GB) 1610612736, reserved: (2.50 GB) 2684354560, total: (6.76 GB) 7259152384; new used: (1.50 GB) 1610612736, reserved: (512.00 MB) 536870912; movedfromreserved: true, moveToReservered: false
2025-09-30 11:36:30,915 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} state transited from [Destroyed] to [Expunging] with event [ExpungeOperation]. VM's original host: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}, new host: null, host before state transition: null
2025-09-30 11:36:30,926 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Updating resource Type = user_vm count for Account with id = 2 Operation = decreasing Amount = 1
2025-09-30 11:36:30,929 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Updating resource Type = cpu count for Account with id = 2 Operation = decreasing Amount = 2
2025-09-30 11:36:30,932 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Updating resource Type = memory count for Account with id = 2 Operation = decreasing Amount = 2048
2025-09-30 11:36:30,961 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Sync job-706 execution on object VmWorkJobQueue.52
2025-09-30 11:36:32,874 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706]) (logid:46b21a65) Executing AsyncJob {"accountId":2,"cmd":"com.cloud.vm.VmWorkStop","cmdInfo":"rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAANHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA","cmdVersion":0,"completeMsid":null,"created":"Tue Sep 30 11:36:30 UTC 2025","id":706,"initMsid":32987882193172,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"19c70210-36c8-41da-898e-c8ccdb3dbc28"}
2025-09-30 11:36:32,874 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706]) (logid:46b21a65) Run VM work job: com.cloud.vm.VmWorkStop for VM 52, job origin: 700
2025-09-30 11:36:32,876 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706, ctx-dbf9d150]) (logid:46b21a65) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":52,"handlerName":"VirtualMachineManagerImpl"}
2025-09-30 11:36:32,878 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706, ctx-dbf9d150]) (logid:46b21a65) Stopped called on VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} but the state is Expunging
2025-09-30 11:36:32,878 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706, ctx-dbf9d150]) (logid:46b21a65) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":52,"handlerName":"VirtualMachineManagerImpl"}
2025-09-30 11:36:32,878 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706, ctx-dbf9d150]) (logid:46b21a65) Complete async job-706, jobStatus: SUCCEEDED, resultCode: 0, result: null
2025-09-30 11:36:32,879 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706, ctx-dbf9d150]) (logid:46b21a65) Publish async job-706 complete on message bus
2025-09-30 11:36:32,879 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706, ctx-dbf9d150]) (logid:46b21a65) Wake up jobs related to job-706
2025-09-30 11:36:32,879 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706, ctx-dbf9d150]) (logid:46b21a65) Update db status for job-706
2025-09-30 11:36:32,880 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706, ctx-dbf9d150]) (logid:46b21a65) Wake up jobs joined with job-706 and disjoin all subjobs created from job- 706
2025-09-30 11:36:32,887 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706]) (logid:46b21a65) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 52, job origin: 700
2025-09-30 11:36:32,887 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706]) (logid:46b21a65) Done executing com.cloud.vm.VmWorkStop for job-706
2025-09-30 11:36:32,888 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-154:[ctx-42de4d59, job-700/job-706]) (logid:46b21a65) Remove job-706 from job monitoring
2025-09-30 11:36:32,901 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} state transited from [Expunging] to [Expunging] with event [ExpungeOperation]. VM's original host: Host {"id":1,"name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1","type":"Routing","uuid":"b9bf8aa6-e12c-4c4f-9284-5494ccad091d"}, new host: null, host before state transition: null
2025-09-30 11:36:32,906 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Expunging vm VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"}
2025-09-30 11:36:32,906 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Cleaning up NICS [] of VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"}.
2025-09-30 11:36:32,906 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Cleaning network for vm: VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"}
2025-09-30 11:36:32,917 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) REMOVE VPC DHCP ENTRY RULES
2025-09-30 11:36:32,918 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Applying dhcp entry in network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:32,927 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.routing.DhcpEntryCommand is 1800 seconds
2025-09-30 11:36:32,928 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Seq 2-7890306547153114550: Routed from 32987882193172
2025-09-30 11:36:32,928 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Seq 2-7890306547153114550: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"02:01:00:d2:00:03","vmIpAddress":"10.1.1.194","vmName":"cks-exist-net-node-1999a54ff9c","defaultRouter":"10.1.1.1","defaultDns":"10.1.1.1","duid":"00:03:00:01:02:01:00:d2:00:03","isDefault":"true","executeInSequence":"false","remove":"true","accessDetails":{"router.name":"r-50-VM","router.guest.ip":"10.1.1.1","router.ip":"169.254.166.44","zone.network.type":"Advanced"},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:33,782 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Seq 2-7890306547153114550: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 10, { GroupAnswer } }
2025-09-30 11:36:33,786 DEBUG [c.c.n.NetworkModelImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Service SecurityGroup is not supported in the network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:33,792 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Removed nic Nic {"broadcastUri":null,"deviceId":0,"iPv4Address":"10.1.1.194","id":78,"instanceId":52,"reservationId":"7884af66-b28b-47c6-95a6-ebfea91a5f87","uuid":"a2a13645-79e8-41a6-afb8-4c1dd417444a"}
2025-09-30 11:36:33,794 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Revoving nic secondary ip entry ...
2025-09-30 11:36:33,795 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage. Data from VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"}.
2025-09-30 11:36:33,801 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Found [0] snapshots [[]] that have checkpoints for volume with id [174].
2025-09-30 11:36:33,803 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Cleaning storage for VM [VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"}].
2025-09-30 11:36:33,810 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783, ctx-3374a70b]) (logid:46b21a65) Found [0] snapshots [[]] that have checkpoints for volume with id [174].
2025-09-30 11:36:33,823 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783, ctx-3374a70b]) (logid:46b21a65) Updating resource Type = volume count for Account with id = 2 Operation = decreasing Amount = 1
2025-09-30 11:36:33,826 DEBUG [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783, ctx-3374a70b]) (logid:46b21a65) Updating resource Type = primary_storage count for Account with id = 2 Operation = decreasing Amount = (8.00 GB) 8589934592
2025-09-30 11:36:33,841 DEBUG [o.a.c.e.o.VolumeOrchestrator] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Found [0] snapshots [[]] that have checkpoints for volume with id [174].
2025-09-30 11:36:33,862 DEBUG [c.c.h.XenServerGuru] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) We are returning the default host to execute commands because the command is not of Copy type.
2025-09-30 11:36:33,862 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Wait time setting on org.apache.cloudstack.storage.command.DeleteCommand is 1800 seconds
2025-09-30 11:36:33,863 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Seq 2-8469300574246936134: Routed from 32987882193172
2025-09-30 11:36:33,863 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Seq 1-8469300574246936134: Sending  { Cmd , MgmtId: 32987882193172, via: 1(ref-trl-9522-k-Mol8-kiran-chavala-kvm1), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"4609771f-e33e-4348-a2e3-0c0ac8c31c42","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"950072a5-f467-4845-befa-4cb432366b51","name":"ref-trl-9522-k-Mol8-kiran-chavala-kvm1-local-950072a5","id":"4","poolType":"Filesystem","host":"10.0.35.118","path":"/var/lib/libvirt/images","port":"0","url":"Filesystem://10.0.35.118/var/lib/libvirt/images/?ROLE=Primary&STOREUUID=950072a5-f467-4845-befa-4cb432366b51","isManaged":"false"}},"name":"ROOT-52","size":"(8.00 GB) 8589934592","path":"4609771f-e33e-4348-a2e3-0c0ac8c31c42","volumeId":"174","vmName":"i-2-52-VM","accountId":"2","format":"QCOW2","provisioningType":"THIN","poolId":"4","id":"174","deviceId":"0","cacheMode":"NONE","hypervisorType":"KVM","directDownload":"false","deployAsIs":"false","checkpointPaths":[],"checkpointImageStoreUrls":[],"followRedirects":"false"}},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:34,904 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Seq 1-8469300574246936134: Received:  { Ans: , MgmtId: 32987882193172, via: 1(ref-trl-9522-k-Mol8-kiran-chavala-kvm1), Ver: v1, Flags: 10, { Answer } }
2025-09-30 11:36:34,913 INFO  [o.a.c.s.v.VolumeServiceImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Volume VolumeObject {"dataStore":"StoragePool {\"id\":4,\"name\":\"ref-trl-9522-k-Mol8-kiran-chavala-kvm1-local-950072a5\",\"poolType\":\"Filesystem\",\"uuid\":\"950072a5-f467-4845-befa-4cb432366b51\"}","volumeVO":"Volume {\"id\":174,\"instanceId\":52,\"name\":\"ROOT-52\",\"uuid\":\"4609771f-e33e-4348-a2e3-0c0ac8c31c42\",\"volumeType\":\"ROOT\"}"} is not referred anywhere, remove it from volumes table
2025-09-30 11:36:34,914 DEBUG [c.c.s.d.VolumeDaoImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Removing volume 174 from DB
2025-09-30 11:36:34,921 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Expunged VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"}
2025-09-30 11:36:34,922 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Starting cleaning up vm VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} resources...
2025-09-30 11:36:34,934 DEBUG [c.c.n.f.FirewallManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) No firewall rules are found for vm: VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"}
2025-09-30 11:36:34,942 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Firewall rules are removed successfully as a part of vm VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} expunge
2025-09-30 11:36:34,951 DEBUG [c.c.n.r.RulesManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Applying port forwarding rules for ip address id=4 as a part of vm expunge
2025-09-30 11:36:34,960 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) APPLYING FIREWALL RULES
2025-09-30 11:36:34,961 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Applying firewall rules in network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:34,965 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.routing.SetPortForwardingRulesCommand is 1800 seconds
2025-09-30 11:36:34,966 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Seq 2-7890306547153114551: Routed from 32987882193172
2025-09-30 11:36:34,966 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Seq 2-7890306547153114551: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100001, [{"com.cloud.agent.api.routing.SetPortForwardingRulesCommand":{"rules":[{"dstIp":"10.1.1.194","dstPortRange":["22","22"],"id":"30","srcIp":"10.0.59.124","protocol":"tcp","srcPortRange":["2223","2223"],"revoked":"true","alreadyAdded":"false","sourceCidrList":[],"purpose":"PortForwarding","defaultEgressPolicy":"false"}],"accessDetails":{"router.name":"r-50-VM","router.guest.ip":"10.1.1.1","router.ip":"169.254.166.44","zone.network.type":"Advanced"},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:36,067 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Seq 2-7890306547153114551: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 0, { GroupAnswer } }
2025-09-30 11:36:36,076 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Port forwarding rules are removed successfully as a part of vm VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} expunge
2025-09-30 11:36:36,077 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Removed vm VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} from all load balancers as a part of expunge process
2025-09-30 11:36:36,079 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Successfully cleaned up vm VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} resources as a part of expunge process
2025-09-30 11:36:36,092 INFO  [c.c.k.c.a.KubernetesClusterDestroyWorker] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95, ctx-f9b14783]) (logid:46b21a65) Destroyed VM VM instance {"id":52,"instanceName":"i-2-52-VM","state":"Expunging","type":"User","uuid":"726aac10-3381-43ff-b701-e5d18dadeee8"} as part of Kubernetes cluster : KubernetesCluster {"id":5,"name":"cks-exist-net","uuid":"746208c1-2b84-426d-92f4-f55bbc1e1ee6"} cleanup
2025-09-30 11:36:36,139 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) APPLYING IP RULES
2025-09-30 11:36:36,139 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Applying ip association in network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:36,168 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.routing.IpAssocCommand is 1800 seconds
2025-09-30 11:36:36,169 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114552: Routed from 32987882193172
2025-09-30 11:36:36,170 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114552: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100001, [{"com.cloud.agent.api.routing.IpAssocCommand":{"ipAddresses":[{"accountId":"2","publicIp":"10.0.59.124","sourceNat":"true","add":"true","oneToOneNat":"false","firstIP":"true","broadcastUri":"vlan://51","vlanGateway":"10.0.48.1","vlanNetmask":"255.255.240.0","vifMacAddress":"1e:00:fa:00:00:04","networkRate":"200","trafficType":"Public","networkName":"cloudbr1","newNic":"false","isPrivateGateway":"false","nicTO":{"deviceId":"0","networkRateMbps":"-1","defaultNic":"false","pxeDisable":"false","details":{"MacLearning":"false","ForgedTransmits":"true","PromiscuousMode":"false","MacAddressChanges":"true"},"dpdkEnabled":"false","gateway":"10.0.48.1","mac":"1e:00:fa:00:00:04","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://51","securityGroupEnabled":"false","name":"cloudbr1"},"mtu":"1500"}],"accessDetails":{"router.name":"r-50-VM","router.guest.ip":"10.0.59.124","network.public.last.ip":"false","router.ip":"169.254.166.44","zone.network.type":"Advanced"},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:37,148 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114552: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 0, { GroupAnswer } }
2025-09-30 11:36:37,156 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) APPLYING LOAD BALANCING RULES
2025-09-30 11:36:37,158 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Applying loadbalancing rules in network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:37,171 DEBUG [c.c.n.NetworkModelImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Service SecurityGroup is not supported in the network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:37,185 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.routing.LoadBalancerConfigCommand is 1800 seconds
2025-09-30 11:36:37,185 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114553: Routed from 32987882193172
2025-09-30 11:36:37,186 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114553: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100001, [{"com.cloud.agent.api.routing.LoadBalancerConfigCommand":{"loadBalancers":[{"uuid":"e0721e9e-e603-4d0b-945e-6972e9d99ca2","srcIp":"10.0.59.124","srcPort":"6443","protocol":"tcp","lbProtocol":"tcp","algorithm":"roundrobin","revoked":"true","alreadyAdded":"false","inline":"false","destinations":[]}],"lbStatsVisibility":"global","lbStatsPublicIP":"10.0.59.124","lbStatsPrivateIP":"169.254.166.44","lbStatsGuestIP":"10.1.1.1","lbStatsPort":"8081","lbStatsSrcCidrs":"0/0","lbStatsAuth":"admin1:AdMiN123","lbStatsUri":"/admin?stats","maxconn":"4096","keepAliveEnabled":"false","nic":{"deviceId":"0","networkRateMbps":"200","defaultNic":"false","pxeDisable":"true","nicUuid":"97c3b4d6-1ac8-4d44-bd32-62a5a12de029","details":{"MacLearning":"false","ForgedTransmits":"true","PromiscuousMode":"false","MacAddressChanges":"true"},"dpdkEnabled":"false","networkId":"210","networkSegmentName":"D1-A2-Z1-S210","uuid":"fcabd5c5-9614-4ae3-b99e-b10630f54b62","ip":"10.1.1.1","netmask":"255.255.255.0","mac":"02:01:00:d2:00:01","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://3007","isolationUri":"vlan://3007","securityGroupEnabled":"false","name":"cloudbr1"},"accessDetails":{"router.name":"r-50-VM","router.guest.ip":"10.1.1.1","router.ip":"169.254.166.44","zone.network.type":"Advanced"},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:38,472 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114553: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 0, { GroupAnswer } }
2025-09-30 11:36:38,483 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) APPLYING IP RULES
2025-09-30 11:36:38,484 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Applying ip association in network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:38,509 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.routing.IpAssocCommand is 1800 seconds
2025-09-30 11:36:38,510 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114554: Routed from 32987882193172
2025-09-30 11:36:38,510 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114554: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100001, [{"com.cloud.agent.api.routing.IpAssocCommand":{"ipAddresses":[{"accountId":"2","publicIp":"10.0.59.124","sourceNat":"true","add":"true","oneToOneNat":"false","firstIP":"true","broadcastUri":"vlan://51","vlanGateway":"10.0.48.1","vlanNetmask":"255.255.240.0","vifMacAddress":"1e:00:fa:00:00:04","networkRate":"200","trafficType":"Public","networkName":"cloudbr1","newNic":"false","isPrivateGateway":"false","nicTO":{"deviceId":"0","networkRateMbps":"-1","defaultNic":"false","pxeDisable":"false","details":{"MacLearning":"false","ForgedTransmits":"true","PromiscuousMode":"false","MacAddressChanges":"true"},"dpdkEnabled":"false","gateway":"10.0.48.1","mac":"1e:00:fa:00:00:04","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://51","securityGroupEnabled":"false","name":"cloudbr1"},"mtu":"1500"}],"accessDetails":{"router.name":"r-50-VM","router.guest.ip":"10.0.59.124","network.public.last.ip":"false","router.ip":"169.254.166.44","zone.network.type":"Advanced"},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:39,462 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114554: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 0, { GroupAnswer } }
2025-09-30 11:36:39,465 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) LB LoadBalancer {"name":"api-lb","id":31,"purpose":"LoadBalancing","state":"Revoke","uuid":"e0721e9e-e603-4d0b-945e-6972e9d99ca2"} is successfully removed
2025-09-30 11:36:39,467 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) LB rule LoadBalancer {"name":"api-lb","id":31,"purpose":"LoadBalancing","state":"Add","uuid":"e0721e9e-e603-4d0b-945e-6972e9d99ca2"} state is set to Add as there are no more active LB-VM mappings
2025-09-30 11:36:39,477 DEBUG [c.c.n.l.LoadBalancingRulesManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Load balancer LoadBalancer {"name":"api-lb","id":31,"purpose":"LoadBalancing","state":"Revoke","uuid":"e0721e9e-e603-4d0b-945e-6972e9d99ca2"} is removed successfully
2025-09-30 11:36:39,485 DEBUG [c.c.k.c.a.KubernetesClusterDestroyWorker] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) The load balancing rule with the Id: 31 was removed
2025-09-30 11:36:39,507 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) APPLYING FIREWALL RULES
2025-09-30 11:36:39,507 DEBUG [o.a.c.n.t.BasicNetworkTopology] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Applying firewall rules in network Network {"id": 210, "name": "cks-network", "uuid": "fcabd5c5-9614-4ae3-b99e-b10630f54b62", "networkofferingid": 28}
2025-09-30 11:36:39,512 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Wait time setting on com.cloud.agent.api.routing.SetFirewallRulesCommand is 1800 seconds
2025-09-30 11:36:39,512 DEBUG [c.c.a.m.ClusteredAgentAttache] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114555: Routed from 32987882193172
2025-09-30 11:36:39,513 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114555: Sending  { Cmd , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 100001, [{"com.cloud.agent.api.routing.SetFirewallRulesCommand":{"rules":[{"id":"32","srcIp":"10.0.59.124","protocol":"tcp","srcPortRange":["6443","6443"],"revoked":"true","alreadyAdded":"false","sourceCidrList":["10.1.1.0/24"],"destCidrList":[],"purpose":"Firewall","trafficType":"Ingress","defaultEgressPolicy":"false"},{"id":"33","srcIp":"10.0.59.124","protocol":"tcp","revoked":"false","alreadyAdded":"true","sourceCidrList":["1.1.1.1/32"],"destCidrList":[],"purpose":"Firewall","trafficType":"Ingress","defaultEgressPolicy":"false"}],"accessDetails":{"router.name":"r-50-VM","router.guest.ip":"10.1.1.1","router.ip":"169.254.166.44","zone.network.type":"Advanced","firewall.egress.default":"false"},"wait":"0","bypassHostMaintenance":"false"}}] }
2025-09-30 11:36:40,496 DEBUG [c.c.a.t.Request] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) Seq 2-7890306547153114555: Received:  { Ans: , MgmtId: 32987882193172, via: 2(ref-trl-9522-k-Mol8-kiran-chavala-kvm2), Ver: v1, Flags: 0, { GroupAnswer } }















2025-09-30 11:36:40,511 DEBUG [c.c.k.c.a.KubernetesClusterDestroyWorker] (API-Job-Executor-7:[ctx-0806c5c6, job-700, ctx-4c425b95]) (logid:46b21a65) The API firewall rule [%s] with the id [%s] was revoked
2025-09-30 11:36:40,519 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-7:[ctx-0806c5c6, job-700]) (logid:46b21a65) Unexpected exception while executing org.apache.cloudstack.api.command.user.kubernetes.cluster.DeleteKubernetesClusterCmd java.lang.NullPointerException: Cannot invoke "java.lang.Integer.intValue()" because the return value of "com.cloud.network.rules.FirewallRuleVO.getSourcePortStart()" is null
        at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterResourceModifierActionWorker.removeSshFirewallRule(KubernetesClusterResourceModifierActionWorker.java:540)
        at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterDestroyWorker.deleteKubernetesClusterIsolatedNetworkRules(KubernetesClusterDestroyWorker.java:178)
        at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterDestroyWorker.deleteKubernetesClusterNetworkRules(KubernetesClusterDestroyWorker.java:215)
        at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterDestroyWorker.checkForRulesToDelete(KubernetesClusterDestroyWorker.java:245)
        at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterDestroyWorker.destroy(KubernetesClusterDestroyWorker.java:323)
        at com.cloud.kubernetes.cluster.KubernetesClusterManagerImpl.destroyKubernetesCluster(KubernetesClusterManagerImpl.java:2379)
        at com.cloud.kubernetes.cluster.KubernetesClusterManagerImpl.destroyKubernetesCluster(KubernetesClusterManagerImpl.java:2387)
        at com.cloud.kubernetes.cluster.KubernetesClusterManagerImpl.deleteKubernetesCluster(KubernetesClusterManagerImpl.java:1964)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:569)

[weizhouapache]

thanks @kiranchavala
added to 4.20.2 milestone

[weizhouapache]

the issue is reproducible

if there are user-defined firewall rules (ALL or other start/end ports), scale/delete CKS cluster will have some issues
it is a bit complicated to fix it, as several code lines are based on the assumption that the firewall rules and port forwarding rules for SSH (to control/worker nodes) start from port 2222.