kvm: fix storage pool refcount race and false umount success - #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

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 map has no entry for the pool, 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.

Which callers can actually collide:

So two increments never race. The reachable losing interleaving is an increment against a decrement while the map has no entry for the pool: they take different monitors, and the decrement's remove() erases the increment. The count then reaches zero while the pool is still in use.

Observed on one KVM host over one day:

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

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, in which case the output is discarded
2. the command succeeded and printed nothing

umount prints nothing on success, so result is always null and this branch always reported 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

The umount is still run through runSimpleBashScript(), because that is what logs the reason the umount failed (device is busy and so on) and that line is the useful diagnostic. Only the decision moved: mountpoint -q says whether the pool is actually unmounted. That also makes "something else already unmounted it" a success rather than a failure.

deleteStoragePool() returns false on a genuine failure rather than throwing. It is called from finally blocks in LibvirtCopyVolumeCommandWrapper, LibvirtPrimaryStorageDownloadCommandWrapper and LibvirtComputingResource.templateToPrimaryDownload, and a throw from a finally discards the result of the operation that just succeeded. The only caller that reads the returned boolean is LibvirtModifyStoragePoolCommandWrapper, which uses the overload that takes pool details and is not on this path.

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.

What this does not fix

Two related problems in the same path are left alone, to keep this change small. Both are worth fixing separately.

1. The decrement is not atomic with the teardown. compute() makes each adjustment atomic; it does not make "decrement reached zero" atomic with the unmount that follows it. Between decStoragePoolRefCount() returning false and destroyStoragePool() running, there is a libvirt connect and a secret lookup, and another thread can take the pool again in that window. That still ends in device is busy.

2. A refcount leak in createStoragePool. incStoragePoolRefCount is inside a try whose only catch is LibvirtException, but checkNetfsStoragePoolMounted and getStoragePool both throw CloudRuntimeException. On that path the compensating decrement is skipped and the count leaks by one, permanently, so the pool is never unmounted. This is the opposite failure to the one fixed here.

Types of changes

• 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:

It is a probabilistic detector, not a deterministic one. It needs real parallelism, so its power depends on the runner: it caught the bug on every run on 6 or more cores, around 6 runs in 10 on 4 cores, and not at all on 2 cores. It never fails with the fix applied.

The test uses a plain LibvirtStorageAdaptor rather than the class's shared Mockito @Spy, because routing 16,000 concurrent calls through Mockito's invocation recorder adds a lock of its own that could mask the race being tested.

Full KVM plugin test suite on this branch: 677 tests, 0 failures, 1 skipped.