Flaky Channel B drain-race test kills pipeline: merge test gates lack retry path

[Trecek]

A remediation pipeline run for #4305 on 2026-07-20 was terminated by a single flaky test failure in the pre_remediation_merge step's post-rebase test gate. Investigation (adversarially validated, flake experimentally confirmed) found two compounding root causes:

1. Proximate: tests/execution/test_process_channel_b.py::TestChannelBDrainRacePipelineAdjudication::test_channel_b_drain_timeout_produces_success_skill_result is a real-subprocess wall-clock race test whose 300s outer timeout was exceeded under heavy concurrent load (suite ran 413s vs 169s minutes earlier; ~11 concurrent headless sessions). The identical commit passed the complete unfiltered suite (31,300 tests) immediately after the failure. Same failure signature as 2026-06-12; the margin raise that followed (120s→300s) did not immunize it.
2. Structural: pre_remediation_merge routes every test_gate/post_rebase_test_gate failure straight to release_issue_failure (since 52db82771, 2026-07-14, Rectify: pre_remediation_merge ref_coherence Recovery — PART A #4255) — a deliberate orphan-prevention escalation, but one that leaves no path distinguishing a transient flake from a genuine regression, even though bounded retry-without-orphaning arms exist at the same step for dirty_tree and ref_coherence. The later merge step lost its genuine check_merge_fix_loop retry in the same commit (its rebase arm was restored by 9da15e9b3 on 07-17; the test-gate arms were not). No semantic rule can detect this routing class.

Remediation directions recommended by the investigation (full detail in the report below): a bounded transient-failure retry arm for the merge test gates; a semantic rule flagging _TEST_STEPS arms routed to terminal steps; observability on the TIMED_OUT adjudication override; and architectural treatment (/rectify) of the drain-race timing fragility.

Related issues: #4228 (closed — the fix that introduced the escalation routing), #3417 (staged — pre_remediation_merge path_validation route), #1032 (staged — flaky-test architectural immunity), #1031 (staged — resolve-failures flake policy).

Investigation

Prior investigation completed interactively. See below for root cause analysis.

Investigation: Pipeline Failure for Issue #4305 — Post-Rebase Test Gate Flake and No-Retry Routing

Date: 2026-07-20
Scope: Why the remediation pipeline for issue #4305 terminated at the merge_worktree post-rebase test gate; whether the failing test is flaky or broken by Part A; why it passed one gate and failed the next; whether the recipe's no-retry routing is correct.
Mode: Standard. Adversarially validated same day by 4 independent validators; every correction below was re-verified against the primary sources before being applied. Flake conclusion additionally confirmed experimentally (see Root Cause 1).

Summary

The pipeline for issue #4305 did not fail because of anything Part A implemented. It failed because a chronically timing-sensitive integration test — tests/execution/test_process_channel_b.py::TestChannelBDrainRacePipelineAdjudication::test_channel_b_drain_timeout_produces_success_skill_result — flaked under heavy machine load during the pre_remediation_merge step's post-rebase test gate, and because that step's routing (changed 2026-07-14 by commit 52db82771) escalates every test-gate failure straight to release_issue_failure, with no path that distinguishes a transient flake from a genuine regression. The flake verdict is experimentally confirmed: the identical worktree commit that failed the gate passed the complete unfiltered suite (31,300 tests) later the same evening. The routing escalation was a deliberate orphan-prevention trade-off within the #4228 work (not a pure accident, as sibling commit ba752303a documents the rationale), but it shipped to mainline in a commit whose message never mentions the test-gate arms, it left a stale contradicting comment in the recipe, part of it (the rebase arm) was already recognized as over-broad and walked back three days later, and no semantic rule can detect the resulting "flake kills pipeline" gap. The same test failed identically on 2026-06-12; the response then was to raise its timeout margins (120s → 300s) — margins that were exceeded again here.

Root Cause

Two independent root causes compounded:

1. Proximate: load-induced wall-clock timeout in a real-subprocess race test — experimentally confirmed as a flake. The test spawns a real Python subprocess that writes a %%ORDER_UP%% Channel B marker after ~3.1s and never writes stdout; the production race resolver must adjudicate COMPLETED via Channel B. The only code path producing timed_out in this test is the outer anyio.move_on_after(timeout=300) scope firing, because run_managed_async unconditionally overrides any adjudicated termination when the outer scope was cancelled (src/autoskillit/execution/process/__init__.py:514-515; the only other TIMED_OUT assignment, :650, is in the separate sync run_managed_sync path this test never touches, and the pytest-timeout SIGALRM path is excluded because the recorded failure is an ordinary AssertionError diff, not a pytest Failed: Timeout). The failing gate's suite wall time was 413.48s versus 169–234s for green runs of the same code, at least 11 concurrent headless sessions across 3 pipeline clones were running that evening, and the worktree's temp/ holds 33 test-run outputs from 19:34–21:57 — sustained contention. Most tellingly, the test passed the pre-rebase gate inside the very same merge_worktree call (green full-selection run temp/test-2026-07-20_205946.txt, 17,354 passed) and flaked in the post-rebase gate minutes later (temp/test-2026-07-20_210233.txt). Confirmation: re-running task test-check in the untouched worktree at the same commit (2026-07-20 ~21:58, under moderate concurrent load) passed the complete unfiltered suite: 31300 passed, 610 skipped, 49 xfailed in 234.13s, TEST_RESULT=PASS (temp/test-2026-07-20_215754.txt). The exact micro-mechanism of the >300s stall in the failing run (event-loop starvation vs. subprocess spawn stall vs. per-tick psutil /proc scans at _process_monitor.py:355,374) remains [NEEDS-EVIDENCE]; everything else here is [SUPPORTED].

2. Structural: the firing step's routing has no transient-failure path — a deliberate but unrefined escalation. The step that fired was pre_remediation_merge (src/autoskillit/recipes/remediation.yaml:721-764), reached after the audit NO GO via check_audit_remediation_loop → counter resets → pre_remediation_merge (:651-652); the orchestrator session's own reasoning immediately before the merge_worktree call reads "moving into the pre-remediation merge phase," and it is the session's only merge_worktree invocation. Its test_gate and post_rebase_test_gate arms route to release_issue_failure (:733-736). Before commit 52db82771 (2026-07-14) those arms routed to remediate — which would have kept the pipeline alive but silently orphaned the un-merged Part A work by starting a fresh replan cycle; the flip to hard failure was reasoned (the same commit's note at :758-764 and, explicitly, sibling commit ba752303a on the unmerged branch pre-remediation-merge-ref-coherence-bypass-orphans-audited-w/4228: escalate rather than "reaching the next worktree creator, which would orphan the live worktree"). So for this step the defect is not "recovery was removed" but "neither the old nor the new routing can retry a transient failure" — even though bounded retry-without-orphaning arms exist at this very step for other failure classes (dirty_tree → commit_guard_pre_remediation, ancestor ref_coherence → check_ref_push_loop_pre_remediation, both of which loop back into the merge). Separately, the same commit did strip genuine recovery from the later merge step (test_gate/post_rebase_test_gate: check_merge_fix_loop → release_issue_failure; rebase: check_merge_rebase_loop → release_issue_failure), outside the commit message's stated scope; commit 9da15e9b3 (2026-07-17, #4279) restored the rebase arm's retry but left the test-gate arms terminal, and the stale note at remediation.yaml:478-481 (from 627d9a69d, 2026-05-28) still claims check_merge_fix_loop guards "dirty_tree / test_gate / post_rebase_test_gate". That step did not fire here, but it carries the same gap. [SUPPORTED]

Exoneration of Part A: Part A's single commit e55a08917 touches 13 files, all in the delivery-bound/response-shaping subsystem (server/_notify.py, server/_response_budget.py, recipe/_api.py, server/tools/_execution_helpers.py, plus an additive resolve_worst_case_delivery_bound in execution/backends/__init__.py, plus tests). tests/execution/test_process_channel_b.py and the three production files it exercises (execution/process/__init__.py, _process_race.py, _process_monitor.py) are byte-identical between develop and the worktree, and no import chain connects the two subsystems in either direction. [SUPPORTED]

Affected Components

• tests/execution/test_process_channel_b.py:456-503: the flaking test; asserts TerminationReason.COMPLETED at line 491 (line 481 in the June version) [SUPPORTED]
• src/autoskillit/execution/process/__init__.py:476-479, 514-515: outer timeout scope and the unconditional TIMED_OUT override that converts a correct Channel B adjudication into timed_out [SUPPORTED]
• src/autoskillit/execution/process/_process_race.py:427-499, 502-576: _watch_session_log drain window and resolve_termination (COMPLETION → COMPLETED at :556) [SUPPORTED]
• src/autoskillit/execution/process/_process_monitor.py:184-421: two-phase Channel B monitor with per-tick psutil checks (:355, :374) [SUPPORTED]
• src/autoskillit/recipes/remediation.yaml:721-764 (pre_remediation_merge, the step that fired), :1056-1090 (merge step, same gap, did not fire), :478-481 (stale loop note), :651-652 (audit-NO-GO route into pre_remediation_merge) [SUPPORTED]
• src/autoskillit/server/git.py:434-436, 463-477: rebase + post-rebase test gate; single tester.run() call, returns MergeFailedStep.POST_REBASE_TEST_GATE, MergeState.WORKTREE_INTACT, error text "The worktree is intact; run resolve-failures to fix the regressions." [SUPPORTED]
• src/autoskillit/smoke_utils/_merge_gate_diagnosis.py:33: classifies post_rebase_test_gate in _TEST_STEPS — intact diagnostic plumbing not reachable from the escalation arms [SUPPORTED]
• src/autoskillit/recipe/rules/rules_merge.py:98, 354: semantic rules that cannot detect a test-step arm routed to a terminal step (merge-failure-skill-domain-mismatch skips any target whose tool is not run_skill, :417; release_issue_failure's tool is release_issue) [SUPPORTED]

Data Flow

1. Implementation/retry phase gates green (multiple full-selection runs, e.g. temp/test-2026-07-20_204037.txt, _204351, _204732); the final test_check PASS at 20:50 local (2026-07-21T03:50:17Z, session 69462ce1): filter: conservative (17588 selected, 12992 deselected), 17354 passed, 197 skipped, 13 xfailed in 169.07s.
2. audit_impl returns NO GO at ~20:58 (remediation file stamped 2026-07-20_205844).
3. Recipe routes audit NO GO → check_audit_remediation_loop → counter resets → pre_remediation_merge (remediation.yaml:651-652 → :721), which invokes merge_worktree — the design being "merge the incomplete-but-correct Part A first, then remediate on top" (step note, :752-764).
4. Inside perform_merge(): pre-rebase test_gate green (temp/test-2026-07-20_205946.txt, 17,354 passed, started 20:59:46) → git rebase --autostash onto the remote feature branch — effectively a no-op, since the remote tip 6641dba96 is the direct parent of worktree HEAD e55a08917 (consistent with the worktree reflog containing no rebase entries: an up-to-date rebase writes none) → post-rebase gate (started 21:02:33): 1 failed, 17353 passed, 197 skipped, 13 xfailed in 413.48s, failure on xdist worker gw2, result returned 21:09:15 local (04:09:15Z). Identical pass/skip/xfail totals to the green runs imply the same conservative selection (the filter env var is injected by DefaultTestRunner, execution/testing.py:295-297, and applied by tests/conftest.py; the gate output itself prints no filter line — selection identity is inferred from totals, not from a per-test diff). [SUPPORTED, with the selection-identity inference noted]
5. perform_merge() returns failed_step: POST_REBASE_TEST_GATE, state: WORKTREE_INTACT → pre_remediation_merge arm (remediation.yaml:735-736) → release_issue_failure (tool release_issue) → issue Non-path verdict token unrecoverable; make_plan lacks on_context_limit route #4305 gets the fail label, claim released, pipeline ends {"success": false}. The merge never completed, so the feature branch (local and remote, tip 6641dba96) does not contain Part A; the worktree (impl-4305-20260720-191353, clean, ahead-by-1) holds the only copy of e55a08917. [SUPPORTED]

Test Gap Analysis

The failing test is the test — this section addresses why the infrastructure lets a flake kill a pipeline:

• No runtime flake tolerance anywhere: pytest-rerunfailures is not a dependency; there are no flaky markers, no quarantine list, no rerun-on-failure at any gate. The only flake defense is write-time numeric margins enforced by the AST guard tests/arch/test_channel_b_timeout_guard.py (minimum timeout >= 60, _phase1_timeout >= 120; this test complies at 300/400 and is not in the EXEMPTIONS dict), which cannot help when a 300s margin is exhausted at runtime. [SUPPORTED]
• The gate has no retry: perform_merge() calls tester.run() exactly once (git.py:465), and the pre_remediation_merge arms route every test-gate failure to a terminal step. [SUPPORTED]
• No semantic rule catches the routing class: merge-routing-incomplete (recipe/rules/rules_merge.py:98) only requires some route per MergeFailedStep; merge-failure-skill-domain-mismatch (:354) skips any arm whose target's tool is not run_skill (:417), so a test-domain failure routed to release_issue_failure (tool release_issue) passes validation silently. [SUPPORTED]
• The TIMED_OUT override erases diagnostic signal: __init__.py:514-515 discards a correct COMPLETED adjudication without recording why the outer scope fired, so a post-mortem cannot distinguish a true hang from scheduler starvation. [SUPPORTED]
• Margin-raising is the only historical remedy and it demonstrably saturates: after the June 12 failure at timeout=120, commits 49c3db3ff (06-28) and 8e9c1a037 (07-03) raised Channel B test margins across this file to timeout=300 / _phase1_timeout=400 (docstrings added verbatim: "guards against the outer wall-clock expiring under xdist -n 4 load"), and 8e9c1a037 widened a sibling drain window 0.5s → 2.0s; e90635a50 (07-04) extended the same docstrings. The 300s margin was then exceeded anyway on 07-20. [SUPPORTED]

Similar Patterns

• Within pre_remediation_merge itself, other transient failure classes already have bounded retry-without-orphaning arms: dirty_tree → commit_guard_pre_remediation (auto-commit, then retries the merge) and ancestor-ref_coherence → check_ref_push_loop_pre_remediation (budgeted push recovery, then retries the merge, added by 52db82771). Test-gate flakes are the one transient class with no such arm. [SUPPORTED]
• At the later merge step, dirty_tree still routes to check_merge_fix_loop (bounded by merge_fix_max_retries: 3) and rebase routes to check_merge_rebase_loop — the latter restored by 9da15e9b3 on 07-17 after 52db82771 had escalated it, showing part of the escalation was already judged over-broad; the test-gate arms were not similarly revisited. [SUPPORTED]
• The June 12 occurrence was absorbed rather than fatal: that pipeline (implementation-family, worktree impl-4023-20260612-180806, clone run impl-20260612-175100-661664) classified the failure failure_subtype = timing_race via the diagnosis path and entered a fix loop per resolve-failures Step 2.5 — which mandates a stabilizing fix (raise timeouts / remove timing dependencies), not a bare re-run. The margin raises of late June are consistent with that remedy. [SUPPORTED]

Design Intent Findings

• Two-phase drain wait (completion_drain_timeout): Introduced in 9ddf695c8 (2026-02-25, "fix: add two-phase drain wait to run_managed_async (Part A)") to stop Channel B from killing the process before Channel A confirmed stdout, which had produced empty-stdout false failures. Now lives in _process_race.py:427-499. Dependents: resolve_termination (_process_race.py:502-576), _build_skill_result / retry FSM (execution/headless/_headless_result.py:216-260, execution/session/_retry_fsm.py:169,207, _session_outcome.py:78,92). Documented in execution/process/AGENTS.md (two-channel race), docs/execution/orchestration.md:65 (drain_race replay rule), docs/design/acp-session-contract.md:296-299 (Channel B provenance bypass). [SUPPORTED]
• The failing test class: Introduced in 80874bfdd (2026-03-01, "add subprocess adjudication integration tests for all TerminationReason paths") to give every TerminationReason a full-boundary real-subprocess test; this class specifically locks the Channel B provenance bypass (drain expiry with empty stdout must still be success=True). [SUPPORTED]
• Escalation routing for pre_remediation_merge test gates: Introduced by 52db82771 (2026-07-14, Rectify: pre_remediation_merge ref_coherence Recovery — PART A #4255, mainline) flipping remediate → release_issue_failure. Deliberate within the pre_remediation_merge ref_coherence bypass orphans audited worktree #4228 effort — the same commit added the rationale note (remediation.yaml:758-764: escalating avoids orphaning the live worktree, since the old remediate route would spawn a fresh cycle atop a feature branch that never received the work) and the unmerged sibling commit ba752303a (same day, branch .../4228, not an ancestor of develop) states the identical rationale in its commit message together with routing-consistency machinery that never shipped. However, the mainline commit's own message describes only ref_coherence recovery; the merge-step arm flips in the same commit stripped a genuine bounded retry (check_merge_fix_loop); the stale :478-481 note was left contradicting the new routing; and 9da15e9b3 walked back only the rebase arm. Net: a reasoned trade-off shipped without its reasoning on mainline, unevenly applied, and never reconciled with the flake case. [SUPPORTED]

Historical Context

• 2026-06-12 (session 4425759f): identical assertion failure (assert result.termination == TerminationReason.COMPLETED got timed_out, then at line 481) as a bystander in an unrelated implementation pipeline's gate (1 failed, 12166 passed, 152 skipped, 7 xfailed in 194.85s). Diagnosed timing_race; handled inside the then-intact fix-loop machinery. [SUPPORTED]
• The area did NOT go untouched afterward (correcting this report's earlier draft): 12 commits since 2026-06-12 touched execution/process/, execution/headless/_headless_result.py, or the test file — including the margin raises 49c3db3ff/8e9c1a037/e90635a50 (this test: timeout 120→300, _phase1_timeout 250→400), shell-capture work 98ef9bdd2, subagent-kill rectify c1e1c4c2d, and a liveness-supervisor add/revert pair f5148ae3a/fa9854f26. None changed the drain-race adjudication semantics; at the failing revision the three process files are byte-identical to current develop. So the June→July remediation was margin-raising only, and the flake recurred above the raised margin. [SUPPORTED]
• Prior fixes in this race family were symptom-layer: 2feb22563 (adjudication semantics — data_confirmed propagation), d15db94ef (symmetric drain window; its message admits being "the root cause of 22 iterative race-variant fixes since 2026-02-19"), 6d58d85c4 (2026-05-30, resume-boundary false-fire — same subsystem, different bug). [SUPPORTED]
• This is a recurring pattern — consider running /rectify for architectural immunity after resolving the immediate issue. Two identical load-induced failures 38 days apart, an intervening margin raise that failed to immunize, a self-documented history of 22 race-variant fixes, and a routing layer that now converts any recurrence into pipeline death.

External Research

No external research was performed. The failure is fully explained by internal evidence (project code, recipes, git history, session logs, and a confirming test run); no third-party library defect is implicated — anyio timeout scopes and pytest-xdist behaved as documented.

Scope Boundary

Investigated: The failing test and its production race path; Part A's full diff and import surface; both gate executions' commands, selections, directories, and timings; the firing step's identity (settled via session-log evidence plus a full YAML flow trace); the remediation recipe's merge routing, its git history on mainline and the abandoned #4228 branch, and the compiled recipe actually present in the pipeline clone (routing identical to develop); session logs (AutoSkillit log tree, Claude project logs, worktree temp artifacts); prior occurrences and fix history since 2026-02; a confirming full-suite re-run in the untouched worktree.

Not yet explored: The precise micro-mechanism of the >300s stall (needs per-test --durations data or an instrumented rerun under synthetic load); whether implementation-family recipes retain fix-loop routing for their merge test gates (the June-12 pipeline suggests they did then); a sweep of other real-subprocess tests sharing this exposure profile; whether fleet-level scheduling should bound concurrent-clone load during test gates.

Recommendations

1. Add a transient-failure arm to pre_remediation_merge (primary, structural). The step already demonstrates the correct pattern for other transient classes: a budgeted check-loop that routes back into the merge (commit_guard_pre_remediation, check_ref_push_loop_pre_remediation) without creating a new worktree — so the documented orphaning rationale does not preclude a bounded test-gate retry arm (e.g., one re-invocation of pre_remediation_merge on test_gate/post_rebase_test_gate failure, escalating to release_issue_failure only when the budget is exhausted or the same test fails twice). For the later merge step, evaluate restoring the pre-52db82771 check_merge_fix_loop routing (as was already done for its rebase arm by 9da15e9b3), verifying that the fix-loop's exhaustion path does not reach a worktree creator — the constraint ba752303a was protecting.
2. Add a semantic rule closing the validation gap. Extend recipe/rules/rules_merge.py so that a MergeFailedStep member of _TEST_STEPS routed directly to a terminal step (tool release_issue or similar) without any bounded-retry arm raises a finding. Today merge-failure-skill-domain-mismatch skips all non-run_skill targets (:417), so this entire class is invisible. Also update or remove the stale note at remediation.yaml:478-481.
3. Make the TIMED_OUT override observable. When execution/process/__init__.py:514-515 discards an adjudicated termination because the outer scope fired, record the discarded adjudication and elapsed phase timings in the result/diagnostics so a flake can be distinguished from a genuine hang post-mortem.
4. Run /rectify on the drain-race timing fragility. Margin-raising (120→300s) has now demonstrably failed once; the chronic pattern indicates the wall-clock coupling itself needs architectural treatment — options to evaluate there include contention isolation for real-subprocess tests, load-aware timeout scaling, or a controlled-clock seam for the race resolver. This investigation deliberately does not pick among them.
5. For the stranded Non-path verdict token unrecoverable; make_plan lacks on_context_limit route #4305 run: nothing invalidates Part A. The intact worktree (impl-4305-20260720-191353, clean, ahead-by-1 with e55a08917) passed the complete unfiltered suite after the failure (31300 passed, temp/test-2026-07-20_215754.txt) — do not delete it; it holds the only copy of Part A. The pipeline is resumable by re-claiming issue Non-path verdict token unrecoverable; make_plan lacks on_context_limit route #4305 (currently labeled bug, recipe:remediation, fail), re-running pre_remediation_merge (expected to pass under normal load), and continuing the remediation cycle for the two open audit findings in .autoskillit/temp/audit-impl/remediation_delivery_bound_starvation_part_a_2026-07-20_205844.md.