Kubernetes cluster deployment fails on new zone #10467

tdtmusic2 · 2025-02-26T11:35:13Z

tdtmusic2
Feb 26, 2025

Hi all. I have a new zone in ACS and for some reason kubernetes deployment fails on it, I cannot understand why from the logs alone. The difference between this zone and others is that it uses local storage instead of shared, so I'm deploying the cluster with a local storage offering. Sometimes the control vm gets deployed and then I get the error about failing to provision the cluster, other times I get "Failed to start Kubernetes cluster : vvvvv as its network cannot be started".
In the management logs I have this:

2025-02-26 13:23:55,543 ERROR [c.c.k.c.a.KubernetesClusterActionWorker] (API-Job-Executor-26:ctx-efec1997 job-114548 ctx-640e4c03) (logid:69810a52) Failed to start Kubernetes cluster : vvvvvv as unable to start associated network : vvvvvv-network
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":2937,"instanceName":"r-2937-VM","type":"DomainRouter","uuid":"22467afa-8088-438a-8839-46d65682abb7"}Scope=interface com.cloud.dc.DataCenter; id=14
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1228)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5486)
        at jdk.internal.reflect.GeneratedMethodAccessor1248.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:105)
        at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
        at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:654)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:602)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
2025-02-26 13:23:55,555 ERROR [c.c.k.c.a.KubernetesClusterActionWorker] (API-Job-Executor-26:ctx-efec1997 job-114548 ctx-640e4c03) (logid:69810a52) Failed to start Kubernetes cluster : vvvvvv as its network cannot be started
com.cloud.exception.ManagementServerException: Failed to start Kubernetes cluster : vvvvvv as unable to start associated network : vvvvvv-network
        at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterStartWorker.startKubernetesClusterNetwork(KubernetesClusterStartWorker.java:374)
        at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterStartWorker.startKubernetesClusterOnCreate(KubernetesClusterStartWorker.java:480)
        at com.cloud.kubernetes.cluster.KubernetesClusterManagerImpl.startKubernetesCluster(KubernetesClusterManagerImpl.java:1366)
        at com.cloud.kubernetes.cluster.KubernetesClusterManagerImpl.startKubernetesCluster(KubernetesClusterManagerImpl.java:1295)
        at jdk.internal.reflect.GeneratedMethodAccessor5234.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
        at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:52)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
        at com.sun.proxy.$Proxy466.startKubernetesCluster(Unknown Source)
        at org.apache.cloudstack.api.command.user.kubernetes.cluster.CreateKubernetesClusterCmd.execute(CreateKubernetesClusterCmd.java:293)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:172)
        at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:112)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:654)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:602)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":2937,"instanceName":"r-2937-VM","type":"DomainRouter","uuid":"22467afa-8088-438a-8839-46d65682abb7"}Scope=interface com.cloud.dc.DataCenter; id=14
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1228)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5486)
        at jdk.internal.reflect.GeneratedMethodAccessor1248.invoke(Unknown Source)
        ... 17 more
2025-02-26 13:23:55,560 WARN  [c.c.k.c.a.KubernetesClusterActionWorker] (API-Job-Executor-26:ctx-efec1997 job-114548 ctx-640e4c03) (logid:69810a52) Failed to transition state of the Kubernetes cluster : vvvvvv in state Error on event CreateFailed
com.cloud.utils.fsm.NoTransitionException: Unable to transition to a new state from Error via CreateFailed
        at com.cloud.utils.fsm.StateMachine2.getTransition(StateMachine2.java:108)
        at com.cloud.utils.fsm.StateMachine2.getNextState(StateMachine2.java:94)
        at com.cloud.utils.fsm.StateMachine2.transitTo(StateMachine2.java:124)
        at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterActionWorker.stateTransitTo(KubernetesClusterActionWorker.java:555)
        at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterActionWorker.logTransitStateAndThrow(KubernetesClusterActionWorker.java:281)
        at com.cloud.kubernetes.cluster.actionworkers.KubernetesClusterStartWorker.startKubernetesClusterOnCreate(KubernetesClusterStartWorker.java:482)
        at com.cloud.kubernetes.cluster.KubernetesClusterManagerImpl.startKubernetesCluster(KubernetesClusterManagerImpl.java:1366)
        at com.cloud.kubernetes.cluster.KubernetesClusterManagerImpl.startKubernetesCluster(KubernetesClusterManagerImpl.java:1295)
        at jdk.internal.reflect.GeneratedMethodAccessor5234.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
        at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:52)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215)
        at com.sun.proxy.$Proxy466.startKubernetesCluster(Unknown Source)
        at org.apache.cloudstack.api.command.user.kubernetes.cluster.CreateKubernetesClusterCmd.execute(CreateKubernetesClusterCmd.java:293)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:172)
        at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:112)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:654)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:602)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
2025-02-26 13:23:55,561 INFO  [c.c.k.c.a.KubernetesClusterActionWorker] (API-Job-Executor-26:ctx-efec1997 job-114548 ctx-640e4c03) (logid:69810a52) Revoking launch permission for systemVM template
2025-02-26 13:23:55,588 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-26:ctx-efec1997 job-114548) (logid:69810a52) Complete async job-114548, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":"530","errortext":"Failed to start Kubernetes cluster : vvvvvv as its network cannot be started"}

Could this be related to some offering that needs to be modified? From all this log output the thing that stands out is com.cloud.exception.InsufficientServerCapacityException, but I don't know what it reffers to.

tdtmusic2 · 2025-02-26T12:19:08Z

tdtmusic2
Feb 26, 2025
Author

Edit: it seems that all it needed was a restart of cloudstack-management, after this I can deploy clusters without issue. I would still like to know why it behaves like this, the logs don't really suggest a restart being needed :)

2 replies

DaanHoogland Feb 26, 2025
Collaborator

usually a management restart should only be needed for non-dynamic settings to be changed. During enabling of kubernetes there is some of that, but by your description it seems you already had k8s enabled in your env, did you?

tdtmusic2 Feb 26, 2025
Author

usually a management restart should only be needed for non-dynamic settings to be changed. During enabling of kubernetes there is some of that, but by your description it seems you already had k8s enabled in your env, did you?

Yes, it was enabled and working in other zones. What was the most weird thing is that it didn't always fail instantly after hitting the create button, sometimes it would bring up 1 or 2 nodes and then fail, other times the control node was up and then the error showed up, etc.

weizhouapache · 2025-02-26T14:36:16Z

weizhouapache
Feb 26, 2025
Collaborator

"Failed to start Kubernetes cluster : vvvvv as its network cannot be started".

there should be some logs which tells why the network cannot be started.

9 replies

DaanHoogland Feb 26, 2025
Collaborator

This is the significant fragement and it shows that the only host is not selected because of not enough capacity:

2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Found 1 hosts for allocation after prioritization: [Host {"id":194,"name":"NODL1","type":"Routing","uuid":"cce73e3a-33f2-440a-8c50-f9133757b992"}]
2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Looking for speed=500Mhz, Ram=256 MB
2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Host name: NODL1, hostId: 194 is in avoid set, skipping this and trying other available hosts
2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Host Allocator returning 0 suitable hosts

therefore the router is not deploy and hence the network is not started.

tdtmusic2 Feb 26, 2025
Author

@tdtmusic2 any logs between VM start attempt #1 and VM start attempt #2 ?

Yeap, this:

2025-02-26 13:14:38,465 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470) (logid:a3c62ef8) Run VM work job: com.cloud.vm.VmWorkStart for VM 29
2025-02-26 13:14:38,472 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Execute VM work job: com.cloud.vm.VmndlerName":"VirtualMachineManagerImpl","userId":2,"rawParams":{"RestartNetwork":"rO0ABXNyABFqYXZhLmxhbmcuQm9vbGVhbs0gcoDVnPruAgABWgAFdmFsdWV4cAE"}}
2025-02-26 13:14:38,475 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) orchestrating VM start for 'r-29b66cdd7d set to null
2025-02-26 13:14:38,495 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) VM instance {"id":2931,"instanceName":f1-45eb-4800-b3e1-1b8ced54bfcc"} state transited from [Stopped] to [Starting] with event [StartRequested]. VM's original host: null, new host: null, host before state transition: null
2025-02-26 13:14:38,496 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Successfully transitioned to stae":"r-2931-VM","type":"DomainRouter","uuid":"d76590f1-45eb-4800-b3e1-1b8ced54bfcc"} reservation id = d8c6b759-c1eb-4831-9384-57b952402e25
2025-02-26 13:14:38,507 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Deploy avoids pods: null, cluste
2025-02-26 13:14:38,521 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) VM start attempt #1
2025-02-26 13:14:38,559 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Adding pods to avoid lists:
2025-02-26 13:14:38,559 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Adding clusters to avoid lis
2025-02-26 13:14:38,559 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Adding hosts to avoid lists:
2025-02-26 13:14:38,559 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) DeploymentPlanner allocation
2025-02-26 13:14:38,559 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Trying to allocate a host anl, requested cpu: 500, requested ram: (256.00 MB) 268435456
2025-02-26 13:14:38,559 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Is ROOT volume READY (pool a
2025-02-26 13:14:38,582 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Deploy avoids pods: [], clus
2025-02-26 13:14:38,582 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Deploy hosts with priorities
2025-02-26 13:14:38,591 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Searching all possible resources under thi
2025-02-26 13:14:38,597 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Listing clusters in order of aggregate cap CPU and RAM capacity under this Zone: 14
2025-02-26 13:14:38,609 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Removing from the clusterId list these clu
2025-02-26 13:14:38,641 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Checking resources in Cluste
2025-02-26 13:14:38,647 INFO  [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8)  Guest VM
2025-02-26 13:14:38,648 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Looking f
2025-02-26 13:14:38,658 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) FirstFitAost {"id":194,"name":"NODL1","type":"Routing","uuid":"cce73e3a-33f2-440a-8c50-f9133757b992"}]
2025-02-26 13:14:38,672 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Found 1 h{"id":194,"name":"NODL1","type":"Routing","uuid":"cce73e3a-33f2-440a-8c50-f9133757b992"}]
2025-02-26 13:14:38,672 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Looking f
2025-02-26 13:14:38,672 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Host {id: 19433757b992} is KVM hypervisor type, no max guest limit check needed
2025-02-26 13:14:38,686 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Host: 194 hasrequested CPU: 1 and requested speed: 500
2025-02-26 13:14:38,686 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Checking if h500 and requested RAM: (256.00 MB) 268435456 , cpuOverprovisioningFactor: 4.0
2025-02-26 13:14:38,692 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Hosts's actuarovisioning: 640000
2025-02-26 13:14:38,692 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Free CPU: 626
2025-02-26 13:14:38,692 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Free RAM: (23B) 268435456
2025-02-26 13:14:38,692 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Host has enou
2025-02-26 13:14:38,692 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) STATS: Can al, actual total: 160000, total with overprovisioning: 640000; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2025-02-26 13:14:38,692 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) STATS: Can al1888, reserved: (0 bytes) 0, total: (250.04 GB) 268477251584; requested mem: (256.00 MB) 268435456, alloc_from_last_host?: false , considerReservedCapacity?: true
2025-02-26 13:14:38,692 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Found a s
2025-02-26 13:14:38,692 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Host Allo
2025-02-26 13:14:38,693 INFO  [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Re-ordering hosts [Host {"ide73e3a-33f2-440a-8c50-f9133757b992"}] by priorities {}
2025-02-26 13:14:38,693 INFO  [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Hosts after re-ordering are:,"uuid":"cce73e3a-33f2-440a-8c50-f9133757b992"}]
2025-02-26 13:14:38,699 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Checking suitable pools for
2025-02-26 13:14:38,699 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) We need to allocate new stor
2025-02-26 13:14:38,702 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Calling StoragePoolAllocator
2025-02-26 13:14:38,710 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) System VMs will use local st
2025-02-26 13:14:38,719 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Checking if storage pool d5-9815-36facb6d157f"}] is suitable to disk [DskChr[ROOT|5242880000|]].
2025-02-26 13:14:38,723 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Volume [Vol[9449|name=ROOT-2931|vm=2931ck compatibility with pool [{"name":"Local London","uuid":"4fa75712-978d-43d5-9815-36facb6d157f"}].
2025-02-26 13:14:38,723 INFO  [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Storage pool Local London (71) does not
2025-02-26 13:14:38,725 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Checking pool 71 for storage, totalSize: 0.00288278856872338, disable threshold: 0.85
2025-02-26 13:14:38,725 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Destination pool id: 71
2025-02-26 13:14:38,764 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Pool ID for the volume with ID 9449 is
2025-02-26 13:14:38,781 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Found storage pool Local London of type
2025-02-26 13:14:38,781 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Total over provisioned capacity calcula
2025-02-26 13:14:38,781 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Total capacity of the pool Local London
2025-02-26 13:14:38,783 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Checking pool: 71 for storage allocatioAllocatedSize : (259.53 GB) 278670344520, askingSize : (4.88 GB) 5242880000, allocated disable threshold: 0.85
2025-02-26 13:14:38,783 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Found suitable local storagekChr[ROOT|5242880000|]] to it, adding to list.
2025-02-26 13:14:38,785 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Checking if storage pool -1ff2-40ee-a71c-927e36e6a470"}] is suitable to disk [DskChr[ROOT|5242880000|]].
2025-02-26 13:14:38,789 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Volume [Vol[9449|name=ROOT-2931|vm=2931ck compatibility with pool [{"name":"NODL1-local-9d437241","uuid":"9d437241-1ff2-40ee-a71c-927e36e6a470"}].
2025-02-26 13:14:38,789 INFO  [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Storage pool NODL1-local-9d437241 (74) apacity
2025-02-26 13:14:38,792 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Checking pool 74 for storage, totalSize.0656565921023235, disable threshold: 0.85
2025-02-26 13:14:38,792 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Destination pool id: 74
2025-02-26 13:14:38,829 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Pool ID for the volume with ID 9449 is
2025-02-26 13:14:38,845 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Found storage pool NODL1-local-9d437241 2
2025-02-26 13:14:38,845 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Total over provisioned capacity calcula
2025-02-26 13:14:38,845 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Total capacity of the pool NODL1-local-
2025-02-26 13:14:38,848 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Checking pool: 74 for storage allocatioocatedSize : (4.88 GB) 5243076768, askingSize : (4.88 GB) 5242880000, allocated disable threshold: 0.85
2025-02-26 13:14:38,848 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Found suitable local storagekChr[ROOT|5242880000|]] to it, adding to list.
2025-02-26 13:14:38,850 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) LocalStoragePoolAllocatore":"Local London","uuid":"4fa75712-978d-43d5-9815-36facb6d157f"}, {"name":"NODL1-local-9d437241","uuid":"9d437241-1ff2-40ee-a71c-927e36e6a470"}]].
2025-02-26 13:14:38,855 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Trying to find a potenial hoe host/pool lists for this VM
2025-02-26 13:14:38,857 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Checking if host: 194 can ac
2025-02-26 13:14:38,858 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Host: 194 can access pool: 7
2025-02-26 13:14:38,863 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Found a potential host id: 1this VM
2025-02-26 13:14:38,865 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Returning Deployment Destina-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(14)-Pod(17)-Cluster(20)-Host(194)-Storage(Volume(9449|ROOT-->Pool(74))]
2025-02-26 13:14:38,867 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Deployment found - Attempt #1 - -VM","type":"DomainRouter","uuid":"d76590f1-45eb-4800-b3e1-1b8ced54bfcc"}, P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(14)-Pod(17)-Cluol(74))]
2025-02-26 13:14:38,893 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) VM instance {"id":2931,"instanceName":f1-45eb-4800-b3e1-1b8ced54bfcc"} state transited from [Starting] to [Starting] with event [OperationRetry]. VM's original host: null, new host: Host {"id":194,"name":"NODL1","type":"Ro992"}, host before state transition: null
2025-02-26 13:14:38,915 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Hosts's actual total CPU: 160000 and C
2025-02-26 13:14:38,916 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) We are allocating VM, increasing the u
2025-02-26 13:14:38,916 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Current Used CPU: 14000 , Free CPU:626
2025-02-26 13:14:38,916 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Current Used RAM: (12.00 GB) 128849018d RAM: (256.00 MB) 268435456
2025-02-26 13:14:38,916 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) CPU STATS after allocation: for host: tal: 160000, total with overprovisioning: 640000; new used:14500, reserved:0; requested cpu:500,alloc_from_last:false
2025-02-26 13:14:38,916 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) RAM STATS after allocation: for host: ved: (0 bytes) 0, total: (250.04 GB) 268477251584; new used: (12.25 GB) 13153337344, reserved: (0 bytes) 0; requested mem: (256.00 MB) 268435456,alloc_from_last:false
2025-02-26 13:14:38,920 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Host: 194 has cpu capability (cpu:80, ested speed: 500
2025-02-26 13:14:38,920 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Checking if host: 194 has enough capac56.00 MB) 268435456 , cpuOverprovisioningFactor: 4.0
2025-02-26 13:14:38,923 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Hosts's actual total CPU: 160000 and C
2025-02-26 13:14:38,923 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) We need to allocate to the last host apacity
2025-02-26 13:14:38,923 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Reserved CPU: 0 , Requested CPU: 500
2025-02-26 13:14:38,923 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Reserved RAM: (0 bytes) 0 , Requested
2025-02-26 13:14:38,923 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) STATS: Failed to alloc resource from hervedMem: (0 bytes) 0, requested mem: (256.00 MB) 268435456
2025-02-26 13:14:38,923 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Host does not have enough reserved CPU
2025-02-26 13:14:38,923 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Checking if host: 194 has enough capac56.00 MB) 268435456 , cpuOverprovisioningFactor: 4.0
2025-02-26 13:14:38,926 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Hosts's actual total CPU: 160000 and C
2025-02-26 13:14:38,926 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Free CPU: 626000 , Requested CPU: 500
2025-02-26 13:14:38,926 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Free RAM: (238.04 GB) 255592349696 , R
2025-02-26 13:14:38,926 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Host has enough CPU and RAM available
2025-02-26 13:14:38,926 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) STATS: Can alloc CPU from host: 194, uotal with overprovisioning: 640000; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2025-02-26 13:14:38,926 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) STATS: Can alloc MEM from host: 194, u 0, total: (250.04 GB) 268477251584; requested mem: (256.00 MB) 268435456, alloc_from_last_host?: false , considerReservedCapacity?: true
2025-02-26 13:14:39,050 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Service SecurityGroup is not supported in
2025-02-26 13:14:39,087 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Asking VirtualRouter to prepare fo0,"iPv4Address":"10.15.0.1","id":15431,"instanceId":2931,"reservationId":"d8c6b759-c1eb-4831-9384-57b952402e25"}
2025-02-26 13:14:39,089 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Service SecurityGroup is not supported in
2025-02-26 13:14:39,282 DEBUG [c.c.n.g.ControlNetworkGuru] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Reserved NIC for r-2931-VM [ipv4:169..1]
2025-02-26 13:14:39,361 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) template 212 is already in sto
2025-02-26 13:14:39,382 DEBUG [o.a.c.s.d.PrimaryDataStoreImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Not found (templateId:212poolId:7
2025-02-26 13:14:39,400 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) template 212 is already in sto
2025-02-26 13:14:39,406 DEBUG [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Found template routing-212 in storag
2025-02-26 13:14:39,409 DEBUG [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Acquire lock on VMTemplateStoragePoo
2025-02-26 13:14:39,417 INFO  [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) lock is acquired for VMTemplateStora
2025-02-26 13:14:39,442 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) copyAsync inspecting src typTE
2025-02-26 13:14:39,468 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) getCommandHostDelegation: class org
2025-02-26 13:14:39,476 DEBUG [c.c.a.m.ClusteredAgentAttache] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Seq 194-5060920081257598385: ForwaId: 73209801370656, via: 194(NODL1), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path"36c99967cb.qcow2","origUrl":"http://download.cloudstack.org/systemvm/4.19/systemvmtemplate-4.19.1-kvm.qcow2.bz2","uuid":"d5103e73-fc6b-4793-90c2-c87cc812e03e","id":"212","format":"QCOW1b0c2386974f389","hvm":"true","displayText":"systemvm-kvm-4.19.1","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://172.17.11.100/secondary","_role":"Image"}},"name":"rousorType":"KVM","bootable":"false","uniqueName":"routing-212","directDownload":"false","deployAsIs":"false","followRedirects":"false"}},"destTO":{"org.apache.cloudstack.storage.to.Templack.org/systemvm/4.19/systemvmtemplate-4.19.1-kvm.qcow2.bz2","uuid":"d5103e73-fc6b-4793-90c2-c87cc812e03e","id":"212","format":"QCOW2","accountId":"1","checksum":"796ce72847a7365ce1b0cm-kvm-4.19.1","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9d437241-1ff2-40ee-a71c-927e36e6a470","name":"NODL1-local-9d437241","id":"74","poolType":lib/libvirt/images","port":"0","url":"Filesystem://172.17.11.81/var/lib/libvirt/images/?ROLE=Primary&STOREUUID=9d437241-1ff2-40ee-a71c-927e36e6a470","isManaged":"false"}},"name":"routirType":"KVM","bootable":"false","uniqueName":"routing-212","directDownload":"false","deployAsIs":"false","followRedirects":"false"}},"executeInSequence":"true","options":{},"options2":"}}] } to 240638319530881
2025-02-26 13:14:39,650 DEBUG [c.c.a.t.Request] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Seq 194-5060920081257598385: Received:  { Ans: ,1, Flags: 110, { CopyCmdAnswer } }
2025-02-26 13:14:39,672 INFO  [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) releasing lock for VMTemplateStorage
2025-02-26 13:14:39,679 ERROR [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Unable to create volume [{"name":"R862995"}] due to [com.cloud.utils.exception.CloudRuntimeException: Can't find volume:6522397c-c425-47da-b1da-db36c99967cb.qcow2].
2025-02-26 13:14:39,680 WARN  [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Unable to contact resource.
2025-02-26 13:14:39,688 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Cleaning up resources for the vmM","type":"DomainRouter","uuid":"d76590f1-45eb-4800-b3e1-1b8ced54bfcc"} in Starting state
2025-02-26 13:14:39,735 DEBUG [c.c.a.m.ClusteredAgentAttache] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Seq 194-5060920081257598386: ForwaId: 73209801370656, via: 194(NODL1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":"false","checkBeforeCleanup":"false","forceStop":"false","vlanToPersistenceMame":"r-2931-VM","executeInSequence":"false","wait":"0","bypassHostMaintenance":"false"}}] } to 240638319530881
2025-02-26 13:14:39,869 DEBUG [c.c.a.t.Request] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Seq 194-5060920081257598386: Received:  { Ans: ,1, Flags: 10, { StopAnswer } }
2025-02-26 13:14:39,886 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Successfully updated id":2931,"instanceName":"r-2931-VM","type":"DomainRouter","uuid":"d76590f1-45eb-4800-b3e1-1b8ced54bfcc"} reboot/stop
2025-02-26 13:14:39,923 DEBUG [c.c.n.NetworkModelImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Service SecurityGroup is not supported in
2025-02-26 13:14:39,935 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) The nic Nic {"broadcastUri":"vlan:"id":15431,"instanceId":2931,"reservationId":"d8c6b759-c1eb-4831-9384-57b952402e25"} on NicProfile {"broadcastUri":null,"deviceId":0,"iPv4Address":"10.15.0.1","id":15431,"reservationId2931} was released according to VM instance {"id":2931,"instanceName":"r-2931-VM","type":"DomainRouter","uuid":"d76590f1-45eb-4800-b3e1-1b8ced54bfcc"} by guru com.cloud.network.guru.Excord.
2025-02-26 13:14:39,949 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Asking VirtualRouter to release NiAddress":"10.15.0.1","id":15431,"reservationId":"d8c6b759-c1eb-4831-9384-57b952402e25","vmId":2931}
2025-02-26 13:14:39,959 DEBUG [c.c.n.g.ControlNetworkGuru] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Released nic: NicProfile {"broadcastU:15434,"reservationId":null,"vmId":2931} for vm VM instance {"id":2931,"instanceName":"r-2931-VM","type":"DomainRouter","uuid":"d76590f1-45eb-4800-b3e1-1b8ced54bfcc"}
2025-02-26 13:14:39,960 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) The nic Nic {"broadcastUri":null,"15434,"instanceId":2931,"reservationId":"d8c6b759-c1eb-4831-9384-57b952402e25"} on NicProfile {"broadcastUri":null,"deviceId":null,"iPv4Address":null,"id":15434,"reservationId":null,"v {"id":2931,"instanceName":"r-2931-VM","type":"DomainRouter","uuid":"d76590f1-45eb-4800-b3e1-1b8ced54bfcc"} by guru com.cloud.network.guru.ControlNetworkGuru@59fbfc5d, now updating rec
2025-02-26 13:14:39,987 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Successfully released network renceName":"r-2931-VM","type":"DomainRouter","uuid":"d76590f1-45eb-4800-b3e1-1b8ced54bfcc"} in Starting state
2025-02-26 13:14:40,010 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Successfully released storage renceName":"r-2931-VM","type":"DomainRouter","uuid":"d76590f1-45eb-4800-b3e1-1b8ced54bfcc"} in Starting state
2025-02-26 13:14:40,011 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Successfully cleaned up resourcee":"r-2931-VM","type":"DomainRouter","uuid":"d76590f1-45eb-4800-b3e1-1b8ced54bfcc"} in Starting state

weizhouapache Feb 26, 2025
Collaborator

This is the significant fragement and it shows that the only host is not selected because of not enough capacity:

2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Found 1 hosts for allocation after prioritization: [Host {"id":194,"name":"NODL1","type":"Routing","uuid":"cce73e3a-33f2-440a-8c50-f9133757b992"}]
2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Looking for speed=500Mhz, Ram=256 MB
2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Host name: NODL1, hostId: 194 is in avoid set, skipping this and trying other available hosts
2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Host Allocator returning 0 suitable hosts

therefore the router is not deploy and hence the network is not started.

Yes

2025-02-26 13:14:39,679 ERROR [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Unable to create volume [{"name":"R862995"}] due to [com.cloud.utils.exception.CloudRuntimeException: Can't find volume:6522397c-c425-47da-b1da-db36c99967cb.qcow2].

Looks like an issue with systemvm template.
How many secondary storages do you use ?
@tdtmusic2

tdtmusic2 Feb 26, 2025
Author

This is the significant fragement and it shows that the only host is not selected because of not enough capacity:

2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Found 1 hosts for allocation after prioritization: [Host {"id":194,"name":"NODL1","type":"Routing","uuid":"cce73e3a-33f2-440a-8c50-f9133757b992"}]
2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Looking for speed=500Mhz, Ram=256 MB
2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Host name: NODL1, hostId: 194 is in avoid set, skipping this and trying other available hosts
2025-02-26 13:14:40,198 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb FirstFitRoutingAllocator) (logid:a3c62ef8) Host Allocator returning 0 suitable hosts

therefore the router is not deploy and hence the network is not started.

Yes

2025-02-26 13:14:39,679 ERROR [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-69:ctx-6947c681 job-114467/job-114470 ctx-f6b009cb) (logid:a3c62ef8) Unable to create volume [{"name":"R862995"}] due to [com.cloud.utils.exception.CloudRuntimeException: Can't find volume:6522397c-c425-47da-b1da-db36c99967cb.qcow2].

Looks like an issue with systemvm template. How many secondary storages do you use ? @tdtmusic2

That host was totally empty, no way a capacity issue on it. About secondary storages, one per zone.

weizhouapache Feb 26, 2025
Collaborator

@tdtmusic2
it looks like the systemvm template image 6522397c-c425-47da-b1da-db36c99967cb.qcow2 does not exist on secondary storage
please check

you can register systemvm template again, and update global setting router.template.kvm to the name of the new template

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Kubernetes cluster deployment fails on new zone #10467

{{title}}

Replies: 2 comments 11 replies

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

Kubernetes cluster deployment fails on new zone #10467

tdtmusic2 Feb 26, 2025

Replies: 2 comments · 11 replies

tdtmusic2 Feb 26, 2025 Author

DaanHoogland Feb 26, 2025 Collaborator

tdtmusic2 Feb 26, 2025 Author

weizhouapache Feb 26, 2025 Collaborator

DaanHoogland Feb 26, 2025 Collaborator

tdtmusic2 Feb 26, 2025 Author

weizhouapache Feb 26, 2025 Collaborator

tdtmusic2 Feb 26, 2025 Author

weizhouapache Feb 26, 2025 Collaborator

tdtmusic2
Feb 26, 2025

Replies: 2 comments 11 replies

tdtmusic2
Feb 26, 2025
Author

DaanHoogland Feb 26, 2025
Collaborator

tdtmusic2 Feb 26, 2025
Author

weizhouapache
Feb 26, 2025
Collaborator

DaanHoogland Feb 26, 2025
Collaborator

tdtmusic2 Feb 26, 2025
Author

weizhouapache Feb 26, 2025
Collaborator

tdtmusic2 Feb 26, 2025
Author

weizhouapache Feb 26, 2025
Collaborator