Skip to content

fix(chaos): bound the recovery kill point by construction, not by a race - #2835

Merged
devarismeroxa merged 1 commit into
mainfrom
fix/chaos-recovery-kill-point-determinism
Aug 27, 2026
Merged

fix(chaos): bound the recovery kill point by construction, not by a race#2835
devarismeroxa merged 1 commit into
mainfrom
fix/chaos-recovery-kill-point-determinism

Conversation

@devarismeroxa

Copy link
Copy Markdown
Contributor

Tier 3 — test harness only. Confined to tests/chaos; no engine or data-path code touched, and
the holdAt seam is inert unless a test sets it. Unblocks #2832 and #2834, since
tests/chaos (race, x3) is a required context on main.

The failure

TestSIGKILL_RecoveryLoop_CrashDuringRecoveredRun failed on #2832's CI
(run 32792092690):

recovery_test.go:300: not true: committedAtKill < cfg.total

That is a vacuity guard firing correctly. The test asserts the SIGKILL landed mid-run; it hadn't,
because the child committed all 60 records before dying, so the test refused to pass while exercising
nothing. The guard is the good part — this PR fixes what made its precondition false, and does not
touch the guard.

Root cause

waitForReadCount is a lagging, parent-side observation of a free-running child. The parent's
stdout reader goroutine and its 1ms poll loop are both subject to descheduling, so "I last saw 30
READ lines" says nothing about where the child is now.

The margin is ~0.3s, not the "orders of magnitude" a sibling scenario's comment claims: at 30 READs
the child is at position 30, and 30 records x 3ms + the 10ms lcPersistDelay debounce is ~150ms to
finish the whole run. Injecting a stall between waitForReadCount and sigkill reproduces CI's
assertion verbatim at 400ms; 200ms and 120ms both pass.

The fix

  1. holdAt production ceiling on recoverySourcePlugin.produceLoop. Once position holdAt (20)
    is sent the child prints LC_HELD and stops for good, so it can never reach total (60). Inert
    at 0, which every other scenario leaves it at. parseLCChildEnv rejects graceful && holdAt>0
    and holdAt >= total — both would otherwise surface only as opaque timeouts.
  2. Kill gated on the durable committed watermark, read from the same on-disk marker the
    assertion reads. upstreamStore.Commit is write -> fsync -> atomic rename, so a cross-process
    reader never sees a torn value.

Why this is deterministic rather than tuned: lower bound observed, upper bound structural. The
first run provably never sends failAt (produceLoop closes the stream instead), so a watermark
past it is positive proof the recovered run is producing. The ceiling means nothing past 20 is ever
produced, so nothing past 20 can ever be committed — however long the parent is descheduled. The
kill point is bracketed in [10, 20] and every value in that interval yields the identical
verdict
, so killAfterCommitted tunes in-flight depth, not pass/fail.

Rejected: enlarging total (tuning, not a bound). Rejected: gating only on committed count — fixes
the lower bound but leaves the upper bound racing, since a stalled parent can observe committed >= 5
while the child is at 60.

This is the same shape as #2534's fix already in this package: sigkill_test.go's mid-snapshot
case had its precondition made structurally true via a 600s persister debounce rather than a wider
margin. Applied here to the production side.

The test still tests what it says: the kill fires at watermark 10 while the producer is still on its
way to 20, so records are genuinely in flight. committedAtKill > cfg.failAt-1 remains meaningful
and is now guaranteed. Added committedAtKill <= cfg.holdAt so removing the cap fails
deterministically instead of flaking back to life.

Proof

result
injected 400ms stall, pre-fix FAIL, assertion identical to CI
injected 3s stall (7.5x), post-fix 10/10 pass
soak, 24 CPU spinners, load avg 61 100/100
same soak, pre-fix 20/20 green
full tests/chaos -race green, run 3x

That pre-fix 20/20 is the honest number: brute-force repetition cannot measure this flake locally
— it is rare on CI and nightly has been green 8 days. Repetition counts are not the evidence; the
bound is. Hence the deterministic reproduction.

Regression test TestRecoveryChild_HoldAt_CapsProductionBelowTotal waits for the ceiling, stalls
400ms (the exact window that reproduced the flake), and asserts the child has not moved. Verified to
fail without the fix — the LC_HELD wait times out and diagnostics print READ 1 … READ 60. That
sleep is adversarial, not load-bearing: enlarging it can only make an unsound cap fail harder, the
inverse of a masking sleep. Documented at the constant.

Independently verified before merge: target test and regression test 5/5 each under -race, full
tests/chaos green under -race.

Known-unfixed sibling

tests/chaos/property2_test.go carries the same unsound pattern across all three cases and both
prune classes (6 subtests) — kill-point vacuity guards racing a free-running child, and unlike
sigkill_test.go it never got persistDelayMS. With a 1.5s stall injected, mid-handoff and
mid-position-write fail, and mid-snapshot hangs for 41.6s rather than failing fast — the
starvation hang sigkillCase's own doc comment describes. On a required check that is a 40s stall
per subtest.

Filed separately rather than folded in, per the small-PR rule. fanout_sigkill_test.go:65 and
nsource_sigkill_test.go:102 also gate on waitForReadCount, but their post-kill assertions do not
depend on the child being mid-run — they degrade to silently weaker coverage, not to red.

Caveats

  • The flake was never observed naturally on the dev machine, under contention or otherwise. Every
    reproduction used an injected stall. The assertion, the margin arithmetic and the READ 1…60
    diagnostics all line up with what CI hit, but it was not caught in the wild.
  • In-flight depth at the kill is typical, not guaranteed: a badly starved runner could drain all 20
    before the signal lands. The assertions still hold (40 records were never produced, so it is still
    a mid-run crash) — only the depth of the invariant-1 window degrades, never the verdict.
  • Developed on darwin; CI runs Linux.

Roadmap: v0.20 WS9-B (flaky tests fixed at cause, never masked).

TestSIGKILL_RecoveryLoop_CrashDuringRecoveredRun failed on PR #2832's CI run
32792092690 with "not true: committedAtKill < cfg.total" (recovery_test.go:300).
That assertion is a vacuity guard and it fired correctly: the SIGKILL did not
land mid-run, so the test refused to pass while not exercising the crash it
claims to.

Cause: the kill was gated on childProcess.waitForReadCount(30) - a LAGGING,
parent-side observation of a child that keeps producing while the parent is
descheduled. The child free-ran to total (60) at paceMS 3, so the window
between "the parent last saw 30 READ lines" and "SIGKILL actually lands" only
had to exceed the ~150ms of remaining production plus the 10ms persister
debounce for the child to finish before it died. Locally a 400ms stall
injected into that window reproduces the CI failure verbatim, first try; 200ms
still passes. That is a ~0.3s margin, not the orders of magnitude the sibling
CrashDuringBackoff scenario enjoys, and `tests/chaos (race, x3)` on a loaded
runner exceeds it.

Fix - the same shape as #2534's (sigkill_test.go's mid-snapshot case, whose
precondition was made structurally true with a 600s persister debounce rather
than a wider margin), applied to the production side:

  - recovery_child.go gains a holdAt seam: a ceiling on how far this process's
    source may ever produce. Once holdAt is sent, produceLoop prints LC_HELD
    and stops for good. Inert at 0, which is what every other scenario and the
    graceful restart child leave it at; parseLCChildEnv rejects the
    combinations that could only ever manifest as an opaque timeout.
  - The kill is now gated on the child's DURABLE upstream commit watermark
    (read off the same on-disk marker the assertion reads, written via
    fsync+atomic-rename so a cross-process reader never sees a torn value),
    not on a read count.

Both guards are now structural. Lower bound: the watermark passing failAt is
positive proof the recovered run is producing, since the first run provably
never sends failAt. Upper bound: holdAt (20) < total (60) caps what this
process can ever commit, however long the parent is descheduled. The kill
point is bracketed in [10, 20]; every value in that interval gives the
identical verdict, so it tunes in-flight depth, not pass/fail.

The test still tests what it says: the SIGKILL lands during the recovered run,
after the induced failure and restart, with records in flight (the cap is a
ceiling, not the trigger - the kill fires at watermark 10 while the producer
is still on its way to 20).

Regression test: TestRecoveryChild_HoldAt_CapsProductionBelowTotal waits for
the ceiling, then stalls 400ms - the exact window that reproduced the flake -
and asserts the child has not moved. Verified to fail without the fix (the
child free-runs to READ 60 and the LC_HELD wait times out) and pass with it.

Verification:
  - Injected-stall repro: 400ms fails identically to CI pre-fix; post-fix a
    3s stall (7.5x) passes 10/10.
  - Soak under real CPU contention (24 spinners, load avg 61): 100/100 across
    both tests. Pre-fix the same soak was 20/20 green, i.e. brute-force
    repetition cannot measure this flake - which is why the bound, not a
    repetition count, is the evidence.
  - Full tests/chaos package green under -race; golangci-lint clean.

Tier 3: test-harness only. No engine or data-path code is touched, and the
seam is inert unless a test sets it.

Refs #2832

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_016xE861dwb3MLgqEdWRECLY
@devarismeroxa
devarismeroxa requested a review from a team as a code owner August 25, 2026 01:15
@devarismeroxa devarismeroxa added this to the v0.20.0 milestone Aug 25, 2026
@devarismeroxa
devarismeroxa merged commit 9244dd7 into main Aug 27, 2026
11 checks passed
@devarismeroxa
devarismeroxa deleted the fix/chaos-recovery-kill-point-determinism branch August 27, 2026 22:12
devarismeroxa added a commit that referenced this pull request Aug 29, 2026
#2840)

* fix(chaos): bound property2 kill points by construction, not by a race

Fixes #2836. tests/chaos/property2_test.go carried the same unsound
pattern #2835 fixed in recovery_test.go: all six subtests (3 kill
windows x 2 upstream classes) watched a FREE-RUNNING child's stdout
and then SIGKILLed it. The child kept producing while the parent was
descheduled, so an observed read count said nothing about where the
child was when the kill landed.

Failure-mode analysis (what this fixes, reproduced on demand): with a
2.5s stall injected between the kill gate and the SIGKILL, against the
pre-fix test, all six subtests fail or hang -
  mid-snapshot (both classes): HANG ~42.6s ("timed out waiting for
    child to exit") - the starvation its own comment describes;
  mid-handoff (both classes): FAIL "got 164" - resumeEmpty asserted,
    but a flush landed and a non-zero position was persisted;
  mid-position-write (both classes): FAIL "got 192" - the stale guard
    (resumePos < killAfterReads) blown through by the free-runner.

The fix gives every kill point one observed LOWER bound and one
STRUCTURAL upper bound, so the verdict no longer depends on when the
kill lands:
  - resumeEmpty cases: 600s persister debounce (the #2534 pattern)
    makes "nothing durably persisted at kill time" structural - no
    flush can ever land before the kill, however long the parent
    stalls; holdAt caps production below total so the child can never
    finish and exit before the kill (its read loop blocks forever).
  - resumeValidNonZero: the kill is gated on the child's DURABLE
    upstream commit watermark (waitForUpstreamCommittedAtLeast), not a
    read count; holdAt caps what the child can ever commit, and the
    stale guard is restated structurally as resumePos <= holdAt.
  - New regression test TestChild_HoldAt_CapsProductionBelowTotal pins
    the ceiling itself: wait for the HELD marker, stall 400ms
    adversarially, assert nothing past the ceiling was produced or
    committed.
  - parseChildEnv rejects invalid combos at child startup (holdAt >=
    total exits exitBadArgs: a cap at/above total bounds nothing).

Verified:
  - Stall-injected (2.5s, the injection that fails all six pre-fix
    subtests): all six subtests + the regression test PASS.
  - Perturbation proof: cap disabled in produceLoop - regression test
    FAILS (HELD marker never appears) and mid-position-write FAILS
    (resume 129 > ceiling 100). The bound is load-bearing, not
    decorative.
  - go test -race -v -count=3 -shuffle=on ./tests/chaos/... (the
    chaos.yml invocation): PASS, 368s.
  - golangci-lint (v2.12.2, per tools/go.mod): clean. go vet: clean.

Rollback: revert this commit; tests only, no engine code touched.
A regression surfaces as a chaos-suite failure, which is a required
CI context.

* docs(chaos): correct property2 comments after independent review

Comment-only honesty fixes from PR #2840's independent review; no code
semantics changed (one vacuous assertion removed):

- The mid-position-write case no longer claims a stale (behind the kill
  point) checkpoint with in-flight records: the watermark-gated kill
  lands on a flushed state where produced == acked == committed, and the
  in-flight window is empty by construction. The comment now states the
  flush-boundary semantics and records that losing the in-flight window
  was the deliberate cost of bounding the kill on the watermark, with
  DBZ-1's sigkill mid-stream case as the intended home of that scenario.
- The 'cap removal fails immediately' claim was not load-robust: under
  the very descheduling this PR targets, a flush can cover as few as
  just over 70 records, so an uncapped run can pass the case-level
  resumePos <= holdAt assertion. Comments now state the airtight bracket
  argument (watermark is always in [killAfterCommitted, holdAt]) and
  cite the regression test's HELD-marker wait as the deterministic
  cap-removal detector, with the case-level assertion labeled a soft
  detector.
- Dropped the regression test's committed <= holdAt assertion, which was
  vacuous at its timing (default 1s debounce, ~480ms elapsed: committed
  is 0 by construction), documenting where the committed side is pinned.
devarismeroxa added a commit that referenced this pull request Aug 29, 2026
…2841)

The mid-stream SIGKILL case estimated its crash window with arithmetic
(killAfterReads=95 at paceMS=15: one ~1s flush landed, a second pending)
then SIGKILLed. Under parent descheduling the child keeps producing
through the observation-to-signal gap, so the crash lands far past the
window the case claims to test - and since every landing point yields
the same gap-free verdict, the case passes vacuously and never flakes
(the identical defect #2836 diagnosed for property2).

Apply the #2835/#2840 bracket pattern exactly:

- Lower bound (observed): gate the kill on the child's durable upstream
  commit watermark reaching killAfterCommitted=70
  (waitForUpstreamCommittedAtLeast) instead of parent-observed READ
  progress - the watermark only moves when a flush lands, so the gate
  cannot fire before a checkpoint is durably persisted.
- Upper bound (structural): holdAt=100 caps the first child's production
  via #2840's CONDUIT_CHAOS_HOLD_AT seam (merged on main after this
  branch started - reused, not duplicated). Nothing past it is ever
  produced, acked, or committed, and the capped child never exits on its
  own, so the kill can never miss a dead process.
- Every value in [70, 100] yields the identical verdict.
- Preconditions asserted, not trusted: a kill landing outside the
  bracket, or a resume position past the ceiling, fails the test. The
  deterministic cap regression test is #2840's
  TestChild_HoldAt_CapsProductionBelowTotal (property2_test.go) - this
  PR adds no duplicate.

Proven: (a) pre-fix + 2.5s stall passes vacuously with the kill point
blown through (watermark 192/193, produced 254/255 vs the claimed
~95-133 window; a temporary bracket assertion fails both prune classes
deterministically - the silent window-skip); (b) post-fix + same stall
passes on both prune classes; (c) cap removed fails deterministically
on both (HELD-marker timeout, and precondition watermark 257 > holdAt
100).

Verification: go test -race -count=3 -shuffle=on ./tests/chaos/... green
(362.5s), golangci-lint v2.12.2 clean, go vet clean.
devarismeroxa added a commit that referenced this pull request Aug 29, 2026
…2841) (#2842)

The mid-stream SIGKILL case estimated its crash window with arithmetic
(killAfterReads=95 at paceMS=15: one ~1s flush landed, a second pending)
then SIGKILLed. Under parent descheduling the child keeps producing
through the observation-to-signal gap, so the crash lands far past the
window the case claims to test - and since every landing point yields
the same gap-free verdict, the case passes vacuously and never flakes
(the identical defect #2836 diagnosed for property2).

Apply the #2835/#2840 bracket pattern exactly:

- Lower bound (observed): gate the kill on the child's durable upstream
  commit watermark reaching killAfterCommitted=70
  (waitForUpstreamCommittedAtLeast) instead of parent-observed READ
  progress - the watermark only moves when a flush lands, so the gate
  cannot fire before a checkpoint is durably persisted.
- Upper bound (structural): holdAt=100 caps the first child's production
  via #2840's CONDUIT_CHAOS_HOLD_AT seam (merged on main after this
  branch started - reused, not duplicated). Nothing past it is ever
  produced, acked, or committed, and the capped child never exits on its
  own, so the kill can never miss a dead process.
- Every value in [70, 100] yields the identical verdict.
- Preconditions asserted, not trusted: a kill landing outside the
  bracket, or a resume position past the ceiling, fails the test. The
  deterministic cap regression test is #2840's
  TestChild_HoldAt_CapsProductionBelowTotal (property2_test.go) - this
  PR adds no duplicate.

Proven: (a) pre-fix + 2.5s stall passes vacuously with the kill point
blown through (watermark 192/193, produced 254/255 vs the claimed
~95-133 window; a temporary bracket assertion fails both prune classes
deterministically - the silent window-skip); (b) post-fix + same stall
passes on both prune classes; (c) cap removed fails deterministically
on both (HELD-marker timeout, and precondition watermark 257 > holdAt
100).

Verification: go test -race -count=3 -shuffle=on ./tests/chaos/... green
(362.5s), golangci-lint v2.12.2 clean, go vet clean.
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.

1 participant