fix(watcher): back off re-forking a hard-failing index worker - #2075
Conversation
A hard index failure (index_fn < 0) left the retry cadence untouched, so a persistently failing project re-forked an index worker every poll for as long as the daemon lived. Observed on 0.10.8/macOS: 2233 consecutive failed workers over 4h43m, ~8/min, every one dying at the same worker-side coordination seal. Read queries stayed healthy throughout, so nothing surfaced to the user while no project could be indexed at all. DeusData#937 deliberately leaves the baseline uncommitted on a failed reindex so the change is retried rather than lost. That guarantee is kept; what changes is the cadence. Each consecutive hard failure doubles the delay, capped at five minutes, taking a permanently failing project from ~480 attempts/hour to ~12 while still recovering on its own once the cause clears. Busy-skip (rc > 0) and success paths are untouched. The delay arithmetic is a pure exported helper so it is unit-testable without a clock. watcher.index.err now carries rc and the consecutive- failure count, and a distinct watcher.index.sustained_failure names a project whose failures are clearly not transient. Note: itoa_buf returns a single shared per-thread buffer, so the two-value log line uses local buffers rather than two itoa_buf calls. Refs DeusData#2015 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01FbrM52pmB1m2SR1vRRoNnf Signed-off-by: Shane McCarron <shane.mccarron@corvexconnect.com>
F1 (major) — the failure state machine the backoff feeds had no test coverage. Deleting the streak reset, or widening the sustained-failure comparison, left all 7788 tests green: the index_backoff_* tests cover the delay arithmetic, and nothing covered the counter that selects which delay applies. A streak that never increments silently degrades the backoff to the unbounded retry it exists to prevent. Adds cbm_watcher_index_failure_count(), alongside the existing cbm_watcher_watch_count() in watcher.h's "Introspection (for testing)" section, and a test that drives a real git repo through fail/fail/succeed on the failing_index_callback seam already used by the DeusData#937 test, asserting the streak goes 0 -> 1 -> 2 -> 0. Verified by mutation: removing the reset turns it red at the reset assertion while every index_backoff_* test stays green. The delay-GATING half stays uncovered on purpose. Every integration test calls cbm_watcher_touch first, which zeroes next_poll_ns, so whether the scheduler honours the computed deadline is unobservable without an injectable clock the watcher does not have. That harness is a larger change than this fix. F3 (minor) — cbm_watcher_index_backoff_ms was non-monotonic for an interval above the ceiling: zero failures returned the interval, one failure returned the smaller ceiling. Unreachable today (POLL_MAX_MS < the ceiling), but the function is exported, so the clamp is now a floor as well as a cap and backing off can never schedule sooner than the project's own cadence. F2 (minor) needed no code change: a busy-skip following an unresolved failure streak keeps the backed-off delay, which is deliberate — only a success clears the streak, and treating rc > 0 as recovery would let a project alternating fail/busy never back off at all. The PR description's over-strong "busy-skip is behaviourally unchanged" claim is corrected there. Refs DeusData#2015 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01FbrM52pmB1m2SR1vRRoNnf Signed-off-by: Shane McCarron <shane.mccarron@corvexconnect.com>
Retracts an incorrect justification from the round-1 commit (4fc5999) and closes the coverage it was used to excuse. MAJOR — the delay wire-up had no coverage, and the reason given for that was wrong. Round 1 claimed the gating half was "structurally unobservable without an injectable clock". It is not. cbm_watcher_touch zeroes next_poll_ns, so a wire-up that never sets a deadline leaves it at zero and the callback fires on every poll: simply NOT calling touch between polls observes gating deterministically, no clock involved. Only the delay's MAGNITUDE needs one. watcher_index_failure_backoff_gates_repolling_issue2015 covers it — one hard failure, then five polls without touch asserting no re-fork, then a touch proving the retry still gets through (so the test cannot pass by observing a dead watcher). Mutation-verified: deleting the wire-up yields "failing_index_calls == 6, expected 1". MINOR — round 1's F1 was half-fixed. Of the two single-token mutations that finding named, only the streak reset was covered; widening the sustained-failure "==" to ">=" still passed. watcher_sustained_failure_logs_ once_issue2015 drives 14 consecutive failures through a cbm_log_set_sink and asserts exactly one emission. Mutation-verified: ">=" yields "sustained_log_hits == 5, expected 1". All three mutations F1 named are now demonstrated caught rather than argued about: reset removal (round 1), wire-up deletion, and the "==" widening. MINOR — cbm_watcher_index_failure_count reads index_failures under projects_lock while poll_project writes it lock-free from a state snapshot. That is the discipline every other per-project field here already follows, so this documents the visibility contract rather than making one field atomic in isolation: the accessor is a diagnostic and test seam, not a synchronisation point, and must not carry scheduling decisions without atomic accessors first. MINOR — watcher.h still described the pre-F3 backoff contract. It now states the clamp is a floor as well as a cap, why the floor exists for an exported function whose reachable inputs cannot currently hit it, and that negative inputs are treated as zero. Still uncovered, now stated precisely rather than hand-waved: the delay's MAGNITUDE. Nothing asserts that ten failures produce a five-minute delay rather than a five-second one. Gating is proven; the numbers are not, and that does need a controllable clock. Refs DeusData#2015 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01FbrM52pmB1m2SR1vRRoNnf Signed-off-by: Shane McCarron <shane.mccarron@corvexconnect.com>
Documentation and claim accuracy only — no behavioural change. Two of the three findings are corrections to inaccurate statements the round-2 commit (61ccd90) introduced. The gating test's framing was overstated, and this time the overstatement was measured rather than argued. Replacing the backoff call with the pre-change `ctx->now + interval_ms * US_PER_MS` leaves the watcher suite green at 82/82: the index_backoff_* tests pass because they exercise the pure function directly, which the reverted scheduler no longer calls, and the streak tests pass because the counter is untouched. So no test in this suite fails when this change's behaviour is removed. The test now records that, with the figure, instead of claiming it demonstrates the backoff. It is a regression guard on a deadline being assigned at all — real, but narrower than round 2 said. Closing that gap needs either a controllable clock or a further accessor exposing next_poll_ns. Both were judged out of scope: a third exported symbol purely for testing, on a change already carrying two, is the API widening earlier rounds flagged. The gap is recorded in the test, the PR description and the round-3 note rather than papered over. The memory-visibility comment claimed index_failures follows "the same discipline every other per-project field in this struct already follows". That is false: active_git is serialized by projects_lock and registered is an atomic_bool. Narrowed to the poll-mutated fields, which are now enumerated. The round-2 decision to document rather than lock still stands — the panel verified the underlying premise — but it was resting on an overbroad claim. watcher.h said the delay "doubles up to a fixed ceiling", which skips the shift cap: the delay plateaus at interval_ms << INDEX_FAIL_SHIFT_MAX, and that reaches the ceiling only for interval_ms >= 4688 ms. Every interval this watcher generates is >= POLL_BASE_MS so the ceiling is always reached in practice, but the function is exported and a caller may pass less. Refs DeusData#2015 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01FbrM52pmB1m2SR1vRRoNnf Signed-off-by: Shane McCarron <shane.mccarron@corvexconnect.com>
|
Thanks for opening this — it has been seen, and it is queued. This note is automated, but it is not a brush-off: it exists so you know where your PR stands instead of having to guess from silence. Current review status: working through a backlog. What that means for this PR, concretely:
Things that will genuinely speed it up whenever review does happen:
If this fixes a bug, a reproduction we can run is worth more than a description of the symptom. Thanks for contributing, and sorry in advance for the wait. |
|
Thank you for this one — the per-project failure counter with a capped doubling backoff on the We are assembling a patch release (v0.10.9) around the install and memory reports, and this belongs in it. Whenever you consider the draft ready, please mark it ready for review and we will take it through the normal review right away. If there is a piece you are still unsure about, say so in the PR and we can work through it together rather than wait. |
|
Marked ready for review — thanks for the confirmation on the shape, and glad it lands in v0.10.9. Three QA rounds have been run against the diff and are already pushed ( On the one red check: This diff touches only Happy to re-run that job if you would like a second data point, or to work through anything else you want changed during review. |
DeusData
added
bug
|
Could I ask for a re-run of For context on the run itself: it is from 2026-09-06, but it is against the current head SHA The failure remains Some field data that arrived sinceThe backoff wedged-daemon scenario recurred on my machine on 2026-09-11 — every index worker refusing to start for 427 minutes — which gave an unplanned before/after for this patch in a single
Worth being straight about the limit, though: the backoff bounds the retry rate, not the total. Over a 427-minute wedge the 5-minute ceiling still permits ~85 retries per project, so dead workers accumulate linearly with daemon uptime until the underlying fault is cleared by hand. That is not a gap in this PR — it is the separate root cause, which I've now written up as #2178 with the mechanism traced through |
|
You asked for a rerun on 11 September and got silence for nine days. I am sorry — that is on us, and the field data you posted in the meantime deserved a faster answer than that. Review: I have no changes to ask for. I read the production diff line by line:
About the red. You read it correctly:
If Thank you for the fix, for three QA rounds you ran on your own, and for coming back with production numbers rather than a reminder. |
|
Merged as a7187ad — thank you. Verified on the merge result before landing: watcher suite 83/83 three runs in a row with the three It ships in the next patch release. The 2,226-versus-560 log comparison you posted is going into the release notes as the reason this matters. |
3 participants
Closes #2015
What
poll_project()treats a hard index failure (index_fnreturningrc < 0) as a transient event: it emitswatcher.index.errand schedules the next poll at the plain interval. A persistent start failure — a poisoned coordination endpoint, an unreadable DB — therefore re-forks an identically-failing worker at the normal cadence for as long as the daemon lives (2,233 workers in 4h43m in the report).This adds a per-project consecutive-failure counter with a doubling, capped backoff on that path only:
index_failuresonproject_state_t, incremented onrc < 0, reset to0by any successful reindex.cbm_watcher_index_backoff_ms(interval_ms, consecutive_failures)— pure function, doubling per consecutive failure up to a shift cap and an absolute ceiling, so a permanently-failing project decays to occasional retries instead of every-poll retries.watcher.index.errnow carriesrcandconsecutiveso the streak is visible in the log rather than inferred from line count.cbm_watcher_index_failure_count()accessor so the counter is testable without reaching into the struct.The watcher guarantee is preserved
Per the maintainer note on #2015 — a failed observation must not be silently committed. It isn't: the
rc < 0arm only logs and lengthens the next poll. It does not touchlast_dirty_sig,pending_dirty_sig, orpending_head. The baseline stays uncommitted exactly as #937 intends, so the pending change is still picked up whenever the underlying failure clears; only the retry cadence decays. The busy-skip (rc > 0) path is untouched.Field evidence
The patched build has been running locally since 2026-09-02. On 2026-09-06 an unrelated daemon-coordination fault made every index worker fail to start — the same permanent-failure class as the original report — across three watched projects.
watcher.index.errevents for a permanent failureThe underlying fault was not fixed by this change and is not meant to be — the point is that the watcher stopped re-forking within seconds instead of accumulating thousands of doomed workers, and the streak counter in the log made the fault diagnosable at a glance.
Tests
tests/test_watcher.cadds coverage for the backoff arithmetic (monotonic, capped, saturating), the counter's increment/reset contract, and the guarantee that a failing poll leaves the baseline uncommitted.Notes
Opened as a draft. Three QA rounds were run against this diff before submission (commits
4fc5999a,61ccd905,08642202); reports follow as comments.🤖 Generated with Claude Code
https://claude.ai/code/session_01Y9gerhYqHmbgnCxmqpVKFc