Hi all from Michigan:
I am working with a new deploy of 4.21 on Centos 9. Specifically, I
cannot get the SSVM to launch. The console proxy is running just fine.
The KVM host is running agent 4.21 on Centos. At this point, I only
have this single host spun up.
An excerpt from the management server log:
2026-03-27 20:14:29,510 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-
Executor-1:[ctx-97e1949b, job-1/job-26, ctx-e8f12238]) (logid:23bddf
40) VM instance {"id":1,"instanceName":"s-1-
VM","state":"Stopped","type":"SecondaryStorageVm","uuid":"da51fa62-
e738-400c-a774-9a524953b1
a7"} state transited from [Starting] to [Stopped] with event
[OperationFailed]. VM's original host: null, new host: null, host
before st
ate transition: Host
{"id":1,"name":"kvm01","type":"Routing","uuid":"976eda71-ea18-4123-
bf46-85a1a7bd8042"}
2026-03-27 20:14:29,515 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-
Executor-1:[ctx-97e1949b, job-1/job-26, ctx-e8f12238]) (logid:23bddf
40) Hosts's actual total CPU: 10000 and CPU after applying
overprovisioning: 10000
2026-03-27 20:14:29,515 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-
Executor-1:[ctx-97e1949b, job-1/job-26, ctx-e8f12238]) (logid:23bddf40)
Hosts's actual total RAM: (29.96 GB) 32169574400 and RAM after applying
overprovisioning: (29.96 GB) 32169574400
2026-03-27 20:14:29,515 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-
Executor-1:[ctx-97e1949b, job-1/job-26, ctx-e8f12238]) (logid:23bddf40)
release cpu from host: Host
{"id":1,"name":"kvm01","type":"Routing","uuid":"976eda71-ea18-4123-
bf46-85a1a7bd8042"}, old used: 1000, reserved: 0, actual total: 10000,
total with overprovisioning: 10000; new used: 500,reserved:0;
movedfromreserved: false,moveToReservered: false
2026-03-27 20:14:29,515 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-
Executor-1:[ctx-97e1949b, job-1/job-26, ctx-e8f12238]) (logid:23bddf40)
release mem from host: Host
{"id":1,"name":"kvm01","type":"Routing","uuid":"976eda71-ea18-4123-
bf46-85a1a7bd8042"}, old used: (1.50 GB) 1610612736, reserved: (0
bytes) 0, total: (29.96 GB) 32169574400; new used: (1.00 GB)
1073741824, reserved: (0 bytes) 0; movedfromreserved: false,
moveToReservered: false
2026-03-27 20:14:29,522 ERROR
[c.c.v.ClusteredVirtualMachineManagerImpl] (Work-Job-Executor-1:[ctx-
97e1949b, job-1/job-26, ctx-e8f12238]) (logid:23bddf40) Unable to
orchestrate start VM instance {"id":1,"instanceName":"s-1-
VM","state":"Stopped","type":"SecondaryStorageVm","uuid":"da51fa62-
e738-400c-a774-9a524953b1a7"} due to [Unable to get answer that is of
class com.cloud.agent.api.StartAnswer].
2026-03-27 20:14:29,526 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-
Executor-1:[ctx-97e1949b, job-1/job-26, ctx-e8f12238]) (logid:23bddf40)
Done executing VM work job:
com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":1,"ha
ndlerName":"VirtualMachineManagerImpl"}
2026-03-27 20:14:29,527 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-
Job-Executor-1:[ctx-97e1949b, job-1/job-26, ctx-e8f12238])
(logid:23bddf40) Complete async job-26, jobStatus: FAILED, resultCode:
0, result:
rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGl
vblZNT3AAAAACAwABSQALY3NFcnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcH
Rpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATa
mF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Ro
cm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2t
UcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeG
NlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-
AAh0AHdVbmFibGUgdG8gb3JjaGVzdHJhdGUgdGhlIHN0YXJ0IG9mIFZNIGluc3RhbmNlIHs
iaW5zdGFuY2VOYW1lIjoicy0xLVZNIiwidXVpZCI6ImRhNTFmYTYyLWU3MzgtNDAwYy1hNz
c0LTlhNTI0OTUzYjFhNyJ9LnVyAB5bTGphdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudDsCR
io8PP0iOQIAAHhwAAAAFHNyABtqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnRhCcWaJjbd
hQIACEIABmZvcm1hdEkACmxpbmVOdW1iZXJMAA9jbGFzc0xvYWRlck5hbWVxAH4ABUwADmR
lY2xhcmluZ0NsYXNzcQB-
AAVMAAhmaWxlTmFtZXEAfgAFTAAKbWV0aG9kTmFtZXEAfgAFTAAKbW9kdWxlTmFtZXEAfgA
FTAANbW9kdWxlVmVyc2lvbnEAfgAFeHABAAAWxnQAA2FwcHQAJmNvbS5jbG91ZC52bS5WaX
J0dWFsTWFjaGluZU1hbmFnZXJJbXBsdAAeVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbC5qY
XZhdAAQb3JjaGVzdHJhdGVTdGFydHBwc3EAfgAMAv____5wdAAtamRrLmludGVybmFsLnJl
ZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3J
JbXBsLmphdmF0AAdpbnZva2UwdAAJamF2YS5iYXNldAAHMTcuMC4xOHNxAH4ADAIAAABNcH
EAfgATcQB-
ABR0AAZpbnZva2VxAH4AFnEAfgAXc3EAfgAMAgAAACtwdAAxamRrLmludGVybmFsLnJlZmx
lY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2
Nlc3NvckltcGwuamF2YXEAfgAZcQB-
ABZxAH4AF3NxAH4ADAIAAAI5cHQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGh
vZC5qYXZhcQB-
ABlxAH4AFnEAfgAXc3EAfgAMAQAAAGZxAH4ADnQAImNvbS5jbG91ZC52bS5WbVdvcmtKb2J
IYW5kbGVyUHJveHl0ABpWbVdvcmtKb2JIYW5kbGVyUHJveHkuamF2YXQAD2hhbmRsZVZtV2
9ya0pvYnBwc3EAfgAMAQAAFz9xAH4ADnEAfgAPcQB-
ABBxAH4AI3Bwc3EAfgAMAQAAAGNxAH4ADnQAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXN
wYXRjaGVydAAYVm1Xb3JrSm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9icHBzcQB-
AAwBAAACsXEAfgAOdAA_b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmZyYW1ld29yay5qb2JzLml
tcGwuQXN5bmNKb2JNYW5hZ2VySW1wbCQ1dAAYQXN5bmNKb2JNYW5hZ2VySW1wbC5qYXZhdA
AMcnVuSW5Db250ZXh0cHBzcQB-AAwBAAAAMXEAfgAOdAA-
b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ
1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5wcHNxAH4ADA
EAAAA4cQB-
AA50AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXV
sdE1hbmFnZWRDb250ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbG
xwcHNxAH4ADAEAAABncQB-
AA50AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXV
sdE1hbmFnZWRDb250ZXh0cQB-
ADN0AA9jYWxsV2l0aENvbnRleHRwcHNxAH4ADAEAAAA1cQB-
AA5xAH4ANnEAfgAzdAAOcnVuV2l0aENvbnRleHRwcHNxAH4ADAEAAAAucQB-
AA50ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb25
0ZXh0UnVubmFibGVxAH4AL3EAfgAwcHBzcQB-AAwBAAACfXEAfgAOcQB-
ACpxAH4AK3EAfgAwcHBzcQB-
AAwCAAACG3B0AC5qYXZhLnV0aWwuY29uY3VycmVudC5FeGVjdXRvcnMkUnVubmFibGVBZGF
wdGVydAAORXhlY3V0b3JzLmphdmFxAH4ANHEAfgAWcQB-ABdzcQB-
AAwCAAABCHB0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrdAAPRnV0dXJlVGF
zay5qYXZhcQB-
ADBxAH4AFnEAfgAXc3EAfgAMAgAABHBwdAAnamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWF
kUG9vbEV4ZWN1dG9ydAAXVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmF0AAlydW5Xb3JrZXJxAH
4AFnEAfgAXc3EAfgAMAgAAAntwdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vb
EV4ZWN1dG9yJFdvcmtlcnEAfgBFcQB-
ADBxAH4AFnEAfgAXc3EAfgAMAgAAA0hwdAAQamF2YS5sYW5nLlRocmVhZHQAC1RocmVhZC5
qYXZhcQB-
ADBxAH4AFnEAfgAXc3IAH2phdmEudXRpbC5Db2xsZWN0aW9ucyRFbXB0eUxpc3R6uBe0PKe
e3gIAAHhweAAAEJp3CAAAAAAAAAAAeA
2026-03-27 20:14:29,527 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-
Job-Executor-1:[ctx-97e1949b, job-1/job-26, ctx-e8f12238])
(logid:23bddf40) Publish async job-26 complete on message bus
2026-03-27 20:14:29,527 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-
Job-Executor-1:[ctx-97e1949b, job-1/job-26, ctx-e8f12238])
(logid:23bddf40) Wake up jobs related to job-26
2026-03-27 20:14:29,527 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-
Job-Executor-1:[ctx-97e1949b, job-1/job-26, ctx-e8f12238])
(logid:23bddf40) Update db status for job-26
2026-03-27 20:14:29,529 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-
Job-Executor-1:[ctx-97e1949b, job-1/job-26, ctx-e8f12238])
(logid:23bddf40) Wake up jobs joined with job-26 and disjoin all
subjobs created from job- 26
2026-03-27 20:14:29,537 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-
Executor-1:[ctx-97e1949b, job-1/job-26]) (logid:23bddf40) Done with run
of VM work job: com.cloud.vm.VmWorkStart for VM 1, job origin: 1
2026-03-27 20:14:29,537 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl$5]
(Work-Job-Executor-1:[ctx-97e1949b, job-1/job-26]) (logid:23bddf40)
Done executing com.cloud.vm.VmWorkStart for job-26
2026-03-27 20:14:29,537 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-
Executor-1:[ctx-97e1949b, job-1/job-26]) (logid:23bddf40) Remove job-26
from job monitoring
2026-03-27 20:14:29,542 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
(secstorage-1:[ctx-b26b71d7]) (logid:470c972d) received secondary
storage vm alert
2026-03-27 20:14:29,542 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
(secstorage-1:[ctx-b26b71d7]) (logid:470c972d) Secondary Storage Vm
creation failure in zone [Mi-connect].
2026-03-27 20:14:29,544 WARN [c.c.a.AlertManagerImpl] (secstorage-
1:[ctx-b26b71d7]) (logid:470c972d) alertType=[19] dataCenterId=[1]
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation
failure in zone [Mi-connect]. Error details: Unable to allocate
capacity on zone [1] due to [null].].
2026-03-27 20:14:29,546 WARN [c.c.a.AlertManagerImpl] (secstorage-
1:[ctx-b26b71d7]) (logid:470c972d) No recipients set in global setting
'alert.email.addresses', skipping sending alert with subject [Secondary
Storage Vm creation failure in zone [Mi-connect]. Error details: Unable
to allocate capacity on zone [1] due to [null].] and content [Secondary
Storage Vm creation failure (zone Mi-connect)].
2026-03-27 20:14:29,546 WARN [c.c.v.SystemVmLoadScanner$1]
(secstorage-1:[ctx-b26b71d7]) (logid:470c972d) Unexpected exception
Unable to orchestrate the start of VM instance {"instanceName":"s-1-
VM","uuid":"da51fa62-e738-400c-a774-9a524953b1a7"}.
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate
the start of VM instance {"instanceName":"s-1-VM","uuid":"da51fa62-
e738-400c-a774-9a524953b1a7"}.
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineM
anagerImpl.java:5830)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMe
thodAccessorImpl.java:77)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Dele
gatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:569)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProx
y.java:102)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineMa
nagerImpl.java:5951)
at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInCo
ntext(AsyncJobManagerImpl.java:689)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Mana
gedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call
(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWi
thContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWit
hContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(Manage
dContextRunnable.java:46)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(Asy
ncJobManagerImpl.java:637)
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(ThreadPoolE
xecutor.java:1136)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPool
Executor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
What did I do wrong here?
--
Ron Gage
Westland, MI
