Skip to content

Cannot ISO to secondary storage - likely due to system vm not working properly #11110

Closed
@fmillah

Description

@fmillah

Couldn't find a host to validate URL http://abbabbabababa/iso/AlmaLinux-8.9-x86_64-minimal.iso
I have looked around and it might seem related to the sytem vm not running, which seems to be the case with mine, system vm seem to be in a perpetual state of starting, or sometimes crashed.
My secondary storage is a nfs mount.
Here is a snip of management-server.log - this is filtered for earning and errors:

at com.cloud.hypervisor.xenserver.resource.Xenserver625StorageProcessor.copyTemplateToPrimaryStorage(Xenserver625StorageProcessor.java:284)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:103)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:65)
at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:36)
at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:30)
at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1778)
at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:41:28,197 ERROR [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-153:[ctx-272f3c35, job-8402/job-20677, ctx-2a9ee9d7]) (logid:d716b59d) Unable to create volume [{"name":"ROOT-5410","uuid":"31cd211a-fbc0-4ffd-a3be-a908c43864fa"}] due to [Catch Exception com.cloud.utils.exception.CloudRuntimeException for template due to com.cloud.utils.exception.CloudRuntimeException: Could not mount secondary storage 10.13.132.103:/mnt/nfs_share on host /var/cloud_mount/91491308-8ca4-3a3d-b5cd-79eda7c07ef7].
2025-06-30 12:41:28,197 WARN [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-153:[ctx-272f3c35, job-8402/job-20677, ctx-2a9ee9d7]) (logid:d716b59d) Unable to contact resource. com.cloud.exception.StorageUnavailableException: Resource [StoragePool:6] is unreachable: Unable to create volume [{"name":"ROOT-5410","uuid":"31cd211a-fbc0-4ffd-a3be-a908c43864fa"}] due to [Catch Exception com.cloud.utils.exception.CloudRuntimeException for template due to com.cloud.utils.exception.CloudRuntimeException: Could not mount secondary storage 10.13.132.103:/mnt/nfs_share on host /var/cloud_mount/91491308-8ca4-3a3d-b5cd-79eda7c07ef7].
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1797)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1944)
at jdk.internal.reflect.GeneratedMethodAccessor306.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
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.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 jdk.proxy3/jdk.proxy3.$Proxy268.prepare(Unknown Source)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1289)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5486)
at jdk.internal.reflect.GeneratedMethodAccessor299.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:41:28,246 WARN [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-153:[ctx-272f3c35, job-8402/job-20677, ctx-2a9ee9d7, FirstFitRoutingAllocator]) (logid:d716b59d) No suitable host found for VM [VM instance {"id":5410,"instanceName":"s-5410-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"9fb701e1-8bc3-421c-b30a-ef8ad818ca67"}] with tags null in zone [1], pod [2], cluster [5].
2025-06-30 12:41:28,283 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-153:[ctx-272f3c35, job-8402/job-20677, ctx-2a9ee9d7]) (logid:d716b59d) Invocation exception, caused by: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":5410,"instanceName":"s-5410-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"9fb701e1-8bc3-421c-b30a-ef8ad818ca67"}Scope=interface com.cloud.dc.DataCenter; id=1
2025-06-30 12:41:28,283 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-153:[ctx-272f3c35, job-8402/job-20677]) (logid:d716b59d) Unable to complete AsyncJob {"accountId":1,"cmd":"com.cloud.vm.VmWorkStart","cmdInfo":"rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAVInQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA","cmdVersion":0,"completeMsid":null,"created":"Mon Jun 30 12:39:20 EDT 2025","id":20677,"initMsid":345051168953,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":1,"uuid":"8f24ce47-f2c9-4fb7-a82f-9a6c891a6ea9"}, job origin: 8402 com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":5410,"instanceName":"s-5410-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"9fb701e1-8bc3-421c-b30a-ef8ad818ca67"}Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1261)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5486)
at jdk.internal.reflect.GeneratedMethodAccessor299.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:41:28,294 WARN [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-dbc83fd1]) (logid:6bdbd1c3) Unable to start secondary storage VM [5410] due to [Unable to create a deployment for VM instance {"id":5410,"instanceName":"s-5410-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"9fb701e1-8bc3-421c-b30a-ef8ad818ca67"}]. com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":5410,"instanceName":"s-5410-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"9fb701e1-8bc3-421c-b30a-ef8ad818ca67"}Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1261)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5486)
at jdk.internal.reflect.GeneratedMethodAccessor299.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:41:28,296 WARN [c.c.a.AlertManagerImpl] (secstorage-1:[ctx-dbc83fd1]) (logid:6bdbd1c3) alertType=[19] dataCenterId=[1] podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure in zone [Datacenter1]. Error details: null].
2025-06-30 12:41:28,299 WARN [c.c.a.AlertManagerImpl] (secstorage-1:[ctx-dbc83fd1]) (logid:6bdbd1c3) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Secondary Storage Vm creation failure in zone [Datacenter1]. Error details: null] and content [Secondary Storage Vm creation failure (zone Datacenter1)].
2025-06-30 12:41:28,479 WARN [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-157:[ctx-e5a66ad6, job-8402/job-20679, ctx-34b312e3, FirstFitRoutingAllocator]) (logid:d716b59d) No suitable host found for VM [VM instance {"id":5410,"instanceName":"s-5410-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"9fb701e1-8bc3-421c-b30a-ef8ad818ca67"}] with tags null in zone [1], pod [2], cluster [5].
2025-06-30 12:41:30,534 WARN [o.a.c.f.j.i.AsyncJobMonitor] (Timer-0:[ctx-a598a587]) (logid:56c26fab) Task (job-20678) has been pending for 128 seconds
2025-06-30 12:41:32,913 ERROR [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-150:[ctx-26847b7e, job-8401/job-20678, ctx-7cc2e72e]) (logid:14f7a463) Unable to orchestrate start VM instance {"id":5408,"instanceName":"v-5408-VM","state":"Stopped","type":"ConsoleProxy","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"} due to [Unable to acquire lock on VMTemplateStoragePool: 9113].
2025-06-30 12:41:32,924 WARN [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-a253afee]) (logid:d7eddb13) Unable to allocate console proxy standby capacity for zone [Zone {"id": "1", "name": "Datacenter1", "uuid": "0a3043ae-83f0-4fcb-9215-ffec35122684"}] due to [Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}.]. com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}.
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5489)
at jdk.internal.reflect.GeneratedMethodAccessor299.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:41:32,925 WARN [c.c.a.AlertManagerImpl] (consoleproxy-1:[ctx-a253afee]) (logid:d7eddb13) alertType=[10] dataCenterId=[1] podId=[null] clusterId=[null] message=[Console proxy creation failure. Zone [Datacenter1]. Error details: Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}.].
2025-06-30 12:41:32,927 WARN [c.c.a.AlertManagerImpl] (consoleproxy-1:[ctx-a253afee]) (logid:d7eddb13) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Console proxy creation failure. Zone [Datacenter1]. Error details: Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}.] and content [Console proxy creation failure (zone Datacenter1)].
2025-06-30 12:41:32,928 WARN [c.c.v.SystemVmLoadScanner$1] (consoleproxy-1:[ctx-a253afee]) (logid:d7eddb13) Unexpected exception Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}. com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}.
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5489)
at jdk.internal.reflect.GeneratedMethodAccessor299.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:41:34,477 WARN [c.c.a.m.a.i.FirstFitRoutingAllocator] (Work-Job-Executor-156:[ctx-f4b69014, job-8401/job-20680, ctx-63a40aae, FirstFitRoutingAllocator]) (logid:14f7a463) No suitable host found for VM [VM instance {"id":5408,"instanceName":"v-5408-VM","state":"Starting","type":"ConsoleProxy","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}] with tags null in zone [1], pod [2], cluster [5].
2025-06-30 12:41:37,588 WARN [c.c.u.s.Script] (StatsCollector-3:[ctx-3605c382]) (logid:7acb5d2e) Execution of process [2047892] for command [/bin/bash -c systemctl status cloudstack-usage | grep " Loaded:" ] failed.
2025-06-30 12:41:37,588 WARN [c.c.u.s.Script] (StatsCollector-3:[ctx-3605c382]) (logid:7acb5d2e) Process [2047892] for command [/bin/bash -c systemctl status cloudstack-usage | grep " Loaded:" ] encountered the error: [Unit cloudstack-usage.service could not be found.].
2025-06-30 12:41:43,687 WARN [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-44:[ctx-965bf5ea]) (logid:1dcb2811) VM power state update time is null, falling back to update time for VM instance {"id":5410,"instanceName":"s-5410-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"9fb701e1-8bc3-421c-b30a-ef8ad818ca67"}
2025-06-30 12:41:44,115 WARN [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-170:[ctx-90a053e8]) (logid:b661a542) VM power state update time is null, falling back to update time for VM instance {"id":5408,"instanceName":"v-5408-VM","state":"Starting","type":"ConsoleProxy","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}
2025-06-30 12:42:36,616 WARN [c.c.a.AlertManagerImpl] (HA-3:[ctx-e14e9fb7]) (logid:862a41bd) alertType=[13] dataCenterId=[0] podId=[null] clusterId=[null] message=[No usage server process running].
2025-06-30 12:42:37,588 WARN [c.c.u.s.Script] (StatsCollector-4:[ctx-2a4e028f]) (logid:704d6e5f) Execution of process [2047929] for command [/bin/bash -c systemctl status cloudstack-usage | grep " Loaded:" ] failed.
2025-06-30 12:42:37,588 WARN [c.c.u.s.Script] (StatsCollector-4:[ctx-2a4e028f]) (logid:704d6e5f) Process [2047929] for command [/bin/bash -c systemctl status cloudstack-usage | grep " Loaded:" ] encountered the error: [Unit cloudstack-usage.service could not be found.].
2025-06-30 12:42:44,120 WARN [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-349:[ctx-5ae9bfee]) (logid:c59fd4cf) VM power state update time is null, falling back to update time for VM instance {"id":5408,"instanceName":"v-5408-VM","state":"Starting","type":"ConsoleProxy","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}
2025-06-30 12:43:30,533 WARN [o.a.c.f.j.i.AsyncJobMonitor] (Timer-0:[ctx-8a6daf0a]) (logid:c43ca5ad) Task (job-20679) has been pending for 122 seconds
2025-06-30 12:43:30,533 WARN [o.a.c.f.j.i.AsyncJobMonitor] (Timer-0:[ctx-8a6daf0a]) (logid:c43ca5ad) Task (job-20680) has been pending for 116 seconds
2025-06-30 12:43:34,195 WARN [c.c.h.x.r.XcpServer83Resource] (DirectAgent-419:[ctx-75e09c35]) (logid:d716b59d) Task failed! Task record: uuid: 40d2560c-82b9-c454-0e3e-b4807c56cede
nameLabel: Async.host.call_plugin
nameDescription:
allowedOperations: []
currentOperations: {}
created: Mon Jun 30 12:41:53 EDT 2025
finished: Mon Jun 30 12:43:58 EDT 2025
status: failure
residentOn: com.xensource.xenapi.Host@ba8ccc07
progress: 1.0
type:
result:
errorInfo: [XENAPI_PLUGIN_FAILURE, mountNfsSecondaryStorage, SROSError, Error reporting error, unknown key Unexpected error while trying to mount 10.13.132.103:/mnt/nfs_share to /var/cloud_mount/91491308-8ca4-3a3d-b5cd-79eda7c07ef7]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
backtrace: (((process xapi)(filename ocaml/xapi/xapi_plugins.ml)(line 78))((process xapi)(filename ocaml/xapi/message_forwarding.ml)(line 143))((process xapi)(filename ocaml/xapi/rbac.ml)(line 191))((process xapi)(filename ocaml/xapi/rbac.ml)(line 200))((process xapi)(filename ocaml/xapi/server_helpers.ml)(line 75)))

2025-06-30 12:43:34,201 WARN [c.c.h.x.r.XcpServer83Resource] (DirectAgent-419:[ctx-75e09c35]) (logid:d716b59d) callHostPlugin failed for cmd: mountNfsSecondaryStorage with args remoteDir: 10.13.132.103:/mnt/nfs_share, localDir: /var/cloud_mount/91491308-8ca4-3a3d-b5cd-79eda7c07ef7, nfsVersion: null, due to Task failed! Task record: uuid: 40d2560c-82b9-c454-0e3e-b4807c56cede
nameLabel: Async.host.call_plugin
nameDescription:
allowedOperations: []
currentOperations: {}
created: Mon Jun 30 12:41:53 EDT 2025
finished: Mon Jun 30 12:43:58 EDT 2025
status: failure
residentOn: com.xensource.xenapi.Host@ba8ccc07
progress: 1.0
type:
result:
errorInfo: [XENAPI_PLUGIN_FAILURE, mountNfsSecondaryStorage, SROSError, Error reporting error, unknown key Unexpected error while trying to mount 10.13.132.103:/mnt/nfs_share to /var/cloud_mount/91491308-8ca4-3a3d-b5cd-79eda7c07ef7]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
backtrace: (((process xapi)(filename ocaml/xapi/xapi_plugins.ml)(line 78))((process xapi)(filename ocaml/xapi/message_forwarding.ml)(line 143))((process xapi)(filename ocaml/xapi/rbac.ml)(line 191))((process xapi)(filename ocaml/xapi/rbac.ml)(line 200))((process xapi)(filename ocaml/xapi/server_helpers.ml)(line 75)))
Task failed! Task record: uuid: 40d2560c-82b9-c454-0e3e-b4807c56cede
nameLabel: Async.host.call_plugin
nameDescription:
allowedOperations: []
currentOperations: {}
created: Mon Jun 30 12:41:53 EDT 2025
finished: Mon Jun 30 12:43:58 EDT 2025
status: failure
residentOn: com.xensource.xenapi.Host@ba8ccc07
progress: 1.0
type:
result:
errorInfo: [XENAPI_PLUGIN_FAILURE, mountNfsSecondaryStorage, SROSError, Error reporting error, unknown key Unexpected error while trying to mount 10.13.132.103:/mnt/nfs_share to /var/cloud_mount/91491308-8ca4-3a3d-b5cd-79eda7c07ef7]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
backtrace: (((process xapi)(filename ocaml/xapi/xapi_plugins.ml)(line 78))((process xapi)(filename ocaml/xapi/message_forwarding.ml)(line 143))((process xapi)(filename ocaml/xapi/rbac.ml)(line 191))((process xapi)(filename ocaml/xapi/rbac.ml)(line 200))((process xapi)(filename ocaml/xapi/server_helpers.ml)(line 75)))

at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:510)
at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.callHostPluginAsync(CitrixResourceBase.java:433)
at com.cloud.hypervisor.xenserver.resource.Xenserver625StorageProcessor.mountNfs(Xenserver625StorageProcessor.java:78)
at com.cloud.hypervisor.xenserver.resource.Xenserver625StorageProcessor.createFileSr(Xenserver625StorageProcessor.java:247)
at com.cloud.hypervisor.xenserver.resource.Xenserver625StorageProcessor.copyTemplateToPrimaryStorage(Xenserver625StorageProcessor.java:284)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:103)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:65)
at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:36)
at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:30)
at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1778)
at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:43:34,204 WARN [c.c.h.x.r.Xenserver625StorageProcessor] (DirectAgent-419:[ctx-75e09c35]) (logid:d716b59d) Could not mount secondary storage 10.13.132.103:/mnt/nfs_share on host /var/cloud_mount/91491308-8ca4-3a3d-b5cd-79eda7c07ef7
2025-06-30 12:43:34,204 WARN [c.c.h.x.r.Xenserver625StorageProcessor] (DirectAgent-419:[ctx-75e09c35]) (logid:d716b59d) Catch Exception com.cloud.utils.exception.CloudRuntimeException for template due to com.cloud.utils.exception.CloudRuntimeException: Could not mount secondary storage 10.13.132.103:/mnt/nfs_share on host /var/cloud_mount/91491308-8ca4-3a3d-b5cd-79eda7c07ef7 com.cloud.utils.exception.CloudRuntimeException: Could not mount secondary storage 10.13.132.103:/mnt/nfs_share on host /var/cloud_mount/91491308-8ca4-3a3d-b5cd-79eda7c07ef7
at com.cloud.hypervisor.xenserver.resource.Xenserver625StorageProcessor.mountNfs(Xenserver625StorageProcessor.java:82)
at com.cloud.hypervisor.xenserver.resource.Xenserver625StorageProcessor.createFileSr(Xenserver625StorageProcessor.java:247)
at com.cloud.hypervisor.xenserver.resource.Xenserver625StorageProcessor.copyTemplateToPrimaryStorage(Xenserver625StorageProcessor.java:284)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:103)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:65)
at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:36)
at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:30)
at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1778)
at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:43:34,242 ERROR [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-157:[ctx-e5a66ad6, job-8402/job-20679, ctx-34b312e3]) (logid:d716b59d) Unable to create volume [{"name":"ROOT-5410","uuid":"31cd211a-fbc0-4ffd-a3be-a908c43864fa"}] due to [Catch Exception com.cloud.utils.exception.CloudRuntimeException for template due to com.cloud.utils.exception.CloudRuntimeException: Could not mount secondary storage 10.13.132.103:/mnt/nfs_share on host /var/cloud_mount/91491308-8ca4-3a3d-b5cd-79eda7c07ef7].
2025-06-30 12:43:34,242 WARN [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-157:[ctx-e5a66ad6, job-8402/job-20679, ctx-34b312e3]) (logid:d716b59d) Unable to contact resource. com.cloud.exception.StorageUnavailableException: Resource [StoragePool:6] is unreachable: Unable to create volume [{"name":"ROOT-5410","uuid":"31cd211a-fbc0-4ffd-a3be-a908c43864fa"}] due to [Catch Exception com.cloud.utils.exception.CloudRuntimeException for template due to com.cloud.utils.exception.CloudRuntimeException: Could not mount secondary storage 10.13.132.103:/mnt/nfs_share on host /var/cloud_mount/91491308-8ca4-3a3d-b5cd-79eda7c07ef7].
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1797)
at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1944)
at jdk.internal.reflect.GeneratedMethodAccessor306.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
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.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 jdk.proxy3/jdk.proxy3.$Proxy268.prepare(Unknown Source)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1289)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5486)
at jdk.internal.reflect.GeneratedMethodAccessor299.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:43:34,325 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-157:[ctx-e5a66ad6, job-8402/job-20679, ctx-34b312e3]) (logid:d716b59d) Invocation exception, caused by: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":5410,"instanceName":"s-5410-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"9fb701e1-8bc3-421c-b30a-ef8ad818ca67"}Scope=interface com.cloud.dc.DataCenter; id=1
2025-06-30 12:43:34,325 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-157:[ctx-e5a66ad6, job-8402/job-20679]) (logid:d716b59d) Unable to complete AsyncJob {"accountId":1,"cmd":"com.cloud.vm.VmWorkStart","cmdInfo":"rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAVInQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA","cmdVersion":0,"completeMsid":null,"created":"Mon Jun 30 12:41:28 EDT 2025","id":20679,"initMsid":345051168953,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":1,"uuid":"9c2c6f9f-0ba7-464b-a065-b84de55ac6cd"}, job origin: 8402 com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":5410,"instanceName":"s-5410-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"9fb701e1-8bc3-421c-b30a-ef8ad818ca67"}Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1261)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5486)
at jdk.internal.reflect.GeneratedMethodAccessor299.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:43:34,338 WARN [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:[ctx-0d293057]) (logid:c3887c77) Unable to start secondary storage VM [5410] due to [Unable to create a deployment for VM instance {"id":5410,"instanceName":"s-5410-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"9fb701e1-8bc3-421c-b30a-ef8ad818ca67"}]. com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":5410,"instanceName":"s-5410-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"9fb701e1-8bc3-421c-b30a-ef8ad818ca67"}Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1261)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5486)
at jdk.internal.reflect.GeneratedMethodAccessor299.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:43:34,511 WARN [o.a.c.m.w.WebhookServiceImpl] (secstorage-1:[ctx-0d293057, ctx-840e077d]) (logid:c3887c77) Skipping delivering event Event {"description":"{"details":"Volume Type: ROOT Volume Id: 31cd211a-fbc0-4ffd-a3be-a908c43864fa Vm Id: 9fb701e1-8bc3-421c-b30a-ef8ad818ca67","event":"VOLUME.DESTROY","status":"Completed"}","eventId":null,"eventType":"VOLUME.DESTROY","eventUuid":null,"resourceType":"Volume","resourceUUID":null} to any webhook as account ID is missing
2025-06-30 12:43:34,511 WARN [o.a.c.f.e.EventDistributorImpl] (secstorage-1:[ctx-0d293057, ctx-840e077d]) (logid:c3887c77) Failed to publish event [category: ActionEvent, type: VOLUME.DESTROY] on bus webhookEventBus
2025-06-30 12:43:34,530 WARN [c.c.a.AlertManagerImpl] (secstorage-1:[ctx-0d293057]) (logid:c3887c77) alertType=[19] dataCenterId=[1] podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure in zone [Datacenter1]. Error details: null].
2025-06-30 12:43:34,535 WARN [c.c.a.AlertManagerImpl] (secstorage-1:[ctx-0d293057]) (logid:c3887c77) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Secondary Storage Vm creation failure in zone [Datacenter1]. Error details: null] and content [Secondary Storage Vm creation failure (zone Datacenter1)].
2025-06-30 12:43:34,646 WARN [c.c.a.m.a.i.FirstFitRoutingAllocator] (secstorage-1:[ctx-5c8e4587, FirstFitRoutingAllocator]) (logid:6512d1af) No suitable host found for VM [VM instance {"id":5411,"instanceName":"s-5411-VM","state":"Stopped","type":"SecondaryStorageVm","uuid":"781f7335-c744-4214-bd94-537bf4e9ce37"}] with tags null in zone [1], pod [2], cluster [5].
2025-06-30 12:43:34,765 ERROR [c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-156:[ctx-f4b69014, job-8401/job-20680, ctx-63a40aae]) (logid:14f7a463) Unable to orchestrate start VM instance {"id":5408,"instanceName":"v-5408-VM","state":"Stopped","type":"ConsoleProxy","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"} due to [Unable to acquire lock on VMTemplateStoragePool: 9114].
2025-06-30 12:43:34,777 WARN [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:[ctx-cd8140b3]) (logid:d3b06e27) Unable to allocate console proxy standby capacity for zone [Zone {"id": "1", "name": "Datacenter1", "uuid": "0a3043ae-83f0-4fcb-9215-ffec35122684"}] due to [Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}.]. com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}.
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5489)
at jdk.internal.reflect.GeneratedMethodAccessor299.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:43:34,778 WARN [c.c.a.AlertManagerImpl] (consoleproxy-1:[ctx-cd8140b3]) (logid:d3b06e27) alertType=[10] dataCenterId=[1] podId=[null] clusterId=[null] message=[Console proxy creation failure. Zone [Datacenter1]. Error details: Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}.].
2025-06-30 12:43:34,781 WARN [c.c.a.AlertManagerImpl] (consoleproxy-1:[ctx-cd8140b3]) (logid:d3b06e27) No recipients set in global setting 'alert.email.addresses', skipping sending alert with subject [Console proxy creation failure. Zone [Datacenter1]. Error details: Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}.] and content [Console proxy creation failure (zone Datacenter1)].
2025-06-30 12:43:34,781 WARN [c.c.v.SystemVmLoadScanner$1] (consoleproxy-1:[ctx-cd8140b3]) (logid:d3b06e27) Unexpected exception Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}. com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate the start of VM instance {"instanceName":"v-5408-VM","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}.
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5489)
at jdk.internal.reflect.GeneratedMethodAccessor299.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:102)
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5610)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:652)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:600)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

2025-06-30 12:43:37,589 WARN [c.c.u.s.Script] (StatsCollector-3:[ctx-98c27f39]) (logid:bf79a669) Execution of process [2048062] for command [/bin/bash -c systemctl status cloudstack-usage | grep " Loaded:" ] failed.
2025-06-30 12:43:37,589 WARN [c.c.u.s.Script] (StatsCollector-3:[ctx-98c27f39]) (logid:bf79a669) Process [2048062] for command [/bin/bash -c systemctl status cloudstack-usage | grep " Loaded:" ] encountered the error: [Unit cloudstack-usage.service could not be found.].
2025-06-30 12:43:44,119 WARN [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-350:[ctx-3ca165e2]) (logid:30a31728) VM power state update time is null, falling back to update time for VM instance {"id":5408,"instanceName":"v-5408-VM","state":"Starting","type":"ConsoleProxy","uuid":"933c7e3d-2e12-41c8-a32e-6c067fae5117"}
2025-06-30 12:43:44,119 WARN [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-350:[ctx-3ca165e2]) (logid:30a31728) VM power state update time is null, falling back to update time for VM instance {"id":5411,"instanceName":"s-5411-VM","state":"Starting","type":"SecondaryStorageVm","uuid":"781f7335-c744-4214-bd94-537bf4e9ce37"}

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions