Bound the suite so a wedged run fails instead of vanishing - #30
Conversation
The test job has stopped mid-suite nine times in five days, holding the runner for GitHub's 360-minute default. Seven were pushes to main, and a job-cap kill concludes cancelled rather than failure, so tend-ci-fix skipped every one -- leaving seven commits on main with no verdict and nothing to say so. timeout on the command rather than timeout-minutes on the job: the job cap reports the same cancelled and would leave the safety net just as blind, while a timed-out command exits 124 and reads as an ordinary red suite. 30 minutes is 2.6x the worst of the last 40 healthy runs.
leaf-agent
left a comment
There was a problem hiding this comment.
The bound itself checks out, and the evidence behind it does: I confirmed the wedge shape independently — every cancelled run of ci.yaml at or past the 360-minute cap, tend-ci-fix.yaml's conclusion == 'failure' gate skipping each one, and the sizing (across the last 60 successful runs the Test suite step peaks at 11.1 min, median 10.4; across the last 30 failing runs, 11.2 min — so 30 minutes is ~2.7× the worst either way). Wrapping the command rather than capping the job is the right call for exactly the reason given.
One correction to the comment, and one gap in what the 124 will hand tend-ci-fix.
--kill-after doesn't reach the workers or the browser. The comment says it's there "because the TERM has to reach eight xdist workers and a headless shell," and the PR body says without it "a child that ignores TERM puts the job back on the 360-minute cap." That holds for uv — the direct child — but not for its descendants, because timeout returns the moment the monitored child is reaped and never gets to the escalation:
Reproduction, coreutils 9.4 (same version as ubuntu-24.04)
== A: direct child ignores TERM ==
$ timeout --kill-after=3s 1s ./child_ignores.sh
exit=137 elapsed=4s # escalation fired
== B: direct child dies on TERM, grandchild ignores it ==
$ timeout --kill-after=3s 1s ./child_dies.sh
exit=124 elapsed=1s # returned at the TERM, never waited out kill-after
grandchild alive 5s after timeout returned
The group send does work — a grandchild that doesn't trap TERM dies with the group. It's the escalation specifically that never happens once uv is gone.
This doesn't weaken the change: 124 fails the step either way, the run concludes failure, and a surviving browser falls to the runner's orphan cleanup — the same Terminate orphan process lines the PR body quotes. --kill-after is still worth keeping for the uv case. Only the stated reason is wrong, and in a comment this load-bearing a later session will read it as a guarantee it isn't. Suggestion inline.
The 124 won't name the wedged test. The PR's payoff is that tend-ci-fix finally gets a run to diagnose, but with -n 8 the log ends at a bare [ 93%] and the timeout adds no test name — so the diagnosing session starts from the same place today's post-mortems do. Worth knowing before the first one fires; a per-test bound would name it, but that's a new dependency and a different PR, so I'd leave this PR as the bound it says it is.
|
Today's sweep re-measured this and the rate has gone up sharply: seven wedges in the last 24 hours, against the nine in five days the description tabulates. Five were pushes to The signature has also tightened, and it is now sharp enough to be worth writing down: all four wedges with retrievable logs stall at exactly The seven, and where each stopped
A live job's log blob isn't served, so the three in flight are counted by duration alone — each is already past 2h on the The orphan set at kill is Five commits on Not proposing a change to the diff — the bound and its sizing still look right, and 30 minutes is still 2.6× the worst healthy |
|
Follow-up with something this thread has not had in five days of recording the wedge: what is running at I ran the full suite on a CI-equivalent box (4 cores, same
— i.e. blocked inside a single That makes it the natural suspect rather than a proven cause. It is the only thing running in the window where every wedged log goes silent; it is already a multi-minute single browser round trip, so one lost response inside it produces exactly the observed shape — a job that prints nothing more and dies at the cap with all eight workers and a One sizing note for this PR, not an objection to it: the 30-minute bound was sized against the 11.6-minute worst whole job, and this single test accounts for 7+ minutes of that on a 4-core runner. The headroom is real but thinner than the whole-job number suggests, so if the bound ever starts firing on healthy runs this is the test to look at first. Also confirmed in the same run: `main` is red at `2bdb38c`
|
leaf-agent
left a comment
There was a problem hiding this comment.
The native step timeout is a better shape than the wrapper it replaces, and it retires the prior thread rather than patching it — no --kill-after semantics to describe, no process-tree reasoning in a comment, and the escalation gap that thread was about stops existing.
I re-checked the one claim the whole change rests on. tend-ci-fix.yaml's gate is github.event.workflow_run.conclusion == 'failure', and this repo's own wedges are the proof that a job-level bound doesn't reach it: the 360-minute cap is the default jobs.<id>.timeout-minutes, and every run it killed concluded cancelled and was skipped. A step timeout fails the step, which fails the job. So the placement on the step rather than the job is what makes this work — one indentation level apart from the bug it fixes, with nothing in CI that would catch the swap.
That reason lives in the PR body and not in the file. Suggestion inline to move it there.
Sizing looks right: 45 against the 16:48 slower run is ~2.7×, and since the linked figures are whole-run durations while the bound is on the step alone, the real headroom is a little wider than that.
## Problem [Run 32954830645](https://github.com/max-sixty/leaf/actions/runs/32954830645) reached 99% of the suite, tripped the 180s faulthandler guard, killed `gw1`, and then sat silent for twenty-five minutes until the step's 45-minute bound ended the job. The guard bought a stack dump that named no test, and gave the rest of the budget back. It cannot name one. Under the sync Playwright API a test blocked on the browser has its own frames in a suspended greenlet, and faulthandler dumps OS threads — so the trip printed the page server's thread, execnet's reader, and Playwright's event loop, and nothing else. Exiting the worker is then worse than doing nothing: xdist clones a replacement, and under `--dist loadgroup` the clone never picks the run back up. What it fired on was probably not a hang. The suite's slowest browser sweeps run 60–105s on four cores at `-n 2` — the shape of machine CI runs on, at the same wall time — so a three-minute clock sits 1.7× above work every run does, and one noisy runner spends that margin. ## Solution Remove `faulthandler_timeout` and `faulthandler_exit_on_timeout`. Both things the guard was meant to buy are already held elsewhere, by machinery that was not added for it: - **Naming a stalled browser wait.** Playwright's own 30-second timeouts fail it with the test's nodeid. That is the shape of the three other recent `ci` failures on main — each one `FAILED tests/test_render_projection.py::test_a_message_reference_travels_or_says_it_cant - TimeoutError`, named, at ordinary cost. - **Making a true wedge visible.** The workflow's 45-minute step bound from #30 is what turns it into the `failure` `tend-ci-fix` answers, and that is the fault #30 was actually about. Net two lines fewer than main, and nothing added. <details><summary>What the dump actually printed</summary> ``` Timeout (0:03:00)! Thread 0x00007f9be7fff6c0 (most recent call first): File "/usr/lib/python3.12/socketserver.py", line 235 in serve_forever ... Thread 0x00007f9c057ff6c0 (most recent call first): File ".../execnet/gateway_base.py", line 1160 in _thread_receiver ... Thread 0x00007f9c0694f080 (most recent call first): File ".../playwright/sync_api/_context_manager.py", line 56 in greenlet_main ....[gw1] node down: Not properly terminated ##[error]The action '🧪 Test suite' has timed out after 45 minutes. ``` Three threads, no test frame among them: the page's dev server, execnet's reader, and the driver greenlet the main thread was sitting in. </details> ## What this gives up One class the guard could have named, had it ever fired there: a wait with no timeout of its own outside the browser. The cold-cache launcher runs in [`test_interact_layer.py`](https://github.com/max-sixty/leaf/blob/333704122e81cadc15d6de357e0df2ac61cc5106/tests/test_interact_layer.py#L389) shell out to `bin/leaf` and let `uv` resolve through the network with no `timeout=`. Those have never hung, and the direct fix if they ever do is a `timeout=` on the call — which names the test and raises in place, rather than exiting a worker the run cannot continue without. Not doing that here; no evidence asks for it yet. The `pytest>=9.1` floor was raised in aef67af solely for `faulthandler_exit_on_timeout` support. Left alone — `uv.lock` pins 9.x either way, and lowering it would be a guess at a version the suite has not been run on. ## Testing `uv run pytest tests` — `574 passed, 6 skipped in 141.73s`. `pre-commit` passes on the changed file. This PR's own `ci` run exercises the config over the full `--run-nightly` suite. Co-authored-by: leaf-agent <318509791+leaf-agent@users.noreply.github.com>
Problem
The
testjob wedged mid-suite nine times in five days. GitHub's six-hour job cap reported those runs ascancelled, sotend-ci-fix—which responds tofailure—ignored them. Seven affected pushes were onmain.Solution
Set a 45-minute timeout on the test step. GitHub Actions marks a step timeout as failed and propagates that result to the job, giving
tend-ci-fixthe signal it needs without GNUtimeoutor manual process-tree handling.The suite now runs with two workers; two recent complete runs took 13:47 and 16:48. Forty-five minutes leaves about 2.7× headroom over the slower run.
Testing
pre-commitpasses on the workflow, including YAML and Actions validation. This PR'scirun exercises the setting on the current workflow.