ahmadamirahmadi1401 opened a new issue, #10353:
URL: https://github.com/apache/cloudstack/issues/10353
### 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":"[email protected]"},
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-55
04-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":"[email protected]"},
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":"[email protected]","id":5,"uuid":"c0852b26-aa19-46d0-8b5f-a4852e2cd242"}]
granted to Account
[{"accountName":"[email protected]","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":"[email protected]","id":5,"uuid":"c0852b26-aa19-46d0-8b5f-a4852e2cd242"}]
granted to Account
[{"accountName":"[email protected]","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 [email protected]
(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":"[email protected]","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":"[email protected]","id":5,"uuid":"c0852b26-aa19-46d0-8b5f-a4852e2cd242"}]
to Domain:3/[email protected]/ 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":"[email protected]","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_QAAAAAAADHcIAAAAEAAAAAF0AA5SZX
N0YXJ0TmV0d29ya3QAP3JPMEFCWE55QUJGcVlYWmhMbXhoYm1jdVFtOXZiR1ZoYnMwZ2NvRFZuUHJ1QWdBQldnQUZkbUZzZFdWNGNBRXhw,
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_QAAAAAAADHcIAAAAEAAAAAF0AA5
SZXN0YXJ0TmV0d29ya3QAP3JPMEFCWE55QUJGcVlYWmhMbXhoYm1jdVFtOXZiR1ZoYnMwZ2NvRFZuUHJ1QWdBQldnQUZkbUZzZFdWNGNBRXhw,
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-AAVMAA5kZWNsYXJpbmdDbGFzc3EAfgAFTAAIZmlsZU5hbWVxAH4ABUwACm1ldGhvZE5hbWVxAH4ABUwACm1vZHVsZU5hbWVxAH4ABUwADW1vZHVsZVZlcnNpb25xAH4ABXhwAQAAA290AANhcHB0AB5jb20uY2xvdWQuaG9zdC5kYW8uSG
9zdERhb0ltcGx0ABBIb3N0RGFvSW1wbC5qYXZhdAAMbG9hZEhvc3RUYWdzcHBzcQB-AAsA_____3B0AC9qZGsuaW50ZXJuYWwucmVmbGVjdC5HZW5lcmF0ZWRNZXRob2RBY2Nlc3NvcjQxOHB0AAZpbnZva2VwcHNxAH4ACwIAAAArcHQAMWpkay5pbnRlcm5hbC5yZWZsZWN0LkRlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGx0ACFEZWxlZ2F0aW5nTWV0aG9kQWNjZXNzb3JJbXBsLmphdmFxAH4AE3QACWphdmEuYmFzZXQABzExLjAuMjVzcQB-AAsCAAACNnB0ABhqYXZhLmxhbmcucmVmbGVjdC5NZXRob2R0AAtNZXRob2QuamF2YXEAfgATcQB-ABdxAH4AGHNxAH4ACwEAAAFYcQB-AA10AChvcmcuc3ByaW5nZnJhbWV3b3JrLmFvcC5zdXBwb3J0LkFvcFV0aWxzdAANQW9wVXRpbHMuamF2YXQAHmludm9rZUpvaW5wb2ludFVzaW5nUmVmbGVjdGlvbnBwc3EAfgALAQAAAMZxAH4ADXQAPG9yZy5zcHJpbmdmcmFtZXdvcmsuYW9wLmZyYW1ld29yay5SZWZsZWN0aXZlTWV0aG9kSW52b2NhdGlvbnQAH1JlZmxlY3RpdmVNZXRob2RJbnZvY2F0aW9uLmphdmF0AA9pbnZva2VKb2lucG9pbnRwcHNxAH4ACwEAAACjcQB-AA1xAH4AIXEAfgAidAAHcHJvY2VlZHBwc3EAfgALAQAAACJxAH4ADXQAMGNvbS5jbG91ZC51dGlscy5kYi5UcmFuc2FjdGlvbkNvbnRleHRJbnRlcmNlcHRvcnQAIlRyYW5zYWN0aW9uQ29udGV4dEludGVyY2VwdG9yLmphdmFxAH4AE3Bwc3EAfgALAQAAAK9xAH4ADXEAfgAhcQB-ACJxAH4AJXBwc3EAfgALAQA
AAGFxAH4ADXQAP29yZy5zcHJpbmdmcmFtZXdvcmsuYW9wLmludGVyY2VwdG9yLkV4cG9zZUludm9jYXRpb25JbnRlcmNlcHRvcnQAIEV4cG9zZUludm9jYXRpb25JbnRlcmNlcHRvci5qYXZhcQB-ABNwcHNxAH4ACwEAAAC6cQB-AA1xAH4AIXEAfgAicQB-ACVwcHNxAH4ACwEAAADXcQB-AA10ADRvcmcuc3ByaW5nZnJhbWV3b3JrLmFvcC5mcmFtZXdvcmsuSmRrRHluYW1pY0FvcFByb3h5dAAXSmRrRHluYW1pY0FvcFByb3h5LmphdmFxAH4AE3Bwc3EAfgALAP____9wdAAWY29tLnN1bi5wcm94eS4kUHJveHk5NnBxAH4AEHBwc3EAfgALAQAAAcNxAH4ADXQALmNvbS5jbG91ZC5kZXBsb3kuRGVwbG95bWVudFBsYW5uaW5nTWFuYWdlckltcGx0ACJEZXBsb3ltZW50UGxhbm5pbmdNYW5hZ2VySW1wbC5qYXZhdAAOcGxhbkRlcGxveW1lbnRwcHNxAH4ACwEAAAS-cQB-AA10ACZjb20uY2xvdWQudm0uVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbHQAHlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwuamF2YXQAEG9yY2hlc3RyYXRlU3RhcnRwcHNxAH4ACwEAABVucQB-AA1xAH4AOHEAfgA5cQB-ADpwcHNxAH4ACwD_____cHQAL2pkay5pbnRlcm5hbC5yZWZsZWN0LkdlbmVyYXRlZE1ldGhvZEFjY2Vzc29yNzQ0cHEAfgATcHBzcQB-AAsCAAAAK3BxAH4AFXEAfgAWcQB-ABNxAH4AF3EAfgAYc3EAfgALAgAAAjZwcQB-ABpxAH4AG3EAfgATcQB-ABdxAH4AGHNxAH4ACwEAAABpcQB-AA10ACJjb20uY2xvdWQudm0uVm1Xb3JrSm9i
SGFuZGxlclByb3h5dAAaVm1Xb3JrSm9iSGFuZGxlclByb3h5LmphdmF0AA9oYW5kbGVWbVdvcmtKb2JwcHNxAH4ACwEAABXqcQB-AA1xAH4AOHEAfgA5cQB-AENwcHNxAH4ACwEAAABmcQB-AA10ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnBwc3EAfgALAQAAAo5xAH4ADXQAP29yZy5hcGFjaGUuY2xvdWRzdGFjay5mcmFtZXdvcmsuam9icy5pbXBsLkFzeW5jSm9iTWFuYWdlckltcGwkNXQAGEFzeW5jSm9iTWFuYWdlckltcGwuamF2YXQADHJ1bkluQ29udGV4dHBwc3EAfgALAQAAADBxAH4ADXQAPm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZSQxdAAbTWFuYWdlZENvbnRleHRSdW5uYWJsZS5qYXZhdAADcnVucHBzcQB-AAsBAAAAN3EAfgANdABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxscHBzcQB-AAsBAAAAZnEAfgANdABAb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dHEAfgBTdAAPY2FsbFdpdGhDb250ZXh0cHBzcQB-AAsBAAAANHEAfgANcQB-AFZxAH4AU3QADnJ1bldpdGhDb250ZXh0cHBzcQB-AAsBAAAALXEAfgANdAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hb
mFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-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_
--
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]
