bhouse-nexthop opened a new pull request, #14189:
URL: https://github.com/apache/cloudstack/pull/14189
### Description
Two bugs in the KVM agent's storage pool teardown path. They are independent
but they show up together, so they are fixed together.
---
**Bug 1 - the storage pool refcount is not thread safe**
```java
final String mutexKey = storagePoolRefCounts.keySet().stream()
.filter(k -> k.equals(uuid))
.findFirst()
.orElse(uuid); // entry absent -> the CALLER'S OWN String
instance
synchronized (mutexKey) { ... }
```
The lock is meant to be the one `String` instance held as the map key, so
that all callers share a monitor. When the entry is absent, `orElse(uuid)`
hands back the caller's own `String` instead. Two threads in that state
synchronize on two different objects and the block guards nothing.
The entry is absent exactly when the count has just dropped to zero, which
is the moment the code is trying to protect. There is also a gap between
reading the key set and entering the block.
What it causes:
- increments get lost
- the count reaches zero while the pool is still in use
- the agent tries to unmount a pool that other VMs are still using
Observed on one KVM host over one day:
| | count |
| --- | --- |
| `deleteStoragePool` calls | 5,651 |
| correctly skipped, pool still in use | 5,629 |
| proceeded to unmount | 22 |
| of those, failed with `device is busy` | **22** |
All 22 failed. If the count were right, reaching zero would mean nothing
holds the mount and the unmount would succeed. They also arrive in bursts, four
threads tearing down the same pool inside 20 seconds:
```
08:52:04,623 (AgentRequest-Handler-14) deleteStoragePool ... had trouble
unmounting the pool
08:52:12,647 (AgentRequest-Handler-18) deleteStoragePool ... had trouble
unmounting the pool
08:52:20,647 (AgentRequest-Handler-23) deleteStoragePool ... had trouble
unmounting the pool
08:52:24,612 (AgentRequest-Handler-27) deleteStoragePool ... had trouble
unmounting the pool
```
---
**Bug 2 - a failed umount is logged and returned as success**
```java
String result = Script.runSimpleBashScript("sleep 5 && umount " +
targetPath);
if (result == null) {
logger.info("Succeeded in unmounting " + targetPath);
destroyStoragePoolHandleException(conn, uuid);
return true;
}
```
`Script.runScript()` returns `null` in two different situations:
1. the command failed
2. the command succeeded and printed nothing on stdout
`umount` reports its errors on stderr and prints nothing on stdout, so a
failed umount is indistinguishable from a successful one and is reported as
success. From an agent log, 28 ms apart:
```
INFO Succeeded in unmounting /mnt/<uuid>
ERROR Failed to destroy libvirt pool <uuid>: ... unexpected exit status 16:
umount.nfs4: /mnt/<uuid>: device is busy
```
---
### Fix
| bug | fix |
| --- | --- |
| refcount race | use `ConcurrentHashMap.compute()`, which is atomic per
key, and drop the broken lock |
| false success | use `Script.runSimpleBashScriptForExitValue()` and check
the exit status |
`compute()` also removes the entry by returning `null`, so the map still
drops pools that are no longer in use. The behaviour seen by callers is
unchanged: `decStoragePoolRefCount()` still reports whether the pool is still
in use.
`incStoragePoolRefCount` and `decStoragePoolRefCount` become `protected` so
the behaviour can be tested. They already are `protected` on `main`.
### Types of changes
- [x] Bug fix (non-breaking change which fixes an issue)
- [ ] New feature (non-breaking change which adds functionality)
- [ ] Breaking change (fix or feature that would cause existing
functionality to change)
- [ ] Enhancement (improves an existing feature and functionality)
- [ ] Cleanup (Code refactoring and cleanup, that may add test cases)
- [ ] build/CI
### How Has This Been Tested?
Added `testStoragePoolRefCountCountsEveryConcurrentIncrement` to
`LibvirtStorageAdaptorTest`.
What it does, per round:
1. take a fresh pool uuid, so the map starts with no entry for it
2. 16 threads meet at a `CyclicBarrier` and then increment the refcount at
once
3. each thread passes its **own** `String` instance, equal to the others but
not the same object, the way the agent does when the uuid is parsed out of a
separate command payload per request
4. release the pool 16 times: the first 15 releases must report it as still
in use, the 16th must report it as free
It runs 500 rounds, because the window only exists while the map has no
entry for the pool. Once an entry is there, the key set lookup does find a
shared instance and the lock works.
Results:
| | outcome |
| --- | --- |
| old code | fails, first seen at round 4: `pool should still be in use
after 15 of 16 releases` |
| with this change | passes, repeated runs |
Full KVM plugin test suite on this branch: 677 tests, 0 failures, 1 skipped.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
