GitHub user bilalinamdar edited a comment on the discussion: CloudStack 4.22 – VM deployment on LINSTOR primary fails during ROOT volume population (qemu-img convert), while volume creation succeeds
Hi, I tested on actual Host and i got the issue **Issue - System vm's not spining up (it gets in loop) on fresh setup linstor primary** I have not seen this issue in HCI (uses 4.19 cloudstack) and the virter env! I don't know why but two time when i deployed it in physical host it had same issue. The other issue i reported of .img of ubuntu that comes next when system vm's will be resolved. It is not there in HCI but it is in virter. **In short** HCI - NO ISSUE (of system vm's and ubuntu img) Virter - Ubuntu Img issue only Physical Host - Both issue system vm's and ubuntu img issue. <img width="1805" height="813" alt="image" src="https://github.com/user-attachments/assets/31a78a4e-c564-45f6-967b-c78dd0ff4b8f"; /> ``` root@cskvm01:~# drbd-reactorctl /etc/drbd-reactor.d/linstor_db.toml: Promoter: Currently active on this node ● drbd-services@linstor_db.target ● ├─ drbd-promote@linstor_db.service ● ├─ var-lib-linstor.mount ● ├─ ocf.rs@service_ip_linstor_db.service ● └─ linstor-controller.service /etc/drbd-reactor.d/mariadb.toml: Promoter: Currently active on this node ● [email protected] ● ├─ [email protected] ● ├─ var-lib-mysql.mount ● ├─ ocf.rs@service_ip_mariadb.service ● └─ mysqld.service root@cskvm01:~# ``` <img width="1776" height="543" alt="image" src="https://github.com/user-attachments/assets/8ddbf384-7929-4aa8-82c5-bf9ad80b05a4"; /> Logs as i added only one node and it was also the cloudstack management so. https://drive.google.com/file/d/1m_QATn-qYURf-_tm_2l_shG90M1jfonm/view?usp=sharing total 8.0K [cskvm01.tar.gz](https://github.com/user-attachments/files/24545205/cskvm01.tar.gz) ``` root@cskvm01:~# cat /etc/cloudstack/agent/agent.properties #Storage #Sat Jan 10 17:13:57 UTC 2026 LibvirtComputingResource.id=1 LibvirtComputingResource.name=cskvm01.poc.local LibvirtComputingResource.uuid=928f7d8f-3e0a-4c09-a0b9-13ba8522bedd cluster=1 domr.scripts.dir=scripts/network/domr/kvm guest.network.device=cloudbr1 guid=f34b9997-57ab-357f-82b0-603f6abc800e host=10.50.11.103@static hypervisor.type=kvm iscsi.session.cleanup.enabled=false keystore.passphrase=vy4yR9Qn6c99DZpY local.storage.uuid=1de9b2c8-088d-420a-b4cf-6b40dfe7cb63 pod=1 port=8250 private.network.device=cloudbr0 public.network.device=cloudbr1 resource=com.cloud.hypervisor.kvm.resource.LibvirtComputingResource vm.migrate.wait=3600 workers=5 zone=1 root@cskvm01:~# ``` ``` root@cskvm01:/var/log/cloudstack# ls -lrth drwxrwx--- 2 cloud cloud 4.0K Jan 10 19:39 management drwxr-xr-x 2 root root 4.0K Jan 10 20:48 agent root@cskvm01:/var/log/cloudstack# cd agent root@cskvm01:/var/log/cloudstack/agent# ls -lrth total 308K -rw-r--r-- 1 root root 3.8K Jan 10 20:48 setup.log -rw-r--r-- 1 root root 28K Jan 10 20:48 agent.out -rw-r--r-- 1 root root 9.5K Jan 10 20:53 security_group.log -rw-r--r-- 1 root root 91K Jan 10 20:53 agent.err -rw-r--r-- 1 root root 159K Jan 10 20:53 agent.log root@cskvm01:/var/log/cloudstack/agent# tail -f agent.err libvirt: QEMU Driver error : Domain not found: no domain with matching name 's-1-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 's-1-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 's-1-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' libvirt: error : no connection driver available for lxc:/// libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 's-1-VM' libvirt: error : no connection driver available for lxc:/// libvirt: QEMU Driver error : Domain not found: no domain with matching name 's-1-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 's-1-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 's-1-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 's-1-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 's-1-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' libvirt: error : no connection driver available for lxc:/// libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' libvirt: QEMU Driver error : Domain not found: no domain with matching name 'v-2-VM' ^C root@cskvm01:/var/log/cloudstack/agent# root@cskvm01:/var/log/cloudstack/agent# root@cskvm01:/var/log/cloudstack/agent# root@cskvm01:/var/log/cloudstack/agent# tail -f agent.log 2026-01-10 16:54:00,440 INFO [kvm.resource.LibvirtConnection] (AgentRequest-Handler-2:[]) (logid:927d5926) No existing libvirtd connection found. Opening a new one 2026-01-10 16:54:00,443 WARN [kvm.resource.LibvirtConnection] (AgentRequest-Handler-2:[]) (logid:927d5926) Can not find a connection for Instance s-1-VM. Assuming the default connection. 2026-01-10 16:54:00,537 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-2:[]) (logid:927d5926) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied. 2026-01-10 16:54:00,537 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-2:[]) (logid:927d5926) Shell script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.sh' is not available. Transformations will not be applied. 2026-01-10 16:54:00,537 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-2:[]) (logid:927d5926) Groovy scripting engine is not initialized. Data transformation skipped. 2026-01-10 16:54:00,633 INFO [kvm.resource.LibvirtConnection] (AgentRequest-Handler-3:[]) (logid:bebc8b9e) No existing libvirtd connection found. Opening a new one 2026-01-10 16:54:00,635 WARN [kvm.resource.LibvirtConnection] (AgentRequest-Handler-3:[]) (logid:bebc8b9e) Can not find a connection for Instance v-2-VM. Assuming the default connection. 2026-01-10 16:54:00,743 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-3:[]) (logid:bebc8b9e) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied. 2026-01-10 16:54:00,743 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-3:[]) (logid:bebc8b9e) Shell script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.sh' is not available. Transformations will not be applied. 2026-01-10 16:54:00,743 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-3:[]) (logid:bebc8b9e) Groovy scripting engine is not initialized. Data transformation skipped. 2026-01-10 16:54:12,536 INFO [kvm.resource.LibvirtConnection] (AgentRequest-Handler-4:[]) (logid:dd9dbbd3) No existing libvirtd connection found. Opening a new one 2026-01-10 16:54:12,539 WARN [kvm.resource.LibvirtConnection] (AgentRequest-Handler-4:[]) (logid:dd9dbbd3) Can not find a connection for Instance v-2-VM. Assuming the default connection. 2026-01-10 16:54:12,636 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-4:[]) (logid:dd9dbbd3) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied. 2026-01-10 16:54:12,637 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-4:[]) (logid:dd9dbbd3) Shell script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.sh' is not available. Transformations will not be applied. 2026-01-10 16:54:12,637 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-4:[]) (logid:dd9dbbd3) Groovy scripting engine is not initialized. Data transformation skipped. 2026-01-10 16:54:12,730 INFO [kvm.resource.LibvirtConnection] (AgentRequest-Handler-5:[]) (logid:ae25b139) No existing libvirtd connection found. Opening a new one 2026-01-10 16:54:12,732 WARN [kvm.resource.LibvirtConnection] (AgentRequest-Handler-5:[]) (logid:ae25b139) Can not find a connection for Instance s-1-VM. Assuming the default connection. 2026-01-10 16:54:12,839 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-5:[]) (logid:ae25b139) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied. 2026-01-10 16:54:12,839 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-5:[]) (logid:ae25b139) Shell script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.sh' is not available. Transformations will not be applied. 2026-01-10 16:54:12,839 WARN [kvm.resource.LibvirtKvmAgentHook] (AgentRequest-Handler-5:[]) (logid:ae25b139) Groovy scripting engine is not initialized. Data transformation skipped. ^C root@cskvm01:/var/log/cloudstack/agent# cd .. root@cskvm01:/var/log/cloudstack# cd management/ root@cskvm01:/var/log/cloudstack/management# ls -lrth total 11M -rw-r--r-- 1 root root 2.3K Jan 10 19:39 setupManagement.log -rw-r--r-- 1 root root 840 Jan 10 19:39 management-server.err -rw-r--r-- 1 root root 180K Jan 10 20:52 management-server.out -rw-r--r-- 1 cloud cloud 3.5M Jan 10 20:53 apilog.log -rw-r--r-- 1 cloud cloud 180K Jan 10 20:53 access.log -rw-r--r-- 1 cloud cloud 7.2M Jan 10 20:54 management-server.log root@cskvm01:/var/log/cloudstack/management# tail -f management-server.log 2026-01-10 16:54:29,502 DEBUG [c.c.s.S.StorageCollector] (StatsCollector-3:[ctx-756e1cbb]) (logid:3d93c77c) There is no secondary storage VM for secondary storage host secondary-nfs 2026-01-10 16:54:29,505 DEBUG [o.a.c.s.d.d.LinstorPrimaryDataStoreDriverImpl] (StatsCollector-3:[ctx-756e1cbb]) (logid:3d93c77c) Requesting storage stats: StoragePool {"id":1,"name":"linstor","poolType":"Linstor","uuid":"56859b26-0e2a-4753-9df4-43df475a62a9"} 2026-01-10 16:54:29,561 DEBUG [o.a.c.s.d.u.LinstorUtil] (StatsCollector-3:[ctx-756e1cbb]) (logid:3d93c77c) Linstor(http://10.50.11.251:3370;cloudstack): storageStats -> 719453159424/1151127552 2026-01-10 16:54:30,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-479a2e29]) (logid:98724567) No inactive management server node found 2026-01-10 16:54:30,596 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-479a2e29]) (logid:98724567) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:32,097 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-5ae6aed7]) (logid:8307ec31) No inactive management server node found 2026-01-10 16:54:32,098 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-5ae6aed7]) (logid:8307ec31) Peer scan is finished. profiler: Done. Duration: 4ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 1ms 2026-01-10 16:54:32,625 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-6:[ctx-c765a256]) (logid:dbfe3d9b) HA health check task is running... 2026-01-10 16:54:33,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-4348143a]) (logid:6377da6b) No inactive management server node found 2026-01-10 16:54:33,596 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-4348143a]) (logid:6377da6b) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:35,096 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-dbc46f12]) (logid:343bccb5) No inactive management server node found 2026-01-10 16:54:35,096 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-dbc46f12]) (logid:343bccb5) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:36,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-d174d11f]) (logid:c55fbe19) No inactive management server node found 2026-01-10 16:54:36,597 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-d174d11f]) (logid:c55fbe19) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:36,627 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-1:[ctx-56b328a6]) (logid:315e527a) HA health check task is running... 2026-01-10 16:54:38,096 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-d129a466]) (logid:a7da045c) No inactive management server node found 2026-01-10 16:54:38,096 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-d129a466]) (logid:a7da045c) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:38,205 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) Enabled non-edge zones available for scan: 1 2026-01-10 16:54:38,210 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) Zone Zone {"id": "1", "name": "CSPOC", "uuid": "1334298c-cfec-4ee6-afbd-dabdfcd8dacf"} is ready to launch console proxy 2026-01-10 16:54:38,212 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) Expand console proxy standby capacity for zone CSPOC 2026-01-10 16:54:38,212 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) Allocating console proxy standby capacity for zone [Zone {"id": "1", "name": "CSPOC", "uuid": "1334298c-cfec-4ee6-afbd-dabdfcd8dacf"}]. 2026-01-10 16:54:38,213 INFO [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) Found a stopped console proxy, starting it. VM: Console VM instance {"id":2,"instanceName":"v-2-VM","state":"Stopped","type":"ConsoleProxy","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"} 2026-01-10 16:54:38,217 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) start parameter value of enterHardwareSetup == <very null> during processing of queued job 2026-01-10 16:54:38,230 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) Sync job-54 execution on object VmWorkJobQueue.2 2026-01-10 16:54:38,246 DEBUG [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) Enabled non-edge zones available for scan: 1 2026-01-10 16:54:38,253 DEBUG [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) Zone [1] is ready to launch secondary storage VM. 2026-01-10 16:54:38,256 INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) No running secondary storage vms found in datacenter id=1, starting one 2026-01-10 16:54:38,258 DEBUG [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) Allocate secondary storage VM standby capacity for zone [1]. 2026-01-10 16:54:38,261 INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) Found a stopped secondary storage VM instance {"id":1,"instanceName":"s-1-VM","state":"Stopped","type":"SecondaryStorageVm","uuid":"72abc787-b8a8-4afa-a8f0-f1ad723e404b"}, starting it. 2026-01-10 16:54:38,263 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) start parameter value of enterHardwareSetup == <very null> during processing of queued job 2026-01-10 16:54:38,271 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) Sync job-55 execution on object VmWorkJobQueue.1 2026-01-10 16:54:39,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-0cf53ff1]) (logid:4b00b4bc) No inactive management server node found 2026-01-10 16:54:39,597 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-0cf53ff1]) (logid:4b00b4bc) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:40,628 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-4:[ctx-6a540bbd]) (logid:983972be) HA health check task is running... 2026-01-10 16:54:41,096 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-28f160f8]) (logid:0306f036) No inactive management server node found 2026-01-10 16:54:41,096 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-28f160f8]) (logid:0306f036) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:42,597 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-caa67379]) (logid:45e27a88) No inactive management server node found 2026-01-10 16:54:42,597 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-caa67379]) (logid:45e27a88) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:43,987 DEBUG [c.c.n.r.V.CheckRouterTask] (RouterStatusMonitor-1:[ctx-ca84f810]) (logid:5d4d5193) Found 0 routers to update status. 2026-01-10 16:54:43,988 DEBUG [c.c.n.r.V.CheckRouterTask] (RouterStatusMonitor-1:[ctx-ca84f810]) (logid:5d4d5193) Found 0 VPC's to update Redundant State. 2026-01-10 16:54:43,989 DEBUG [c.c.n.r.V.CheckRouterTask] (RouterStatusMonitor-1:[ctx-ca84f810]) (logid:5d4d5193) Found 0 networks to update RvR status. 2026-01-10 16:54:44,097 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-e1cee940]) (logid:f0fa5c29) No inactive management server node found 2026-01-10 16:54:44,097 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-e1cee940]) (logid:f0fa5c29) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:44,255 WARN [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) Unable to allocate console proxy standby capacity for zone [Zone {"id": "1", "name": "CSPOC", "uuid": "1334298c-cfec-4ee6-afbd-dabdfcd8dacf"}] due to [Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}.]. com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}. at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5954) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:6075) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:698) 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:646) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) at java.base/java.lang.Thread.run(Thread.java:1583) 2026-01-10 16:54:44,256 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) received console proxy alert 2026-01-10 16:54:44,257 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) Console proxy creation failure. Zone [CSPOC]. 2026-01-10 16:54:44,259 WARN [c.c.a.AlertManagerImpl] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) alertType=[10] dataCenterId=[1] podId=[null] clusterId=[null] message=[Console proxy creation failure. Zone [CSPOC]. Error details: Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}.]. 2026-01-10 16:54:44,263 WARN [c.c.a.AlertManagerImpl] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Console proxy creation failure. Zone [CSPOC]. Error details: Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}.] and content [Console proxy creation failure (zone CSPOC)]. 2026-01-10 16:54:44,264 WARN [c.c.v.SystemVmLoadScanner$1] (consoleproxy-1:[ctx-52832cbe]) (logid:afda88ce) Unexpected exception Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}. com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}. at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5954) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:6075) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:698) 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:646) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) at java.base/java.lang.Thread.run(Thread.java:1583) 2026-01-10 16:54:44,297 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) received secondary storage vm alert 2026-01-10 16:54:44,298 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) Secondary Storage Vm creation failure in zone [CSPOC]. 2026-01-10 16:54:44,300 WARN [c.c.a.AlertManagerImpl] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) alertType=[19] dataCenterId=[1] podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure in zone [CSPOC]. Error details: Unable to allocate capacity on zone [1] due to [null].]. 2026-01-10 16:54:44,304 WARN [c.c.a.AlertManagerImpl] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Secondary Storage Vm creation failure in zone [CSPOC]. Error details: Unable to allocate capacity on zone [1] due to [null].] and content [Secondary Storage Vm creation failure (zone CSPOC)]. 2026-01-10 16:54:44,305 WARN [c.c.v.SystemVmLoadScanner$1] (secstorage-1:[ctx-1d1d9897]) (logid:eacb5cb5) Unexpected exception Unable to orchestrate the start of VM instance {"instanceName":"s-1-VM","uuid":"72abc787-b8a8-4afa-a8f0-f1ad723e404b"}. com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate the start of VM instance {"instanceName":"s-1-VM","uuid":"72abc787-b8a8-4afa-a8f0-f1ad723e404b"}. at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5954) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:6075) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:698) 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:646) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) at java.base/java.lang.Thread.run(Thread.java:1583) 2026-01-10 16:54:44,630 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-6:[ctx-ad674fc1]) (logid:f092f5a9) HA health check task is running... 2026-01-10 16:54:45,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-d4fb5eaf]) (logid:bb8bcff1) No inactive management server node found 2026-01-10 16:54:45,596 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-d4fb5eaf]) (logid:bb8bcff1) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:47,100 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-5ff078e8]) (logid:9c2838d9) No inactive management server node found 2026-01-10 16:54:47,100 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-5ff078e8]) (logid:9c2838d9) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:48,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-3cb78272]) (logid:2b47b8ea) No inactive management server node found 2026-01-10 16:54:48,596 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-3cb78272]) (logid:2b47b8ea) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:48,631 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-1:[ctx-4f484c46]) (logid:8419c96e) HA health check task is running... 2026-01-10 16:54:50,097 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-715dd17a]) (logid:be75586e) No inactive management server node found 2026-01-10 16:54:50,097 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-715dd17a]) (logid:be75586e) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:50,530 DEBUG [c.c.a.ApiServlet] (qtp1047478056-545:[ctx-e4af6513]) (logid:15684cd1) ===START=== 10.10.100.254 -- GET managementserverid=902855be-c422-4040-9efe-c9db68372337&command=readyForShutdown&response=json& 2026-01-10 16:54:50,530 DEBUG [c.c.a.ApiServlet] (qtp1047478056-545:[ctx-e4af6513]) (logid:15684cd1) Two factor authentication is already verified for the user 2, so skipping 2026-01-10 16:54:50,537 DEBUG [c.c.a.ApiServer] (qtp1047478056-545:[ctx-e4af6513, ctx-d02efad2]) (logid:15684cd1) CIDRs from which account 'Account [{"accountName":"admin","id":2,"uuid":"9c6504ab-ee3a-11f0-bd36-de01a885d20e"}]' is allowed to perform API calls: 0.0.0.0/0,::/0 2026-01-10 16:54:50,539 INFO [o.a.c.a.DynamicRoleBasedAPIAccessChecker] (qtp1047478056-545:[ctx-e4af6513, ctx-d02efad2]) (logid:15684cd1) Account for user id 9c6572ae-ee3a-11f0-bd36-de01a885d20e is Root Admin or Domain Admin, all APIs are allowed. 2026-01-10 16:54:50,539 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker] (qtp1047478056-545:[ctx-e4af6513, ctx-d02efad2]) (logid:15684cd1) RoleService is enabled. We will use it instead of StaticRoleBasedAPIAccessChecker. 2026-01-10 16:54:50,539 DEBUG [o.a.c.r.ApiRateLimitServiceImpl] (qtp1047478056-545:[ctx-e4af6513, ctx-d02efad2]) (logid:15684cd1) API rate limiting is disabled. We will not use ApiRateLimitService. 2026-01-10 16:54:50,543 DEBUG [c.c.a.ApiServlet] (qtp1047478056-545:[ctx-e4af6513, ctx-d02efad2]) (logid:15684cd1) ===END=== 10.10.100.254 -- GET managementserverid=902855be-c422-4040-9efe-c9db68372337&command=readyForShutdown&response=json& 2026-01-10 16:54:51,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-da4ac5e8]) (logid:9761d79d) No inactive management server node found 2026-01-10 16:54:51,596 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-da4ac5e8]) (logid:9761d79d) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:52,633 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-4:[ctx-26e5fb28]) (logid:20674040) HA health check task is running... 2026-01-10 16:54:53,097 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-b65b4ce3]) (logid:fd692a70) No inactive management server node found 2026-01-10 16:54:53,097 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-b65b4ce3]) (logid:fd692a70) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:54,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-5ef69965]) (logid:6147b2bd) No inactive management server node found 2026-01-10 16:54:54,596 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-5ef69965]) (logid:6147b2bd) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:56,097 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-b4173d67]) (logid:3f49a256) No inactive management server node found 2026-01-10 16:54:56,097 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-b4173d67]) (logid:3f49a256) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:56,634 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-6:[ctx-8ee5503e]) (logid:15d87aea) HA health check task is running... 2026-01-10 16:54:57,597 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-2ef4f5ef]) (logid:1483b8aa) No inactive management server node found 2026-01-10 16:54:57,597 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-2ef4f5ef]) (logid:1483b8aa) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:54:59,096 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-ef9900e7]) (logid:03a19ace) No inactive management server node found 2026-01-10 16:54:59,096 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-ef9900e7]) (logid:03a19ace) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:00,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-590fd4f8]) (logid:29b7e33b) No inactive management server node found 2026-01-10 16:55:00,596 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-590fd4f8]) (logid:29b7e33b) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:00,635 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-1:[ctx-6f3c6468]) (logid:ebaa5e40) HA health check task is running... 2026-01-10 16:55:02,097 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-497b1ed7]) (logid:3e461091) No inactive management server node found 2026-01-10 16:55:02,097 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-497b1ed7]) (logid:3e461091) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:03,597 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-13335966]) (logid:e770d3b3) No inactive management server node found 2026-01-10 16:55:03,597 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-13335966]) (logid:e770d3b3) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:04,637 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-4:[ctx-c7a402e0]) (logid:0f199f88) HA health check task is running... 2026-01-10 16:55:05,096 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-f00eb544]) (logid:200f8fcd) No inactive management server node found 2026-01-10 16:55:05,096 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-f00eb544]) (logid:200f8fcd) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:06,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-4378b4cd]) (logid:954b9b91) No inactive management server node found 2026-01-10 16:55:06,596 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-4378b4cd]) (logid:954b9b91) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:07,897 DEBUG [c.c.s.StatsCollector] (Cluster-Worker-7:[ctx-427ab4d5]) (logid:57a4a188) StatusUpdate from 11186894151426, json: {"managementServerHostId":1,"managementServerHostUuid":"ba488de4-06d6-4b0d-ad0d-a286800f7e4f","managementServerRunId":1768059584183,"collectionTime":"2026-01-10T16:55:07+0000","sessions":0,"cpuUtilization":0.0,"totalJvmMemoryBytes":1855455232,"freeJvmMemoryBytes":1331542840,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":4558317,"jvmStartTime":1768059549522,"availableProcessors":48,"loadAverage":0.4931640625,"totalInit":2155151360,"totalUsed":768163080,"totalCommitted":2104688640,"pid":13478,"jvmName":"[email protected]","jvmVendor":"Ubuntu","jvmVersion":"21.0.9+10-Ubuntu-124.04","osDistribution":"Ubuntu 24.04.3 LTS","lastAgents":[],"agents":["928f7d8f-3e0a-4c09-a0b9-13ba8522bedd"],"agentCount":1,"heapMemoryUsed":524523104,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threadsDaemonCount":18,"threadsRunnableC ount":31,"threadsTerminatedCount":0,"threadsTotalCount":268,"threadsWaitingCount":157,"systemMemoryTotal":1081788805120,"systemMemoryFree":1072993984512,"systemMemoryUsed":1374416,"systemMemoryVirtualSize":25273212928,"logInfo":"","systemTotalCpuCycles":59355.951,"systemLoadAverages":[0.49,0.51,0.4],"systemCyclesUsage":[169315,26833,25689037],"dbLocal":false,"usageLocal":false,"systemBootTime":"2026-01-10T19:25:05+0000","kernelVersion":"6.8.0-90-generic"} 2026-01-10 16:55:08,097 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-9bc43de4]) (logid:d95e22e5) No inactive management server node found 2026-01-10 16:55:08,097 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-9bc43de4]) (logid:d95e22e5) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:08,203 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) Enabled non-edge zones available for scan: 1 2026-01-10 16:55:08,209 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) Zone Zone {"id": "1", "name": "CSPOC", "uuid": "1334298c-cfec-4ee6-afbd-dabdfcd8dacf"} is ready to launch console proxy 2026-01-10 16:55:08,211 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) Expand console proxy standby capacity for zone CSPOC 2026-01-10 16:55:08,212 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) Allocating console proxy standby capacity for zone [Zone {"id": "1", "name": "CSPOC", "uuid": "1334298c-cfec-4ee6-afbd-dabdfcd8dacf"}]. 2026-01-10 16:55:08,213 INFO [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) Found a stopped console proxy, starting it. VM: Console VM instance {"id":2,"instanceName":"v-2-VM","state":"Stopped","type":"ConsoleProxy","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"} 2026-01-10 16:55:08,216 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) start parameter value of enterHardwareSetup == <very null> during processing of queued job 2026-01-10 16:55:08,229 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) Sync job-58 execution on object VmWorkJobQueue.2 2026-01-10 16:55:08,246 DEBUG [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) Enabled non-edge zones available for scan: 1 2026-01-10 16:55:08,253 DEBUG [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) Zone [1] is ready to launch secondary storage VM. 2026-01-10 16:55:08,259 INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) No running secondary storage vms found in datacenter id=1, starting one 2026-01-10 16:55:08,261 DEBUG [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) Allocate secondary storage VM standby capacity for zone [1]. 2026-01-10 16:55:08,263 INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) Found a stopped secondary storage VM instance {"id":1,"instanceName":"s-1-VM","state":"Stopped","type":"SecondaryStorageVm","uuid":"72abc787-b8a8-4afa-a8f0-f1ad723e404b"}, starting it. 2026-01-10 16:55:08,265 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) start parameter value of enterHardwareSetup == <very null> during processing of queued job 2026-01-10 16:55:08,274 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) Sync job-59 execution on object VmWorkJobQueue.1 2026-01-10 16:55:08,639 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-6:[ctx-70fa52dd]) (logid:edc828b7) HA health check task is running... 2026-01-10 16:55:09,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-24bee354]) (logid:de53f4d8) No inactive management server node found 2026-01-10 16:55:09,596 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-24bee354]) (logid:de53f4d8) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 2ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:11,098 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-0a4656c9]) (logid:84692406) No inactive management server node found 2026-01-10 16:55:11,098 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-0a4656c9]) (logid:84692406) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:12,597 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-602dfac7]) (logid:0a079773) No inactive management server node found 2026-01-10 16:55:12,597 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-602dfac7]) (logid:0a079773) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:12,640 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-1:[ctx-d78bde75]) (logid:a2a87ce9) HA health check task is running... 2026-01-10 16:55:13,928 DEBUG [c.c.s.S.DbCollector] (StatsCollector-5:[ctx-7c1c3e91]) (logid:31174fc1) DbCollector is running... 2026-01-10 16:55:13,971 DEBUG [c.c.n.E.ExternalDeviceNetworkUsageTask] (ExternalNetworkMonitor-1:[ctx-e32297fd]) (logid:2fb3d192) External devices are not used. Skipping external device usage collection 2026-01-10 16:55:13,980 DEBUG [o.a.c.b.BackupManagerImpl] (BackupPollTask:[ctx-48e54a6d]) (logid:e94205d1) Backup backup.poll is being called at 2026-01-10T16:55:13+0000 2026-01-10 16:55:13,986 DEBUG [c.c.n.r.V.NetworkUsageTask] (RouterMonitor-1:[ctx-dac7a463]) (logid:eaac6fd0) Found 0 running routers. 2026-01-10 16:55:13,986 DEBUG [c.c.n.r.V.CheckRouterTask] (RouterStatusMonitor-1:[ctx-1d115f6e]) (logid:f6892b5d) Found 0 routers to update status. 2026-01-10 16:55:13,987 DEBUG [c.c.n.r.V.CheckRouterTask] (RouterStatusMonitor-1:[ctx-1d115f6e]) (logid:f6892b5d) Found 0 VPC's to update Redundant State. 2026-01-10 16:55:13,988 DEBUG [c.c.n.r.V.CheckRouterTask] (RouterStatusMonitor-1:[ctx-1d115f6e]) (logid:f6892b5d) Found 0 networks to update RvR status. 2026-01-10 16:55:14,037 INFO [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:[ctx-6a77443b]) (logid:a57732a6) Verifying the current state of [0] snapshot schedules and scheduling next jobs, if necessary. 2026-01-10 16:55:14,038 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:[ctx-6a77443b]) (logid:a57732a6) Snapshot scheduler is being called at [2026-01-10T16:55:14+0000]. 2026-01-10 16:55:14,039 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:[ctx-6a77443b]) (logid:a57732a6) There are [0] scheduled snapshots to be executed at [2026-01-10T16:55:14+0000]. 2026-01-10 16:55:14,095 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-dd622448]) (logid:350b7d3d) No inactive management server node found 2026-01-10 16:55:14,096 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-dd622448]) (logid:350b7d3d) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:14,264 WARN [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) Unable to allocate console proxy standby capacity for zone [Zone {"id": "1", "name": "CSPOC", "uuid": "1334298c-cfec-4ee6-afbd-dabdfcd8dacf"}] due to [Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}.]. com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}. at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5954) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:6075) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:698) 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:646) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) at java.base/java.lang.Thread.run(Thread.java:1583) 2026-01-10 16:55:14,264 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) received console proxy alert 2026-01-10 16:55:14,265 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) Console proxy creation failure. Zone [CSPOC]. 2026-01-10 16:55:14,268 WARN [c.c.a.AlertManagerImpl] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) alertType=[10] dataCenterId=[1] podId=[null] clusterId=[null] message=[Console proxy creation failure. Zone [CSPOC]. Error details: Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}.]. 2026-01-10 16:55:14,274 WARN [c.c.a.AlertManagerImpl] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Console proxy creation failure. Zone [CSPOC]. Error details: Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}.] and content [Console proxy creation failure (zone CSPOC)]. 2026-01-10 16:55:14,275 WARN [c.c.v.SystemVmLoadScanner$1] (consoleproxy-1:[ctx-a1684e2b]) (logid:65c48fc5) Unexpected exception Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}. com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate the start of VM instance {"instanceName":"v-2-VM","uuid":"a0ea4a34-7c54-47cf-ae0c-ae6aa461de3f"}. at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5954) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:6075) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:698) 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:646) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) at java.base/java.lang.Thread.run(Thread.java:1583) 2026-01-10 16:55:14,300 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) received secondary storage vm alert 2026-01-10 16:55:14,301 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) Secondary Storage Vm creation failure in zone [CSPOC]. 2026-01-10 16:55:14,302 WARN [c.c.a.AlertManagerImpl] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) alertType=[19] dataCenterId=[1] podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure in zone [CSPOC]. Error details: Unable to allocate capacity on zone [1] due to [null].]. 2026-01-10 16:55:14,306 WARN [c.c.a.AlertManagerImpl] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Secondary Storage Vm creation failure in zone [CSPOC]. Error details: Unable to allocate capacity on zone [1] due to [null].] and content [Secondary Storage Vm creation failure (zone CSPOC)]. 2026-01-10 16:55:14,307 WARN [c.c.v.SystemVmLoadScanner$1] (secstorage-1:[ctx-f0af7da1]) (logid:b73ddf5f) Unexpected exception Unable to orchestrate the start of VM instance {"instanceName":"s-1-VM","uuid":"72abc787-b8a8-4afa-a8f0-f1ad723e404b"}. com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate the start of VM instance {"instanceName":"s-1-VM","uuid":"72abc787-b8a8-4afa-a8f0-f1ad723e404b"}. at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5954) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:6075) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:698) 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:646) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) at java.base/java.lang.Thread.run(Thread.java:1583) 2026-01-10 16:55:14,927 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) ManagementServerCollector is running... 2026-01-10 16:55:14,928 DEBUG [c.c.u.d.DbProperties] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) DB properties were already loaded 2026-01-10 16:55:14,928 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Executing command [/bin/bash -c systemctl status cloudstack-usage | grep " Loaded:" ]. 2026-01-10 16:55:14,939 WARN [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Execution of process [74847] for command [/bin/bash -c systemctl status cloudstack-usage | grep " Loaded:" ] failed. 2026-01-10 16:55:14,940 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Exit value of process [74847] for command [/bin/bash -c systemctl status cloudstack-usage | grep " Loaded:" ] is [1]. 2026-01-10 16:55:14,940 WARN [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Process [74847] for command [/bin/bash -c systemctl status cloudstack-usage | grep " Loaded:" ] encountered the error: [Unit cloudstack-usage.service could not be found.]. 2026-01-10 16:55:14,940 DEBUG [c.c.s.StatsCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) usage install: null 2026-01-10 16:55:14,940 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Sessions active: 1 2026-01-10 16:55:14,940 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Executing command [/bin/bash -c cat /etc/os-release | grep PRETTY_NAME | cut -f2 -d '=' | tr -d '"' ]. 2026-01-10 16:55:14,947 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Successfully executed process [74850] for command [/bin/bash -c cat /etc/os-release | grep PRETTY_NAME | cut -f2 -d '=' | tr -d '"' ]. 2026-01-10 16:55:14,947 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Executing command [/bin/bash -c uname -r ]. 2026-01-10 16:55:14,952 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Successfully executed process [74855] for command [/bin/bash -c uname -r ]. 2026-01-10 16:55:14,953 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Executing command [/bin/bash -c cat /proc/meminfo | grep MemTotal | cut -f 2 -d ':' | tr -d 'a-zA-z ' ]. 2026-01-10 16:55:14,958 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Successfully executed process [74856] for command [/bin/bash -c cat /proc/meminfo | grep MemTotal | cut -f 2 -d ':' | tr -d 'a-zA-z ' ]. 2026-01-10 16:55:14,958 INFO [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) system memory from /proc: 1081788710912 2026-01-10 16:55:14,958 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Executing command [/bin/bash -c cat /proc/meminfo | grep MemFree | cut -f 2 -d ':' | tr -d 'a-zA-z ' ]. 2026-01-10 16:55:14,964 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Successfully executed process [74861] for command [/bin/bash -c cat /proc/meminfo | grep MemFree | cut -f 2 -d ':' | tr -d 'a-zA-z ' ]. 2026-01-10 16:55:14,964 INFO [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) free memory from /proc: 1070586175488 2026-01-10 16:55:14,964 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Executing command [/bin/bash -c ps -o rss= 18579 ]. 2026-01-10 16:55:14,982 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Successfully executed process [74866] for command [/bin/bash -c ps -o rss= 18579 ]. 2026-01-10 16:55:14,982 INFO [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) used memory from /proc: 1406056 2026-01-10 16:55:14,982 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Executing command [/bin/bash -c date -d @$(grep btime /proc/stat | awk '{print $2}') '+%Y-%m-%d %H:%M:%S' ]. 2026-01-10 16:55:14,988 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Successfully executed process [74867] for command [/bin/bash -c date -d @$(grep btime /proc/stat | awk '{print $2}') '+%Y-%m-%d %H:%M:%S' ]. 2026-01-10 16:55:14,988 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Executing command [/bin/bash -c ps -o vsz= 18579 ]. 2026-01-10 16:55:15,006 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Successfully executed process [74871] for command [/bin/bash -c ps -o vsz= 18579 ]. 2026-01-10 16:55:15,006 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Executing command [/bin/bash -c cat /proc/cpuinfo | grep "cpu MHz" | grep "cpu MHz" | cut -f 2 -d : | tr -d ' '| tr '\n' " " ]. 2026-01-10 16:55:15,013 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Successfully executed process [74872] for command [/bin/bash -c cat /proc/cpuinfo | grep "cpu MHz" | grep "cpu MHz" | cut -f 2 -d : | tr -d ' '| tr '\n' " " ]. 2026-01-10 16:55:15,013 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Executing command [/bin/bash -c cat /proc/loadavg ]. 2026-01-10 16:55:15,015 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Successfully executed process [74879] for command [/bin/bash -c cat /proc/loadavg ]. 2026-01-10 16:55:15,015 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Executing command [/bin/bash -c cat /proc/stat | grep "cpu " | tr -d "cpu" ]. 2026-01-10 16:55:15,020 DEBUG [c.c.u.s.Script] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Successfully executed process [74880] for command [/bin/bash -c cat /proc/stat | grep "cpu " | tr -d "cpu" ]. 2026-01-10 16:55:15,021 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail buffersdirect.capacity, 1044286 2026-01-10 16:55:15,021 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail buffersdirect.count, 155 2026-01-10 16:55:15,021 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail buffersdirect.used, 1044286 2026-01-10 16:55:15,021 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail buffersmapped.capacity, 13587365 2026-01-10 16:55:15,021 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail buffersmapped.count, 407 2026-01-10 16:55:15,021 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail buffersmapped.used, 13587365 2026-01-10 16:55:15,021 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail gcPS-MarkSweep.count, 5 2026-01-10 16:55:15,021 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail gcPS-MarkSweep.time, 623 2026-01-10 16:55:15,021 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail gcPS-Scavenge.count, 53 2026-01-10 16:55:15,021 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail gcPS-Scavenge.time, 507 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail jvmname, [email protected] 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail jvmuptime, 4532539 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail jvmvendor, Ubuntu OpenJDK 64-Bit Server VM 21.0.9+10-Ubuntu-124.04 (21) 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memoryheap.committed, 1860698112 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memoryheap.init, 2147483648 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memoryheap.usage, 0.3067401654443319 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorynon-heap.committed, 255787008 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorynon-heap.init, 7667712 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorynon-heap.max, -1 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorynon-heap.usage, -2.50153912E8 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorynon-heap.used, 250153912 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorypools.CodeHeap-'non-nmethods'.usage, 0.24022363818090955 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorypools.CodeHeap-'non-profiled-nmethods'.usage, 0.205090217025572 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorypools.CodeHeap-'profiled-nmethods'.usage, 0.39928581042430766 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorypools.Compressed-Class-Space.usage, 0.014417625963687897 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorypools.Metaspace.usage, 0.9866643267790024 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorypools.PS-Eden-Space.usage, 0.6055549948037898 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorypools.PS-Old-Gen.usage, 0.11734343465541755 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorypools.PS-Survivor-Space.usage, 0.9812372381036932 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorytotal.committed, 2116485120 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorytotal.init, 2155151360 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorytotal.max, 1908932607 2026-01-10 16:55:15,022 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail memorytotal.used, 835813048 2026-01-10 16:55:15,023 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail threadsdeadlocks, [] 2026-01-10 16:55:15,023 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail threadsnew.count, 0 2026-01-10 16:55:15,023 DEBUG [c.c.s.S.ManagementServerCollector] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) not storing detail threadstimed_waiting.count, 87 2026-01-10 16:55:15,024 DEBUG [c.c.c.ClusterManagerImpl] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Forwarding {"managementServerHostId":2,"managementServerHostUuid":"902855be-c422-4040-9efe-c9db68372337","managementServerRunId":1768059599347,"collectionTime":"2026-01-10T16:55:14+0000","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":1860698112,"freeJvmMemoryBytes":1276023360,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":4532457,"jvmStartTime":1768059582510,"availableProcessors":48,"loadAverage":0.09375,"totalInit":2155151360,"totalUsed":834826104,"totalCommitted":2116485120,"pid":18579,"jvmName":"[email protected]","jvmVendor":"Ubuntu","jvmVersion":"21.0.9+10-Ubuntu-124.04","osDistribution":"Ubuntu 24.04.3 LTS","lastAgents":[],"agents":[],"agentCount":0,"heapMemoryUsed":585546304,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threadsDaemonCount":18,"threadsRunnableCount":31,"threadsTerminatedCount":0,"threadsTotalCount":264,"threads WaitingCount":146,"systemMemoryTotal":1081788710912,"systemMemoryFree":1070586175488,"systemMemoryUsed":1406056,"systemMemoryVirtualSize":24993816576,"logInfo":"","systemTotalCpuCycles":59420.138,"systemLoadAverages":[0.09,0.5,0.58],"systemCyclesUsage":[188077,35478,26175444],"dbLocal":false,"usageLocal":false,"systemBootTime":"2026-01-10T19:23:20+0000","kernelVersion":"6.8.0-90-generic"} to ManagementServer {"id":1,"msid":11186894151426,"name":"cskvm03.poc.local","uuid":"ba488de4-06d6-4b0d-ad0d-a286800f7e4f"} 2026-01-10 16:55:15,025 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Worker-3:[ctx-9b8c7f3e]) (logid:d3314045) Cluster PDU 244098703675918 -> 11186894151426. agent: 0, pdu seq: 391, pdu ack seq: 0, json: {"managementServerHostId":2,"managementServerHostUuid":"902855be-c422-4040-9efe-c9db68372337","managementServerRunId":1768059599347,"collectionTime":"2026-01-10T16:55:14+0000","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":1860698112,"freeJvmMemoryBytes":1276023360,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":4532457,"jvmStartTime":1768059582510,"availableProcessors":48,"loadAverage":0.09375,"totalInit":2155151360,"totalUsed":834826104,"totalCommitted":2116485120,"pid":18579,"jvmName":"[email protected]","jvmVendor":"Ubuntu","jvmVersion":"21.0.9+10-Ubuntu-124.04","osDistribution":"Ubuntu 24.04.3 LTS","lastAgents":[],"agents":[],"agentCount":0,"heapMemoryUsed":585546304,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threadsDaemonCount":18,"th readsRunnableCount":31,"threadsTerminatedCount":0,"threadsTotalCount":264,"threadsWaitingCount":146,"systemMemoryTotal":1081788710912,"systemMemoryFree":1070586175488,"systemMemoryUsed":1406056,"systemMemoryVirtualSize":24993816576,"logInfo":"","systemTotalCpuCycles":59420.138,"systemLoadAverages":[0.09,0.5,0.58],"systemCyclesUsage":[188077,35478,26175444],"dbLocal":false,"usageLocal":false,"systemBootTime":"2026-01-10T19:23:20+0000","kernelVersion":"6.8.0-90-generic"} 2026-01-10 16:55:15,024 DEBUG [c.c.c.ClusterManagerImpl] (StatsCollector-4:[ctx-e5e9426c]) (logid:e446cdf7) Forwarding {"managementServerHostId":2,"managementServerHostUuid":"902855be-c422-4040-9efe-c9db68372337","managementServerRunId":1768059599347,"collectionTime":"2026-01-10T16:55:14+0000","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":1860698112,"freeJvmMemoryBytes":1276023360,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":4532457,"jvmStartTime":1768059582510,"availableProcessors":48,"loadAverage":0.09375,"totalInit":2155151360,"totalUsed":834826104,"totalCommitted":2116485120,"pid":18579,"jvmName":"[email protected]","jvmVendor":"Ubuntu","jvmVersion":"21.0.9+10-Ubuntu-124.04","osDistribution":"Ubuntu 24.04.3 LTS","lastAgents":[],"agents":[],"agentCount":0,"heapMemoryUsed":585546304,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threadsDaemonCount":18,"threadsRunnableCount":31,"threadsTerminatedCount":0,"threadsTotalCount":264,"threads WaitingCount":146,"systemMemoryTotal":1081788710912,"systemMemoryFree":1070586175488,"systemMemoryUsed":1406056,"systemMemoryVirtualSize":24993816576,"logInfo":"","systemTotalCpuCycles":59420.138,"systemLoadAverages":[0.09,0.5,0.58],"systemCyclesUsage":[188077,35478,26175444],"dbLocal":false,"usageLocal":false,"systemBootTime":"2026-01-10T19:23:20+0000","kernelVersion":"6.8.0-90-generic"} to ManagementServer {"id":2,"msid":244098703675918,"name":"cskvm01.poc.local","uuid":"902855be-c422-4040-9efe-c9db68372337"} 2026-01-10 16:55:15,025 DEBUG [c.c.c.ClusterServiceServletImpl] (Cluster-Worker-3:[ctx-9b8c7f3e]) (logid:d3314045) Executing ClusterServicePdu with service URL: https://10.50.11.103:9090/clusterservice 2026-01-10 16:55:15,025 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Worker-1:[ctx-d3d861eb]) (logid:5fa8a28d) Cluster PDU 244098703675918 -> 244098703675918. agent: 0, pdu seq: 392, pdu ack seq: 0, json: {"managementServerHostId":2,"managementServerHostUuid":"902855be-c422-4040-9efe-c9db68372337","managementServerRunId":1768059599347,"collectionTime":"2026-01-10T16:55:14+0000","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":1860698112,"freeJvmMemoryBytes":1276023360,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":4532457,"jvmStartTime":1768059582510,"availableProcessors":48,"loadAverage":0.09375,"totalInit":2155151360,"totalUsed":834826104,"totalCommitted":2116485120,"pid":18579,"jvmName":"[email protected]","jvmVendor":"Ubuntu","jvmVersion":"21.0.9+10-Ubuntu-124.04","osDistribution":"Ubuntu 24.04.3 LTS","lastAgents":[],"agents":[],"agentCount":0,"heapMemoryUsed":585546304,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threadsDaemonCount":18,"t hreadsRunnableCount":31,"threadsTerminatedCount":0,"threadsTotalCount":264,"threadsWaitingCount":146,"systemMemoryTotal":1081788710912,"systemMemoryFree":1070586175488,"systemMemoryUsed":1406056,"systemMemoryVirtualSize":24993816576,"logInfo":"","systemTotalCpuCycles":59420.138,"systemLoadAverages":[0.09,0.5,0.58],"systemCyclesUsage":[188077,35478,26175444],"dbLocal":false,"usageLocal":false,"systemBootTime":"2026-01-10T19:23:20+0000","kernelVersion":"6.8.0-90-generic"} 2026-01-10 16:55:15,025 DEBUG [c.c.c.ClusterServiceServletImpl] (Cluster-Worker-1:[ctx-d3d861eb]) (logid:5fa8a28d) Executing ClusterServicePdu with service URL: https://10.50.11.101:9090/clusterservice 2026-01-10 16:55:15,029 DEBUG [c.c.s.StatsCollector] (Cluster-Worker-7:[ctx-d5487bf7]) (logid:05c86efc) StatusUpdate from 244098703675918, json: {"managementServerHostId":2,"managementServerHostUuid":"902855be-c422-4040-9efe-c9db68372337","managementServerRunId":1768059599347,"collectionTime":"2026-01-10T16:55:14+0000","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":1860698112,"freeJvmMemoryBytes":1276023360,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":4532457,"jvmStartTime":1768059582510,"availableProcessors":48,"loadAverage":0.09375,"totalInit":2155151360,"totalUsed":834826104,"totalCommitted":2116485120,"pid":18579,"jvmName":"[email protected]","jvmVendor":"Ubuntu","jvmVersion":"21.0.9+10-Ubuntu-124.04","osDistribution":"Ubuntu 24.04.3 LTS","lastAgents":[],"agents":[],"agentCount":0,"heapMemoryUsed":585546304,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threadsDaemonCount":18,"threadsRunnableCount":31,"threadsTerminatedCount":0,"threa dsTotalCount":264,"threadsWaitingCount":146,"systemMemoryTotal":1081788710912,"systemMemoryFree":1070586175488,"systemMemoryUsed":1406056,"systemMemoryVirtualSize":24993816576,"logInfo":"","systemTotalCpuCycles":59420.138,"systemLoadAverages":[0.09,0.5,0.58],"systemCyclesUsage":[188077,35478,26175444],"dbLocal":false,"usageLocal":false,"systemBootTime":"2026-01-10T19:23:20+0000","kernelVersion":"6.8.0-90-generic"} 2026-01-10 16:55:15,029 DEBUG [c.c.c.ClusterServiceServletImpl] (Cluster-Worker-1:[ctx-d3d861eb]) (logid:5fa8a28d) POST https://10.50.11.101:9090/clusterservice response :true, responding time: 4 ms 2026-01-10 16:55:15,029 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Worker-1:[ctx-d3d861eb]) (logid:5fa8a28d) Cluster PDU 244098703675918 -> 244098703675918 completed. time: 4ms. agent: 0, pdu seq: 392, pdu ack seq: 0, json: {"managementServerHostId":2,"managementServerHostUuid":"902855be-c422-4040-9efe-c9db68372337","managementServerRunId":1768059599347,"collectionTime":"2026-01-10T16:55:14+0000","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":1860698112,"freeJvmMemoryBytes":1276023360,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":4532457,"jvmStartTime":1768059582510,"availableProcessors":48,"loadAverage":0.09375,"totalInit":2155151360,"totalUsed":834826104,"totalCommitted":2116485120,"pid":18579,"jvmName":"[email protected]","jvmVendor":"Ubuntu","jvmVersion":"21.0.9+10-Ubuntu-124.04","osDistribution":"Ubuntu 24.04.3 LTS","lastAgents":[],"agents":[],"agentCount":0,"heapMemoryUsed":585546304,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"thre adsDaemonCount":18,"threadsRunnableCount":31,"threadsTerminatedCount":0,"threadsTotalCount":264,"threadsWaitingCount":146,"systemMemoryTotal":1081788710912,"systemMemoryFree":1070586175488,"systemMemoryUsed":1406056,"systemMemoryVirtualSize":24993816576,"logInfo":"","systemTotalCpuCycles":59420.138,"systemLoadAverages":[0.09,0.5,0.58],"systemCyclesUsage":[188077,35478,26175444],"dbLocal":false,"usageLocal":false,"systemBootTime":"2026-01-10T19:23:20+0000","kernelVersion":"6.8.0-90-generic"} 2026-01-10 16:55:15,031 DEBUG [c.c.c.ClusterServiceServletImpl] (Cluster-Worker-3:[ctx-9b8c7f3e]) (logid:d3314045) POST https://10.50.11.103:9090/clusterservice response :true, responding time: 6 ms 2026-01-10 16:55:15,031 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Worker-3:[ctx-9b8c7f3e]) (logid:d3314045) Cluster PDU 244098703675918 -> 11186894151426 completed. time: 6ms. agent: 0, pdu seq: 391, pdu ack seq: 0, json: {"managementServerHostId":2,"managementServerHostUuid":"902855be-c422-4040-9efe-c9db68372337","managementServerRunId":1768059599347,"collectionTime":"2026-01-10T16:55:14+0000","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":1860698112,"freeJvmMemoryBytes":1276023360,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":4532457,"jvmStartTime":1768059582510,"availableProcessors":48,"loadAverage":0.09375,"totalInit":2155151360,"totalUsed":834826104,"totalCommitted":2116485120,"pid":18579,"jvmName":"[email protected]","jvmVendor":"Ubuntu","jvmVersion":"21.0.9+10-Ubuntu-124.04","osDistribution":"Ubuntu 24.04.3 LTS","lastAgents":[],"agents":[],"agentCount":0,"heapMemoryUsed":585546304,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threa dsDaemonCount":18,"threadsRunnableCount":31,"threadsTerminatedCount":0,"threadsTotalCount":264,"threadsWaitingCount":146,"systemMemoryTotal":1081788710912,"systemMemoryFree":1070586175488,"systemMemoryUsed":1406056,"systemMemoryVirtualSize":24993816576,"logInfo":"","systemTotalCpuCycles":59420.138,"systemLoadAverages":[0.09,0.5,0.58],"systemCyclesUsage":[188077,35478,26175444],"dbLocal":false,"usageLocal":false,"systemBootTime":"2026-01-10T19:23:20+0000","kernelVersion":"6.8.0-90-generic"} 2026-01-10 16:55:15,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-242bf9c0]) (logid:5d09dca0) No inactive management server node found 2026-01-10 16:55:15,596 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-242bf9c0]) (logid:5d09dca0) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:16,641 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-4:[ctx-5df60c13]) (logid:31327015) HA health check task is running... 2026-01-10 16:55:17,096 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-0b36506e]) (logid:7fd687eb) No inactive management server node found 2026-01-10 16:55:17,096 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-0b36506e]) (logid:7fd687eb) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:18,596 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-73901284]) (logid:b7d2284f) No inactive management server node found 2026-01-10 16:55:18,596 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-73901284]) (logid:b7d2284f) Peer scan is finished. profiler: Done. Duration: 2ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:18,943 DEBUG [c.c.v.V.CleanupTask] (Vm-Operations-Cleanup-1:[ctx-b7f9f550]) (logid:2daa157c) VM Operation Thread Running 2026-01-10 16:55:18,971 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-6deed206]) (logid:ff36ff2c) VM scheduler.poll is being called at 2026-01-10T16:55:00+0000 2026-01-10 16:55:18,975 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:[ctx-983b8b1e]) (logid:c4ca7172) Resetting hosts suitable for reconnect 2026-01-10 16:55:18,975 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-6deed206]) (logid:ff36ff2c) Got 0 scheduled jobs to be executed at 2026-01-10T16:55:00+0000 2026-01-10 16:55:18,976 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:[ctx-983b8b1e]) (logid:c4ca7172) Completed resetting hosts suitable for reconnect 2026-01-10 16:55:18,976 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:[ctx-983b8b1e]) (logid:c4ca7172) Acquiring hosts for clusters already owned by this management server 2026-01-10 16:55:18,976 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:[ctx-983b8b1e]) (logid:c4ca7172) Completed acquiring hosts for clusters already owned by this management server 2026-01-10 16:55:18,976 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:[ctx-983b8b1e]) (logid:c4ca7172) Acquiring hosts for clusters not owned by any management server 2026-01-10 16:55:18,977 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:[ctx-983b8b1e]) (logid:c4ca7172) Completed acquiring hosts for clusters not owned by any management server 2026-01-10 16:55:18,977 INFO [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-6deed206]) (logid:ff36ff2c) Cleaned up 0 VM scheduled job entries 2026-01-10 16:55:19,039 DEBUG [o.a.c.c.ClusterDrsServiceImpl] (VMSchedulerPollTask:[ctx-f4707d05]) (logid:25e79067) ClusterDRS.poll is being called at 2026-01-10T16:55:00+0000 2026-01-10 16:55:19,045 DEBUG [o.a.c.c.ClusterDrsServiceImpl] (VMSchedulerPollTask:[ctx-f4707d05]) (logid:25e79067) Removed 0 old drs migration plans 2026-01-10 16:55:19,091 DEBUG [o.a.c.b.B.BackupSyncTask] (BackgroundTaskPollManager-6:[ctx-e75312fe]) (logid:6db4cb81) Backup Sync Task is not enabled in zone [Zone {"id": "1", "name": "CSPOC", "uuid": "1334298c-cfec-4ee6-afbd-dabdfcd8dacf"}]. Skipping this zone! 2026-01-10 16:55:20,096 INFO [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-f1943ddf]) (logid:bbc318e6) No inactive management server node found 2026-01-10 16:55:20,096 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Heartbeat-1:[ctx-f1943ddf]) (logid:bbc318e6) Peer scan is finished. profiler: Done. Duration: 3ms , profilerQueryActiveList: Done. Duration: 1ms, , profilerSyncClusterInfo: Done. Duration: 0ms, profilerInvalidatedNodeList: Done. Duration: 0ms, profilerRemovedList: Done. Duration: 0ms,, profilerNewList: Done. Duration: 0ms, profilerInactiveList: Done. Duration: 0ms 2026-01-10 16:55:20,642 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-3:[ctx-826cc95a]) (logid:2797708e) HA health check task is running... ^C root@cskvm01:/var/log/cloudstack/management# ``` GitHub link: https://github.com/apache/cloudstack/discussions/12388#discussioncomment-15464012 ---- This is an automatically sent email for [email protected]. To unsubscribe, please send an email to: [email protected]
