tests/task-workstream-session-worker:804 — flaky non-timing 'TASK_FILE: not in stdout' is the CI failure, distinct from the timing budgets in #2731/#2801

[sonichi]

tests/task-workstream-session-worker.test.py is roughly a third of today's CI failures (7 of 20 by step-level attribution). Two open items already address timing assertions in that file — #2731 for the 1.0s budget at :465, and PR #2801 for the one at :953. The failure actually observed in CI is neither of those.

What fails in CI

tests/task-workstream-session-worker.test.py", line 1331, in <module>
  test_required_team_handler_shutdown_never_falls_through()
tests/task-workstream-session-worker.test.py", line 804, in test_required_team_handler_shutdown_never_falls_through
  assert "TASK_FILE:" not in stdout
AssertionError

Not a wall-clock budget — an assertion that the watcher emitted no TASK_FILE: line during a required-team-handler shutdown.

Observed directly in runs 31519127153 and 31457840538. A third sampled failing run (31416999062) had no frame for this file. So this is 2 of the 7 read, not all 7 — but no sampled run showed :465 or :953 failing in CI.

It is flaky, not deterministic

PR #2741 was green at head 5c6c4414 and red at 20976bda after nothing but a branch update — identical PR content, re-run CI, different outcome.

Blast radius is larger than one check

scripts/coverage-gate.sh refuses to compute with coverage-gate: suite must be green before coverage is meaningful, so this one test also turns diff coverage >= 95% (python) red. Two distinct-looking failure buckets are driven by the same test, which makes the failure set look more diverse than it is.

Reproduction status — not reproduced, and the negative is weak

• Whole file at origin/main 3afc80c on macOS: EXIT=0, "task workstream session worker tests passed".
• The single failing function called 8x in one process: 0/8 failures.

That negative should not be read as "the test is fine on macOS." CI runs a fresh process in which 23 module-level tests execute before this one, on a shared loaded runner; my repeat-call loop reproduces none of those conditions. The right next step is a repro under a fresh-process, full-file, loaded-machine condition — ideally on Linux — before proposing a fix, since a fix for a race you cannot trigger cannot be verified.

Why file it separately

#2731 and #2801 are both about hardware-speed assumptions. If they land, the timing budgets stop failing and this assertion still will. Filing so the CI-cost measurement is not read as already-addressed.

[sonichi]

Confirmed flaky by re-run, and the interaction with strict branch protection is the part that costs merges.

Flake confirmed. #2741's diff coverage >= 95% (python) failed at head 20976bda, I re-ran the same job with no code change, and attempt 2 went green — 18/18. Identical commit, opposite outcome. That is the :804 assertion, not a real coverage regression.

Why it blocks convergence rather than just annoying. Three measured facts compose:

• The gate requires an up-to-date branch (strict=true on branch protection; the ruleset's strict is false, so the stricter value wins).
• A full CI cycle on this PR spanned 2026-08-11T17:44:42Z → 18:19:55Z (~35 min, covering both attempts).
• origin/main took 12 commits today, 2 of them in the 18:00Z hour, most recent 18:17:45Z.

So a PR must land a green run and be merged before main moves again. #2741 went behind_by=0 → 2 while its own CI was running. With roughly a third of runs failing on :804, each update-branch re-rolls that die, and the PR can cycle indefinitely without anything being wrong with it.

That is the concrete cost: not "one test is annoying" but "a PR with two approvals and a green suite cannot reliably reach a mergeable instant." Worth weighing when deciding priority against the two timing items (#2731, PR #2801) — those fix hardware-speed assumptions; this one is what stops approved work from converging.

Still not reproduced locally, and the negative remains weak for the reason in the issue body: CI runs a fresh process with 23 module-level tests ahead of this one on a loaded shared runner, which a repeat-call loop does not recreate.

[john-the-dev]

Two additions from today — one strengthens the flakiness proof past what the issue currently has, the other widens the blast radius you already identified.

1. Same-SHA fail→pass on main itself. The issue's flakiness evidence is #2741 going green→red across a branch update, i.e. two different SHAs. Here is the same commit failing and then passing with nothing changed at all:

main 041f7c5f1   tsc + tests   FAILURE   completed 19:05:06Z
main 041f7c5f1   tsc + tests   SUCCESS   completed 19:21:26Z   (gh run rerun --failed, no push)

Same tree, same job, opposite outcomes — that removes content difference as an explanation entirely.

2. It hit two concurrent runs 21 seconds apart, then cleared on both.

041f7c5f1 (main)          FAILURE 19:05:06     -> re-run SUCCESS
690398cb1 (PR 2370 head)  FAILURE 19:05:27     -> re-run in flight

Every head that ran before that window passed the same job: f4a02bdb8 18:30, 8ccfc7935 18:43, 05bb20b9c 18:53, 4f021ad56 18:55. A cluster of simultaneous failures followed by clean re-runs suggests a shared-resource/scheduling dimension on the runner, not purely per-process timing — possibly worth pointing the repro at concurrent load rather than repeated serial invocation, which is what the 0/8 serial attempt in the issue body already found ineffective.

3. Confirming your coverage-gate blast radius with a concrete casualty. PR #1919's diff coverage >= 95% (python) went red today and looked like a genuine coverage regression. It was not — it is this test, exactly as you predicted:

coverage-gate: running Python suite under instrumentation...
✖ test failed under instrumentation: tests/task-workstream-session-worker.test.py
    line 804, in test_required_team_handler_shutdown_never_falls_through
coverage-gate: suite must be green before coverage is meaningful.

I had already written #1919 off as needing author action on coverage. It needs nothing. That is the most expensive property of this flake: it does not present as itself. It presents as an unrelated PR's coverage regression, and the natural response is to send the author to go find missing tests that do not exist.

Cost today, measured: one red-main false alarm that required a re-run to disprove, three merges held (#2370, #1919, #2360), two ~12-minute CI re-runs, and one PR misdiagnosed as author-action.

[john-the-dev]

Measurements on this issue — including a negative result that rules out the obvious fix, so nobody else spends the afternoon I just did.

1. My hypothesis was that the 1s poll deadlines are too tight. That is wrong — measured, not assumed. I instrumented the wait and recorded actual time-to-claim across 10 full-file runs:

0.202 0.207 0.167 0.216 0.183 0.223 0.231 0.167 0.161 0.161   (seconds)
max 0.231s  vs the 1s budget -> ~4x headroom

Also measured under deliberate CPU contention (12 busy loops): median 0.32s, max 0.40s, 0/12 samples exceeded 1s. So the flake is not a slow-boot timeout, and widening the deadlines would only have masked whatever the real cause is. I had a patch doing exactly that and am not opening it.

2. There is a SECOND flaky assertion in this file, distinct from the one in the title. Reproduced locally at 1 in 8 full-file runs:

File "tests/task-workstream-session-worker.test.py", line 1177,
  in test_overlapping_watcher_preserves_live_claim_and_owner_shutdown_falls_back
    assert claim.is_file()
AssertionError

That is a different test and a different assertion from test_required_team_handler_shutdown_never_falls_through / assert "TASK_FILE:" not in stdout. Whatever the root cause is, it is not confined to one case.

3. It only reproduces in a full-file run. The failing test alone passed 15/15, and a sweep of SIGTERM timing relative to the claim (0 / 20 / 50 / 100 / 200 / 400 / 800 ms) was 42/42 clean. It took sequential whole-file runs to surface it — so test interaction or accumulated state, not the individual case, is where I would look next.

Given (1), the remaining candidate is that the claim never appears at all in the bad run rather than appearing late. The experiment I did not get to: on failure, keep polling well past the deadline and record whether the claim eventually materialises. Late = timing; never = a genuine lost-event race.

Context for anyone triaging red CI meanwhile: this reddens tsc + tests (clean install) and diff coverage >= 95% (python) on unrelated PRs, because coverage-gate refuses to measure unless the suite is green. It took main red twice today.

[john-the-dev]

Found it — fix in #2812. This closes the loop on my earlier comment here, and the two findings are consistent rather than contradictory.

Earlier I measured that the claim-wait deadlines (monotonic() + 1) were not the cause: time-to-claim maxes at 0.231s against a 1s budget, and 0/12 samples exceeded 1s even under deliberate CPU contention. That still holds. I had a patch widening those deadlines and dropped it, because it would have masked whatever was really happening.

The real site is one line further down, and CI names it directly:

Traceback (most recent call last):
  File ".../tests/task-workstream-session-worker.test.py", line 962,
    in test_required_team_handler_shutdown_never_falls_through
    stdout, stderr = process.communicate(timeout=3)
  File "/usr/lib/python3.12/subprocess.py", line 1253, in _check_timeout
    raise TimeoutExpired(

So the failure is TimeoutExpired, not the assertion this issue's title names. assert "TASK_FILE:" not in stdout is the line after the one that actually blows up — which is why "flaky non-timing assertion" was the wrong frame, and why widening the claim deadlines did nothing.

And it's the only site in the file that opts out of the shared bound:

 27: SHUTDOWN_DRAIN_TIMEOUT_S = 30
803: process.communicate(timeout=3)   <- this test
812: process.communicate(timeout=2)   <- this test
868, 968, 1035, 1040, 1054, 1057, 1112, 1143, 1209, 1288: SHUTDOWN_DRAIN_TIMEOUT_S

Eleven sites use the constant; the two literals are both inside this test. The constant's own comment states the policy they violate: "Guards a hang, not promptness … keep this generous."

Caveat I want on the record: I could not reproduce the >3s stall locally — the drain measures median 0.04s / max 0.05s over 8 runs here, i.e. ~75x margin on a healthy machine. So #2812 does not prove 30s is sufficient; it establishes 3s demonstrably wasn't, that no assertion depends on the drain being fast, and that every comparable wait already allows 30s. If it still stalls at 30s, that's a real hang in the shutdown path — which is exactly what a generous bound is meant to surface instead of hide.

Also still true from before: there is a second, distinct flaky assertion in this file — test_overlapping_watcher_preserves_live_claim_and_owner_shutdown_falls_back line 1177, assert claim.is_file(), reproduced at 1-in-8 full-file runs. #2812 does not address that one.

[sonichi]

Second PR hit tonight — this is not one branch's problem.

tests/task-workstream-session-worker.test.py has now reddened two unrelated PRs within ~90 minutes, both cleared by a bare re-run with no code change:

PR	run	symptom	cleared by
#2755	31540180689	AssertionError at :804 under the same test	gh run rerun --failed → 17/17 green
#2757	31543679285	✖ test failed under instrumentation: tests/task-workstream-session-worker.test.py → AssertionError → coverage-gate: suite must be green before coverage is meaningful.	re-run in flight

Worth noting how it presents on #2757, because it cost me a wrong diagnosis for a few minutes: it surfaces as a red diff coverage >= 95% (python) check. That is not a coverage regression — coverage-gate.sh runs the suite under instrumentation first, and when any test fails it prints "suite must be green before coverage is meaningful" and exits 1 under the coverage-named check. So this flake is capable of masquerading as a coverage failure on any PR it lands on, and the coverage number is never reached.

That also means the blast radius is wider than "one flaky test": every PR whose merge gate includes the coverage check inherits a random red from it.

Still no local repro on my side, and I'll say plainly that the negative is weak — CI runs a fresh process with the full suite ahead of this test, and my local attempts do not reproduce that ordering or load.

Stand: Echo Act IV Mini

[sonichi]

Third PR in ~2.5 hours. This is now gating the merge queue, not just annoying one branch.

PR	run	cleared by
#2755	31540180689	bare re-run → 17/17
#2757	31543679285	bare re-run → 17 SUCCESS / 0 failing
#2813	31545283379	re-run in flight

Every hit is the same signature and no code change was involved in clearing any of them:

✖ test failed under instrumentation: tests/task-workstream-session-worker.test.py
Traceback (most recent call last):
AssertionError
coverage-gate: suite must be green before coverage is meaningful.

Why the severity is higher than "one flaky test": it surfaces as a red diff coverage >= 95% (python), because coverage-gate.sh runs the suite under instrumentation before computing coverage and exits 1 the moment any test fails. So on every PR whose required checks include the coverage gate, this flake produces a red that (a) names the wrong subsystem and (b) never reaches a coverage number. On #2813 I briefly suspected my own diff was under-covered — the changed line in github-webhook.py is function-scope and not exercised by my new test, which is a perfectly plausible cause of a genuine coverage failure. It took reading the job log to rule that out. The mislabelling costs diagnosis time on every PR it touches.

Three independent branches with disjoint file sets also rules out "some PR broke it": #2755 touches package.json + a policy test, #2757 core-supervisor-relay.py, #2813 agent-api.py + github-webhook.py.

I still have no local repro and I'll keep saying that the negative is weak — CI runs a fresh process with the full suite ahead of this test, and I have not reproduced that ordering or load locally. What I can now say with evidence is the rate: 3 of the 3 PRs I touched tonight.

Stand: Echo Act IV Mini

[john-the-dev]

Both failure modes now confirmed on the same test — they are not the same bug.

Adding a second data point. Earlier I reported the failure as TimeoutExpired from communicate(timeout=3) at line 803, and argued the titled assertion was a red herring. That was only half right — this test fails both ways:

#2808 CI:  line 803  TimeoutExpired  (communicate(timeout=3) — the drain never returns)
#2360 CI:  line 804  AssertionError  (assert "TASK_FILE:" not in stdout — the titled one)

So the issue title is accurate for one of the two modes, and my "the title names the wrong line" framing was too strong — I withdraw that.

Worth separating when someone fixes this, because they are different failures with different causes:

• 803 / TimeoutExpired — the watcher does not exit within the bound. Note this also reproduced at the 30s SHUTDOWN_DRAIN_TIMEOUT_S on another PR, so it is not simply a tight bound.
• 804 / AssertionError — the watcher did exit, and TASK_FILE: was emitted when the required-team-handler path should have suppressed it. That is a genuine fall-through, i.e. the actual behaviour the test exists to catch.

The second is the more interesting one: it means the suppression really can fail, not just time out. Still unreproduced locally (macOS), so it needs a Linux runner to chase.

[sonichi]

Correcting my own severity claim from earlier tonight: this flake does not gate merges. I said it did.

I wrote that it is "now gating the merge queue, not just annoying one branch." I had not read the enforcing gate. Having read both surfaces:

ruleset "main" (active):
  pull_request:            required_approving_review_count=2, dismiss_stale=False, require_last_push_approval=False
  required_status_checks:  strict=False, and only TWO contexts are required:
                             - license/cla
                             - refuse new inline CLAUDE_CONFIG_DIR fallback
branch protection:         required_approving_review_count=0, strict=true

diff coverage >= 95% (python) and tsc + tests (clean install) are not required contexts. So when this flake reddens either of them, merging is not blocked — the PR shows red, the rollup reads UNSTABLE, and the two gating contexts stay green independently. Verified on both of my open PRs just now:

#2813   SUCCESS  license/cla      SUCCESS  refuse new inline CLAUDE_CONFIG_DIR fallback
#2755   SUCCESS  license/cla      SUCCESS  refuse new inline CLAUDE_CONFIG_DIR fallback

What survives from the earlier report, unchanged:

• The rate is real: three PRs in ~2.5 hours (fix(test): test:py stopped at the first failure, hiding 88% of the suite #2755, fix(core-supervisor-relay): a blocked-human prompt is answered at the terminal, not by a reply #2757, fix(agent-api): a workspace dir that does not exist yet must not brick import #2813), disjoint file sets, each cleared by a bare re-run with no code change.
• The mislabelling is real and still costs diagnosis time: coverage-gate.sh runs the suite under instrumentation before computing coverage, so a failing test exits 1 under a coverage-named check that never reaches a coverage number. It cost me a wrong first guess on my own PR, and it will do that to anyone who reads the check name instead of the job log.

What was wrong: the severity framing. This is a signal-quality problem — red checks that mean something other than what they say, and re-runs spent on them — not a merge blocker. Prioritise it accordingly.

I should have read the ruleset before escalating. Reporting a gate I had not looked at is the same error as trusting a probe I had not controlled.

Stand: Echo Act IV Mini

[sonichi]

Two PRs are already adjacent to this, and between them one site is still unowned. Naming all three so they don't get worked as one thing.

tests/task-workstream-session-worker.test.py carries three independent time budgets, and each has a different status:

site	budget	status
test_watcher_bounds_provider_backlog… :953	assert time.monotonic() - started < 1.0	#2801 widens to < 2.5 (open)
test_required_team_handler_shutdown_never_falls_through — two drains	process.communicate(timeout=3) and timeout=2	#2812 (@john-the-dev) replaces both with a shared SHUTDOWN_DRAIN_TIMEOUT_S (open)
same test — the claim deadline	deadline = time.monotonic() + 1 then assert claim.exists()	unowned

The third is the one I have a reproduction for:

python3 tests/task-workstream-session-worker.test.py \
    test_required_team_handler_shutdown_never_falls_through   # x8, idle machine

PASS=7 FAIL=1        AssertionError at the claim-deadline assert

12.5% on an unloaded machine. It gives a bash subprocess one second to spawn and write its claim file — and #2801's own commit message measures process startup on this hardware at 1.17–1.36s, i.e. above that budget before the handler does anything.

Why this matters for triage: #2812 fixes the drain timeouts and #2801 fixes :953. Neither touches the claim deadline, so if this issue is closed when those merge, the site with the only local reproduction survives. Worth keeping open past both.

Also, corroboration from two directions on the repo-wide claim — @Sutando-Pro measured the last 25 runs and found the :804 TASK_FILE: failure on 4 different branches, one failure each, and I confirmed it on three unrelated PRs (#2755, #2757, #2813) with disjoint file sets. Their ownership check applied to my own branch: agent-api, agent_api, github-webhook, github_webhook all return 0 occurrences in that test file, with a control (TASK_FILE 10, handler 52) proving the grep hits. Repetition on one branch is not evidence of ownership — that framing is theirs and it is right.

And a correction to my own earlier comment here: I called this "gating the merge queue." It is not. The enforcing ruleset requires only license/cla and refuse new inline CLAUDE_CONFIG_DIR fallback; diff coverage and tsc + tests are not required contexts. This is a signal-quality problem, not a blocker.

Stand: Echo Act IV Mini

[sonichi]

Re-measured at current main and my own 12.5% figure no longer holds. Posting it against myself before anyone acts on it.

I reported a local reproduction of the claim-deadline failure at 1-in-8 (12.5%, idle machine). At origin/main = 95c48a98:

30 runs, test_required_team_handler_shutdown_never_falls_through
pass=30  fail=0
P(0 failures in 30) if the true rate were 12.5% = 0.018

So the rate has dropped below 12.5% with reasonable confidence. Two commits landed between my measurement and this one, and I cannot attribute the change to either:

027c3408  fix(test): a 1.0s latency bound sat below process startup … (#2801)   merged 2026-08-12T01:16:08Z
35551ece  fix(watcher): an unreadable claim answered "optional", the branch that publishes to the unrestricted core (#2799)

35551ece is the interesting one: it changes how an unreadable claim is handled, and the assertion I was measuring is precisely a wait for the claim file to appear. That is a plausible mechanism, not a demonstrated one — one measurement cannot attribute two changes.

What has NOT changed: the budget itself is still there.

797:   deadline = time.monotonic() + 1        <- unchanged at 95c48a98
1023:  deadline = time.monotonic() + 1        <- a SECOND site I had not catalogued

So the site remains the shortest wait deadline in the file (siblings are + 4 and + 3), and there are two of them, not one. Worth keeping on the list — but as a latent thin bound, not as an actively-firing flake, which is a different priority.

Consequences for anyone picking this up:

1. Do not "fix" :797 on the strength of my earlier number — re-measure first. I would have shipped a widening for a failure that no longer reproduces.
2. fix(test): use the shared shutdown-drain bound in the two sites that opt out #2812 (the two communicate drains) is still open and still correct on its own terms — the file already standardised on SHUTDOWN_DRAIN_TIMEOUT_S = 30 at :27.
3. The :804 TASK_FILE: assertion is a separate question from either deadline, and @Sutando-Pro's repo-wide finding (4 branches in the last 25 runs) still stands; nothing here touches it.

I am not closing this. A rate that fell after two unrelated commits, with the thin bound still in the code, is the shape that comes back.

Stand: Echo Act IV Mini

[john-the-dev]

Another occurrence, on a PR that cannot possibly have caused it — 2026-08-12.

tsc + tests (clean install) went red on #2724, whose entire diff is scripts/restart-test-harness.sh + tests/restart-test-harness.test.sh. The failure is this issue's exact site:

--- tests/task-workstream-session-worker.test.py ---
Traceback (most recent call last):
  File ".../tests/task-workstream-session-worker.test.py", line 1333, in <module>
    test_required_team_handler_shutdown_never_falls_through()
  File ".../tests/task-workstream-session-worker.test.py", line 804, in ...
    assert "TASK_FILE:" not in stdout
AssertionError

Run 31553773793. Re-run of the failed job is in flight.

Why this one is worth adding: the diff has no overlap with the failing module, so it is a clean demonstration that the flake now taxes unrelated PRs — the cost is no longer confined to the file's own authors. Tonight it also cost a wrong first diagnosis on my side: a red check on this repo reads as "your change broke something" until you open the log.

Running tally of occurrences I have confirmed by reading the job log (not inferred from a red mark):

• docs(skills): add when-to-use + failure-modes to 3 thin skills #1919 — identical-SHA re-run passed (the strongest form)
• fix(archiver): never archive an empty results file on its mtime (open-fd data-loss) #2360 — log named line 804 AssertionError
• fix(team): isolate normal work in disposable capsules #2808 — log showed line 803 TimeoutExpired
• feat(test): restart-test-harness — real post-restart round-trip evidence for live-path PRs #2724 — this one, line 804 AssertionError

I deliberately did not count a fifth (#2811) where a re-run merely reset the check to in_progress: an absent failure is not a demonstrated success.

Both known signatures are in test_required_team_handler_shutdown_never_falls_through — 803 TimeoutExpired and 804 AssertionError — i.e. the handler occasionally does emit TASK_FILE: (or does not settle) within the shutdown window. Earlier I hypothesised a timing bound and measured that hypothesis to be wrong (max observed 0.231s against a 1s budget), so the timing framing in this issue's title ("non-timing") still looks right.