Kubernetes cluster goes into error state #10353
Description
problem
I have a network, and I use it when building Kuber. However, when I checked the cloud stack logs, I noticed that it apparently could not start my router, and I got an exception Error. My cluster does not even show any of the controller and worker machines and finally the cluster goes to error state.
The following log is related to the problem:
2025-02-09 06:44:58,172 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-39:ctx-ceb65524 job-21305) (logid:eb172dee) Add job-21305 into job monitoring 2025-02-09 06:44:58,174 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (qtp341748265-21476:ctx-52df34e4 ctx-67dca492 ctx-1ba31c5c) (logid:bad513b5) submit async job-21305, details: AsyncJobVO: {id:21305, userId: 5, accountId: 5, instanceType: KubernetesCluster, instanceId: 487, cmd: org.apache.cloudstack.api.command.user.kubernetes.cluster.CreateKubernetesClusterCmd, cmdInfo: {"controlnodes":"1","apiKey":"KUJwsxLgw_PXlSayXI-e3KqsBq4-EKcsmYfxvxqaL_jRXtZOPgregege09A","signature":"AQymHtb3Aq7adR1RR7Bob1aflrs\u003d","keypair":"01jjekybd44qbj5n785pw6q3x6","httpmethod":"GET","ctxAccountId":"5","uuid":"53a70faa-ab56-45eb-9aa4-33d89eaecf13","domainid":"31bb99ae-d529-4b0a-8240-0bfe1de3b7a8","cmdEventType":"KUBERNETES.CLUSTER.CREATE","kubernetesversionid":"955d4629-49b7-49f3-a56e-89b20aacbb1d","size":"1","serviceofferingid":"5f03e21c-2a4e-499a-b1de-0bf1ac95a432","response":"json","ctxUserId":"5","name":"f4ebc728df05346e7d2f785b1ff8fc5b-01jkmq8ej078dbm9g8w1b5rjy0","zoneid":"b7b84374-f17b-4dc2-9d16-ef9858e7e232","networkid":"73751eed-5504-4435-811d-b415fb5a5dd8","ctxStartEventId":"65843","id":"487","ctxDetails":"{\"interface com.cloud.kubernetes.cluster.KubernetesCluster\":\"53a70faa-ab56-45eb-9aa4-33d89eaecf13\",\"interface com.cloud.dc.DataCenter\":\"b7b84374-f17b-4dc2-9d16-ef9858e7e232\",\"interface com.cloud.offering.ServiceOffering\":\"5f03e21c-2a4e-499a-b1de-0bf1ac95a432\",\"interface com.cloud.domain.Domain\":\"31bb99ae-d529-4b0a-8240-0bfe1de3b7a8\",\"interface com.cloud.kubernetes.version.KubernetesSupportedVersion\":\"955d4629-49b7-49f3-a56e-89b20aacbb1d\",\"interface com.cloud.network.Network\":\"73751eed-5504-4435-811d-b415fb5a5dd8\"}","account":"newgmail@gmail.com"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345051312967, completeMsid: null, lastUpdated: null, lastPolled: null, created: null, removed: null} 2025-02-09 06:44:58,183 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305) (logid:eff3ec0a) Executing AsyncJobVO: {id:21305, userId: 5, accountId: 5, instanceType: KubernetesCluster, instanceId: 487, cmd: org.apache.cloudstack.api.command.user.kubernetes.cluster.CreateKubernetesClusterCmd, cmdInfo: {"controlnodes":"1","apiKey":"KUJwsxLgw_PXlSayXI-e3KqsBq4-EKcsmYfxvxqaL_jRXtZOPgregege09A","signature":"AQymHtb3Aq7adR1RR7Bob1aflrs\u003d","keypair":"01jjekybd44qbj5n785pw6q3x6","httpmethod":"GET","ctxAccountId":"5","uuid":"53a70faa-ab56-45eb-9aa4-33d89eaecf13","domainid":"31bb99ae-d529-4b0a-8240-0bfe1de3b7a8","cmdEventType":"KUBERNETES.CLUSTER.CREATE","kubernetesversionid":"955d4629-49b7-49f3-a56e-89b20aacbb1d","size":"1","serviceofferingid":"5f03e21c-2a4e-499a-b1de-0bf1ac95a432","response":"json","ctxUserId":"5","name":"f4ebc728df05346e7d2f785b1ff8fc5b-01jkmq8ej078dbm9g8w1b5rjy0","zoneid":"b7b84374-f17b-4dc2-9d16-ef9858e7e232","networkid":"73751eed-5504-4435-811d-b415fb5a5dd8","ctxStartEventId":"65843","id":"487","ctxDetails":"{\"interface com.cloud.kubernetes.cluster.KubernetesCluster\":\"53a70faa-ab56-45eb-9aa4-33d89eaecf13\",\"interface com.cloud.dc.DataCenter\":\"b7b84374-f17b-4dc2-9d16-ef9858e7e232\",\"interface com.cloud.offering.ServiceOffering\":\"5f03e21c-2a4e-499a-b1de-0bf1ac95a432\",\"interface com.cloud.domain.Domain\":\"31bb99ae-d529-4b0a-8240-0bfe1de3b7a8\",\"interface com.cloud.kubernetes.version.KubernetesSupportedVersion\":\"955d4629-49b7-49f3-a56e-89b20aacbb1d\",\"interface com.cloud.network.Network\":\"73751eed-5504-4435-811d-b415fb5a5dd8\"}","account":"newgmail@gmail.com"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345051312967, completeMsid: null, lastUpdated: null, lastPolled: null, created: null, removed: null} 2025-02-09 06:44:58,208 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Access to Account [{"accountName":"newgmail@gmail.com","id":5,"uuid":"c0852b26-aa19-46d0-8b5f-a4852e2cd242"}] granted to Account [{"accountName":"newgmail@gmail.com","id":5,"uuid":"c0852b26-aa19-46d0-8b5f-a4852e2cd242"}] by DomainChecker 2025-02-09 06:44:58,212 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Access to Account [{"accountName":"newgmail@gmail.com","id":5,"uuid":"c0852b26-aa19-46d0-8b5f-a4852e2cd242"}] granted to Account [{"accountName":"newgmail@gmail.com","id":5,"uuid":"c0852b26-aa19-46d0-8b5f-a4852e2cd242"}] by DomainChecker 2025-02-09 06:44:58,215 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Account [c0852b26-aa19-46d0-8b5f-a4852e2cd242] has access to resource. 2025-02-09 06:44:58,218 INFO [c.c.n.NetworkModelImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Checking permission for account newgmail@gmail.com (c0852b26-aa19-46d0-8b5f-a4852e2cd242) on network 01hbjj7v1bfesn3gpsctyc97xb_1738567302 (73751eed-5504-4435-811d-b415fb5a5dd8) 2025-02-09 06:44:58,220 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Access to Network {"id": 771, "name": "01hbjj7v1bfesn3gpsctyc97xb_1738567302", "uuid": "73751eed-5504-4435-811d-b415fb5a5dd8", "networkofferingid": 25} granted to Account [{"accountName":"newgmail@gmail.com","id":5,"uuid":"c0852b26-aa19-46d0-8b5f-a4852e2cd242"}] by DomainChecker 2025-02-09 06:44:58,223 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Account [c0852b26-aa19-46d0-8b5f-a4852e2cd242] has access to resource. 2025-02-09 06:44:58,224 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Access granted to Account [{"accountName":"newgmail@gmail.com","id":5,"uuid":"c0852b26-aa19-46d0-8b5f-a4852e2cd242"}] to Domain:3/newgmail@gmail.com/ by AffinityGroupAccessChecker 2025-02-09 06:44:58,224 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Account [c0852b26-aa19-46d0-8b5f-a4852e2cd242] has access to resource. 2025-02-09 06:44:58,224 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Account [c0852b26-aa19-46d0-8b5f-a4852e2cd242] has access to resource. 2025-02-09 06:44:58,266 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Access to com.cloud.kubernetes.cluster.KubernetesClusterVO$$EnhancerByCGLIB$$d51ff7a7@7961af8 granted to Account [{"accountName":"newgmail@gmail.com","id":5,"uuid":"c0852b26-aa19-46d0-8b5f-a4852e2cd242"}] by DomainChecker 2025-02-09 06:44:58,276 INFO [c.c.k.c.a.KubernetesClusterActionWorker] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Starting Kubernetes cluster : f4ebc728df05346e7d2f785b1ff8fc5b-01jkmq8ej078dbm9g8w1b5rjy0 2025-02-09 06:44:58,308 DEBUG [c.c.k.c.a.KubernetesClusterActionWorker] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Checking deployment destination for Kubernetes cluster : f4ebc728df05346e7d2f785b1ff8fc5b-01jkmq8ej078dbm9g8w1b5rjy0 in zone : DC-02 2025-02-09 06:44:58,311 DEBUG [c.c.k.c.a.KubernetesClusterActionWorker] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Checking host : mykvm for capacity already reserved 1 2025-02-09 06:44:58,314 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Checking if host: 10 has enough capacity for requested CPU: 4600 and requested RAM: (2.00 GB) 2147483648 , cpuOverprovisioningFactor: 4.0 2025-02-09 06:44:58,315 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Hosts's actual total CPU: 110400 and CPU after applying overprovisioning: 441600 2025-02-09 06:44:58,315 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Free CPU: 406100 , Requested CPU: 4600 2025-02-09 06:44:58,315 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Free RAM: (45.26 GB) 48597209088 , Requested RAM: (2.00 GB) 2147483648 2025-02-09 06:44:58,315 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Host has enough CPU and RAM available 2025-02-09 06:44:58,315 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) STATS: Can alloc CPU from host: 10, used: 35500, reserved: 0, actual total: 110400, total with overprovisioning: 441600; requested cpu:4600,alloc_from_last_host?:false ,considerReservedCapacity?: true 2025-02-09 06:44:58,315 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) STATS: Can alloc MEM from host: 10, used: (16.50 GB) 17716740096, reserved: (0 bytes) 0, total: (61.76 GB) 66313949184; requested mem: (2.00 GB) 2147483648, alloc_from_last_host?: false , considerReservedCapacity?: true 2025-02-09 06:44:58,315 DEBUG [c.c.k.c.a.KubernetesClusterActionWorker] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Found host : mykvm for with enough capacity, CPU=4600 RAM=(2.00 GB) 2147483648 2025-02-09 06:44:58,317 DEBUG [c.c.k.c.a.KubernetesClusterActionWorker] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Checking host : mykvm for capacity already reserved 2 2025-02-09 06:44:58,317 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Checking if host: 10 has enough capacity for requested CPU: 9200 and requested RAM: (4.00 GB) 4294967296 , cpuOverprovisioningFactor: 4.0 2025-02-09 06:44:58,318 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Hosts's actual total CPU: 110400 and CPU after applying overprovisioning: 441600 2025-02-09 06:44:58,318 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Free CPU: 406100 , Requested CPU: 9200 2025-02-09 06:44:58,318 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Free RAM: (45.26 GB) 48597209088 , Requested RAM: (4.00 GB) 4294967296 2025-02-09 06:44:58,318 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Host has enough CPU and RAM available 2025-02-09 06:44:58,318 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) STATS: Can alloc CPU from host: 10, used: 35500, reserved: 0, actual total: 110400, total with overprovisioning: 441600; requested cpu:9200,alloc_from_last_host?:false ,considerReservedCapacity?: true 2025-02-09 06:44:58,318 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) STATS: Can alloc MEM from host: 10, used: (16.50 GB) 17716740096, reserved: (0 bytes) 0, total: (61.76 GB) 66313949184; requested mem: (4.00 GB) 4294967296, alloc_from_last_host?: false , considerReservedCapacity?: true 2025-02-09 06:44:58,318 DEBUG [c.c.k.c.a.KubernetesClusterActionWorker] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Found host : mykvm for with enough capacity, CPU=9200 RAM=(4.00 GB) 4294967296 2025-02-09 06:44:58,318 INFO [c.c.k.c.a.KubernetesClusterActionWorker] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Suitable hosts found in datacenter : DC-02, creating deployment destination 2025-02-09 06:44:58,319 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Starting network Network {"id": 771, "name": "01hbjj7v1bfesn3gpsctyc97xb_1738567302", "uuid": "73751eed-5504-4435-811d-b415fb5a5dd8", "networkofferingid": 25}... 2025-02-09 06:44:58,349 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Lock is acquired for network id 771 as a part of network implement 2025-02-09 06:44:58,349 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Asking ExternalGuestNetworkGuru to implement Network {"id": 771, "name": "01hbjj7v1bfesn3gpsctyc97xb_1738567302", "uuid": "73751eed-5504-4435-811d-b415fb5a5dd8", "networkofferingid": 25} 2025-02-09 06:44:58,489 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Asking VirtualRouter to implement Network {"id": 771, "name": "01hbjj7v1bfesn3gpsctyc97xb_1738567302", "uuid": "73751eed-5504-4435-811d-b415fb5a5dd8", "networkofferingid": 25} 2025-02-09 06:44:58,491 DEBUG [c.c.n.r.NetworkHelperImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Starting router VM instance {"id":1998,"instanceName":"r-1998-VM","type":"DomainRouter","uuid":"0c35ea7c-1452-42f3-8847-0d07f311aee4"} 2025-02-09 06:44:58,492 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) start parameter value of enterHardwareSetup == null during processing of queued job 2025-02-09 06:44:58,521 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Sync job-21306 execution on object VmWorkJobQueue.1998 2025-02-09 06:45:00,156 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:e0e740c4) Add job-21306 into job monitoring 2025-02-09 06:45:00,161 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:eff3ec0a) Executing AsyncJobVO: {id:21306, userId: 5, accountId: 5, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAAFAAAAAAAAAAUAAAAAAAAHznQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRmFjdG9ySQAJdGhyZXNob2xkeHA_QAAAAAAADHcIAAAAEAAAAAF0AA5SZXN0YXJ0TmV0d29ya3QAP3JPMEFCWE55QUJGcVlYWmhMbXhoYm1jdVFtOXZiR1ZoYnMwZ2NvRFZuUHJ1QWdBQldnQUZkbUZzZFdWNGNBRXhw, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345051312967, completeMsid: null, lastUpdated: null, lastPolled: null, created: Sun Feb 09 06:44:58 UTC 2025, removed: null} 2025-02-09 06:45:00,162 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:eff3ec0a) Run VM work job: com.cloud.vm.VmWorkStart for VM 1998, job origin: 21305 2025-02-09 06:45:00,165 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Execute VM work job: com.cloud.vm.VmWorkStart{"accountId":5,"dcId":0,"vmId":1998,"handlerName":"VirtualMachineManagerImpl","userId":5,"rawParams":{"RestartNetwork":"rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE"}} 2025-02-09 06:45:00,169 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) orchestrating VM start for 'r-1998-VM' com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d set to null 2025-02-09 06:45:00,181 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) VM instance {"id":1998,"instanceName":"r-1998-VM","type":"DomainRouter","uuid":"0c35ea7c-1452-42f3-8847-0d07f311aee4"} state transited from [Stopped] to [Starting] with event [StartRequested]. VM's original host: null, new host: null, host before state transition: null 2025-02-09 06:45:00,188 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Successfully transitioned to start state for VM instance {"id":1998,"instanceName":"r-1998-VM","type":"DomainRouter","uuid":"0c35ea7c-1452-42f3-8847-0d07f311aee4"} reservation id = 5a24bf76-a3df-4379-a5b8-72764dd78c88 2025-02-09 06:45:00,224 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Deploy avoids pods: null, clusters: null, hosts: null 2025-02-09 06:45:00,227 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) VM start attempt #1 2025-02-09 06:45:00,231 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Root volume is ready, need to place VM in volume's cluster 2025-02-09 06:45:00,231 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Vol[2282|name=ROOT-1998|vm=1998|ROOT] is READY, changing deployment plan to use this pool's dcId: 1 , podId: 1 , and clusterId: 1 2025-02-09 06:45:00,242 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Adding pods to avoid lists: [] 2025-02-09 06:45:00,242 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Adding clusters to avoid lists: [] 2025-02-09 06:45:00,242 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Adding hosts to avoid lists: [] 2025-02-09 06:45:00,242 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) DeploymentPlanner allocation algorithm: null 2025-02-09 06:45:00,242 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 500, requested ram: (256.00 MB) 268435456 2025-02-09 06:45:00,242 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Is ROOT volume READY (pool already allocated)?: Yes 2025-02-09 06:45:00,248 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Deploy avoids pods: [], clusters: [], hosts: [] 2025-02-09 06:45:00,248 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Deploy hosts with priorities {} , hosts have NORMAL priority by default 2025-02-09 06:45:00,249 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) This VM has last host_id specified, trying to choose the same host: 13 2025-02-09 06:45:00,327 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) VM instance {"id":1998,"instanceName":"r-1998-VM","type":"DomainRouter","uuid":"0c35ea7c-1452-42f3-8847-0d07f311aee4"} state transited from [Starting] to [Stopped] with event [OperationFailed]. VM's original host: null, new host: null, host before state transition: null 2025-02-09 06:45:00,333 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Invocation exception, caused by: java.lang.NullPointerException 2025-02-09 06:45:00,334 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306 ctx-b4a10a10) (logid:eff3ec0a) Rethrow exception java.lang.NullPointerException 2025-02-09 06:45:00,334 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:eff3ec0a) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 1998, job origin: 21305 2025-02-09 06:45:00,334 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:eff3ec0a) Unable to complete AsyncJobVO: {id:21306, userId: 5, accountId: 5, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAAFAAAAAAAAAAUAAAAAAAAHznQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRmFjdG9ySQAJdGhyZXNob2xkeHA_QAAAAAAADHcIAAAAEAAAAAF0AA5SZXN0YXJ0TmV0d29ya3QAP3JPMEFCWE55QUJGcVlYWmhMbXhoYm1jdVFtOXZiR1ZoYnMwZ2NvRFZuUHJ1QWdBQldnQUZkbUZzZFdWNGNBRXhw, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345051312967, completeMsid: null, lastUpdated: null, lastPolled: null, created: Sun Feb 09 06:44:58 UTC 2025, removed: null}, job origin:21305 2025-02-09 06:45:00,342 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:eff3ec0a) Complete async job-21306, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyAB5qYXZhLmxhbmcuTnVsbFBvaW50ZXJFeGNlcHRpb25HpaGO_zHhuAIAAHhyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsDAARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4ACHB1cgAeW0xqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnQ7AkYqPDz9IjkCAAB4cAAAACJzcgAbamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50YQnFmiY23YUCAAhCAAZmb3JtYXRJAApsaW5lTnVtYmVyTAAPY2xhc3NMb2FkZXJOYW1lcQB-AAVMAA5kZWNsYXJpbmdDbGFzc3EAfgAFTAAIZmlsZU5hbWVxAH4ABUwACm1ldGhvZE5hbWVxAH4ABUwACm1vZHVsZU5hbWVxAH4ABUwADW1vZHVsZVZlcnNpb25xAH4ABXhwAQAAA290AANhcHB0AB5jb20uY2xvdWQuaG9zdC5kYW8uSG9zdERhb0ltcGx0ABBIb3N0RGFvSW1wbC5qYXZhdAAMbG9hZEhvc3RUYWdzcHBzcQB-AAsA_____3B0AC9qZGsuaW50ZXJuYWwucmVmbGVjdC5HZW5lcmF0ZWRNZXRob2RBY2Nlc3NvcjQxOHB0AAZpbnZva2VwcHNxAH4ACwIAAAArcHQAMWpkay5pbnRlcm5hbC5yZWZsZWN0LkRlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGx0ACFEZWxlZ2F0aW5nTWV0aG9kQWNjZXNzb3JJbXBsLmphdmFxAH4AE3QACWphdmEuYmFzZXQABzExLjAuMjVzcQB-AAsCAAACNnB0ABhqYXZhLmxhbmcucmVmbGVjdC5NZXRob2R0AAtNZXRob2QuamF2YXEAfgATcQB-ABdxAH4AGHNxAH4ACwEAAAFYcQB-AA10AChvcmcuc3ByaW5nZnJhbWV3b3JrLmFvcC5zdXBwb3J0LkFvcFV0aWxzdAANQW9wVXRpbHMuamF2YXQAHmludm9rZUpvaW5wb2ludFVzaW5nUmVmbGVjdGlvbnBwc3EAfgALAQAAAMZxAH4ADXQAPG9yZy5zcHJpbmdmcmFtZXdvcmsuYW9wLmZyYW1ld29yay5SZWZsZWN0aXZlTWV0aG9kSW52b2NhdGlvbnQAH1JlZmxlY3RpdmVNZXRob2RJbnZvY2F0aW9uLmphdmF0AA9pbnZva2VKb2lucG9pbnRwcHNxAH4ACwEAAACjcQB-AA1xAH4AIXEAfgAidAAHcHJvY2VlZHBwc3EAfgALAQAAACJxAH4ADXQAMGNvbS5jbG91ZC51dGlscy5kYi5UcmFuc2FjdGlvbkNvbnRleHRJbnRlcmNlcHRvcnQAIlRyYW5zYWN0aW9uQ29udGV4dEludGVyY2VwdG9yLmphdmFxAH4AE3Bwc3EAfgALAQAAAK9xAH4ADXEAfgAhcQB-ACJxAH4AJXBwc3EAfgALAQAAAGFxAH4ADXQAP29yZy5zcHJpbmdmcmFtZXdvcmsuYW9wLmludGVyY2VwdG9yLkV4cG9zZUludm9jYXRpb25JbnRlcmNlcHRvcnQAIEV4cG9zZUludm9jYXRpb25JbnRlcmNlcHRvci5qYXZhcQB-ABNwcHNxAH4ACwEAAAC6cQB-AA1xAH4AIXEAfgAicQB-ACVwcHNxAH4ACwEAAADXcQB-AA10ADRvcmcuc3ByaW5nZnJhbWV3b3JrLmFvcC5mcmFtZXdvcmsuSmRrRHluYW1pY0FvcFByb3h5dAAXSmRrRHluYW1pY0FvcFByb3h5LmphdmFxAH4AE3Bwc3EAfgALAP____9wdAAWY29tLnN1bi5wcm94eS4kUHJveHk5NnBxAH4AEHBwc3EAfgALAQAAAcNxAH4ADXQALmNvbS5jbG91ZC5kZXBsb3kuRGVwbG95bWVudFBsYW5uaW5nTWFuYWdlckltcGx0ACJEZXBsb3ltZW50UGxhbm5pbmdNYW5hZ2VySW1wbC5qYXZhdAAOcGxhbkRlcGxveW1lbnRwcHNxAH4ACwEAAAS-cQB-AA10ACZjb20uY2xvdWQudm0uVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbHQAHlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwuamF2YXQAEG9yY2hlc3RyYXRlU3RhcnRwcHNxAH4ACwEAABVucQB-AA1xAH4AOHEAfgA5cQB-ADpwcHNxAH4ACwD_____cHQAL2pkay5pbnRlcm5hbC5yZWZsZWN0LkdlbmVyYXRlZE1ldGhvZEFjY2Vzc29yNzQ0cHEAfgATcHBzcQB-AAsCAAAAK3BxAH4AFXEAfgAWcQB-ABNxAH4AF3EAfgAYc3EAfgALAgAAAjZwcQB-ABpxAH4AG3EAfgATcQB-ABdxAH4AGHNxAH4ACwEAAABpcQB-AA10ACJjb20uY2xvdWQudm0uVm1Xb3JrSm9iSGFuZGxlclByb3h5dAAaVm1Xb3JrSm9iSGFuZGxlclByb3h5LmphdmF0AA9oYW5kbGVWbVdvcmtKb2JwcHNxAH4ACwEAABXqcQB-AA1xAH4AOHEAfgA5cQB-AENwcHNxAH4ACwEAAABmcQB-AA10ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnBwc3EAfgALAQAAAo5xAH4ADXQAP29yZy5hcGFjaGUuY2xvdWRzdGFjay5mcmFtZXdvcmsuam9icy5pbXBsLkFzeW5jSm9iTWFuYWdlckltcGwkNXQAGEFzeW5jSm9iTWFuYWdlckltcGwuamF2YXQADHJ1bkluQ29udGV4dHBwc3EAfgALAQAAADBxAH4ADXQAPm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZSQxdAAbTWFuYWdlZENvbnRleHRSdW5uYWJsZS5qYXZhdAADcnVucHBzcQB-AAsBAAAAN3EAfgANdABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxscHBzcQB-AAsBAAAAZnEAfgANdABAb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dHEAfgBTdAAPY2FsbFdpdGhDb250ZXh0cHBzcQB-AAsBAAAANHEAfgANcQB-AFZxAH4AU3QADnJ1bldpdGhDb250ZXh0cHBzcQB-AAsBAAAALXEAfgANdAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-AE9xAH4AUHBwc3EAfgALAQAAAlpxAH4ADXEAfgBKcQB-AEtxAH4AUHBwc3EAfgALAgAAAgNwdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-AFRxAH4AF3EAfgAYc3EAfgALAgAAAQhwdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgBQcQB-ABdxAH4AGHNxAH4ACwIAAARocHQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2VycQB-ABdxAH4AGHNxAH4ACwIAAAJ0cHQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AZXEAfgBQcQB-ABdxAH4AGHNxAH4ACwIAAAM9cHQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgBQcQB-ABdxAH4AGHNyAB9qYXZhLnV0aWwuQ29sbGVjdGlvbnMkRW1wdHlMaXN0ergXtDynnt4CAAB4cHg 2025-02-09 06:45:00,343 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:eff3ec0a) Publish async job-21306 complete on message bus 2025-02-09 06:45:00,343 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:eff3ec0a) Wake up jobs related to job-21306 2025-02-09 06:45:00,343 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:eff3ec0a) Update db status for job-21306 2025-02-09 06:45:00,345 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:eff3ec0a) Wake up jobs joined with job-21306 and disjoin all subjobs created from job- 21306 2025-02-09 06:45:00,375 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:eff3ec0a) Done executing com.cloud.vm.VmWorkStart for job-21306 2025-02-09 06:45:00,376 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-70:ctx-c3aefcac job-21305/job-21306) (logid:eff3ec0a) Remove job-21306 from job monitoring 2025-02-09 06:45:00,408 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Cleaning up because we're unable to implement the network Network {"id": 771, "name": "01hbjj7v1bfesn3gpsctyc97xb_1738567302", "uuid": "73751eed-5504-4435-811d-b415fb5a5dd8", "networkofferingid": 25} 2025-02-09 06:45:00,481 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Lock is acquired for network Network {"id": 771, "name": "01hbjj7v1bfesn3gpsctyc97xb_1738567302", "uuid": "73751eed-5504-4435-811d-b415fb5a5dd8", "networkofferingid": 25} as a part of network shutdown 2025-02-09 06:45:00,484 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Sending network shutdown to VirtualRouter 2025-02-09 06:45:00,487 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Stopping router VM instance {"id":1998,"instanceName":"r-1998-VM","type":"DomainRouter","uuid":"0c35ea7c-1452-42f3-8847-0d07f311aee4"} 2025-02-09 06:45:00,518 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Sync job-21307 execution on object VmWorkJobQueue.1998 2025-02-09 06:45:02,162 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307) (logid:3d2f0729) Add job-21307 into job monitoring 2025-02-09 06:45:02,165 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307) (logid:eff3ec0a) Executing AsyncJobVO: {id:21307, userId: 5, accountId: 5, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAAFAAAAAAAAAAUAAAAAAAAHznQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345051312967, completeMsid: null, lastUpdated: null, lastPolled: null, created: Sun Feb 09 06:45:00 UTC 2025, removed: null} 2025-02-09 06:45:02,168 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307) (logid:eff3ec0a) Run VM work job: com.cloud.vm.VmWorkStop for VM 1998, job origin: 21305 2025-02-09 06:45:02,170 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307 ctx-81b7396a) (logid:eff3ec0a) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":5,"accountId":5,"vmId":1998,"handlerName":"VirtualMachineManagerImpl"} 2025-02-09 06:45:02,172 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307 ctx-81b7396a) (logid:eff3ec0a) VM is already stopped: VM instance {"id":1998,"instanceName":"r-1998-VM","type":"DomainRouter","uuid":"0c35ea7c-1452-42f3-8847-0d07f311aee4"} 2025-02-09 06:45:02,172 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307 ctx-81b7396a) (logid:eff3ec0a) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":5,"accountId":5,"vmId":1998,"handlerName":"VirtualMachineManagerImpl"} 2025-02-09 06:45:02,173 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307 ctx-81b7396a) (logid:eff3ec0a) Complete async job-21307, jobStatus: SUCCEEDED, resultCode: 0, result: null 2025-02-09 06:45:02,174 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307 ctx-81b7396a) (logid:eff3ec0a) Publish async job-21307 complete on message bus 2025-02-09 06:45:02,174 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307 ctx-81b7396a) (logid:eff3ec0a) Wake up jobs related to job-21307 2025-02-09 06:45:02,174 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307 ctx-81b7396a) (logid:eff3ec0a) Update db status for job-21307 2025-02-09 06:45:02,175 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307 ctx-81b7396a) (logid:eff3ec0a) Wake up jobs joined with job-21307 and disjoin all subjobs created from job- 21307 2025-02-09 06:45:02,221 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307) (logid:eff3ec0a) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 1998, job origin: 21305 2025-02-09 06:45:02,221 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307) (logid:eff3ec0a) Done executing com.cloud.vm.VmWorkStop for job-21307 2025-02-09 06:45:02,223 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-71:ctx-8a2816ac job-21305/job-21307) (logid:eff3ec0a) Remove job-21307 from job monitoring 2025-02-09 06:45:02,258 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Network id=771 is shutdown successfully, cleaning up corresponding resources now. 2025-02-09 06:45:02,261 DEBUG [c.c.n.g.GuestNetworkGuru] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Releasing vnet for the network id=771 2025-02-09 06:45:02,371 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Lock is released for network Network {"id": 771, "name": "01hbjj7v1bfesn3gpsctyc97xb_1738567302", "uuid": "73751eed-5504-4435-811d-b415fb5a5dd8", "networkofferingid": 25} as a part of network shutdown 2025-02-09 06:45:02,440 DEBUG [o.a.c.e.o.NetworkOrchestrator] (API-Job-Executor-39:ctx-ceb65524 job-21305 ctx-966ac5d2) (logid:eff3ec0a) Lock is released for network id 771 as a part of network implement 2025-02-09 06:45:02,480 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-39:ctx-ceb65524 job-21305) (logid:eff3ec0a) Unexpected exception while executing org.apache.cloudstack.api.command.user.kubernetes.cluster.CreateKubernetesClusterCmd 2025-02-09 06:45:02,482 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305) (logid:eff3ec0a) Complete async job-21305, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":"530"} 2025-02-09 06:45:02,483 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305) (logid:eff3ec0a) Publish async job-21305 complete on message bus 2025-02-09 06:45:02,483 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305) (logid:eff3ec0a) Wake up jobs related to job-21305 2025-02-09 06:45:02,483 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305) (logid:eff3ec0a) Update db status for job-21305 2025-02-09 06:45:02,484 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305) (logid:eff3ec0a) Wake up jobs joined with job-21305 and disjoin all subjobs created from job- 21305 2025-02-09 06:45:02,535 DEBUG [c.c.a.ApiServer] (API-Job-Executor-39:ctx-ceb65524 job-21305) (logid:eff3ec0a) Retrieved cmdEventType from job info: KUBERNETES.CLUSTER.CREATE 2025-02-09 06:45:02,540 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-39:ctx-ceb65524 job-21305) (logid:eff3ec0a) Done executing org.apache.cloudstack.api.command.user.kubernetes.cluster.CreateKubernetesClusterCmd for job-21305 2025-02-09 06:45:02,542 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-39:ctx-ceb65524 job-21305) (logid:eff3ec0a) Remove job-21305 from job monitoring
versions
CloudStack 4.19.1.3
kvm cluster with 3host
The steps to reproduce the bug
No response
What to do about it?
No response