fix(runtime): drain shutdown past the dispatch deadline and jitter restart backoff - #275
Conversation
|
Force-pushed one fix: the jitter this PR adds made
Timing cannot fix it: count-1 gives [0.5 s, 1.0 s] and count-2 gives [1.0 s, 2.0 s], and those bands touch, so no sleep distinguishes a kept count from a reset one. The assertion was also redundant. Worth noting separately: |
d92cadf to
7ab9674
Compare
|
Force-pushed three follow-ups from a review pass on whether this PR corners us. All three are cheap now and expensive after a tag. 1. The stop-drop was silent and systematically biased. The fan-out iterates All three shutdown drop sites now count, with Note this widens an existing metric's label set, which is an operator contract change. Doing it now rather than after the tag is the point, and #243 is about to touch this metric anyway. 2. Raising The drain default is The resolved bound is now logged as 3. The key was process-scoped but sat in a per-dispatch section.
|
7ab9674 to
01faf6c
Compare
…start backoff The hardcoded 10 s drain lost to the 120 s default dispatch deadline: any dispatch running longer than 10 s at SIGTERM forced exit 1 before the in-flight dispatch committed its cursor, on every restart and upgrade. Two changes close the race. The drain bound is now [limits.dispatch] shutdown_drain_secs, defaulting to deadline_secs plus 30 s, saturating instead of overflowing on a maximal deadline. And the supervisor now halts the dispatch fan-out between guest calls once shutdown fires: one event is a serial sweep of revives plus per-module dispatches, each deadline-bounded on its own, so without the halt the drain had to cover the whole fan-out rather than one call. With it, at most one deadline-bounded call is ever left in flight, which the untuned default outlasts. A timed-out drain still exits 1: the fan-out halts between calls and the drain outlasts the one in flight, so a timeout is a wedged task, and Restart=on-failure should restart it. On that path the cursor stays at the last committed dispatch; a resume subscription replays the in-flight event at the next start, and a block event is not replayed. A halted fan-out has the same cursor shape: skipped chain-log events replay, skipped blocks do not. docs/production.md states the contract, raises TimeoutStopSec above the bound, and adds a pre-upgrade step to re-diff the unit. Restart backoff is now jittered into the upper half of each doubling step by a hash of identity and a per-process nonce, so modules that failed on one shared outage do not retry in lockstep within an engine or across a fleet on one config. The delay stays deterministic per (seed, failure count) for tests. Closes #148 AI Assistance: Claude Fable 5 used for the implementation.
01faf6c to
db14fc1
Compare
The bug
The shutdown drain was a hardcoded 10 s constant (
SHUTDOWN_DRAIN_TIMEOUTinbuilder.rs) while the default dispatch deadline is 120 s, and a drain that ran out calledstd::process::exit(1).This was not a rare corner: every stop and every upgrade of a deployment whose modules take more than 10 s in
on_eventhit it, because the event loop only observes shutdown between dispatches and the drain is what waits for the in-flight guest call to return.Meanwhile
docs/production.mdpublished a systemd unit whose comment promised the opposite, that a stop "drains the in-flight dispatch, commits its cursor, and exits 0", withTimeoutStopSec=30schosen as headroom over a drain deadline that was neither 30 s nor configurable.Why it is data loss, not a papercut
persist_progress_markerandcommit_chain_log_cursorrun only afterDispatchOutcome::Ok, that is after the guest call returns, so killing the process mid-call skips that dispatch's cursor commit while every host-call write the guest already made is durable (per-call fsynced redb transaction, ADR-0014).The persisted cursor therefore stays at the last committed dispatch: a
resume = truechain-log subscription re-opens at that cursor and replays the killed event on top of partial writes, and a block subscription has no resume at all, so the killed block is simply lost with its writes half applied.The fix
[limits.dispatch] shutdown_drain_secsis new, defaulting to the resolveddeadline_secsplus a 30 s margin, so 150 s untuned; zero refuses at load like every other limit, and an explicit override resolves to exactly the value written.Deriving the default from the deadline rather than fixing a number means the drain still outlasts the dispatch it drains when an operator raises
deadline_secsand leaves the drain unset, so the 10 s against 120 s race cannot recur without an explicit operator choice.A drain sized for one dispatch is only sound if the drained unit is one guest call, and it was not: one event iteration is a
sweepof revives plus a serial per-moduledispatch_toloop, each separately deadline-bounded, so an untuned drain still lost against a two-module block fan-out. The supervisor now carries a synchronous stop probe (nexum_tasks::Shutdown::is_fired, wired fromtasks.subscribe()inbuilder.rs) checked insweep, in both candidate loops, and at chain-log entry and post-revive, so a fired stop halts the fan-out at the next guest-call boundary and at most one deadline-bounded call is ever left in flight.Exit 1 on a timed-out drain is kept, and the reason is now recorded at the exit site: with the fan-out halting between calls and the default drain outlasting the one call it can be left waiting on, a timeout means a wedged task rather than a long dispatch, so
Restart=on-failurerestarting the process is the right remedy. The restart-loop objection to exit 1 applied only while the drain could lose to an in-budget dispatch.Restart backoff is now equal-jittered:
backoff_for(failure_count, seed)keeps the 1 s doubling and the 300 s cap but draws from the upper half of each step, seeded byjitter_seed(identity)over the module id, the block-subscription chain, or module id XOR chain id. The seed mixes a per-process nonce fromstd::hash::RandomState, so a fleet running oneengine.tomlagainst one provider decorrelates too, not just the modules inside one engine. No new dependency;backoff_forstays a pure function of(seed, failure_count)with no clock and no RNG state, so it is exactly assertable under the paused-clock harness.Operator impact
An operator who upgrades and configures nothing gets a 150 s drain instead of a 10 s one, which is the point of the change but also means the installed unit must be updated: the published
TimeoutStopSecmoves from30sto180s, and a unit left at30sturns every stop into a SIGKILL at 30 s with no "shutdown drain exceeded deadline" line in journald, because systemd pre-empts the engine's own forced exit.docs/production.mdsection 10 (pre-upgrade) therefore gains a step to diff the installed unit against section 2 andsystemctl daemon-reload, with that consequence stated; section 2 states the new contract, and section 4 states plainly what a forced exit does to each of the two cursor keys.Nothing else changes at defaults: no metric was added or renamed, and no existing key changed meaning.
Review
The review raised 19 findings across three passes, deduplicating to 11 distinct issues; all 11 were fixed, and 2 further recommendations attached to them were declined.
Fixed: the blocker above, that the deadline-derived default still lost to a multi-module fan-out (3 reports); the false "always outlasts the dispatch it drains" guarantee in
docs/production.md; the missing upgrade step forTimeoutStopSec; the exit-1 rationale comment, which had inherited the same false premise; thecaps_at_five_minutesassertion, which pinned a lower bound the function does not hold atfailure_count = 9(base 256 s, so the 150 s to 300 s band starts at 10) along with the rustdoc table row that said the same thing; the untested config-to-handle plumbing, now pinned by the launch test setting a non-default drain and asserting the handle carries it; aDurationadd overflow that panicked at config load for adeadline_secswithin 30 ofu64::MAX, even under an explicit override, nowsaturating_add; the fleet-wide determinism of the jitter seed; and two comment-noise findings (assert_backoff_base, the limits test doc) plus the systemd unit comment, which now carries only the one constraint an operator editing the unit cannot infer.Declined: lifting the
DrainOutcometo exit-code mapping into a pure function, because the timed-out arm is two lines beside its stated decision and the plumbing it was meant to protect is now pinned by the launch test, so a unit test asserting a literal1would pin nothing real; and rewordingdocs/02-modules-events-packaging.md:144, which states doubling, the 300 s cap and upper-half jitter with no per-count numeric band, so nothing in it is false.just ciis green: 783 tests, plus doctests.Closes #148
AI Assistance: Claude Fable 5 and Claude Opus 5 used for the implementation, review, and this description.