Repository navigation
kvm: stop a stuck rbd_open from wedging the agent - #14199
bhouse-nexthop wants to merge 6 commits into
Conversation
A clone from a template opens the template with rbd_open(). librados leaves rados_osd_op_timeout and rados_mon_op_timeout at 0, which means an operation waits forever, so a completion that never arrives parks the agent thread that issued it for the life of the process. The agent runs a host's storage commands in sequence, so every command queued behind that thread stops with it. Nothing released the cluster handles either. Rados only calls rados_shutdown() from finalize(), so a handle the KVM plugin opened stayed alive until the garbage collector happened to reach it, and then shut down on the finalizer thread rather than on the thread that did the work. Several paths also leaked the IO context and the open image when a call failed part way through, because the clean up ran only on the success path, and the snapshot backup never closed its image at all. Add CephUtil, which opens a connected handle with the timeouts applied and offers non-throwing helpers to close an image, destroy an IO context and shut a handle down. Route every handle in the plugin through it and clean up from finally blocks, so that each path releases what it opened. The timeouts bound a single operation rather than a whole request, so a long copy or flatten is made up of many operations that are each well inside the limit. They are exposed as rados.osd.op.timeout and rados.mon.op.timeout in agent.properties; setting either to 0 restores the previous behaviour of waiting forever. Signed-off-by: Brad House <bhouse@nexthop.ai>
A read write open registers a watcher on the image header and lets the image take its exclusive lock. A clone parent, and an image that is only read or stat'ed, need neither, and the extra work is done inside rbd_open() while the caller waits. Open the template read only when cloning from it, on both the same cluster and the cross cluster path, and open the snapshot read only when backing it up. The base snapshot still has to be created and protected on a writable handle, so the first clone of a template reopens it read write for that step alone; every later clone of the same template finds the snapshot and keeps the read only handle. Signed-off-by: Brad House <bhouse@nexthop.ai>
Codecov Report❌ Patch coverage is Additional details and impacted files@@ Coverage Diff @@
## 4.22 #14199 +/- ##
============================================
+ Coverage 17.97% 18.26% +0.29%
- Complexity 16184 16613 +429
============================================
Files 5930 5940 +10
Lines 535615 537788 +2173
Branches 65582 65929 +347
============================================
+ Hits 96271 98223 +1952
+ Misses 428377 428374 -3
- Partials 10967 11191 +224
Flags with carried forward coverage won't be shown. Click here to find out more. ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
Correctness fixes to the two preceding commits: - deleteSnapshot reported success when the image could not be opened. Moving the connect and open inside the inner try put rbd_open() failures into a catch that only logs, so the method fell through to its success return. The management server would drop the snapshot record while the snapshot stayed on the cluster, and a protected one then blocks removal of its parent volume. The open is back outside that catch. - The template reopen closed the read only handle and left the field pointing at it, so a failure of the reopen sent the already freed pointer to rbd_close() a second time in the finally. That is a use after free in librbd, which takes the agent down rather than raising an exception. The field is cleared first. - CephUtil.connect() abandoned the cluster handle if anything between rados_create() and the return threw, which is the leak the class exists to prevent, and the new connect timeout makes that path ordinary rather than rare. It now releases the handle before rethrowing. - The cephx secret is null for a pool with no cephx user, and librados aborts the process rather than returning an error if it is handed one. Guard as getRbdPhysicalDisk already does. Failures that were silent are now reported, which matters because a timeout makes them reachable: - rbd_read returns a negative errno rather than throwing, and the snapshot backup loop treated that as end of image: a short file on secondary storage, recorded as a good backup. It now fails, as does a write error, which was swallowed too. - A failed RBD snapshot create or remove logged and then returned a success answer, recording a snapshot in CloudStack with nothing behind it on the cluster. Also: client_mount_timeout now honours 0 like the other two, ioCtxDestroyQuietly guards the handle it dereferences, the constants left unused by the previous commits are removed, the three properties are documented in agent.properties, and the RBD cleanup tests assert the handle is shut down. Signed-off-by: Brad House <bhouse@nexthop.ai>
Default rados.osd.op.timeout and rados.mon.op.timeout to 0, which leaves the options unset and keeps the librados behaviour of waiting forever. Nothing about how an existing deployment talks to Ceph changes unless an operator sets them. rados.client.mount.timeout keeps its default of 30, which is the value the code passed before it became a property. agent.properties carries the reasoning and a suggested starting point, since an operator has no way to pick a value from the property name alone. Signed-off-by: Brad House <bhouse@nexthop.ai>
…ccess Closing an RBD image is where librbd flushes, so a close that fails on an image just written is the last chance a lost write has to surface. Routing those two closes through the non-throwing helper turned that into a warning and returned the disk anyway, which would register a volume whose tail writes never landed. Close the written destination explicitly and let it fail the copy; the finally still covers the paths that did not get that far. deleteSnapshot had the same shape: a failed snapUnprotect or snapRemove was logged and the method still answered "removed successfully", dropping the record while the snapshot kept pinning space on the cluster, and one left protected also blocks removal of its parent volume. It now fails, except for ENOENT, where the snapshot is already gone and the delete has nothing left to do. The same ENOENT tolerance keeps the RBD branch of ManageSnapshotCommand idempotent for deletes. Also corrects the applyTimeouts javadoc, which said 0 means waiting forever for all three options; that is true of the two operation timeouts but the connect timeout falls back to the librados default of 300s. The snapshot test now pins the unwind order, since destroying an IO context after its cluster handle has been shut down would be a use after free. Signed-off-by: Brad House <bhouse@nexthop.ai>
|
@blueorangutan package |
|
@weizhouapache a [SL] Jenkins job has been kicked to build packages. It will be bundled with KVM, XenServer and VMware SystemVM templates. I'll keep you posted as I make progress. |
|
Packaging result [SF]: ✔️ el8 ✔️ el9 ✔️ el10 ✔️ debian ✔️ suse15. SL-JID 19300 |
|
@blueorangutan test |
|
@weizhouapache a [SL] Trillian-Jenkins test job (ol8 mgmt + kvm-ol8) has been kicked to run smoke tests |
|
[SF] Trillian test result (tid-17029)
|
|
@vladimirpetrov @sureshanaparti could you take a look at this one? We'd like this fix to make it into the upcoming 4.22.2 release. |
|
with both timeouts at 0 by default, does anything here stop the original hang out of the box? looks like the agent would still wait forever on that rbd_open |
it looks @bhouse-nexthop replied to a wrong PR |
|
@Damans227 you're right, out of the box this doesn't bound that wait. With both timeouts at 0, Leaving them at 0 was deliberate. A single value that fits every cluster is hard to pick, and a timeout that's too tight turns a slow but healthy operation during backfill or recovery into a failed deploy or snapshot. So I made it opt in and put a suggested starting point in What does apply by default: the clone parent is now opened read only, so If you and the other reviewers would prefer non-zero defaults, I'm happy to switch to 60/30. I've also fixed the description, which overstated what happens without the timeouts set. |
|
@weizhouapache @Damans227 this is waiting on one decision: whether the two Ceph timeouts should stay at 0 (opt in, as now) or default to 60s osd / 30s mon (see my reply above on 10-14). I'm happy to switch the defaults today if you'd prefer that. Once that's settled, could it go into 4.22.2? I understand the release is due late this week or early next. |
@bhouse-nexthop lets default to 60s osd / 30s mon. at 0 the hang still happens for anyone who doesnt know to set them, and a failed deploy can be retried while a stuck host cant. anyone with a slow cluster can still raise them or set 0. |
Default rados.osd.op.timeout to 60 and rados.mon.op.timeout to 30. With the options left unset, an operation that never completes still parks the agent thread, and with it the host's storage command queue, for anyone who does not know to set them. A failed operation can be retried; a wedged host cannot. Setting either property to 0 still leaves the option unset and keeps the librados behaviour of waiting forever, and a cluster whose single operations legitimately run longer can raise them. Signed-off-by: Brad House <bhouse@nexthop.ai>
|
@Damans227 agreed, done in 85de0b5. |
@bhouse-nexthop that covers it |
Damans227
left a comment
Damans227
left a comment
There was a problem hiding this comment.
thanks @bhouse-nexthop, the new defaults look right. CLGTM
Description
A VM deploy wedged a KVM agent thread for 7.8 hours and took the cluster's VM creation with it. The thread was cloning a template on RBD and never returned.
Stack from the agent, with the native frames underneath:
Ceph was healthy the whole time:
HEALTH_OK, every OSD up, no watchers on the template, no blocklisted clients, and the same template opened instantly withrbdon that same host.The user visible effect was that new VM deploys kept failing with
InsufficientServerCapacityException, on a cluster where every host had terabytes of free memory. That error is what a deploy reports when the planner ends up with no usable destination, whatever the reason, so it sent us looking at capacity for a while before the real cause turned up in an agent thread dump.Three things in the KVM plugin turned one stuck call into an outage:
rados_osd_op_timeoutandrados_mon_op_timeoutat0, which means wait foreverRadosonly callsrados_shutdown()fromfinalize(), and nothing in the plugin calledshutDown(), so every handle waited for the garbage collectorfinallyat all, so a failure part way through leaked the open image and the IO contextThe agent runs a host's storage commands in sequence, so the stuck thread also blocked every command queued behind it for that host.
Fix
1. Bound the operations. A new
CephUtil.connect()applies per-operation timeouts to every handle:rados.client.mount.timeoutrados.osd.op.timeoutrados.mon.op.timeoutThe operation timeouts are on by default. Left at
0, the hang still happens for anyone who doesn't know to set them, and a failed operation can be retried while a wedged host can't. Setting either to0leaves the librados option unset and keeps the old wait-forever behaviour, and a cluster whose single operations legitimately run longer, for example during heavy backfill or recovery, can raise them.agent/conf/agent.propertiesdocuments both.They limit a single operation and not a whole request, so a long copy or flatten is made up of many operations that are each well inside the limit.
2. Release what we open.
CephUtiladds non-throwingcloseQuietly,ioCtxDestroyQuietlyandshutDownQuietly, and every path cleans up from afinally.CephUtil.connect()3. Open read only where we only read. A read write open registers a watcher on the image header and lets the image take its exclusive lock. A clone parent needs neither:
Creating and protecting the base snapshot are writes, so the first clone of a template reopens it read write for that one step. Every later clone of that template keeps the read only handle. The same change applies to the cross cluster copy and to reading a snapshot during backup. Paths that really do write, such as
snapCreate,snapUnprotectandsnapRemove, are unchanged.4. Report failures that were silent. Wrong regardless, and reachable the moment a timeout is set:
rbd_readreturns a negative errno rather than throwing, and the snapshot backup loop treated that as end of image — a short file on secondary storage, recorded as a good backup. A read or write error now fails the answer.getPhysicalDiskalready did.What this does not fix
The thread was waiting on an internal librbd completion that never arrived, so a per operation timeout may not reach that particular wait. Where the timeouts do reach it, this change lets the agent recover and keeps one stuck call from blocking a host's whole command queue. It does not fix librbd.
Types of changes
How Has This Been Tested?
mvn -pl core,agent,plugins/hypervisors/kvm testbuilds clean and the existing unit tests pass.wchanandsyscallstate showing an untimed futex wait, and the librbd frames recovered by matching return addresses on the stuck thread's stack against a disassembly of the same build.0leaves the librados options unset exactly as before.