Skip to content

fix(runtime): drain shutdown past the dispatch deadline and jitter restart backoff - #275

Merged
mfw78 merged 1 commit into
mainfrom
fix/shutdown-drain-and-jitter
Aug 17, 2026
Merged

fix(runtime): drain shutdown past the dispatch deadline and jitter restart backoff#275
mfw78 merged 1 commit into
mainfrom
fix/shutdown-drain-and-jitter

Conversation

@mfw78

@mfw78 mfw78 commented Aug 17, 2026

Copy link
Copy Markdown
Contributor

The bug

The shutdown drain was a hardcoded 10 s constant (SHUTDOWN_DRAIN_TIMEOUT in builder.rs) while the default dispatch deadline is 120 s, and a drain that ran out called std::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_event hit 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.md published a systemd unit whose comment promised the opposite, that a stop "drains the in-flight dispatch, commits its cursor, and exits 0", with TimeoutStopSec=30s chosen as headroom over a drain deadline that was neither 30 s nor configurable.

Why it is data loss, not a papercut

persist_progress_marker and commit_chain_log_cursor run only after DispatchOutcome::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 = true chain-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_secs is new, defaulting to the resolved deadline_secs plus 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_secs and 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 sweep of revives plus a serial per-module dispatch_to loop, 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 from tasks.subscribe() in builder.rs) checked in sweep, 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-failure restarting 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 by jitter_seed(identity) over the module id, the block-subscription chain, or module id XOR chain id. The seed mixes a per-process nonce from std::hash::RandomState, so a fleet running one engine.toml against one provider decorrelates too, not just the modules inside one engine. No new dependency; backoff_for stays 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 TimeoutStopSec moves from 30s to 180s, and a unit left at 30s turns 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.md section 10 (pre-upgrade) therefore gains a step to diff the installed unit against section 2 and systemctl 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 for TimeoutStopSec; the exit-1 rationale comment, which had inherited the same false premise; the caps_at_five_minutes assertion, which pinned a lower bound the function does not hold at failure_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; a Duration add overflow that panicked at config load for a deadline_secs within 30 of u64::MAX, even under an explicit override, now saturating_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 DrainOutcome to 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 literal 1 would pin nothing real; and rewording docs/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 ci is green: 783 tests, plus doctests.

Closes #148

AI Assistance: Claude Fable 5 and Claude Opus 5 used for the implementation, review, and this description.

@mfw78

mfw78 commented Aug 17, 2026

Copy link
Copy Markdown
Contributor Author

Force-pushed one fix: the jitter this PR adds made poison_pill_quarantines_module_after_threshold fail about one run in five, and I measured it at 2/12 before the change.

backoff_for(2, seed) yields base = 2s, half_ms = 1000 and jitter_ms uniform in 0..=1000, so the count-2 backoff is uniform in [1.0 s, 2.0 s]. The test slept 1.2 s and asserted no restart was due, which is false whenever jitter_ms <= 200. process_nonce() reseeds from RandomState per process, so it is a fresh draw every run rather than load sensitivity.

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. a_restart_keeps_the_failure_curve (lifecycle.rs:353) already proves the count survives a restart, deterministically, on a fixed seed. So the timing assertion is deleted and the sleep now clears the whole count-2 band. 12/12 green after the change.

Worth noting separately: supervisor/tests/lifecycle.rs still has three real tokio::time::sleep calls against the house rule from #144. They are deterministic against the jitter bands as written, so this PR does not chase them, but they are the obvious next thing to move onto the paused clock.

@mfw78
mfw78 force-pushed the fix/shutdown-drain-and-jitter branch from d92cadf to 7ab9674 Compare August 17, 2026 08:35
@mfw78

mfw78 commented Aug 17, 2026

Copy link
Copy Markdown
Contributor Author

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 (0..self.modules.len()), which is [[modules]] declaration order, so the stop always lands in the same place: the module declared last misses a block at every stop, and the first never does. Not random, permanent, and it increments nothing and logs nothing. Meanwhile nexum_runtime_dispatch_dropped_total already exists with help text "Events dropped before dispatch, by reason" and no reason label at all.

All three shutdown drop sites now count, with reason = "shutdown": the block fan-out, the extension fan-out and the chain-log path. The block fan-out also warns with the names of the modules that missed it. The existing rate-limit site gains reason = "rate_limited", so the help text becomes true and the two behaviours are separable.

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 deadline_secs silently invalidated the systemd unit we publish.

The drain default is deadline_secs + 30s and the published unit sets TimeoutStopSec=180s. An operator raising the deadline to 300s gets a 330s drain default and a SIGKILL at 180s, mid-call, which is the exact bug this PR exists to fix. They never touched the drain.

The resolved bound is now logged as shutdown_drain_secs on the supervisor ready line at every start, and the handbook says to read it there rather than recompute it, and states that raising the deadline raises the drain with it while the unit does not follow.

3. The key was process-scoped but sat in a per-dispatch section.

[limits.dispatch] shutdown_drain_secs is now [limits.shutdown] drain_secs. There is one process and one stop, while [limits.dispatch]'s sibling max_fuel_per_dispatch already has per-component overrides in [policy.component.<id>]. If [limits.dispatch] ever grows the same, a per-component shutdown drain is meaningless. The retired spelling refuses at parse under deny_unknown_fields and there is a test pinning that.

just ci green, 783 tests.

@mfw78
mfw78 force-pushed the fix/shutdown-drain-and-jitter branch from 7ab9674 to 01faf6c Compare August 17, 2026 12:17
…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.
@mfw78
mfw78 force-pushed the fix/shutdown-drain-and-jitter branch from 01faf6c to db14fc1 Compare August 17, 2026 12:42
@mfw78
mfw78 merged commit dfe16aa into main Aug 17, 2026
5 checks passed
@mfw78
mfw78 deleted the fix/shutdown-drain-and-jitter branch August 17, 2026 12:42
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

runtime: configurable shutdown drain and restart backoff jitter

1 participant