SammyOina commented on issue #10319: URL: https://github.com/apache/cloudstack/issues/10319#issuecomment-2632407570
```shell 2025-02-03 23:18:59,575 ERROR [c.c.c.ClusterServiceServletImpl] (Cluster-Worker-3:[ctx-c6c2a092]) (logid:1cd75554) Exception from : https://127.0.0.1:9090/clusterservice, method : null, exception : javax.net.ssl.SSLPeerUnverifiedException: Certificate for <127.0.0.1> doesn't match any of the subject alternative names: [10.172.192.34, 10.172.192.30, fe80:0:0:0:ce96:e5ff:fef5:25bb, cloudstack.internal, ultraviolet.local] 2025-02-03 23:18:59,575 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Worker-3:[ctx-c6c2a092]) (logid:1cd75554) Cluster PDU 224948475209146 -> 224948475209146 completed. time: 1ms. agent: 0, pdu seq: 26, pdu ack seq: 0, json: {"managementServerHostId":1,"managementServerHostUuid":"6c6e9883-0c56-4fce-8cde-10bc9d666ef9","collectionTime":"Feb 3, 2025, 11:18:59 PM","sessions":1,"cpuUtilization":0.0,"totalJvmMemoryBytes":499646464,"freeJvmMemoryBytes":63666648,"maxJvmMemoryBytes":1908932607,"processJvmMemoryBytes":0,"jvmUptime":1523578,"jvmStartTime":1738623215954,"availableProcessors":24,"loadAverage":0.255859375,"totalInit":523567104,"totalUsed":666691872,"totalCommitted":737280000,"pid":308945,"jvmName":"[email protected]","jvmVendor":"Ubuntu","jvmVersion":"21.0.5+11-Ubuntu-1ubuntu124.04","osDistribution":"Ubuntu 24.04.1 LTS","agentCount":1,"heapMemoryUsed":436744784,"heapMemoryTotal":1908932608,"threadsBlockedCount":0,"threadsDaemonCount":17,"threadsRunnableCount":19,"threadsT erminatedCount":0,"threadsTotalCount":402,"threadsWaitingCount":305,"systemMemoryTotal":32965242880,"systemMemoryFree":16111304704,"systemMemoryUsed":1253684,"systemMemoryVirtualSize":17203412992,"logInfo":"","systemTotalCpuCycles":76346.82099999998,"systemLoadAverages":[0.26,0.1,0.18],"systemCyclesUsage":[486749,160113,102606275],"dbLocal":true,"usageLocal":false,"systemBootTime":"Feb 3, 2025, 11:20:59 AM","kernelVersion":"6.11.0+"} 2025-02-03 23:18:59,793 DEBUG [o.a.c.h.H.HAManagerBgPollTask] (BackgroundTaskPollManager-6:[ctx-ffdaf835]) (logid:6b3a1b8f) HA health check task is running... 2025-02-03 23:19:00,557 DEBUG [c.c.a.t.Request] (AgentManager-Handler-2:[]) (logid:) Seq 2-3494511835862794589: Processing: { Ans: , MgmtId: 224948475209146, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] } 2025-02-03 23:19:00,557 DEBUG [c.c.a.t.Request] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Seq 2-3494511835862794589: Received: { Ans: , MgmtId: 224948475209146, via: 2(ultraviolet.local), Ver: v1, Flags: 10, { StopAnswer } } 2025-02-03 23:19:00,561 DEBUG [c.c.n.g.ControlNetworkGuru] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Released nic: NicProfile {"broadcastUri":null,"deviceId":null,"iPv4Address":null,"id":1127,"reservationId":null,"vmId":660} for vm VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} 2025-02-03 23:19:00,561 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) The nic Nic {"broadcastUri":null,"deviceId":0,"iPv4Address":"169.254.213.95","id":1127,"instanceId":660,"reservationId":"77331f67-53f1-4fa4-8112-738d1dd97387"} on NicProfile {"broadcastUri":null,"deviceId":null,"iPv4Address":null,"id":1127,"reservationId":null,"vmId":660} was released according to VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} by guru com.cloud.network.guru.ControlNetworkGuru@48d54b1c, now updating record. 2025-02-03 23:19:00,564 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Releasing ip address for reservationId=77331f67-53f1-4fa4-8112-738d1dd97387, nic=1128 2025-02-03 23:19:00,564 DEBUG [c.c.n.g.PodBasedNetworkGuru] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Released nic: NicProfile {"broadcastUri":null,"deviceId":null,"iPv4Address":null,"id":1128,"reservationId":null,"vmId":660} for vm VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} 2025-02-03 23:19:00,564 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) The nic Nic {"broadcastUri":null,"deviceId":1,"iPv4Address":"172.16.10.30","id":1128,"instanceId":660,"reservationId":"77331f67-53f1-4fa4-8112-738d1dd97387"} on NicProfile {"broadcastUri":null,"deviceId":null,"iPv4Address":null,"id":1128,"reservationId":null,"vmId":660} was released according to VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} by guru com.cloud.network.guru.PodBasedNetworkGuru@1324605b, now updating record. 2025-02-03 23:19:00,565 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Successfully released network resources for the VM VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} in Starting state 2025-02-03 23:19:00,567 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Successfully released storage resources for the VM VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} in Starting state 2025-02-03 23:19:00,567 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Successfully cleaned up resources for the VM VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} in Starting state 2025-02-03 23:19:00,567 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) VM start attempt #2 2025-02-03 23:19:00,568 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Root volume is ready, need to place VM in volume's cluster 2025-02-03 23:19:00,568 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Vol[376|name=ROOT-660|vm=660|ROOT] is READY, changing deployment plan to use this pool's dcId: 2, podId: 2, and clusterId: 2 2025-02-03 23:19:00,568 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Trying to deploy VM [error decoding VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"}] and details: Plan [error decoding {"_clusterId":2,"_dcId":2,"_physicalNetworkId":null,"_podId":2,"_poolId":2,"migrationPlan":false}]; avoid list [{"_podIds":[],"_clusterIds":[],"_hostIds":[2]}] and planner: []. 2025-02-03 23:19:00,569 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Trying to allocate a host and storage pools from datacenter [{"name":"uv-dell-2","uuid":"bf6f5332-ddfc-4793-95b9-c1696e1b48dc"}], pod [{"name":"pod2","uuid":"6b30cf43-a40b-43c6-bc30-dba58280cb16"}], cluster [{"name":"cluster2","uuid":"dc1279a6-9c80-4be4-bd71-a30934575f38"}], to deploy VM [{"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"}] with requested CPU [500] and requested RAM [(512.00 MB) 536870912]. 2025-02-03 23:19:00,569 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) ROOT volume [42ae9d0b-d015-4219-9399-6e30f42e8ec8] is ready to deploy VM [db9ad80f-05d6-4082-94c5-191ddbecfb33]. 2025-02-03 23:19:00,570 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Adding pods [] to the avoid set because these pods are in the Disabled state. 2025-02-03 23:19:00,570 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Adding clusters [] of pod [2] to the void set because these clusters are in the Disabled state. 2025-02-03 23:19:00,571 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Adding hosts [] of datacenter [bf6f5332-ddfc-4793-95b9-c1696e1b48dc] to the avoid set, because these hosts are in the Disabled state. 2025-02-03 23:19:00,571 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) DeploymentPlan [DataCenterDeployment] has not specified host. Trying to find another destination to deploy VM [db9ad80f-05d6-4082-94c5-191ddbecfb33], avoiding pods [], clusters [] and hosts [2]. 2025-02-03 23:19:00,571 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Deploy avoids pods: [], clusters: [], hosts: [2]. 2025-02-03 23:19:00,571 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Deploy hosts with priorities {}, hosts have NORMAL priority by default 2025-02-03 23:19:00,571 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Searching resources only under specified Cluster: 2 2025-02-03 23:19:00,573 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Checking resources in Cluster: 2 under Pod: 2 2025-02-03 23:19:00,573 INFO [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac, FirstFitRoutingAllocator]) (logid:6d42f2b9) Guest VM is requested with Custom[UEFI] Boot Type false 2025-02-03 23:19:00,573 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac, FirstFitRoutingAllocator]) (logid:6d42f2b9) Looking for hosts in zone [2], pod [2], cluster [2] 2025-02-03 23:19:00,574 INFO [o.a.c.u.r.ReflectionToStringBuilderUtils] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac, FirstFitRoutingAllocator]) (logid:6d42f2b9) Collection [[]] is empty or has only null values, not reflecting it. 2025-02-03 23:19:00,574 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac, FirstFitRoutingAllocator]) (logid:6d42f2b9) Adding hosts [null] to the avoid set because these hosts do not support HA. 2025-02-03 23:19:00,574 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac, FirstFitRoutingAllocator]) (logid:6d42f2b9) FirstFitAllocator has 1 hosts to check for allocation: [Host {"id":2,"name":"ultraviolet.local","type":"Routing","uuid":"86b3b883-4b15-4328-a3fe-56e41cd46ad3"}] 2025-02-03 23:19:00,575 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac, FirstFitRoutingAllocator]) (logid:6d42f2b9) Found 1 hosts for allocation after prioritization: [Host {"id":2,"name":"ultraviolet.local","type":"Routing","uuid":"86b3b883-4b15-4328-a3fe-56e41cd46ad3"}] 2025-02-03 23:19:00,575 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac, FirstFitRoutingAllocator]) (logid:6d42f2b9) Looking for speed=500Mhz, Ram=512 MB 2025-02-03 23:19:00,575 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac, FirstFitRoutingAllocator]) (logid:6d42f2b9) Host name: ultraviolet.local, hostId: 2 is in avoid set, skipping this and trying other available hosts 2025-02-03 23:19:00,575 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac, FirstFitRoutingAllocator]) (logid:6d42f2b9) Host Allocator returning 0 suitable hosts 2025-02-03 23:19:00,575 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) No suitable hosts found. 2025-02-03 23:19:00,575 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) No suitable hosts found under this Cluster: 2 2025-02-03 23:19:00,575 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Could not find suitable Deployment Destination for this VM under any clusters, returning. 2025-02-03 23:19:00,576 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Searching resources only under specified Cluster: 2 2025-02-03 23:19:00,576 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) The specified cluster is in avoid set, returning. 2025-02-03 23:19:00,576 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) VM start attempt #3 2025-02-03 23:19:00,576 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Trying to deploy VM [error decoding VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"}] and details: Plan [error decoding {"_clusterId":null,"_dcId":2,"_physicalNetworkId":null,"_podId":2,"_poolId":null,"migrationPlan":false}]; avoid list [{"_podIds":[],"_clusterIds":[2],"_hostIds":[2]}] and planner: []. 2025-02-03 23:19:00,577 DEBUG [o.a.c.u.r.ReflectionToStringBuilderUtils] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Object is null, not reflecting it. 2025-02-03 23:19:00,577 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Trying to allocate a host and storage pools from datacenter [{"name":"uv-dell-2","uuid":"bf6f5332-ddfc-4793-95b9-c1696e1b48dc"}], pod [{"name":"pod2","uuid":"6b30cf43-a40b-43c6-bc30-dba58280cb16"}], cluster [null], to deploy VM [{"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"}] with requested CPU [500] and requested RAM [(512.00 MB) 536870912]. 2025-02-03 23:19:00,577 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) ROOT volume [42ae9d0b-d015-4219-9399-6e30f42e8ec8] is not ready to deploy VM [db9ad80f-05d6-4082-94c5-191ddbecfb33]. 2025-02-03 23:19:00,578 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Adding pods [] to the avoid set because these pods are in the Disabled state. 2025-02-03 23:19:00,578 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Adding clusters [] of pod [2] to the void set because these clusters are in the Disabled state. 2025-02-03 23:19:00,578 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Adding hosts [] of datacenter [bf6f5332-ddfc-4793-95b9-c1696e1b48dc] to the avoid set, because these hosts are in the Disabled state. 2025-02-03 23:19:00,579 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) DeploymentPlan [DataCenterDeployment] has not specified host. Trying to find another destination to deploy VM [db9ad80f-05d6-4082-94c5-191ddbecfb33], avoiding pods [], clusters [2] and hosts [2]. 2025-02-03 23:19:00,579 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Deploy avoids pods: [], clusters: [2], hosts: [2]. 2025-02-03 23:19:00,579 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Deploy hosts with priorities {}, hosts have NORMAL priority by default 2025-02-03 23:19:00,579 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Searching resources only under specified Pod: 2 2025-02-03 23:19:00,579 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Listing clusters in order of aggregate capacity, that have (at least one host with) enough CPU and RAM capacity under this Pod: 2 2025-02-03 23:19:00,580 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Removing from the clusterId list these clusters from avoid set: [2] 2025-02-03 23:19:00,580 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) No clusters found after removing disabled clusters and clusters in avoid list, returning. 2025-02-03 23:19:00,584 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} state transited from [Starting] to [Stopped] with event [OperationFailed]. VM's original host: null, new host: null, host before state transition: Host {"id":2,"name":"ultraviolet.local","type":"Routing","uuid":"86b3b883-4b15-4328-a3fe-56e41cd46ad3"} 2025-02-03 23:19:00,587 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Hosts's actual total CPU: 68256 and CPU after applying overprovisioning: 68256 2025-02-03 23:19:00,587 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Hosts's actual total RAM: (29.70 GB) 31891501056 and RAM after applying overprovisioning: (29.70 GB) 31891501056 2025-02-03 23:19:00,587 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) release cpu from host: 2, old used: 1000,reserved: 0, actual total: 68256, total with overprovisioning: 68256; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse 2025-02-03 23:19:00,587 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) release mem from host: 2, old used: (1.50 GB) 1610612736,reserved: (0 bytes) 0, total: (29.70 GB) 31891501056; new used: (1.00 GB) 1073741824,reserved:(0 bytes) 0; movedfromreserved: false,moveToReserveredfalse 2025-02-03 23:19:00,588 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Invocation exception, caused by: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"}Scope=interface com.cloud.dc.DataCenter; id=2 2025-02-03 23:19:00,588 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171, ctx-b872c7ac]) (logid:6d42f2b9) Rethrow exception com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"}Scope=interface com.cloud.dc.DataCenter; id=2 2025-02-03 23:19:00,588 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171]) (logid:6d42f2b9) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 660, job origin: 1025 2025-02-03 23:19:00,588 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171]) (logid:6d42f2b9) Unable to complete AsyncJobVO: {id:1171, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAClHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 22494847 5209146, completeMsid: null, lastUpdated: null, lastPolled: null, created: Mon Feb 03 23:18:54 UTC 2025, removed: null}, job origin: 1025 com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"}Scope=interface com.cloud.dc.DataCenter; id=2 2025-02-03 23:19:00,588 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171]) (logid:6d42f2b9) Complete async job-1171, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyADdjb20uY2xvdWQuZXhjZXB0aW9uLkluc3VmZmljaWVudFNlcnZlckNhcGFjaXR5RXhjZXB0aW9uVk1PcAAAABACAAFaABVhZmZpbml0eUdyb3Vwc0FwcGxpZWR4cgAxY29tLmNsb3VkLmV4Y2VwdGlvbi5JbnN1ZmZpY2llbnRDYXBhY2l0eUV4Y2VwdGlvblZNT3AAAAAVAgACTAACaWR0ABBMamF2YS9sYW5nL0xvbmc7TAAFc2NvcGV0ABFMamF2YS9sYW5nL0NsYXNzO3hyACJjb20uY2xvdWQuZXhjZXB0aW9uLkNsb3VkRXhjZXB0aW9ueeiOG_HkRMcCAAJMAAtjc0Vycm9yQ29kZXQAE0xqYXZhL2xhbmcvSW50ZWdlcjtMAAZpZExpc3R0ABVMamF2YS91dGlsL0FycmF5TGlzdDt4cgATamF2YS5sYW5nLkV4Y2VwdGlvbtD9Hz4aOxzEAgAAeHIAE2phdmEubGFuZy5UaHJvd2FibGXVxjUnOXe4ywMABEwABWNhdXNldAAVTGphdmEvbGFuZy9UaHJvd2FibGU7TAANZGV0YWlsTWVzc2FnZXQAEkxqYXZhL2xhbmcvU3RyaW5nO1sACnN0YWNrVHJhY2V0AB5bTGphdmEvbGFuZy9TdGFja1RyYWNlRWxlbWVudDtMABRzdXBwcmVzc2VkRXhjZXB0aW9uc3QAEExqYXZhL3V0aWwvTGlzdDt4cHEAfgANdACcVW5hYmxlIHRvIGNyZWF0ZSBhIGRlcGxve W1lbnQgZm9yIFZNIGluc3RhbmNlIHsiaWQiOjY2MCwiaW5zdGFuY2VOYW1lIjoicy02NjAtVk0iLCJ0eXBlIjoiU2Vjb25kYXJ5U3RvcmFnZVZtIiwidXVpZCI6ImRiOWFkODBmLTA1ZDYtNDA4Mi05NGM1LTE5MWRkYmVjZmIzMyJ9dXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAATc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAIQgAGZm9ybWF0SQAKbGluZU51bWJlckwAD2NsYXNzTG9hZGVyTmFtZXEAfgAKTAAOZGVjbGFyaW5nQ2xhc3NxAH4ACkwACGZpbGVOYW1lcQB-AApMAAptZXRob2ROYW1lcQB-AApMAAptb2R1bGVOYW1lcQB-AApMAA1tb2R1bGVWZXJzaW9ucQB-AAp4cAEAAATVdAADYXBwdAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0ABBvcmNoZXN0cmF0ZVN0YXJ0cHBzcQB-ABEBAAAVW3EAfgATcQB-ABRxAH4AFXEAfgAWcHBzcQB-ABECAAAAZ3B0AC9qZGsuaW50ZXJuYWwucmVmbGVjdC5EaXJlY3RNZXRob2RIYW5kbGVBY2Nlc3NvcnQAH0RpcmVjdE1ldGhvZEhhbmRsZUFjY2Vzc29yLmphdmF0AAZpbnZva2V0AAlqYXZhLmJhc2V0AAYyMS4wLjVzcQB-ABECAAACRHB0ABhqYXZhLmxhbmcucmVmbGVjdC5NZXRob2R0AAtNZXRob2QuamF2YXEAfgAbcQB-ABxxAH4AHXNxAH4AEQEAAABqcQB-ABN0ACJjb20uY2xvdWQudm0uVm1Xb3JrSm9iSGFuZGxlcl Byb3h5dAAaVm1Xb3JrSm9iSGFuZGxlclByb3h5LmphdmF0AA9oYW5kbGVWbVdvcmtKb2JwcHNxAH4AEQEAABXXcQB-ABNxAH4AFHEAfgAVcQB-ACRwcHNxAH4AEQEAAABjcQB-ABN0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnBwc3EAfgARAQAAAoxxAH4AE3QAP29yZy5hcGFjaGUuY2xvdWRzdGFjay5mcmFtZXdvcmsuam9icy5pbXBsLkFzeW5jSm9iTWFuYWdlckltcGwkNXQAGEFzeW5jSm9iTWFuYWdlckltcGwuamF2YXQADHJ1bkluQ29udGV4dHBwc3EAfgARAQAAADFxAH4AE3QAPm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZSQxdAAbTWFuYWdlZENvbnRleHRSdW5uYWJsZS5qYXZhdAADcnVucHBzcQB-ABEBAAAAOHEAfgATdABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxscHBzcQB-ABEBAAAAZ3EAfgATdABAb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dHEAfgA0dAAPY2FsbFdpdGhDb250ZXh0cHBzcQB-ABEBAAAANXEAfgATcQB-ADdxAH4ANHQADnJ1bldpdGhDb250ZXh0cHBzcQB-ABEBAAAALnEAfgATdAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29 udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ADBxAH4AMXBwc3EAfgARAQAAAlhxAH4AE3EAfgArcQB-ACxxAH4AMXBwc3EAfgARAgAAAjxwdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ADVxAH4AHHEAfgAdc3EAfgARAgAAAT1wdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAxcQB-ABxxAH4AHXNxAH4AEQIAAAR4cHQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2VycQB-ABxxAH4AHXNxAH4AEQIAAAKCcHQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4ARnEAfgAxcQB-ABxxAH4AHXNxAH4AEQIAAAYvcHQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAxcQB-ABxxAH4AHXNyAB9qYXZhLnV0aWwuQ29sbGVjdGlvbnMkRW1wdHlMaXN0ergXtDynnt4CAAB4cHhzcgARamF2YS5sYW5nLkludGVnZXIS4qCk94GHOAIAAUkABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAQ73NyABNqYXZhLnV0aWwuQXJyYXlMaXN0eIHSHZnHYZ0DAAFJAARzaXpleHAAAAAAdwQAAAAAeHNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cQB-AFAAAAAAAAAAAnZyABdjb20uY2xvdWQuZGMuRGF0YUNlbnRlchBQ VG0DRR4AAgAAeHAA 2025-02-03 23:19:00,588 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171]) (logid:6d42f2b9) Publish async job-1171 complete on message bus 2025-02-03 23:19:00,588 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171]) (logid:6d42f2b9) Wake up jobs related to job-1171 2025-02-03 23:19:00,588 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171]) (logid:6d42f2b9) Update db status for job-1171 2025-02-03 23:19:00,589 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171]) (logid:6d42f2b9) Wake up jobs joined with job-1171 and disjoin all subjobs created from job- 1171 2025-02-03 23:19:00,591 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171]) (logid:6d42f2b9) Done executing com.cloud.vm.VmWorkStart for job-1171 2025-02-03 23:19:00,592 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-146:[ctx-3da299cf, job-1025/job-1171]) (logid:6d42f2b9) Remove job-1171 from job monitoring 2025-02-03 23:19:00,594 WARN [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Unable to start secondary storage VM [660] due to [Unable to create a deployment for VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"}]. com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"}Scope=interface com.cloud.dc.DataCenter; id=2 2025-02-03 23:19:00,594 INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Unable to start secondary storage VM [660] for standby capacity, it will be recycled and will start a new one. 2025-02-03 23:19:00,597 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Sync job-1172 execution on object VmWorkJobQueue.660 2025-02-03 23:19:00,643 DEBUG [c.c.a.t.Request] (AgentManager-Handler-3:[]) (logid:) Seq 2-3494511835862794590: Processing: { Ans: , MgmtId: 224948475209146, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] } 2025-02-03 23:19:00,643 DEBUG [c.c.a.t.Request] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Seq 2-3494511835862794590: Received: { Ans: , MgmtId: 224948475209146, via: 2(ultraviolet.local), Ver: v1, Flags: 10, { StopAnswer } } 2025-02-03 23:19:00,648 DEBUG [c.c.n.g.ControlNetworkGuru] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Released nic: NicProfile {"broadcastUri":null,"deviceId":null,"iPv4Address":null,"id":1124,"reservationId":null,"vmId":659} for vm VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} 2025-02-03 23:19:00,648 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) The nic Nic {"broadcastUri":null,"deviceId":0,"iPv4Address":"169.254.180.24","id":1124,"instanceId":659,"reservationId":"df5d43a8-1aa2-4889-887c-ce6c41bd01ea"} on NicProfile {"broadcastUri":null,"deviceId":null,"iPv4Address":null,"id":1124,"reservationId":null,"vmId":659} was released according to VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} by guru com.cloud.network.guru.ControlNetworkGuru@48d54b1c, now updating record. 2025-02-03 23:19:00,650 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Releasing ip address for reservationId=df5d43a8-1aa2-4889-887c-ce6c41bd01ea, nic=1125 2025-02-03 23:19:00,651 DEBUG [c.c.n.g.PodBasedNetworkGuru] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Released nic: NicProfile {"broadcastUri":null,"deviceId":null,"iPv4Address":null,"id":1125,"reservationId":null,"vmId":659} for vm VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} 2025-02-03 23:19:00,651 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) The nic Nic {"broadcastUri":null,"deviceId":1,"iPv4Address":"172.16.10.22","id":1125,"instanceId":659,"reservationId":"df5d43a8-1aa2-4889-887c-ce6c41bd01ea"} on NicProfile {"broadcastUri":null,"deviceId":null,"iPv4Address":null,"id":1125,"reservationId":null,"vmId":659} was released according to VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} by guru com.cloud.network.guru.PodBasedNetworkGuru@1324605b, now updating record. 2025-02-03 23:19:00,652 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Successfully released network resources for the VM VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} in Starting state 2025-02-03 23:19:00,654 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Successfully released storage resources for the VM VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} in Starting state 2025-02-03 23:19:00,654 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Successfully cleaned up resources for the VM VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} in Starting state 2025-02-03 23:19:00,654 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) VM start attempt #2 2025-02-03 23:19:00,654 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Root volume is ready, need to place VM in volume's cluster 2025-02-03 23:19:00,654 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Vol[375|name=ROOT-659|vm=659|ROOT] is READY, changing deployment plan to use this pool's dcId: 2, podId: 2, and clusterId: 2 2025-02-03 23:19:00,655 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Trying to deploy VM [error decoding VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"}] and details: Plan [error decoding {"_clusterId":2,"_dcId":2,"_physicalNetworkId":null,"_podId":2,"_poolId":2,"migrationPlan":false}]; avoid list [{"_podIds":[],"_clusterIds":[],"_hostIds":[2]}] and planner: []. 2025-02-03 23:19:00,656 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Trying to allocate a host and storage pools from datacenter [{"name":"uv-dell-2","uuid":"bf6f5332-ddfc-4793-95b9-c1696e1b48dc"}], pod [{"name":"pod2","uuid":"6b30cf43-a40b-43c6-bc30-dba58280cb16"}], cluster [{"name":"cluster2","uuid":"dc1279a6-9c80-4be4-bd71-a30934575f38"}], to deploy VM [{"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"}] with requested CPU [500] and requested RAM [(1.00 GB) 1073741824]. 2025-02-03 23:19:00,656 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) ROOT volume [6eca55c4-4173-4d17-9163-d10cc67d72de] is ready to deploy VM [9176a552-5253-423d-ac17-5d017511ce21]. 2025-02-03 23:19:00,657 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Adding pods [] to the avoid set because these pods are in the Disabled state. 2025-02-03 23:19:00,657 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Adding clusters [] of pod [2] to the void set because these clusters are in the Disabled state. 2025-02-03 23:19:00,657 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Adding hosts [] of datacenter [bf6f5332-ddfc-4793-95b9-c1696e1b48dc] to the avoid set, because these hosts are in the Disabled state. 2025-02-03 23:19:00,658 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) DeploymentPlan [DataCenterDeployment] has not specified host. Trying to find another destination to deploy VM [9176a552-5253-423d-ac17-5d017511ce21], avoiding pods [], clusters [] and hosts [2]. 2025-02-03 23:19:00,658 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Deploy avoids pods: [], clusters: [], hosts: [2]. 2025-02-03 23:19:00,658 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Deploy hosts with priorities {}, hosts have NORMAL priority by default 2025-02-03 23:19:00,658 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Searching resources only under specified Cluster: 2 2025-02-03 23:19:00,660 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Checking resources in Cluster: 2 under Pod: 2 2025-02-03 23:19:00,660 INFO [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32, FirstFitRoutingAllocator]) (logid:795c34a4) Guest VM is requested with Custom[UEFI] Boot Type false 2025-02-03 23:19:00,660 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32, FirstFitRoutingAllocator]) (logid:795c34a4) Looking for hosts in zone [2], pod [2], cluster [2] 2025-02-03 23:19:00,661 INFO [o.a.c.u.r.ReflectionToStringBuilderUtils] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32, FirstFitRoutingAllocator]) (logid:795c34a4) Collection [[]] is empty or has only null values, not reflecting it. 2025-02-03 23:19:00,661 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32, FirstFitRoutingAllocator]) (logid:795c34a4) Adding hosts [null] to the avoid set because these hosts do not support HA. 2025-02-03 23:19:00,661 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32, FirstFitRoutingAllocator]) (logid:795c34a4) FirstFitAllocator has 1 hosts to check for allocation: [Host {"id":2,"name":"ultraviolet.local","type":"Routing","uuid":"86b3b883-4b15-4328-a3fe-56e41cd46ad3"}] 2025-02-03 23:19:00,662 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32, FirstFitRoutingAllocator]) (logid:795c34a4) Found 1 hosts for allocation after prioritization: [Host {"id":2,"name":"ultraviolet.local","type":"Routing","uuid":"86b3b883-4b15-4328-a3fe-56e41cd46ad3"}] 2025-02-03 23:19:00,662 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32, FirstFitRoutingAllocator]) (logid:795c34a4) Looking for speed=500Mhz, Ram=1024 MB 2025-02-03 23:19:00,662 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32, FirstFitRoutingAllocator]) (logid:795c34a4) Host name: ultraviolet.local, hostId: 2 is in avoid set, skipping this and trying other available hosts 2025-02-03 23:19:00,662 DEBUG [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32, FirstFitRoutingAllocator]) (logid:795c34a4) Host Allocator returning 0 suitable hosts 2025-02-03 23:19:00,662 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) No suitable hosts found. 2025-02-03 23:19:00,662 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) No suitable hosts found under this Cluster: 2 2025-02-03 23:19:00,662 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Could not find suitable Deployment Destination for this VM under any clusters, returning. 2025-02-03 23:19:00,663 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Searching resources only under specified Cluster: 2 2025-02-03 23:19:00,663 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) The specified cluster is in avoid set, returning. 2025-02-03 23:19:00,663 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) VM start attempt #3 2025-02-03 23:19:00,663 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Trying to deploy VM [error decoding VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"}] and details: Plan [error decoding {"_clusterId":null,"_dcId":2,"_physicalNetworkId":null,"_podId":2,"_poolId":null,"migrationPlan":false}]; avoid list [{"_podIds":[],"_clusterIds":[2],"_hostIds":[2]}] and planner: []. 2025-02-03 23:19:00,664 DEBUG [o.a.c.u.r.ReflectionToStringBuilderUtils] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Object is null, not reflecting it. 2025-02-03 23:19:00,664 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Trying to allocate a host and storage pools from datacenter [{"name":"uv-dell-2","uuid":"bf6f5332-ddfc-4793-95b9-c1696e1b48dc"}], pod [{"name":"pod2","uuid":"6b30cf43-a40b-43c6-bc30-dba58280cb16"}], cluster [null], to deploy VM [{"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"}] with requested CPU [500] and requested RAM [(1.00 GB) 1073741824]. 2025-02-03 23:19:00,664 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) ROOT volume [6eca55c4-4173-4d17-9163-d10cc67d72de] is not ready to deploy VM [9176a552-5253-423d-ac17-5d017511ce21]. 2025-02-03 23:19:00,665 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Adding pods [] to the avoid set because these pods are in the Disabled state. 2025-02-03 23:19:00,665 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Adding clusters [] of pod [2] to the void set because these clusters are in the Disabled state. 2025-02-03 23:19:00,665 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Adding hosts [] of datacenter [bf6f5332-ddfc-4793-95b9-c1696e1b48dc] to the avoid set, because these hosts are in the Disabled state. 2025-02-03 23:19:00,666 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) DeploymentPlan [DataCenterDeployment] has not specified host. Trying to find another destination to deploy VM [9176a552-5253-423d-ac17-5d017511ce21], avoiding pods [], clusters [2] and hosts [2]. 2025-02-03 23:19:00,666 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Deploy avoids pods: [], clusters: [2], hosts: [2]. 2025-02-03 23:19:00,666 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Deploy hosts with priorities {}, hosts have NORMAL priority by default 2025-02-03 23:19:00,666 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Searching resources only under specified Pod: 2 2025-02-03 23:19:00,666 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Listing clusters in order of aggregate capacity, that have (at least one host with) enough CPU and RAM capacity under this Pod: 2 2025-02-03 23:19:00,668 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Removing from the clusterId list these clusters from avoid set: [2] 2025-02-03 23:19:00,668 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) No clusters found after removing disabled clusters and clusters in avoid list, returning. 2025-02-03 23:19:00,672 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} state transited from [Starting] to [Stopped] with event [OperationFailed]. VM's original host: null, new host: null, host before state transition: Host {"id":2,"name":"ultraviolet.local","type":"Routing","uuid":"86b3b883-4b15-4328-a3fe-56e41cd46ad3"} 2025-02-03 23:19:00,674 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Hosts's actual total CPU: 68256 and CPU after applying overprovisioning: 68256 2025-02-03 23:19:00,674 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Hosts's actual total RAM: (29.70 GB) 31891501056 and RAM after applying overprovisioning: (29.70 GB) 31891501056 2025-02-03 23:19:00,674 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) release cpu from host: 2, old used: 500,reserved: 0, actual total: 68256, total with overprovisioning: 68256; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse 2025-02-03 23:19:00,674 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) release mem from host: 2, old used: (1.00 GB) 1073741824,reserved: (0 bytes) 0, total: (29.70 GB) 31891501056; new used: (0 bytes) 0,reserved:(0 bytes) 0; movedfromreserved: false,moveToReserveredfalse 2025-02-03 23:19:00,675 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Invocation exception, caused by: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"}Scope=interface com.cloud.dc.DataCenter; id=2 2025-02-03 23:19:00,675 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170, ctx-d4c64b32]) (logid:795c34a4) Rethrow exception com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"}Scope=interface com.cloud.dc.DataCenter; id=2 2025-02-03 23:19:00,675 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170]) (logid:795c34a4) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 659, job origin: 1024 2025-02-03 23:19:00,675 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170]) (logid:795c34a4) Unable to complete AsyncJobVO: {id:1170, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAACk3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 22494847 5209146, completeMsid: null, lastUpdated: null, lastPolled: null, created: Mon Feb 03 23:18:54 UTC 2025, removed: null}, job origin: 1024 com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"}Scope=interface com.cloud.dc.DataCenter; id=2 2025-02-03 23:19:00,676 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170]) (logid:795c34a4) Complete async job-1170, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyADdjb20uY2xvdWQuZXhjZXB0aW9uLkluc3VmZmljaWVudFNlcnZlckNhcGFjaXR5RXhjZXB0aW9uVk1PcAAAABACAAFaABVhZmZpbml0eUdyb3Vwc0FwcGxpZWR4cgAxY29tLmNsb3VkLmV4Y2VwdGlvbi5JbnN1ZmZpY2llbnRDYXBhY2l0eUV4Y2VwdGlvblZNT3AAAAAVAgACTAACaWR0ABBMamF2YS9sYW5nL0xvbmc7TAAFc2NvcGV0ABFMamF2YS9sYW5nL0NsYXNzO3hyACJjb20uY2xvdWQuZXhjZXB0aW9uLkNsb3VkRXhjZXB0aW9ueeiOG_HkRMcCAAJMAAtjc0Vycm9yQ29kZXQAE0xqYXZhL2xhbmcvSW50ZWdlcjtMAAZpZExpc3R0ABVMamF2YS91dGlsL0FycmF5TGlzdDt4cgATamF2YS5sYW5nLkV4Y2VwdGlvbtD9Hz4aOxzEAgAAeHIAE2phdmEubGFuZy5UaHJvd2FibGXVxjUnOXe4ywMABEwABWNhdXNldAAVTGphdmEvbGFuZy9UaHJvd2FibGU7TAANZGV0YWlsTWVzc2FnZXQAEkxqYXZhL2xhbmcvU3RyaW5nO1sACnN0YWNrVHJhY2V0AB5bTGphdmEvbGFuZy9TdGFja1RyYWNlRWxlbWVudDtMABRzdXBwcmVzc2VkRXhjZXB0aW9uc3QAEExqYXZhL3V0aWwvTGlzdDt4cHEAfgANdACWVW5hYmxlIHRvIGNyZWF0ZSBhIGRlcGxve W1lbnQgZm9yIFZNIGluc3RhbmNlIHsiaWQiOjY1OSwiaW5zdGFuY2VOYW1lIjoidi02NTktVk0iLCJ0eXBlIjoiQ29uc29sZVByb3h5IiwidXVpZCI6IjkxNzZhNTUyLTUyNTMtNDIzZC1hYzE3LTVkMDE3NTExY2UyMSJ9dXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAATc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAIQgAGZm9ybWF0SQAKbGluZU51bWJlckwAD2NsYXNzTG9hZGVyTmFtZXEAfgAKTAAOZGVjbGFyaW5nQ2xhc3NxAH4ACkwACGZpbGVOYW1lcQB-AApMAAptZXRob2ROYW1lcQB-AApMAAptb2R1bGVOYW1lcQB-AApMAA1tb2R1bGVWZXJzaW9ucQB-AAp4cAEAAATVdAADYXBwdAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0ABBvcmNoZXN0cmF0ZVN0YXJ0cHBzcQB-ABEBAAAVW3EAfgATcQB-ABRxAH4AFXEAfgAWcHBzcQB-ABECAAAAZ3B0AC9qZGsuaW50ZXJuYWwucmVmbGVjdC5EaXJlY3RNZXRob2RIYW5kbGVBY2Nlc3NvcnQAH0RpcmVjdE1ldGhvZEhhbmRsZUFjY2Vzc29yLmphdmF0AAZpbnZva2V0AAlqYXZhLmJhc2V0AAYyMS4wLjVzcQB-ABECAAACRHB0ABhqYXZhLmxhbmcucmVmbGVjdC5NZXRob2R0AAtNZXRob2QuamF2YXEAfgAbcQB-ABxxAH4AHXNxAH4AEQEAAABqcQB-ABN0ACJjb20uY2xvdWQudm0uVm1Xb3JrSm9iSGFuZGxlclByb3h5dA AaVm1Xb3JrSm9iSGFuZGxlclByb3h5LmphdmF0AA9oYW5kbGVWbVdvcmtKb2JwcHNxAH4AEQEAABXXcQB-ABNxAH4AFHEAfgAVcQB-ACRwcHNxAH4AEQEAAABjcQB-ABN0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnBwc3EAfgARAQAAAoxxAH4AE3QAP29yZy5hcGFjaGUuY2xvdWRzdGFjay5mcmFtZXdvcmsuam9icy5pbXBsLkFzeW5jSm9iTWFuYWdlckltcGwkNXQAGEFzeW5jSm9iTWFuYWdlckltcGwuamF2YXQADHJ1bkluQ29udGV4dHBwc3EAfgARAQAAADFxAH4AE3QAPm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZSQxdAAbTWFuYWdlZENvbnRleHRSdW5uYWJsZS5qYXZhdAADcnVucHBzcQB-ABEBAAAAOHEAfgATdABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxscHBzcQB-ABEBAAAAZ3EAfgATdABAb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dHEAfgA0dAAPY2FsbFdpdGhDb250ZXh0cHBzcQB-ABEBAAAANXEAfgATcQB-ADdxAH4ANHQADnJ1bldpdGhDb250ZXh0cHBzcQB-ABEBAAAALnEAfgATdAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5 NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ADBxAH4AMXBwc3EAfgARAQAAAlhxAH4AE3EAfgArcQB-ACxxAH4AMXBwc3EAfgARAgAAAjxwdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ADVxAH4AHHEAfgAdc3EAfgARAgAAAT1wdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAxcQB-ABxxAH4AHXNxAH4AEQIAAAR4cHQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2VycQB-ABxxAH4AHXNxAH4AEQIAAAKCcHQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4ARnEAfgAxcQB-ABxxAH4AHXNxAH4AEQIAAAYvcHQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAxcQB-ABxxAH4AHXNyAB9qYXZhLnV0aWwuQ29sbGVjdGlvbnMkRW1wdHlMaXN0ergXtDynnt4CAAB4cHhzcgARamF2YS5sYW5nLkludGVnZXIS4qCk94GHOAIAAUkABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAQ73NyABNqYXZhLnV0aWwuQXJyYXlMaXN0eIHSHZnHYZ0DAAFJAARzaXpleHAAAAAAdwQAAAAAeHNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cQB-AFAAAAAAAAAAAnZyABdjb20uY2xvdWQuZGMuRGF0YUNlbnRlchBQVG0DRR4A AgAAeHAA 2025-02-03 23:19:00,676 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170]) (logid:795c34a4) Publish async job-1170 complete on message bus 2025-02-03 23:19:00,676 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170]) (logid:795c34a4) Wake up jobs related to job-1170 2025-02-03 23:19:00,676 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170]) (logid:795c34a4) Update db status for job-1170 2025-02-03 23:19:00,676 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170]) (logid:795c34a4) Wake up jobs joined with job-1170 and disjoin all subjobs created from job- 1170 2025-02-03 23:19:00,679 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170]) (logid:795c34a4) Done executing com.cloud.vm.VmWorkStart for job-1170 2025-02-03 23:19:00,679 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-145:[ctx-41bfec57, job-1024/job-1170]) (logid:795c34a4) Remove job-1170 from job monitoring 2025-02-03 23:19:00,680 WARN [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Unable to start proxy [659] due to [Unable to create a deployment for VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"}]. com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"}Scope=interface com.cloud.dc.DataCenter; id=2 2025-02-03 23:19:00,681 INFO [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Unable to start console proxy vm for standby capacity, vm id : 659, will recycle it and start a new one 2025-02-03 23:19:00,683 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Sync job-1173 execution on object VmWorkJobQueue.659 2025-02-03 23:19:01,262 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-4:[]) (logid:) Ping from Routing host 2(ultraviolet.local) 2025-02-03 23:19:01,262 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:[]) (logid:) Process host VM state report from ping process. host: 2. 2025-02-03 23:19:01,262 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:[]) (logid:) Process VM state report. host: 2, number of records in report: 0. 2025-02-03 23:19:01,263 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:[]) (logid:) Done with process of VM state report. host: 2 2025-02-03 23:19:02,010 DEBUG [c.c.a.ApiServlet] (qtp1047478056-368:[ctx-c00ddb81]) (logid:43e5c4f0) ===START=== 0:0:0:0:0:0:0:1 -- GET command=readyForShutdown&response=json&sessionkey=0INeJHuBjMAMtV8_JkBzblVPNI0 2025-02-03 23:19:02,010 DEBUG [c.c.a.ApiServlet] (qtp1047478056-368:[ctx-c00ddb81]) (logid:43e5c4f0) Two factor authentication is already verified for the user 2, so skipping 2025-02-03 23:19:02,012 DEBUG [c.c.a.ApiServer] (qtp1047478056-368:[ctx-c00ddb81, ctx-62c60540]) (logid:43e5c4f0) CIDRs from which account 'Account [{"accountName":"admin","id":2,"uuid":"8c19107f-dfd2-11ef-bca6-cc96e5f525ba"}]' is allowed to perform API calls: 0.0.0.0/0,::/0 2025-02-03 23:19:02,013 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker] (qtp1047478056-368:[ctx-c00ddb81, ctx-62c60540]) (logid:43e5c4f0) RoleService is enabled. We will use it instead of StaticRoleBasedAPIAccessChecker. 2025-02-03 23:19:02,013 DEBUG [o.a.c.r.ApiRateLimitServiceImpl] (qtp1047478056-368:[ctx-c00ddb81, ctx-62c60540]) (logid:43e5c4f0) API rate limiting is disabled. We will not use ApiRateLimitService. 2025-02-03 23:19:02,014 INFO [c.c.a.ApiServlet] (qtp1047478056-368:[ctx-c00ddb81, ctx-62c60540]) (logid:43e5c4f0) (userId=2 accountId=2 sessionId=node0xft6iuusa10qlorpsfpw2n3w0) 0:0:0:0:0:0:0:1 -- GET command=readyForShutdown&response=json&sessionkey=0INeJHuBjMAMtV8_JkBzblVPNI0 200 {"readyforshutdownresponse":{"readyforshutdown":{"readyforshutdown":true,"shutdowntriggered":false,"pendingjobscount":0}}} 2025-02-03 23:19:02,014 DEBUG [c.c.a.ApiServlet] (qtp1047478056-368:[ctx-c00ddb81, ctx-62c60540]) (logid:43e5c4f0) ===END=== 0:0:0:0:0:0:0:1 -- GET command=readyForShutdown&response=json&sessionkey=0INeJHuBjMAMtV8_JkBzblVPNI0 2025-02-03 23:19:02,489 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$6] (AsyncJobMgr-Heartbeat-1:[ctx-a781ef82]) (logid:b6fd3caa) Execute sync-queue item: SyncQueueItemVO {id:1127, queueId: 1124, contentType: AsyncJob, contentId: 1172, lastProcessMsid: 224948475209146, lastprocessNumber: 3, lastProcessTime: Mon Feb 03 23:19:02 UTC 2025, created: Mon Feb 03 23:19:00 UTC 2025} 2025-02-03 23:19:02,490 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:[ctx-a781ef82]) (logid:b6fd3caa) Schedule queued job-1172 2025-02-03 23:19:02,491 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$6] (AsyncJobMgr-Heartbeat-1:[ctx-a781ef82]) (logid:b6fd3caa) Execute sync-queue item: SyncQueueItemVO {id:1128, queueId: 1123, contentType: AsyncJob, contentId: 1173, lastProcessMsid: 224948475209146, lastprocessNumber: 3, lastProcessTime: Mon Feb 03 23:19:02 UTC 2025, created: Mon Feb 03 23:19:00 UTC 2025} 2025-02-03 23:19:02,491 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:[ctx-a781ef82]) (logid:b6fd3caa) Schedule queued job-1173 2025-02-03 23:19:02,491 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172]) (logid:f6f7f51b) Add job-1172 into job monitoring 2025-02-03 23:19:02,492 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173]) (logid:571890c8) Add job-1173 into job monitoring 2025-02-03 23:19:02,494 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172]) (logid:6d42f2b9) Executing AsyncJobVO: {id:1172, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAClHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 224948475209146, completeMsid: null, lastUpdated: null, lastPolled: null, created: Mon Feb 03 23:19:00 UTC 2025, removed: null} 2025-02-03 23:19:02,494 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172]) (logid:6d42f2b9) Run VM work job: com.cloud.vm.VmWorkStop for VM 660, job origin: 1025 2025-02-03 23:19:02,494 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173]) (logid:795c34a4) Executing AsyncJobVO: {id:1173, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAACk3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 224948475209146, completeMsid: null, lastUpdated: null, lastPolled: null, created: Mon Feb 03 23:19:00 UTC 2025, removed: null} 2025-02-03 23:19:02,494 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172, ctx-c4ff0b9f]) (logid:6d42f2b9) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":1,"accountId":1,"vmId":660,"handlerName":"VirtualMachineManagerImpl"} 2025-02-03 23:19:02,494 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173]) (logid:795c34a4) Run VM work job: com.cloud.vm.VmWorkStop for VM 659, job origin: 1024 2025-02-03 23:19:02,495 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173, ctx-61d48ae8]) (logid:795c34a4) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":1,"accountId":1,"vmId":659,"handlerName":"VirtualMachineManagerImpl"} 2025-02-03 23:19:02,495 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172, ctx-c4ff0b9f]) (logid:6d42f2b9) VM is already stopped: VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} 2025-02-03 23:19:02,495 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172, ctx-c4ff0b9f]) (logid:6d42f2b9) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":1,"accountId":1,"vmId":660,"handlerName":"VirtualMachineManagerImpl"} 2025-02-03 23:19:02,495 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172, ctx-c4ff0b9f]) (logid:6d42f2b9) Complete async job-1172, jobStatus: SUCCEEDED, resultCode: 0, result: null 2025-02-03 23:19:02,495 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172, ctx-c4ff0b9f]) (logid:6d42f2b9) Publish async job-1172 complete on message bus 2025-02-03 23:19:02,495 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172, ctx-c4ff0b9f]) (logid:6d42f2b9) Wake up jobs related to job-1172 2025-02-03 23:19:02,495 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172, ctx-c4ff0b9f]) (logid:6d42f2b9) Update db status for job-1172 2025-02-03 23:19:02,495 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173, ctx-61d48ae8]) (logid:795c34a4) VM is already stopped: VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} 2025-02-03 23:19:02,495 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173, ctx-61d48ae8]) (logid:795c34a4) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":1,"accountId":1,"vmId":659,"handlerName":"VirtualMachineManagerImpl"} 2025-02-03 23:19:02,495 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173, ctx-61d48ae8]) (logid:795c34a4) Complete async job-1173, jobStatus: SUCCEEDED, resultCode: 0, result: null 2025-02-03 23:19:02,496 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172, ctx-c4ff0b9f]) (logid:6d42f2b9) Wake up jobs joined with job-1172 and disjoin all subjobs created from job- 1172 2025-02-03 23:19:02,496 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173, ctx-61d48ae8]) (logid:795c34a4) Publish async job-1173 complete on message bus 2025-02-03 23:19:02,496 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173, ctx-61d48ae8]) (logid:795c34a4) Wake up jobs related to job-1173 2025-02-03 23:19:02,496 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173, ctx-61d48ae8]) (logid:795c34a4) Update db status for job-1173 2025-02-03 23:19:02,496 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173, ctx-61d48ae8]) (logid:795c34a4) Wake up jobs joined with job-1173 and disjoin all subjobs created from job- 1173 2025-02-03 23:19:02,498 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172]) (logid:6d42f2b9) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 660, job origin: 1025 2025-02-03 23:19:02,498 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172]) (logid:6d42f2b9) Done executing com.cloud.vm.VmWorkStop for job-1172 2025-02-03 23:19:02,498 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-147:[ctx-dfcaa17f, job-1025/job-1172]) (logid:6d42f2b9) Remove job-1172 from job monitoring 2025-02-03 23:19:02,499 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173]) (logid:795c34a4) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 659, job origin: 1024 2025-02-03 23:19:02,499 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173]) (logid:795c34a4) Done executing com.cloud.vm.VmWorkStop for job-1173 2025-02-03 23:19:02,499 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-148:[ctx-a4d8d11e, job-1024/job-1173]) (logid:795c34a4) Remove job-1173 from job monitoring 2025-02-03 23:19:02,502 DEBUG [c.c.c.CapacityManagerImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} state transited from [Stopped] to [Expunging] with event [ExpungeOperation]. VM's original host: null, new host: null, host before state transition: null 2025-02-03 23:19:02,503 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} state transited from [Stopped] to [Expunging] with event [ExpungeOperation]. VM's original host: null, new host: null, host before state transition: null 2025-02-03 23:19:02,503 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Expunging vm VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} 2025-02-03 23:19:02,503 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Cleaning up NICS [] of VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"}. 2025-02-03 23:19:02,503 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Cleaning network for vm: 659 2025-02-03 23:19:02,504 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Expunging vm VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} 2025-02-03 23:19:02,504 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Cleaning up NICS [] of VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"}. 2025-02-03 23:19:02,504 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Cleaning network for vm: 660 2025-02-03 23:19:02,505 DEBUG [c.c.n.g.PublicNetworkGuru] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) public network deallocate network: networkId: 204, ip: 172.16.10.11 2025-02-03 23:19:02,506 DEBUG [c.c.n.IpAddressManagerImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) IP address [Ip[172.16.10.11-2]] is direct; therefore, the resource count should not be updated. 2025-02-03 23:19:02,506 DEBUG [c.c.n.g.PublicNetworkGuru] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) public network deallocate network: networkId: 204, ip: 172.16.10.12 2025-02-03 23:19:02,507 DEBUG [c.c.n.IpAddressManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) IP address [Ip[172.16.10.12-2]] is direct; therefore, the resource count should not be updated. 2025-02-03 23:19:02,507 DEBUG [c.c.n.g.PublicNetworkGuru] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Deallocated nic: NicProfile {"broadcastUri":null,"deviceId":null,"iPv4Address":null,"id":1123,"reservationId":null,"vmId":659} 2025-02-03 23:19:02,508 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Removed nic id=1123 2025-02-03 23:19:02,508 DEBUG [c.c.n.g.PublicNetworkGuru] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Deallocated nic: NicProfile {"broadcastUri":null,"deviceId":null,"iPv4Address":null,"id":1126,"reservationId":null,"vmId":660} 2025-02-03 23:19:02,508 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Revoving nic secondary ip entry ... 2025-02-03 23:19:02,509 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Removed nic id=1126 2025-02-03 23:19:02,509 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Revoving nic secondary ip entry ... 2025-02-03 23:19:02,510 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Removed nic id=1124 2025-02-03 23:19:02,510 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Revoving nic secondary ip entry ... 2025-02-03 23:19:02,511 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Removed nic id=1127 2025-02-03 23:19:02,511 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Revoving nic secondary ip entry ... 2025-02-03 23:19:02,512 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Removed nic id=1125 2025-02-03 23:19:02,513 DEBUG [o.a.c.e.o.NetworkOrchestrator] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Revoving nic secondary ip entry ... 2025-02-03 23:19:02,513 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage. Data from VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"}. 2025-02-03 23:19:02,513 DEBUG [o.a.c.e.o.VolumeOrchestrator] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Cleaning storage for VM [null]. 2025-02-03 23:19:02,514 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Removed nic id=1128 2025-02-03 23:19:02,514 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Revoving nic secondary ip entry ... 2025-02-03 23:19:02,514 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage. Data from VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"}. 2025-02-03 23:19:02,514 DEBUG [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Cleaning storage for VM [null]. 2025-02-03 23:19:02,519 WARN [o.a.c.m.w.WebhookServiceImpl] (consoleproxy-1:[ctx-e304a582, ctx-3898cff9]) (logid:2d8931cd) Skipping delivering event [ID: null, description: {"details":"Volume Type: ROOT Volume Id: 6eca55c4-4173-4d17-9163-d10cc67d72de Vm Id: 9176a552-5253-423d-ac17-5d017511ce21","event":"VOLUME.DESTROY","status":"Completed"}] to any webhook as account ID is missing 2025-02-03 23:19:02,519 WARN [o.a.c.f.e.EventDistributorImpl] (consoleproxy-1:[ctx-e304a582, ctx-3898cff9]) (logid:2d8931cd) Failed to publish event [category: ActionEvent, type: VOLUME.DESTROY] on bus webhookEventBus 2025-02-03 23:19:02,520 WARN [o.a.c.m.w.WebhookServiceImpl] (secstorage-1:[ctx-ebc123fd, ctx-01996650]) (logid:8fc3b243) Skipping delivering event [ID: null, description: {"details":"Volume Type: ROOT Volume Id: 42ae9d0b-d015-4219-9399-6e30f42e8ec8 Vm Id: db9ad80f-05d6-4082-94c5-191ddbecfb33","event":"VOLUME.DESTROY","status":"Completed"}] to any webhook as account ID is missing 2025-02-03 23:19:02,520 WARN [o.a.c.f.e.EventDistributorImpl] (secstorage-1:[ctx-ebc123fd, ctx-01996650]) (logid:8fc3b243) Failed to publish event [category: ActionEvent, type: VOLUME.DESTROY] on bus webhookEventBus 2025-02-03 23:19:02,530 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) getCommandHostDelegation: class org.apache.cloudstack.storage.command.DeleteCommand 2025-02-03 23:19:02,531 DEBUG [c.c.h.XenServerGuru] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) We are returning the default host to execute commands because the command is not of Copy type. 2025-02-03 23:19:02,531 DEBUG [c.c.a.m.ClusteredAgentAttache] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Seq 2-3494511835862794591: Routed from 224948475209146 2025-02-03 23:19:02,531 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) getCommandHostDelegation: class org.apache.cloudstack.storage.command.DeleteCommand 2025-02-03 23:19:02,531 DEBUG [c.c.h.XenServerGuru] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) We are returning the default host to execute commands because the command is not of Copy type. 2025-02-03 23:19:02,531 DEBUG [c.c.a.t.Request] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Seq 2-3494511835862794591: Sending { Cmd , MgmtId: 224948475209146, via: 2(ultraviolet.local), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"6eca55c4-4173-4d17-9163-d10cc67d72de","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"e46a7f5f-fd84-31dc-92dc-f6a77fda375a","name":"Primary2","id":"2","poolType":"NetworkFilesystem","host":"172.16.10.2","path":"/export/primary","port":"2049","url":"NetworkFilesystem://172.16.10.2/export/primary/?ROLE=Primary&STOREUUID=e46a7f5f-fd84-31dc-92dc-f6a77fda375a","isManaged":"false"}},"name":"ROOT-659","size":"(0 bytes) 0","path":"6eca55c4-4173-4d17-9163-d10cc67d72de","volumeId":"375","vmName":"v-659-VM","accountId":"1","format":"QCOW2","provisioningType":"THIN","poolId":"2","id":"375","deviceId":"0","hyper visorType":"KVM","directDownload":"false","deployAsIs":"false","followRedirects":"false"}},"wait":"0","bypassHostMaintenance":"true"}}] } 2025-02-03 23:19:02,532 DEBUG [c.c.a.m.ClusteredAgentAttache] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Seq 2-3494511835862794592: Routed from 224948475209146 2025-02-03 23:19:02,532 DEBUG [c.c.a.t.Request] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Seq 2-3494511835862794592: Sending { Cmd , MgmtId: 224948475209146, via: 2(ultraviolet.local), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"42ae9d0b-d015-4219-9399-6e30f42e8ec8","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"e46a7f5f-fd84-31dc-92dc-f6a77fda375a","name":"Primary2","id":"2","poolType":"NetworkFilesystem","host":"172.16.10.2","path":"/export/primary","port":"2049","url":"NetworkFilesystem://172.16.10.2/export/primary/?ROLE=Primary&STOREUUID=e46a7f5f-fd84-31dc-92dc-f6a77fda375a","isManaged":"false"}},"name":"ROOT-660","size":"(0 bytes) 0","path":"42ae9d0b-d015-4219-9399-6e30f42e8ec8","volumeId":"376","vmName":"s-660-VM","accountId":"1","format":"QCOW2","provisioningType":"THIN","poolId":"2","id":"376","deviceId":"0","hypervi sorType":"KVM","directDownload":"false","deployAsIs":"false","followRedirects":"false"}},"wait":"0","bypassHostMaintenance":"true"}}] } 2025-02-03 23:19:02,603 DEBUG [c.c.a.t.Request] (AgentManager-Handler-6:[]) (logid:) Seq 2-3494511835862794592: Processing: { Ans: , MgmtId: 224948475209146, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] } 2025-02-03 23:19:02,603 DEBUG [c.c.a.t.Request] (AgentManager-Handler-5:[]) (logid:) Seq 2-3494511835862794591: Processing: { Ans: , MgmtId: 224948475209146, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] } 2025-02-03 23:19:02,603 DEBUG [c.c.a.t.Request] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Seq 2-3494511835862794592: Received: { Ans: , MgmtId: 224948475209146, via: 2(ultraviolet.local), Ver: v1, Flags: 10, { Answer } } 2025-02-03 23:19:02,603 DEBUG [c.c.a.t.Request] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Seq 2-3494511835862794591: Received: { Ans: , MgmtId: 224948475209146, via: 2(ultraviolet.local), Ver: v1, Flags: 10, { Answer } } 2025-02-03 23:19:02,606 INFO [o.a.c.s.v.VolumeServiceImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Volume 376 is not referred anywhere, remove it from volumes table 2025-02-03 23:19:02,606 DEBUG [c.c.s.d.VolumeDaoImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Removing volume 376 from DB 2025-02-03 23:19:02,606 INFO [o.a.c.s.v.VolumeServiceImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Volume 375 is not referred anywhere, remove it from volumes table 2025-02-03 23:19:02,606 DEBUG [c.c.s.d.VolumeDaoImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Removing volume 375 from DB 2025-02-03 23:19:02,609 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Expunged VM instance {"id":660,"instanceName":"s-660-VM","type":"SecondaryStorageVm","uuid":"db9ad80f-05d6-4082-94c5-191ddbecfb33"} 2025-02-03 23:19:02,609 DEBUG [c.c.v.ClusteredVirtualMachineManagerImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Expunged VM instance {"id":659,"instanceName":"v-659-VM","type":"ConsoleProxy","uuid":"9176a552-5253-423d-ac17-5d017511ce21"} 2025-02-03 23:19:02,610 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) received secondary storage vm alert 2025-02-03 23:19:02,611 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Secondary Storage Vm creation failure in zone [uv-dell-2]. 2025-02-03 23:19:02,611 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) received console proxy alert 2025-02-03 23:19:02,611 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) Console proxy creation failure. Zone [uv-dell-2]. 2025-02-03 23:19:02,611 WARN [c.c.a.AlertManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) alertType=[19] dataCenterId=[2] podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure in zone [uv-dell-2]. Error details: null]. 2025-02-03 23:19:02,612 WARN [c.c.a.AlertManagerImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) alertType=[10] dataCenterId=[2] podId=[null] clusterId=[null] message=[Console proxy creation failure. Zone [uv-dell-2]. Error details: null]. 2025-02-03 23:19:02,613 WARN [c.c.a.AlertManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Secondary Storage Vm creation failure in zone [uv-dell-2]. Error details: null] and content [Secondary Storage Vm creation failure (zone uv-dell-2)]. 2025-02-03 23:19:02,613 INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-ebc123fd]) (logid:8fc3b243) Primary secondary storage is not even started, wait until next turn 2025-02-03 23:19:02,613 WARN [c.c.a.AlertManagerImpl] (consoleproxy-1:[ctx-e304a582]) (logid:2d8931cd) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Console proxy creation failure. Zone [uv-dell-2]. Error details: null] and content [Console proxy creation failure (zone uv-dell-2)]. ``` -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected]
