Skip to content

ci(tooling): port the second fault-handler belt, calibrate the gate bound (BACKLOG #1304) - #818

Open
wshallwshall wants to merge 1 commit into
mainfrom
claude/builder-1304-tooling-faulthandler-belt
Open

ci(tooling): port the second fault-handler belt, calibrate the gate bound (BACKLOG #1304)#818
wshallwshall wants to merge 1 commit into
mainfrom
claude/builder-1304-tooling-faulthandler-belt

Conversation

@wshallwshall

Copy link
Copy Markdown
Collaborator

BACKLOG #1304 -- the instrumentation limb, not the cause

The cause is untouched. The item's own limit still holds: a 4-vCPU hosted runner is
not measurable from a developer box, so the distribution shape transfers and the
absolute numbers do not. Nothing here theorises about runner contention, xdist
pressure, or pwsh startup.

Four things landed: the answer to the item's one checkable question, the port that
answer implied, the missing calibration on the 60s bound, and tonight's fourth test
name. One thing is deliberately NOT built and is named below. One decision is the
owner's and is a recommendation only.

The tooling tier carried ONE of the two belts, not zero

That is the answer, and the halving is the point -- a bundled "it has no belts"
would have been the exact defect this item spent an amendment on.

Belt Where it comes from Engine step Tooling step (before)
--timeout-method=thread addopts in pyproject.toml, repo-wide live live
PYTHONFAULTHANDLER=1 + -o faulthandler_timeout= per-step env + CLI live absent

The control that makes the zero trustworthy. PYTHONFAULTHANDLER: "1" was on 11
steps in ci.yml before this change and is on 12 after -- so a bare grep of the file
finds it and concludes the tier has it. That is the same instrument error the item records twice ("does this FILE
contain a timeout" against "does this TEST have a bound"). The question here is "does
this STEP carry it", so the answer is read by parsing the YAML and addressing the
step by name. The engine step is the positive control: the same reader returns
present for Tests (pytest) and absent for Harness tests (pytest) in one pass.

What the port actually buys, which is less than the item hoped

I verified it on a deliberately wedged process before shipping it, and the result
contradicted the reason I was porting it for.

Paired local arms, on a test that blocks in subprocess.run with no timeout= of
its own -- the shape 164 of this tier's 317 subprocess calls have, across 57 of
the 138 files in tests/tooling_manifest.txt (AST count at 46ea10a78, against a
control of 153 bounded calls, so a zero was reachable):

+ Timeout + (pytest-timeout) Timeout (0:00:03)! (faulthandler) log lines
Arm A -- config as it was 2 0 75
Arm B -- config as ported 2 1 121

Arm A already names the failure. The thread method fires and dumps the frame down
to _winapi.WaitForSingleObject. Reading the pinned pytest_timeout on disk says
why: timeout_timer dumps from a watchdog THREAD and calls os._exit(1), so it
never needs to interrupt the wedged main thread.

So ci.yml's stated reason for this belt is wrong. It says the belt "fires even
when the thread-timer CANNOT interrupt a main-thread C-level wait", naming
subprocess.wait. Measured false, above. I left the engine comment as it stands and
recorded the correction in the item and in the new comment: the belt is still worth
carrying, only its stated reason is wrong, and rewriting a contended region of
another tier's derivation is not this change's business. A reviewer may reasonably
ask for that one sentence to be fixed too; say so and it is a two-line follow-up.

What it does buy, and the comment says only this: a second watchdog on an
independent mechanism (CPython's dump_traceback_later, not a Python
threading.Timer) writing down a different path -- a dup'd raw stderr fd, not
config.get_terminal_writer(). _pytest/faulthandler.py comments that xdist
monkeypatches sys.stderr with a non-file, and whether the terminal-writer dump
survives a worker's os._exit and reaches the controller log is NOT established here
(no xdist on the measuring box). PYTHONFAULTHANDLER=1 additionally arms the
fatal-signal handler before pytest_configure arms pytest's own and after
pytest_unconfigure disables it, and is inherited by Python children. faulthandler
only dumps; it never kills, so no run's outcome changes.

The 60s bound is calibrated, and calibrating it found a defect

tests/test_worktree_gate.py:36 had no recorded calibration -- the surviving half of
the item's not-measured list, and the half its own correction says still stands.

Worst case 4.6s per call, n=127 real launches across both gate files (p50 2.1s,
p99 4.2s, one sub-50ms sample excluded as a call that raised before launching).
Sequential, on a box already running several peer pytest sessions, so it is a
contended sample -- the useful direction, and still not a 4-vCPU runner.

The defect: at 60 the diagnostic could never fire locally. pytest-timeout arms in
pytest_runtest_protocol, covering setup + call + teardown; this bound starts later,
inside the call. So pytest's window strictly contains it and at equal values pytest
expires first. Measured with a paired control rather than reasoned:

in-test bound pytest bound winner
5s --timeout=5 pytest, 2/2 -- the diagnostic never fired
5s --timeout=30 the in-test bound, 2/2

addopts carries --timeout=60. So the bound was live on CI's tooling leg (which
overrides to 120) and decorative on every local run -- exactly the silent
one-platform failure its 45s sibling's comment was written to prevent.

Moved to 45, a 9.8x margin, clearing both bounds and matching its sibling. This
is the one judgment call in the PR: it changes the signature string from after 60 seconds to after 45 seconds.
Anyone grepping CI history before this merge wants
the old string. The item records that.

Tonight's test names, recorded with the list left open

tests/test_worktree_gate_control_plane.py::test_a_bare_config_read_of_a_d0 and
::test_a_bare_config_read_of_a_d3, workers gw1 and gw0, PR 763 and PR 771 read from
the job log. Same file as one already named in the item, same bound, two different
test functions.

Written in without a fresh total, deliberately. The item's own amendment records
that a counted enumeration nothing re-checks is the SDS-3.6 shape, and it has now
understated twice; a third count would just be the next thing to go stale. The note
says instead that the stable signature is the SCRIPT and the BOUND -- the test
function has changed on every sighting, while worktree_gate.ps1 and
claim-reconcile.ps1 have not.

Deliberately NOT built: --max-worker-restart=0

The engine step's third belt, and on the evidence it is the strongest remaining
candidate -- it is what answers a controller left polling a dead worker until the
30-minute step cap, which is the item's third observed mode.

It is not ported because it is a behaviour change, not instrumentation: a worker
death fails the run instead of being survived. The engine tier justified that on a
33-job sample showing the recovery path never once saved a run. There is no such
sample for this tier, and shipping it without one is the shape of transfer this item
exists to refuse. It needs its own measurement.

One mechanism finding that belongs to it, read from the pinned library rather
than inferred: pytest_timeout.timeout_timer ends in os._exit(1), and under -n a
worker that os._exits closes its execnet channel with no workerfinished, which
the controller reports as a crashed worker. The item's amendment asked whether "a
timeout that takes the worker down with it would present exactly this way". This
establishes that such a path EXISTS. It does not establish that it fired
, and the
amendment's refusal to assume in either direction stands.

Rerun budget -- recommendation only, the decision is the owner's

The item asks for one and calls the status quo an unwritten norm. It is a policy call
about how the queue is run, so nothing here implements it. Recommended shape:

  1. One rerun, then stop. A second consecutive red on the same head is treated as
    real until someone says otherwise. The item's own sample is 4 clean / 3 failed / 1
    clean; a streak of three is already outside what one rerun absorbs.
  2. Record every rerun on the PR, in one line naming the leg and the head SHA. The
    item's sharpest sentence is that rerunning is "manufacturing a green rather than
    earning one", and the cost is not the rerun -- it is that afterwards a manufactured
    green and an earned one are indistinguishable. A line in the PR body is the whole
    remedy and it costs nothing.
  3. Never rerun to clear a required context without reading which job failed.
    Nothing distinguishes this item from a real regression at the moment it fires, and
    the leg is the single largest contributor to a red default branch -- so the reader
    who skips the log is exactly the reader who will discount a real one.

Not recommended: any automated retry. A retry inside the harness is the same act one
level down with the evidence hidden inside a passing test, which is the argument
run_gate's own docstring already makes for not retrying there.

Checks

Ran: ruff check, ruff format --check, mypy messagefoundry (strict, 267 files,
clean), scripts/docs/backlog_status_check.py, scripts/quality/licence_header_check.py,
scripts/quality/control_char_check.py, scripts/quality/workflow_local_action_check.py,
and pytest over test_ci_faulthandler_belts (new), test_tooling_partition,
test_ci_engine_step_excludes_webconsole, test_ci_tooling_gate,
test_backlog_citation_check, test_backlog_status_check,
test_backlog_hygiene_claim_extraction, test_ledger_check -- 146 passed -- plus
test_worktree_gate and test_worktree_gate_control_plane at the new bound.

Mutation-proved the new guard before calling it done: dropping
-o faulthandler_timeout= reds 2 tests, inverting the ordering to 100 reds 1, and
dropping the engine step's PYTHONFAULTHANDLER reds 1. Each reds only its own test.

Skipped, and it needs a hosted leg to read: the full suite. A peer session
measured a local full run reaching four percent in eighty-five minutes on this box.
Also skipped: any -n 4 arm of the timing measurement -- pytest-xdist is not
installed in the venv available to this worktree, which is why the xdist claims above
are marked not-established rather than measured.

Read the repo harness tests legs on this PR specifically. It edits that job's
own step, so this PR is the first place the ported belt runs.

…ound (BACKLOG #1304)

The tooling tier carried one of the engine tier's two hang-diagnostic belts.
PYTHONFAULTHANDLER=1 plus -o faulthandler_timeout= was absent from `Harness tests
(pytest)`. Ported at 150 against that step's own 120, pinned by
tests/test_ci_faulthandler_belts.py. All three mutations verified red first.

Measured, and it corrects ci.yml's stated reason: pytest-timeout's thread method
DOES fire on a wedged subprocess.wait. It dumps from a watchdog thread and calls
os._exit(1), so it never needs to interrupt the main thread. The port is a second
opinion on an independent mechanism, not the thing that names the failure.

GATE_TIMEOUT_S carried no calibration. Worst case 4.6s over n=127 real launches,
and calibrating it found a defect: at 60 against addopts' --timeout=60 the
diagnostic could never fire locally. Moved to 45, a 9.8x margin.
@wshallwshall wshallwshall added the reviewed A reviewer has read this. Removed automatically when new commits arrive. label Sep 3, 2026
@github-actions github-actions Bot added the ci-red A required check went red. Attribute it before retrying. label Sep 4, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

ci-red A required check went red. Attribute it before retrying. reviewed A reviewer has read this. Removed automatically when new commits arrive.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant