Cannot cancel maintenance mode of a primary storage v4.21

problem

Zone-wide storage:
If there are virtual machines on specific primary storage and that storage is set to Maintenance mode it is not possible to cancel the maintenance mode if the agents in the zone were restarted.
Cluster-wide storage pool:
If there are virtual machines on such pool, and the pool is set to maintenance and after that if we try to cancel the maintenance mode it's not possible

versions

4.21
Zone-wide primary storage - StorPool and NFS
Cluster-wide primary storage - NFS

The steps to reproduce the bug

All VMs are created with service offering that have storage tags. I haven't tested it without tags
Zone-wide pool:

deploy a VM
enable maintenance mode of the storage pool
force reconnect all host in the zone from the UI (or restart the cloudstack-agent service)
cancle maintenance mode of the storage pool

Cluster-wide

deploy a VM
enable maintenance mode
cancle maintenance mode

2025-09-30 14:09:42,578 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) Found pools [[]] that match with tags [[nfs-c
luster2]].
2025-09-30 14:09:42,578 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) No storage pools available for [shared] volum
e allocation.
2025-09-30 14:09:42,578 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) Using volume allocation algorithm random to r
eorder pools.
2025-09-30 14:09:42,578 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) Trying to find suitable pools to allocate volume [Vo
lume {"id":562,"instanceId":380,"name":"ROOT-380","uuid":"bb7f3c0b-19f8-4be1-a6ce-bf29cff9a0ff","volumeType":"ROOT"}] necessary to deploy VM [VM instance {"id":380,"instanceName":"i-2-380-VM","state":"Startin
g","type":"User","uuid":"f4f66160-a169-4b4a-8729-df528c516c33"}], using StoragePoolAllocator: [ZoneWideStoragePoolAllocator].
2025-09-30 14:09:42,580 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) Could not find any zone wide storage pool that ma
tched with any of the following tags [[nfs-cluster2]].
2025-09-30 14:09:42,581 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) ZoneWideStoragePoolAllocator is returning [0] sui
table storage pools [[]].
2025-09-30 14:09:42,581 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) Using volume allocation algorithm random to reord
er pools.
2025-09-30 14:09:42,581 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) No suitable pools found for volume [Volume {"id":562
,"instanceId":380,"name":"ROOT-380","uuid":"bb7f3c0b-19f8-4be1-a6ce-bf29cff9a0ff","volumeType":"ROOT"}] used by VM [VM instance {"id":380,"instanceName":"i-2-380-VM","state":"Starting","type":"User","uuid":"f
4f66160-a169-4b4a-8729-df528c516c33"}] under cluster: [3].
2025-09-30 14:09:42,581 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) No suitable pools found
2025-09-30 14:09:42,581 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) No suitable storagePools found under this Cluster: C
luster {id: "3", name: "Cluster-A-2", uuid: "bd8f0dce-1699-4879-8804-04713a1a87ee"}
2025-09-30 14:09:42,583 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) Could not find suitable Deployment Destination for t
his VM under any clusters, returning. 
2025-09-30 14:09:42,584 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) Searching resources only under specified Pod: HostPod {"id":1,"nam
e":"Pod-A","uuid":"f1cb86a7-ea4f-4211-a104-dd501578d7e4"}
2025-09-30 14:09:42,584 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) Listing clusters in order of aggregate capacity, that have (at lea
st one host with) enough CPU and RAM capacity under this Pod: 1
2025-09-30 14:09:42,585 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) CapacityType: CPU is used for Cluster ordering
2025-09-30 14:09:42,586 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) Removing from the clusterId list these clusters from avoid set: [1
, 3]
2025-09-30 14:09:42,587 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) No clusters found after removing disabled clusters and clusters in
 avoid list, returning.
2025-09-30 14:09:42,594 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) VM instance {"id":380,"instanceName":"i-2-380-VM","state":"Sto
pped","type":"User","uuid":"f4f66160-a169-4b4a-8729-df528c516c33"} state transited from [Starting] to [Stopped] with event [OperationFailed]. VM's original host: Host {"id":7,"name":"cs-dev-kvm-3-4","type":"R
outing","uuid":"e078cdb7-8819-43b2-a2c9-262788ad6099"}, new host: null, host before state transition: null
2025-09-30 14:09:42,598 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) Invocation exception, caused by: com.cloud.exception.Insuffi
cientServerCapacityException: Unable to create a deployment for VM instance {"id":380,"instanceName":"i-2-380-VM","state":"Starting","type":"User","uuid":"f4f66160-a169-4b4a-8729-df528c516c33"}Scope=interface com.cloud.dc.DataCenter; id=1
2025-09-30 14:09:42,599 INFO  [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445, ctx-59178917]) (logid:51ee9166) Rethrow exception com.cloud.exception.InsufficientServerCapa
cityException: Unable to create a deployment for VM instance {"id":380,"instanceName":"i-2-380-VM","state":"Starting","type":"User","uuid":"f4f66160-a169-4b4a-8729-df528c516c33"}Scope=interface com.cloud.dc.D
ataCenter; id=1
2025-09-30 14:09:42,599 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445]) (logid:51ee9166) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 380, job origi
n: 5444
2025-09-30 14:09:42,599 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-15:[ctx-6b4bcd04, job-5444/job-5445]) (logid:51ee9166) Unable to complete AsyncJob {"accountId":2,"cmd":"com.cloud.vm.VmWorkStart",
"cmdInfo":"rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zd
ElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkc
QB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAABfHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwc
HA","cmdVersion":0,"completeMsid":null,"created":"Tue Sep 30 14:09:41 UTC 2025","id":5445,"initMsid":2199191191555,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,
"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"68e14887-3529-4f40-a73d-1960007af720"}, job origin: 5444 com.cloud.exception.InsufficientServerCapacityException: Unable t
o create a deployment for VM instance {"id":380,"instanceName":"i-2-380-VM","state":"Starting","type":"User","uuid":"f4f66160-a169-4b4a-8729-df528c516c33"}Scope=interface com.cloud.dc.DataCenter; id=1
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1451)

What to do about it?

No response

@slavkap

Hi @slavkap I could replicate it on 4.21 but not on main branch with NFS cluster-wide storage, was able to cancel maintenance mode properly.

@harikrishna-patnala @weizhouapache maybe worth checking also zone-wide NFS on main branch and 4.20

@slavkap

Hi @slavkap I could replicate it on 4.21 but not on main branch with NFS cluster-wide storage, was able to cancel maintenance mode properly.

@harikrishna-patnala @weizhouapache maybe worth checking also zone-wide NFS on main branch and 4.20

@nvazquez
Any error logs ?

@weizhouapache

Hi @weizhouapache for 4.21:

2025-09-30 12:03:04,171 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Trying to find suitable pools to allocate volume [Volume {"id":3,"instanceId":3,"na
me":"ROOT-3","uuid":"d702b70c-26c9-47e1-b809-331aa95293c6","volumeType":"ROOT"}] necessary to deploy VM [VM instance {"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}], us
ing StoragePoolAllocator: [LocalStoragePoolAllocator].
2025-09-30 12:03:04,171 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) LocalStoragePoolAllocator is returning null since the disk profile does not use loc
al storage and bypassStorageTypeCheck is false.
2025-09-30 12:03:04,171 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Trying to find suitable pools to allocate volume [Volume {"id":3,"instanceId":3,"na
me":"ROOT-3","uuid":"d702b70c-26c9-47e1-b809-331aa95293c6","volumeType":"ROOT"}] necessary to deploy VM [VM instance {"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}], us
ing StoragePoolAllocator: [ClusterScopeStoragePoolAllocator].
2025-09-30 12:03:04,172 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Looking for pools in dc [1], pod [1] and cluster [1]. Disabled pools will be
 ignored.
2025-09-30 12:03:04,177 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Found pools [[StoragePool {"id":1,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez
-kvm-pri1","poolType":"NetworkFilesystem","uuid":"e18412c1-7ca8-391e-a36c-bd2f1e17e0f9"}]] that match with tags [[]].
2025-09-30 12:03:04,177 DEBUG [c.c.a.ApiServlet] (qtp253011924-23:[ctx-33c4b4a5]) (logid:97086b9c) ===START===  10.0.3.251 -- GET  jobId=b6c287d1-b670-444c-89b7-c739dbfe0ee5&command=queryAsyncJobResult&response=json&
2025-09-30 12:03:04,177 DEBUG [c.c.a.ApiServlet] (qtp253011924-23:[ctx-33c4b4a5]) (logid:97086b9c) Two factor authentication is already verified for the user 2, so skipping
2025-09-30 12:03:04,179 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Checking if storage pool [StoragePool {"id":1,"name":"ref-trl-9583-k-Mr8-nic
olas-vazquez-kvm-pri1","poolType":"NetworkFilesystem","uuid":"e18412c1-7ca8-391e-a36c-bd2f1e17e0f9"}] is suitable to disk [DskChr[ROOT|8589934592|]].
2025-09-30 12:03:04,179 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) StoragePool [StoragePool {"id":1,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez-
kvm-pri1","poolType":"NetworkFilesystem","uuid":"e18412c1-7ca8-391e-a36c-bd2f1e17e0f9"}] is in avoid set, skipping this pool to allocation of disk [DskChr[ROOT|8589934592|]].
2025-09-30 12:03:04,179 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Adding storage pool [StoragePool {"id":1,"name":"ref-trl-9583-k-Mr8-nicolas-
vazquez-kvm-pri1","poolType":"NetworkFilesystem","uuid":"e18412c1-7ca8-391e-a36c-bd2f1e17e0f9"}] to avoid set during allocation of disk [DskChr[ROOT|8589934592|]].
2025-09-30 12:03:04,179 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) ClusterScopeStoragePoolAllocator is returning [0] suitable storage pools [[]
].
2025-09-30 12:03:04,180 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Using volume allocation algorithm random to reorder pools.
2025-09-30 12:03:04,180 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Trying to find suitable pools to allocate volume [Volume {"id":3,"instanceId":3,"na
me":"ROOT-3","uuid":"d702b70c-26c9-47e1-b809-331aa95293c6","volumeType":"ROOT"}] necessary to deploy VM [VM instance {"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}], us
ing StoragePoolAllocator: [ZoneWideStoragePoolAllocator].
2025-09-30 12:03:04,183 DEBUG [c.c.a.ApiServer] (qtp253011924-23:[ctx-33c4b4a5, ctx-7f911202]) (logid:97086b9c) CIDRs from which account 'Account [{"accountName":"admin","id":2,"uuid":"2d5b7d34-9df0-11f0-8b37-1e004c0003f2"}]' is allowe
d to perform API calls: 0.0.0.0/0,::/0
2025-09-30 12:03:04,184 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Could not find any zone wide storage pool that matched with any of the following
 tags [[]].
2025-09-30 12:03:04,184 INFO  [o.a.c.a.DynamicRoleBasedAPIAccessChecker] (qtp253011924-23:[ctx-33c4b4a5, ctx-7f911202]) (logid:97086b9c) Account for user id 2d5c2b80-9df0-11f0-8b37-1e004c0003f2 is Root Admin or Domain Admin, all APIs a
re allowed.
2025-09-30 12:03:04,185 DEBUG [o.a.c.a.StaticRoleBasedAPIAccessChecker] (qtp253011924-23:[ctx-33c4b4a5, ctx-7f911202]) (logid:97086b9c) RoleService is enabled. We will use it instead of StaticRoleBasedAPIAccessChecker.
2025-09-30 12:03:04,185 DEBUG [o.a.c.r.ApiRateLimitServiceImpl] (qtp253011924-23:[ctx-33c4b4a5, ctx-7f911202]) (logid:97086b9c) API rate limiting is disabled. We will not use ApiRateLimitService.
2025-09-30 12:03:04,185 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) ZoneWideStoragePoolAllocator is returning [0] suitable storage pools [[]].
2025-09-30 12:03:04,185 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Using volume allocation algorithm random to reorder pools.
2025-09-30 12:03:04,185 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) No suitable pools found for volume [Volume {"id":3,"instanceId":3,"name":"ROOT-3","uuid":"d702b70c-26c9-47e1-b809-331aa95293c6","volumeType":"ROOT"}] used by VM [VM instance {"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}] under cluster: [1].
2025-09-30 12:03:04,186 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) No suitable pools found
2025-09-30 12:03:04,186 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) No suitable storagePools found under this Cluster: Cluster {id: "1", name: "p1-c1", uuid: "5eaa27b1-3e55-409f-ae27-36eadfc056d5"}
2025-09-30 12:03:04,189 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Could not find suitable Deployment Destination for this VM under any clusters, returning. 
2025-09-30 12:03:04,189 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Searching resources only under specified Pod: HostPod {"id":1,"name":"Pod1","uuid":"34a2069d-5a73-4f2a-9911-ba8bf0f5e8b9"}
2025-09-30 12:03:04,190 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Listing clusters in order of aggregate capacity, that have (at least one host with) enough CPU and RAM capacity under this Pod: 1
2025-09-30 12:03:04,192 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) CapacityType: CPU is used for Cluster ordering
2025-09-30 12:03:04,193 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Removing from the clusterId list these clusters from avoid set: [1]
2025-09-30 12:03:04,193 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) No clusters found after removing disabled clusters and clusters in avoid list, returning.
2025-09-30 12:03:04,198 DEBUG [c.c.a.ApiServlet] (qtp253011924-23:[ctx-33c4b4a5, ctx-7f911202]) (logid:97086b9c) ===END===  10.0.3.251 -- GET  jobId=b6c287d1-b670-444c-89b7-c739dbfe0ee5&command=queryAsyncJobResult&response=json&
2025-09-30 12:03:04,207 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) VM instance {"id":3,"instanceName":"i-2-3-VM","state":"Stopped","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"} state transited from [Starting] to [Stopped] with event [OperationFailed]. VM's original host: Host {"id":2,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez-kvm2","type":"Routing","uuid":"98a1e36c-bb70-465d-a171-344fcda28a14"}, new host: null, host before state transition: Host {"id":2,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez-kvm2","type":"Routing","uuid":"98a1e36c-bb70-465d-a171-344fcda28a14"}
2025-09-30 12:03:04,213 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Hosts's actual total CPU: 6300 and CPU after applying overprovisioning: 12600
2025-09-30 12:03:04,213 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Hosts's actual total RAM: (6.59 GB) 7072067584 and RAM after applying overprovisioning: (6.59 GB) 7072067584
2025-09-30 12:03:04,213 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) release cpu from host: Host {"id":2,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez-kvm2","type":"Routing","uuid":"98a1e36c-bb70-465d-a171-344fcda28a14"}, old used: 2000, reserved: 0, actual total: 6300, total with overprovisioning: 12600; new used: 1500,reserved:0; movedfromreserved: false,moveToReservered: false
2025-09-30 12:03:04,213 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) release mem from host: Host {"id":2,"name":"ref-trl-9583-k-Mr8-nicolas-vazquez-kvm2","type":"Routing","uuid":"98a1e36c-bb70-465d-a171-344fcda28a14"}, old used: (2.50 GB) 2684354560, reserved: (0 bytes) 0, total: (6.59 GB) 7072067584; new used: (2.00 GB) 2147483648, reserved: (0 bytes) 0; movedfromreserved: false, moveToReservered: false
2025-09-30 12:03:04,225 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Invocation exception, caused by: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}Scope=interface com.cloud.dc.DataCenter; id=1
2025-09-30 12:03:04,225 INFO  [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50, ctx-f29a5c39]) (logid:849acb31) Rethrow exception com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}Scope=interface com.cloud.dc.DataCenter; id=1
2025-09-30 12:03:04,225 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50]) (logid:849acb31) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 3, job origin: 49
2025-09-30 12:03:04,225 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-11:[ctx-9124964b, job-49/job-50]) (logid:849acb31) Unable to complete AsyncJob {"accountId":2,"cmd":"com.cloud.vm.VmWorkStart","cmdInfo":"rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAA3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA","cmdVersion":0,"completeMsid":null,"created":"Tue Sep 30 11:57:59 UTC 2025","id":50,"initMsid":32986623902706,"instanceId":null,"instanceType":null,"lastPolled":null,"lastUpdated":null,"processStatus":0,"removed":null,"result":null,"resultCode":0,"status":"IN_PROGRESS","userId":2,"uuid":"ae190a75-a4bf-4e73-9ae0-866a8360b080"}, job origin: 49 com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM instance {"id":3,"instanceName":"i-2-3-VM","state":"Starting","type":"User","uuid":"85f910b1-8a76-4264-8b3c-78caaec825c2"}Scope=interface com.cloud.dc.DataCenter; id=1
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1451)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5827)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
        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:5951)
        at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:99)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:689)
        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: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(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)

@nvazquez

thanks @nvazquez, for testing it! I will check it also on the main for the zone-wide

@nvazquez

@nvazquez, I've upgraded my env. 4.21 with the main, and unfortunately got the same issue with cluster-wide pool too

@sureshanaparti

it might be related to #9903
cc @sureshanaparti

PS: it worked in my testing on acs 4.20 and 4.21

@slavkap

@slavkap @weizhouapache @harikrishna-patnala in my initial test on 4.21 I was not using storage tags and could replicate the issue. However, repeated the test using storage tags on the cluster-wide pools and service offering for the VM deployment and was able to cancel maintenance properly. Could it be an issue with tags looking for VM deployments after cancelling maintenance mode?

@slavkap @weizhouapache @harikrishna-patnala in my initial test on 4.21 I was not using storage tags and could replicate the issue. However, repeated the test using storage tags on the cluster-wide pools and service offering for the VM deployment and was able to cancel maintenance properly. Could it be an issue with tags looking for VM deployments after cancelling maintenance mode?

actually what make me confused is: why volumes are migrated during vm start when cancel storage maintenance, it does not make any sense.
In that scanario, the storage should be available for vm start/deployment, right ?
maybe we should mark the storage as Up at first, then start the vms which are stopped when enable storage maintenance.

@weizhouapache

@weizhouapache yes it is strange, in some cases it migrated the volume but other cases the volume stayed on the pool in maintenance. However, to cancel the maintenance mode properly the pool in Up state should match the storage tag of the pool in maintenance in order to succeed, otherwise the VM deployment failed and couldn't cancel maintenance for the pool

@weizhouapache

@weizhouapache, in my case I have one NFS cluster-wide, 1 NFS zone-wide and 2 StorPool zone-wide pools, and the VMs are stopped. After that it cannot find pool with the matching tag to start the VM. The SQL query is looking for pools with status=Up and matching tags

25-10-01 11:59:37,982 TRACE [c.c.u.d.T.Statement] (Work-Job-Executor-12:[ctx-5a4edfb7, job-5470/job-5471, ctx-16d60488]) (logid:0c10c265) Preparing: SELECT storage_pool.* from storage_pool LEFT JOIN storage_pool_tags ON storage_pool.id = storage_pool_tags.pool_id WHERE storage_pool.removed is null and storage_pool.status = 'Up' AND storage_pool_tags.is_tag_a_rule = 0 and storage_pool.data_center_id = ? and (storage_pool.pod_id = ? or storage_pool.pod_id is null) and storage_pool.scope = ? and (storage_pool.cluster_id = ? OR storage_pool.cluster_id IS NULL) AND ((storage_pool_tags.tag='nfs-cluster1')) GROUP BY storage_pool_tags.pool_id HAVING COUNT(storage_pool_tags.tag) >= ?

maybe we should mark the storage as Up at first, then start the vms which are stopped when enable storage maintenance.

I agree with this one ^^

@slavkap

@weizhouapache, in my case I have one NFS cluster-wide, 1 NFS zone-wide and 2 StorPool zone-wide pools, and the VMs are stopped. After that it cannot find pool with the matching tag to start the VM. The SQL query is looking for pools with status=Up and matching tags

25-10-01 11:59:37,982 TRACE [c.c.u.d.T.Statement] (Work-Job-Executor-12:[ctx-5a4edfb7, job-5470/job-5471, ctx-16d60488]) (logid:0c10c265) Preparing: SELECT storage_pool.* from storage_pool LEFT JOIN storage_pool_tags ON storage_pool.id = storage_pool_tags.pool_id WHERE storage_pool.removed is null and storage_pool.status = 'Up' AND storage_pool_tags.is_tag_a_rule = 0 and storage_pool.data_center_id = ? and (storage_pool.pod_id = ? or storage_pool.pod_id is null) and storage_pool.scope = ? and (storage_pool.cluster_id = ? OR storage_pool.cluster_id IS NULL) AND ((storage_pool_tags.tag='nfs-cluster1')) GROUP BY storage_pool_tags.pool_id HAVING COUNT(storage_pool_tags.tag) >= ?

maybe we should mark the storage as Up at first, then start the vms which are stopped when enable storage maintenance.

I agree with this one ^^

@slavkap @nvazquez
I just found that the behavior on storpool pools is same as we agreed when cancel storage migration .....

cloudstack/plugins/storage/volume/storpool/src/main/java/org/apache/cloudstack/storage/datastore/lifecycle/StorPoolPrimaryDataStoreLifeCycle.java

Lines 238 to 245 in cd12fa5

    
           @Override 
        
           public boolean cancelMaintain(DataStore store) { 
        
               logger.debug("cancelMaintain"); 
        
               dataStoreHelper.cancelMaintain(store); 
        
               storagePoolAutmation.cancelMaintain(store); 
        
               return true; 
        
           }

created a draft PR: #11773

@weizhouapache

thanks, @weizhouapache, I think this should fix part of the issue. If the agent is restarted during pool maintenance, the cancel maintenance will still fail. I think here

cloudstack/server/src/main/java/com/cloud/storage/StoragePoolAutomationImpl.java

Line 366 in cd12fa5

if (pool.getPoolType() == Storage.StoragePoolType.DatastoreCluster) {

we should include a check if there is a record in the storage_pool_host_ref DB table and if not to add such for the pool with the host

thanks, @weizhouapache, I think this should fix part of the issue. If the agent is restarted during pool maintenance, the cancel maintenance will still fail. I think here

cloudstack/server/src/main/java/com/cloud/storage/StoragePoolAutomationImpl.java

Line 366 in cd12fa5

if (pool.getPoolType() == Storage.StoragePoolType.DatastoreCluster) {
we should include a check if there is a record in the storage_pool_host_ref DB table and if not to add such for the pool with the host

make sense.

added a commit :
https://github.com/apache/cloudstack/pull/11773/files#diff-2ae1a642d4b460abaeaed7f34f604fa1026e4c4232b0df899bfda216d9742186

fixed by #11773

Navigation Menu

Repository navigation

Cannot cancel maintenance mode of a primary storage v4.21 #11764

problem

versions

The steps to reproduce the bug

What to do about it?

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

	@Override
	public boolean cancelMaintain(DataStore store) {
	logger.debug("cancelMaintain");

	dataStoreHelper.cancelMaintain(store);
	storagePoolAutmation.cancelMaintain(store);
	return true;
	}

Cannot cancel maintenance mode of a primary storage v4.21 #11764

Description

problem

versions

The steps to reproduce the bug

What to do about it?

Activity

nvazquez commented on Sep 30, 2025

weizhouapache commented on Sep 30, 2025

nvazquez commented on Sep 30, 2025

slavkap commented on Oct 1, 2025

slavkap commented on Oct 1, 2025

weizhouapache commented on Oct 1, 2025

nvazquez commented on Oct 1, 2025

weizhouapache commented on Oct 1, 2025

nvazquez commented on Oct 1, 2025

slavkap commented on Oct 1, 2025

weizhouapache commented on Oct 1, 2025

slavkap commented on Oct 2, 2025

weizhouapache commented on Oct 2, 2025

weizhouapache commented on Oct 8, 2025

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions