GitHub user MitchDrage created a discussion: Management server's repeatedly 
crashing with a cache lock

I'm having issues with my magement servers crashing repeatedly. It's crashing 
one server and then almost perfectly after a two hour gap, crashes the next 
server; and then the last, until all 3 are down. 
This is not a production cluster yet, and this started after upgrading from 
4.21.1 to 4.22.1.

Here's the facts I have:
It's a 3-node managment cluster backed by galera 3 node DB cluster with HAProxy 
in front.
I initially believed this was related to #13382 - it has very similar hallmarks 
(issues with the HikariCP pool being exhausted), and I enabled OOBM right after 
the upgrade to 4.22.1. I've since turned off OOBM across my nodes and it hasn't 
resolved the issue.
The DB (Galera cluster) shows no long transactions, no lock waits, and plenty 
of spare connections. So this isn't a DB-capacity problem as far as I can tell.

What I've actually caught it doing via thread dumps mid-hang: every single API 
request on the affected node routes through ApiServlet.doUseForwardHeaders(), 
which reads a config value out of the Caffeine-backed cache in ConfigDepotImpl.
When that value needs to be loaded (cache miss/expiry) the thread doing the 
load holds the cache's lock for the entire load, including a blocking call out 
to HikariCP for a DB connection. If that one thread gets stuck waiting on the 
pool for even a couple of seconds, every other request thread touching that 
same config key piles up behind it - not because the DB is slow, but because 
they're all queued on a Java lock, waiting for one unlucky thread to get a 
connection.

So with OOBM off, the trigger clearly isn't OOBM specifically - it's whatever 
creates even brief local pool pressure on that one node. I've caught this same 
lock/stack shape from two completely different code paths now (once through the 
normal API-request path, once through CAManagerImpl.createSSLEngine() during 
cert/SSL setup), which tells me it's not tied to one feature - it's a general 
property of how ConfigDepotImpl loads cache entries. Anything that makes a 
handful of connections busy at once on a given node - a burst of host/agent 
reconnects, a slow query, whatever - is enough to wedge it, and once wedged it 
doesn't recover on its own; I've had to hard-restart cloudstack-management 
every time.

That also explains the cascade pattern I'm seeing: once one node wedges and 
gets bounced, whatever load it was carrying (agents, API traffic) piles onto 
the remaining nodes, which raises the odds of tripping the same lock on the 
next one - hence the ~2 hour drift between each node going down in turn.

Has anyone else seen this since 4.22? I couldn't find any other mention of an 
issue like this in discussions or issues.

What I've tried so far:

- Disabled OOBM entirely across all three nodes - issue persisted, ruling it 
out as a necessary trigger (though it may still be a trigger among others).
- Increased db.cloud.minIdleConnections from the installer default of 5 to 20 
(against maxActive=250) - the theory being that a cold pool with almost no warm 
headroom has to spin up new connections right at the moment a node's already 
under pressure. Hasn't eliminated the wedges, though anecdotally they feel less 
frequent.
- Added explicit connectTimeout/socketTimeout to db.cloud.url.params - bounds 
the underlying JDBC socket calls themselves, since HikariCP's own 
connectionTimeout only bounds the wait for a pooled connection, not a hung 
TCP-level connect to a new one.
- Bumped JVM heap (-Xmx) on all three nodes, after also increasing each node's 
RAM - mainly aimed at a separate but possibly related crash mode (systemctl 
showing 219/CGROUP exits), not the wedge itself.
- Checked Galera directly during a live incident - no long-running 
transactions, nothing in information_schema.innodb_lock_waits, and only a small 
fraction of max_connections in use cluster-wide. Confirms the pressure is local 
to one node's Hikari pool, not DB-cluster capacity.
- Removed a load balancer VIP that was fronting agent↔management traffic, 
switching agents to connect directly to all three management IPs instead - 
partly to rule out the LB as a source of connection-state weirdness 
contributing to reconnect bursts.

Thread dumps attached here:
<details> <summary>Thread dumps</summary>
The lock-holder - stuck computing a cache-miss value, blocked getting a 
connection from the pool:


org.apache.cloudstack.framework.config.impl.ConfigDepotImpl.getConfigStringValueInternal(ConfigDepotImpl.java:289)
org.apache.cloudstack.framework.config.impl.ConfigDepotImpl$$Lambda.apply(Unknown
 Source)
org.apache.cloudstack.utils.cache.LazyCache$$Lambda.load(Unknown Source)
com.github.benmanes.caffeine.cache.LocalLoadingCache.lambda$newMappingFunction$3(LocalLoadingCache.java:183)
com.github.benmanes.caffeine.cache.LocalLoadingCache$$Lambda.apply(Unknown 
Source)
com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$doComputeIfAbsent$14(BoundedLocalCache.java:2715)
  - locked <0x...> (a com.github.benmanes.caffeine.cache.PSWMS)
com.github.benmanes.caffeine.cache.BoundedLocalCache$$Lambda.apply(Unknown 
Source)
java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1940)
  - locked <0x...> (a java.util.concurrent.ConcurrentHashMap$Node)
com.cloud.utils.db.GenericDaoBase.findById(GenericDaoBase.java:997)
com.cloud.utils.db.GenericDaoBase.lockRow(GenericDaoBase.java:1062)
com.cloud.utils.db.GenericDaoBase.findById(GenericDaoBase.java:1080)
com.cloud.utils.db.TransactionLegacy.prepareAutoCloseStatement(TransactionLegacy.java:467)
com.cloud.utils.db.TransactionLegacy.prepareStatement(TransactionLegacy.java:474)
com.cloud.utils.db.TransactionLegacy.getConnection(TransactionLegacy.java:563)
com.cloud.utils.HikariDataSource.getConnection(HikariDataSource.java:99)
com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:144)
com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162)  <-- 
BLOCKED HERE, pool fully checked out
Every other request thread, piled up on the lock, never even getting as far as 
needing a connection themselves:


com.cloud.api.ApiServlet.doUseForwardHeaders(ApiServlet.java:686)
com.cloud.api.ApiServlet.getClientAddress(ApiServlet.java:695)
com.github.benmanes.caffeine.cache.BoundedLocalCache.computeIfAbsent(BoundedLocalCache.java:2668)
com.github.benmanes.caffeine.cache.BoundedLocalCache.doComputeIfAbsent(BoundedLocalCache.java:2685)
com.github.benmanes.caffeine.cache.LocalCache.computeIfAbsent(LocalCache.java:112)
com.github.benmanes.caffeine.cache.LocalLoadingCache.get(LocalLoadingCache.java:58)
org.apache.cloudstack.framework.config.ConfigKey.value(ConfigKey.java:390)
org.apache.cloudstack.framework.config.impl.ConfigDepotImpl.getConfigStringValue(ConfigDepotImpl.java:302)
org.apache.cloudstack.utils.cache.LazyCache.get(LazyCache.java:38)
- waiting to lock <0x...> (a java.util.concurrent.ConcurrentHashMap$Node)
The second call site (the one that convinced me this isn't OOBM- or 
API-specific — same lock, reached from certificate/SSL setup instead):


org.apache.cloudstack.ca.CAManagerImpl.createSSLEngine(CAManagerImpl.java:281)
org.apache.cloudstack.ca.provider.RootCAProvider.createSSLEngine(RootCAProvider.java:274)
org.apache.cloudstack.framework.config.ConfigKey.value(ConfigKey.java:390)
org.apache.cloudstack.framework.config.impl.ConfigDepotImpl.getConfigStringValue(ConfigDepotImpl.java:302)
org.apache.cloudstack.utils.cache.LazyCache.get(LazyCache.java:38)
com.github.benmanes.caffeine.cache.LocalLoadingCache.get(LocalLoadingCache.java:58)
com.github.benmanes.caffeine.cache.LocalCache.computeIfAbsent(LocalCache.java:112)
com.github.benmanes.caffeine.cache.BoundedLocalCache.doComputeIfAbsent(BoundedLocalCache.java:2685)
com.github.benmanes.caffeine.cache.BoundedLocalCache.computeIfAbsent(BoundedLocalCache.java:2668)
  - waiting to lock <0x...> (a 
java.util.concurrent.ConcurrentHashMap$ReservationNode)
Same lock-holder shape underneath both: GenericDaoBase.lockRow()/findById() 
blocked in HikariPool.getConnection() → ConcurrentBag.borrow() → 
SynchronousQueue.poll().

Thread counts blocked on this varied a lot run to run - anywhere from ~14 to 97 
qtp* threads stuck on the same lock, depending on how much request traffic was 
in flight when it hit.

</details>

GitHub link: https://github.com/apache/cloudstack/discussions/13542

----
This is an automatically sent email for [email protected].
To unsubscribe, please send an email to: [email protected]

Reply via email to