From 9c183e826dd54a7660b9615d6fda7b49767efbb6 Mon Sep 17 00:00:00 2001 From: wshallwshall Date: Wed, 16 Sep 2026 12:51:52 -0500 Subject: [PATCH 1/4] fix(test): stop the spawn-heavy tooling files contending for one runner's vCPUs (BACKLOG #1304) BACKLOG #1304 is the sole cause of main going red across the seven post-1174 reds: six of seven failed `PWSH LAUNCH TIMED OUT after 45s`, seven of seven on `subprocess.TimeoutExpired`, none on real harness breakage. The `repo harness tests (windows-2025)` leg is not itself a required context, but `CI gate` aggregates it, so the flake reds main and keeps PRs out of the queue. THE CAUSE WAS ALREADY EVIDENCED BY 5e5a8a5ab AND IS NOT RE-DERIVED HERE. tests/test_session_mail.py::_race starts RACERS=16 concurrent pwsh, three times per job, on a 4-vCPU runner; every test over 20 seconds in five windows-2025 jobs completes inside the window where the spawn-heavy files overlap. This commit is the remedy only. THE REMEDY: A BURST LOCK, NOT A HIGHER CEILING AND NOT A SMALLER STORM. A bulk spawner takes tests/_spawn_lock.py EXCLUSIVELY for the length of its burst; every single launch takes it SHARED. The storm still gets all 16 of its concurrent processes, so the property _race asserts is untouched, and no single launch is in flight beside it. WHY NOT THE OTHER TWO CANDIDATES. Raising GATE_TIMEOUT_S is refused by the row's own text: the failure is a launch that never returns, so a higher bound only makes the next occurrence take longer to fail. Cutting RACERS is the always-pass failure tests/_dead_pid.py records for a sibling flake. _race exists to prove exactly one of N concurrent claimers wins, and _require_real_contention SKIPS when the host cannot produce contention at that N -- so a lower N turns a race test into a sequential one that still reports green. tests/test_spawn_lock.py pins RACERS=16 and DRAINS=8 so a later pass cannot take that shortcut quietly. An xdist group (`--dist loadgroup`) was the closest alternative and lost on two counts. It lives in ci.yml's pytest invocation, which PR 1196 is rewriting +97/-7 for the unlanded -n 3 experiment, so it would collide head-on. And it separates the files that are spawn-heavy TODAY; a new bulk spawner rejoins the storm silently. The lock binds the constraint to the call site instead, so a new spawner opts in by wrapping itself. PRICED AGAINST RUNNER SLOTS, NOT BILLED MINUTES (Lander reading, BACKLOG #1788: compute on a queue entry never exceeds 11.7 minutes while wall clock reaches 62, the variance entirely queueing at ~80 jobs against 20 slots). This adds no job, no matrix leg and no workflow change -- it spends wall clock inside a slot the tooling job already holds, which is the cheap direction under that measurement. No merge_group arm is added to tooling; that stays sequenced behind this fix. EVERY FAILURE MODE DEGRADES TO TODAY'S BEHAVIOUR, which is what makes it safe to land. No lock root, a saturated wait, a stale entry reaped while its owner is alive, an OSError on any filesystem call -- each proceeds WITHOUT the lock. There is no path that blocks a test forever or fails one. That is tests/conftest.py's rule for its per-process slot: "It never fails a run." Scoped to one pytest run, not to the machine: xdist exports one per-run testrunuid into every worker as PYTEST_XDIST_TESTRUNUID, so four workers of one job share a lock while two unrelated local runs do not serialise. On a CI runner there is exactly one run, so run-scoped and machine-scoped coincide precisely where the fix has to work. Staleness is by timestamp rather than by probing the owner pid, because conftest's tasklist probe would start a process inside a remedy for too many processes. THE DIAGNOSTIC IT PROTECTS IS PINNED, because this change could have disarmed it silently. run_gate now calls run_single, which looks subprocess.run up on the MODULE at call time, so test_worktree_gate_control_plane.py's monkeypatch.setattr(harness.subprocess, "run", ...) still intercepts it. A `from subprocess import run` would have bypassed that patch and left the #1304 launch-timeout test green against a diagnostic that no longer fires. There is a named negative control for exactly that. The mutual-exclusion test carries a positive control: the same probe with the lock disabled must actually overlap, or the assertion proves nothing. WHAT THIS DOES NOT COVER. scripts/coord/overlap.ps1 defaults ParallelLimit=16 and eight manifest files invoke it, each able to hold 16 runspaces spawning git concurrently. That is plausibly a larger uncounted concurrency source than _race, it was found by sweeping the tier rather than by CI evidence, and it is untouched here. tests/test_worktree_gate.py's _pwsh_identity also starts another pwsh while building the timeout message -- an extra spawn on the hot failure path, bounded at 15s and swallowed, likewise untouched. test_coord_lock.py's eight-way burst IS wrapped, on sweep evidence rather than CI evidence: eight concurrent pwsh with the winner holding 8 s is the same shape. Checks, all foreground in the worktree venv: ruff check and ruff format clean on all five touched files; mypy strict clean on messagefoundry (258 files) and on both new modules. Tests, with the process count beside every timing because this box carries concurrent sessions -- 211 passed in 180.49s over test_session_mail, test_worktree_gate, test_spawn_lock and test_coord_lock at `-n 4 --dist loadfile`, CI's own shape, at 4 python and 29 pwsh resident; 227 passed in 398.45s over test_worktree_gate_control_plane and test_worktree_gate_escaped_quote; 23 passed over test_spawn_lock and test_tooling_partition. Local runs report INCOMPLETE RUN without the vault extra, as expected here. This box has 20 cores and CANNOT reproduce a 4-vCPU failure, so no local timing is offered as evidence that the fix works -- only as sizing for the wait bounds. --- tests/_spawn_lock.py | 280 ++++++++++++++++++++++++++++++++++++ tests/test_coord_lock.py | 10 +- tests/test_session_mail.py | 14 +- tests/test_spawn_lock.py | 244 +++++++++++++++++++++++++++++++ tests/test_worktree_gate.py | 6 +- tests/tooling_manifest.txt | 1 + 6 files changed, 551 insertions(+), 4 deletions(-) create mode 100644 tests/_spawn_lock.py create mode 100644 tests/test_spawn_lock.py diff --git a/tests/_spawn_lock.py b/tests/_spawn_lock.py new file mode 100644 index 000000000..7acb58cda --- /dev/null +++ b/tests/_spawn_lock.py @@ -0,0 +1,280 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Foundation, LLC and contributors +"""Keep a pwsh STORM and a single pwsh LAUNCH off the same vCPUs -- BACKLOG #1304. + +THE FAILURE THIS EXISTS TO REMOVE. ``tests/test_worktree_gate.py`` raises ``PWSH LAUNCH TIMED OUT +after 45s`` on the ``windows-2025`` harness leg. That leg is not itself a required context, but +``CI gate`` aggregates it, so the flake reds ``main`` and keeps PRs out of the merge queue. + +THE CAUSE IS MEASURED, NOT GUESSED, and it is recorded in full in commit ``5e5a8a5ab`` and in the +``raise`` this module protects. In short: ``tests/test_session_mail.py::_race`` starts 16 concurrent +``pwsh`` processes, three times per job, on a 4-vCPU runner. Across five windows-2025 harness jobs +EVERY test over 20 seconds completes inside the window where the spawn-heavy files overlap -- a +window that is 2.4 to 3.1 percent of the run. Held within ONE file, so worker, fixtures and code are +constant and only the clock moves:: + + test_worktree_gate_control_plane inside n=20 p50 4.39s max 67.94s + outside n=151 p50 1.98s max 5.20s + +A ``pwsh`` startup regression is REFUTED there. Raising the ceiling is NOT the fix: the failure is a +launch that never returns, so a higher bound only makes the next occurrence take longer to fail. + +WHAT THIS DOES. A bulk spawner takes the lock EXCLUSIVELY for the length of its storm; every single +launch takes it SHARED. So the storm still gets all 16 of its concurrent processes -- the property +its test actually asserts is untouched -- and no single launch is in flight beside it. + +WHY NOT SIMPLY CUT THE RACER COUNT. ``_race`` exists to prove that exactly one of N concurrent +claimers wins, and ``_require_real_contention`` SKIPS the test when the host cannot produce real +contention at that N. Lowering N to fit a small runner turns a race test into a sequential one that +still reports green. ``tests/_dead_pid.py`` records the same lesson for a sibling flake: converting a +loud false-failure into a quiet always-pass is worse than the flake it replaces. + +WHY NOT AN XDIST GROUP. ``--dist loadgroup`` would separate the files that are spawn-heavy TODAY, and +it lives in the pytest invocation in ``.github/workflows/ci.yml`` rather than beside the code it +governs. This module binds the constraint to the call site, so a new bulk spawner opts in by wrapping +itself rather than by someone remembering to edit a workflow. + +EVERY FAILURE MODE HERE DEGRADES TO TODAY'S BEHAVIOUR, WHICH IS THE PROPERTY THAT MAKES IT SAFE TO +LAND. No lock directory, a saturated wait, a stale entry reaped while its owner is in fact alive, an +``OSError`` on any filesystem call -- each one proceeds WITHOUT the lock. The worst case is the +unsynchronised run we have now; there is no path here that blocks a test forever or fails one. That +mirrors ``tests/conftest.py``'s per-process slot, which states the same rule: "It never fails a run." + +THE LOCK IS SCOPED TO ONE PYTEST RUN, NOT TO THE MACHINE, and the difference only matters off CI. +``xdist`` generates one ``testrunuid`` per run (``workermanage.py``) and exports it into every worker +as ``PYTEST_XDIST_TESTRUNUID`` (``remote.py``), so all four workers of one job agree on the key while +two unrelated local runs do not serialise against each other. On a CI runner there is exactly one run, +so run-scoped and machine-scoped are the same thing precisely where the fix has to work. + +STALENESS IS BY TIMESTAMP, NOT BY PROBING THE OWNER PID. ``tests/conftest.py`` reaps its slots by +shelling out to ``tasklist``; doing that here would start a process inside the remedy for too many +processes. Every hold in this module is bounded by its own caller's timeout, so age alone is +sufficient -- and reaping a live holder only drops us back to the unsynchronised behaviour above. +""" + +from __future__ import annotations + +import os +import subprocess +import threading +import time +from collections.abc import Iterator, Sequence +from contextlib import contextmanager, suppress +from itertools import count +from pathlib import Path +from typing import Any, Final, cast + +#: Longest a single launch will WAIT for a storm to finish before giving up and running anyway. +#: +#: SIZED FROM THE STORM, measured 2026-09-16 on a 20-core developer box carrying 2 competing pytest +#: processes and 28 resident pwsh at the start of the run -- the process count is quoted because a +#: timing from a shared box without one is not a measurement. ``tests/test_session_mail.py`` spends +#: 26.5s total in its three bursts (20.26s + 3.77s + 2.47s by ``--durations``), dominated by one. +#: That box has 20 cores, so it CANNOT reproduce the 4-vCPU failure and these are lower bounds; they +#: are used only to size a wait, never to argue the fix works. CI's own figure agrees in magnitude -- +#: 2.4 to 3.1 percent of a ~1250s run is a 30-39s overlap window. +#: +#: THE BURSTS DO NOT OVERLAP EACH OTHER: all four live in one file, and ``--dist loadfile`` gives a +#: file to ONE worker, which runs its tests in sequence. So a waiting test queues behind at most one +#: burst, and this bound is a per-test bound in practice rather than only a per-call one. +_SINGLE_WAIT_S: Final = 30.0 + +#: Longest a storm will wait for in-flight single launches to drain before starting anyway. A single +#: hold is one ``pwsh`` launch, bounded by its caller at 45s but observed at a ~2s median, so this is +#: generous. Proceeding early costs only the overlap we have today. +_BURST_DRAIN_S: Final = 15.0 + +#: A reader entry older than this is treated as abandoned. The longest legitimate hold is one gate +#: launch at ``GATE_TIMEOUT_S`` (45s) plus process overhead, so 120s cannot reap a live holder that is +#: behaving; if it ever does, the effect is that a storm starts beside it, which is today's behaviour. +_READER_STALE_S: Final = 120.0 + +#: A turnstile older than this is treated as abandoned. The longest legitimate storm is bounded by +#: its own test at ``@pytest.mark.timeout(300)`` with per-racer ``timeout=240``, so 360s clears it. +_BURST_STALE_S: Final = 360.0 + +_POLL_S: Final = 0.05 + +#: Distinguishes concurrent readers inside ONE process. xdist workers are separate processes, so the +#: pid separates those; a ``ThreadPoolExecutor`` inside one test is why the thread id and counter are +#: needed as well. +_TICKET = count() + + +def _run_id() -> str: + """The key every worker of one pytest run agrees on, and that two unrelated runs do not share.""" + return os.environ.get("PYTEST_XDIST_TESTRUNUID") or f"pid-{os.getpid()}" + + +def _lock_root() -> Path | None: + """Machine-global for the repo, then narrowed to this run. ``None`` means run without the lock. + + The git common dir is shared by every worktree of the checkout, which is the same directory + ``tests/conftest.py`` anchors its slots to. Resolving it costs one ``git`` call per process, so + the result is cached in ``_ROOT`` below rather than recomputed per launch. + """ + try: + common = subprocess.run( + ["git", "rev-parse", "--path-format=absolute", "--git-common-dir"], + capture_output=True, + text=True, + check=False, + timeout=30, + ).stdout.strip() + except (OSError, subprocess.SubprocessError): + return None + if not common: + return None + root = Path(common) / "mefor-coord" / "pwsh-burst" / _run_id() + try: + (root / "readers").mkdir(parents=True, exist_ok=True) + except OSError: + return None + return root + + +_ROOT: Final = _lock_root() + + +def _age(path: Path) -> float | None: + """Seconds since ``path`` was created, or ``None`` if it is gone or unreadable.""" + try: + return time.time() - path.stat().st_mtime + except OSError: + return None + + +def _turnstile_blocks(root: Path) -> bool: + """Is a storm holding the turnstile right now? Reaps it first if it is abandoned.""" + gate = root / "burst.lock" + age = _age(gate) + if age is None: + return False + if age > _BURST_STALE_S: + with suppress(OSError): + gate.unlink(missing_ok=True) + return False + return True + + +def _live_readers(root: Path) -> int: + """Count in-flight single launches, reaping abandoned entries as it goes.""" + readers = root / "readers" + try: + entries = list(readers.iterdir()) + except OSError: + return 0 + live = 0 + for entry in entries: + age = _age(entry) + if age is None: + continue + if age > _READER_STALE_S: + with suppress(OSError): + entry.unlink(missing_ok=True) + continue + live += 1 + return live + + +@contextmanager +def single_spawn() -> Iterator[None]: + """Hold the SHARED side across one process launch. + + Waits out a storm if one is running, registers as a reader so a storm about to start waits for + this launch instead of racing it, then yields. Gives up waiting after ``_SINGLE_WAIT_S`` and runs + anyway, because a bounded overlap is today's behaviour and a test that never returns is not. + """ + root = _ROOT + if root is None: + yield + return + + deadline = time.monotonic() + _SINGLE_WAIT_S + ticket = root / "readers" / f"{os.getpid()}-{threading.get_ident()}-{next(_TICKET)}.lock" + held = False + try: + while True: + if not _turnstile_blocks(root): + try: + # Register BEFORE re-checking: a storm that takes the turnstile between the check + # above and this write still sees this entry when it drains, so the two cannot + # both conclude they have the field to themselves. + fd = os.open(ticket, os.O_CREAT | os.O_EXCL | os.O_WRONLY) + os.close(fd) + held = True + except OSError: + pass # cannot register: fall through and run unsynchronised + if not held or not _turnstile_blocks(root): + break + # A storm won the race for the turnstile. Stand down and wait for it. + with suppress(OSError): + ticket.unlink(missing_ok=True) + held = False + if time.monotonic() >= deadline: + break + time.sleep(_POLL_S) + yield + finally: + if held: + with suppress(OSError): + ticket.unlink(missing_ok=True) + + +@contextmanager +def spawn_burst(label: str) -> Iterator[None]: + """Hold the EXCLUSIVE side across a burst of concurrent process launches. + + ``label`` is written into the turnstile so a stuck run names its own holder rather than leaving + the next reader to guess. Takes the turnstile to stop NEW single launches, then waits for the + in-flight ones to drain so they finish at full speed instead of inside this burst. + + The burst itself is never blocked: if the turnstile cannot be taken, or the drain does not finish + inside ``_BURST_DRAIN_S``, it proceeds regardless. + """ + root = _ROOT + if root is None: + yield + return + + gate = root / "burst.lock" + held = False + deadline = time.monotonic() + _BURST_DRAIN_S + while time.monotonic() < deadline: + try: + fd = os.open(gate, os.O_CREAT | os.O_EXCL | os.O_WRONLY) + os.write(fd, f"{label} pid={os.getpid()} at={time.time():.0f}".encode()) + os.close(fd) + held = True + break + except FileExistsError: + if not _turnstile_blocks(root): # reaps an abandoned turnstile, then retries + continue + time.sleep(_POLL_S) + except OSError: + break # cannot take it at all: run unsynchronised rather than fail the test + try: + if held: + while time.monotonic() < deadline and _live_readers(root): + time.sleep(_POLL_S) + yield + finally: + if held: + with suppress(OSError): + gate.unlink(missing_ok=True) + + +def run_single(cmd: Sequence[str], **kwargs: Any) -> subprocess.CompletedProcess[str]: + """``subprocess.run`` for ONE launch, held on the shared side of the lock. + + A drop-in at the call site so wrapping a launch is a one-word edit rather than a re-indent of the + block around it -- which keeps this change off the same lines as the open work on these files. + + ``subprocess.run`` is looked up on the MODULE at call time, deliberately. Module objects are + singletons, so ``test_worktree_gate_control_plane.py``'s + ``monkeypatch.setattr(harness.subprocess, "run", ...)`` -- which drives the launch-timeout + diagnostic -- still intercepts this call. A ``from subprocess import run`` here would silently + bypass that test's patch and the test would stop proving anything. + """ + with single_spawn(): + return cast("subprocess.CompletedProcess[str]", subprocess.run(cmd, **kwargs)) diff --git a/tests/test_coord_lock.py b/tests/test_coord_lock.py index 306fce9dd..63b62c4da 100644 --- a/tests/test_coord_lock.py +++ b/tests/test_coord_lock.py @@ -27,6 +27,8 @@ import pytest +from tests._spawn_lock import spawn_burst + LOCK = Path(__file__).resolve().parents[1] / "scripts" / "coord" / "lock.ps1" pytestmark = pytest.mark.skipif( @@ -141,7 +143,13 @@ def test_eight_concurrent_claimants_never_hold_it_at_once(repo: Path, tmp_path: barrier = tmp_path / "barrier" barrier.mkdir() - with ThreadPoolExecutor(max_workers=8) as pool: + # Eight concurrent pwsh, and the winner holds for 8 s -- the same shape as the storm BACKLOG #1304 + # is about, found by sweeping the tier rather than by CI evidence. Nothing about the claimants + # changes; the lock only keeps single-launch tests off these vCPUs while they run. + with ( + spawn_burst("coord_lock.mutex_under_load x8"), + ThreadPoolExecutor(max_workers=8) as pool, + ): claims = [ pool.submit( acquire, diff --git a/tests/test_session_mail.py b/tests/test_session_mail.py index 7075b3165..64d4a7ecc 100644 --- a/tests/test_session_mail.py +++ b/tests/test_session_mail.py @@ -45,6 +45,8 @@ import pytest +from tests._spawn_lock import spawn_burst + ROOT = Path(__file__).resolve().parents[1] COORD = ROOT / "scripts" / "coord" HOOKS = ROOT / "scripts" / "hooks" @@ -653,7 +655,12 @@ def one(i: int) -> subprocess.CompletedProcess[str]: capture_output=True, text=True, timeout=240, check=False, ) # fmt: skip - with concurrent.futures.ThreadPoolExecutor(max_workers=RACERS) as ex: + # RACERS stays 16 -- see tests/_spawn_lock.py for why cutting it is the wrong fix. The burst lock + # keeps single-launch tests off these vCPUs while the storm runs, without changing what runs here. + with ( + spawn_burst(f"session_mail._race {mode} x{RACERS}"), + concurrent.futures.ThreadPoolExecutor(max_workers=RACERS) as ex, + ): procs = [f.result() for f in [ex.submit(one, i) for i in range(1, RACERS + 1)]] rows: list[dict[str, Any]] = [] for p in procs: @@ -948,7 +955,10 @@ def test_concurrent_drains_deliver_one_message_once(repo: Path, tmp_path: Path) def one(_: int) -> subprocess.CompletedProcess[str]: return run_drain(repo) - with concurrent.futures.ThreadPoolExecutor(max_workers=DRAINS) as ex: + with ( + spawn_burst(f"session_mail.concurrent_drains x{DRAINS}"), + concurrent.futures.ThreadPoolExecutor(max_workers=DRAINS) as ex, + ): procs = [f.result() for f in [ex.submit(one, i) for i in range(DRAINS)]] texts = [injection(p) for p in procs] diff --git a/tests/test_spawn_lock.py b/tests/test_spawn_lock.py new file mode 100644 index 000000000..000f75076 --- /dev/null +++ b/tests/test_spawn_lock.py @@ -0,0 +1,244 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Foundation, LLC and contributors +"""Tests for the pwsh burst lock (tests/_spawn_lock.py) -- BACKLOG #1304. + +THE PROPERTY UNDER TEST is mutual exclusion between a BURST and a SINGLE launch, and it is asserted +with a positive control: the same probe run with the lock disabled must actually overlap. A +concurrency test that would pass against a no-op is the failure mode this repo has already paid for, +so the control is not optional here. + +THE SECOND THING THESE PIN is that the remedy did not quietly disarm what it protects. ``run_single`` +must still be interceptable by ``monkeypatch.setattr(harness.subprocess, "run", ...)``, because +``test_worktree_gate_control_plane.py`` drives the #1304 launch-timeout diagnostic that way. An +indirection that bypassed the patch would leave that test passing while proving nothing. +""" + +from __future__ import annotations + +import os +import subprocess +import threading +import time +from pathlib import Path +from typing import Any + +import pytest + +from tests import _spawn_lock +from tests._spawn_lock import run_single, single_spawn, spawn_burst + + +@pytest.fixture +def lock_root(tmp_path: Path, monkeypatch: pytest.MonkeyPatch) -> Path: + """Point the module at a private root, so a test never waits on a real run's storm.""" + root = tmp_path / "pwsh-burst" + (root / "readers").mkdir(parents=True) + monkeypatch.setattr(_spawn_lock, "_ROOT", root) + return root + + +class _Window: + """Records when each side held the lock, so overlap is decided on timestamps, not on a flag.""" + + def __init__(self) -> None: + self.spans: list[tuple[str, float, float]] = [] + self._guard = threading.Lock() + + def record(self, who: str, start: float, end: float) -> None: + with self._guard: + self.spans.append((who, start, end)) + + def overlapped(self) -> bool: + for i, (_, a_start, a_end) in enumerate(self.spans): + for _, b_start, b_end in self.spans[i + 1 :]: + if a_start < b_end and b_start < a_end: + return True + return False + + +def _burst(window: _Window, hold: float, ready: threading.Event) -> None: + with spawn_burst("probe"): + start = time.monotonic() + ready.set() + time.sleep(hold) + window.record("burst", start, time.monotonic()) + + +def _single(window: _Window, hold: float) -> None: + with single_spawn(): + start = time.monotonic() + time.sleep(hold) + window.record("single", start, time.monotonic()) + + +def test_a_burst_and_a_single_launch_never_hold_the_lock_at_once(lock_root: Path) -> None: + """The whole point: while a storm runs, no single launch is in flight beside it.""" + window = _Window() + ready = threading.Event() + burst = threading.Thread(target=_burst, args=(window, 0.4, ready)) + burst.start() + assert ready.wait(10), "the burst never took the lock" + single = threading.Thread(target=_single, args=(window, 0.05)) + single.start() + burst.join(30) + single.join(30) + + assert len(window.spans) == 2, f"a side never recorded: {window.spans}" + assert not window.overlapped(), f"burst and single launch overlapped: {window.spans}" + + +def test_the_control_without_the_lock_does_overlap( + tmp_path: Path, monkeypatch: pytest.MonkeyPatch +) -> None: + """POSITIVE CONTROL for the row above. With the lock disabled the same probe MUST overlap. + + Without this, a lock that silently did nothing -- an unwritable root, a typo in the directory + name -- would pass the mutual-exclusion assertion by never letting either side run concurrently + in the first place, and the suite would report a fix that is not there. + """ + monkeypatch.setattr(_spawn_lock, "_ROOT", None) + window = _Window() + ready = threading.Event() + burst = threading.Thread(target=_burst, args=(window, 0.4, ready)) + burst.start() + assert ready.wait(10) + single = threading.Thread(target=_single, args=(window, 0.05)) + single.start() + burst.join(30) + single.join(30) + + assert window.overlapped(), ( + f"the unlocked control did NOT overlap, so the locked assertion proves nothing: " + f"{window.spans}" + ) + + +def test_a_single_launch_gives_up_and_runs_rather_than_waiting_forever( + lock_root: Path, monkeypatch: pytest.MonkeyPatch +) -> None: + """FAIL-OPEN, the property that makes this safe to land: a wedged turnstile costs a bounded wait, + never a hung test. A lock that could block forever would be a worse failure than the flake.""" + monkeypatch.setattr(_spawn_lock, "_SINGLE_WAIT_S", 0.3) + (lock_root / "burst.lock").write_text("wedged", encoding="ascii") + + start = time.monotonic() + with single_spawn(): + waited = time.monotonic() - start + assert waited >= 0.25, f"it did not wait for the turnstile at all: {waited:.3f}s" + assert waited < 20, f"it waited far past its own bound: {waited:.3f}s" + + +def test_a_burst_starts_even_when_a_reader_never_drains( + lock_root: Path, monkeypatch: pytest.MonkeyPatch +) -> None: + """The same fail-open rule on the storm side: an abandoned reader must not stall the burst.""" + monkeypatch.setattr(_spawn_lock, "_BURST_DRAIN_S", 0.3) + (lock_root / "readers" / "99999-1-0.lock").write_text("", encoding="ascii") + + start = time.monotonic() + with spawn_burst("probe"): + waited = time.monotonic() - start + assert waited < 20, f"the burst stalled behind a stuck reader: {waited:.3f}s" + + +def test_an_abandoned_turnstile_is_reaped_rather_than_waited_out(lock_root: Path) -> None: + """A crashed storm must not keep every later launch queued behind a file nobody owns.""" + gate = lock_root / "burst.lock" + gate.write_text("crashed", encoding="ascii") + old = time.time() - (_spawn_lock._BURST_STALE_S + 60) + os.utime(gate, (old, old)) + + start = time.monotonic() + with single_spawn(): + waited = time.monotonic() - start + assert waited < 5, f"a stale turnstile was waited out instead of reaped: {waited:.3f}s" + assert not gate.exists(), "the stale turnstile was not reaped" + + +def test_a_stale_reader_entry_does_not_hold_a_burst(lock_root: Path) -> None: + """The reader-side twin of the row above: an entry older than any legitimate hold is abandoned.""" + entry = lock_root / "readers" / "99999-1-0.lock" + entry.write_text("", encoding="ascii") + old = time.time() - (_spawn_lock._READER_STALE_S + 60) + os.utime(entry, (old, old)) + + assert _spawn_lock._live_readers(lock_root) == 0 + assert not entry.exists(), "the stale reader entry was not reaped" + + +def test_no_lock_root_runs_both_sides_unsynchronised(monkeypatch: pytest.MonkeyPatch) -> None: + """No directory, no lock, no failure. A test must never fail BECAUSE the lock was unavailable.""" + monkeypatch.setattr(_spawn_lock, "_ROOT", None) + with spawn_burst("probe"): + pass + with single_spawn(): + pass + + +def test_a_single_launch_releases_its_ticket(lock_root: Path) -> None: + """A leaked ticket would make every later burst pay the full drain timeout.""" + with single_spawn(): + assert _spawn_lock._live_readers(lock_root) == 1 + assert _spawn_lock._live_readers(lock_root) == 0 + + +def test_run_single_still_honours_a_patched_subprocess_run( + lock_root: Path, monkeypatch: pytest.MonkeyPatch +) -> None: + """NEGATIVE CONTROL protecting the #1304 diagnostic. + + ``test_worktree_gate_control_plane.py::test_a_pwsh_LAUNCH_timeout_is_reported_as_its_own_event`` + drives the launch timeout with ``monkeypatch.setattr(harness.subprocess, "run", ...)``. That + patches the ``subprocess`` MODULE, so it only reaches ``run_single`` while this looks the + attribute up at call time. A ``from subprocess import run`` in _spawn_lock.py would bypass it and + leave that test green against a diagnostic that no longer fires. + """ + seen: list[Any] = [] + + def never_returns(*args: object, **kwargs: object) -> None: + seen.append(args) + raise subprocess.TimeoutExpired(cmd="pwsh", timeout=45) + + monkeypatch.setattr(subprocess, "run", never_returns) + with pytest.raises(subprocess.TimeoutExpired): + run_single(["pwsh", "-NoProfile", "-Command", "exit 0"], capture_output=True, text=True) + assert seen, "run_single did not route through the patched subprocess.run" + + +def test_run_single_returns_what_subprocess_run_returns(lock_root: Path) -> None: + """The wrapper must be transparent -- it adds a lock, not a behaviour change.""" + proc = run_single(["git", "--version"], capture_output=True, text=True, check=False, timeout=60) + assert proc.returncode == 0 + assert "git" in proc.stdout.lower() + + +def test_the_storm_counts_are_unchanged(lock_root: Path) -> None: + """THE REMEDY MUST NOT HAVE WEAKENED WHAT IT PROTECTS, and this is where that is pinned. + + Cutting ``RACERS`` was the cheap candidate fix for #1304 and it is the wrong one: ``_race`` + exists to prove exactly one of N concurrent claimers wins, and ``_require_real_contention`` + SKIPS when the host cannot produce contention at that N. A lower N turns a race test into a + sequential one that still reports green -- the always-pass failure ``tests/_dead_pid.py`` + records for a sibling flake. If a later change needs these numbers down, it needs evidence that + the property survives, not this test deleted. + """ + from tests.test_session_mail import DRAINS, RACERS + + assert RACERS == 16, "RACERS moved; see tests/_spawn_lock.py for why that is not the #1304 fix" + assert DRAINS == 8, "DRAINS moved; the same argument applies" + + +def test_the_run_id_is_shared_by_xdist_workers_and_private_otherwise( + monkeypatch: pytest.MonkeyPatch, +) -> None: + """Scope check. Workers of ONE run must agree; two unrelated local runs must not serialise. + + xdist exports ``PYTEST_XDIST_TESTRUNUID`` into every worker from a single per-run uuid, which is + what makes the four workers of a CI job share one lock. With it absent the key falls back to the + process, so a developer's run does not queue behind a peer session's storm. + """ + monkeypatch.setenv("PYTEST_XDIST_TESTRUNUID", "shared-run-uid") + assert _spawn_lock._run_id() == "shared-run-uid" + + monkeypatch.delenv("PYTEST_XDIST_TESTRUNUID", raising=False) + assert _spawn_lock._run_id() == f"pid-{os.getpid()}" diff --git a/tests/test_worktree_gate.py b/tests/test_worktree_gate.py index f35af9df4..abf94b0cd 100644 --- a/tests/test_worktree_gate.py +++ b/tests/test_worktree_gate.py @@ -23,6 +23,8 @@ import pytest +from tests._spawn_lock import run_single + GATE = Path(__file__).resolve().parents[1] / "scripts" / "hooks" / "worktree_gate.ps1" pytestmark = pytest.mark.skipif( @@ -109,7 +111,9 @@ def run_gate( """ raw = payload if isinstance(payload, str) else json.dumps(payload) try: - proc = subprocess.run( + # run_single, not subprocess.run: holds the shared side of tests/_spawn_lock.py so this + # launch is never in flight beside a 16-process pwsh storm (BACKLOG #1304). + proc = run_single( [ "pwsh", "-NoProfile", diff --git a/tests/tooling_manifest.txt b/tests/tooling_manifest.txt index 85ed23555..eafad7f46 100644 --- a/tests/tooling_manifest.txt +++ b/tests/tooling_manifest.txt @@ -133,6 +133,7 @@ tests/test_session_mail.py tests/test_session_registry.py tests/test_setup_leak_gate_reports_source.py tests/test_shipped_line_endings_pinned.py +tests/test_spawn_lock.py tests/test_stale_repo_slug_check.py tests/test_stalled_prs.py tests/test_steer_inject.py From 35d18ff3a9cab985ae4b3b25bc8ba2be55bdfadf Mon Sep 17 00:00:00 2001 From: wshallwshall Date: Wed, 16 Sep 2026 13:19:07 -0500 Subject: [PATCH 2/4] fix(test): type the burst-lock seam and make its fail-open path self-diagnosing (BACKLOG #1304) Four findings from the /simplify pass on the previous commit. No behaviour change to the remedy itself; every change here is either a correction, a guard, or a diagnostic. THE SEAM IS NOW TYPED, AND THIS WAS THE REAL HOLE. run_single was a total subprocess.run passthrough, so nothing stopped this tier's hundreds of cheap `git` calls being routed through it. Every held ticket extends every concurrent burst's drain wait, so bursts would stop draining, hit _BURST_DRAIN_S, and proceed unsynchronised -- the lock disabling ITSELF, failing open exactly as designed, with nothing going red. It now refuses anything but pwsh or powershell, matched on the binary name so a full path or a .exe suffix still passes. The storm counts were already pinned against weakening the writers; this pins the reader population against weakening them. THE `--dist loadgroup` ARGUMENT WAS WRONG AND IS CORRECTED. loadgroup does not serialise groups against each other; it PINS same-group tests to one worker. The docstring implied the former. The honest reading is that it would stop the spawn-heavy files overlapping each other, at the cost of collapsing the tier's four heaviest files onto one worker that then sets the wall clock, while the other three workers keep launching pwsh throughout the storm. Recorded rather than quietly reworded, because the previous text would have let a reader conclude the option had been weighed on merit. FAIL-OPEN EVENTS ARE NOW RECORDED, which the turnstile's label previously invited and nothing delivered: it was written and never read. The fix is deliberately partial, so when a launch times out again the log has to separate three outcomes that otherwise look identical -- the lock did not cover that source, the lock covered it and fell open, or the cause is something else. `_note` writes to stderr, which pytest surfaces on failure, and never raises. WHAT THE FIX DOES NOT COVER IS NOW IN THE MODULE, not only in a commit message: overlap.ps1's ParallelLimit=16 git fan-out across several manifest files, test_announce_hook.py's 2-way pool, and the roughly 66 other files in the tier that launch pwsh without taking the shared side, so a storm does not wait for them. The missing abstraction is a shared run_pwsh launcher every site uses; naming it is not building it. Also: _lock_root is a pure query again -- it no longer reaps as a side effect, so a caller asking only whether the path resolves cannot trigger a recursive delete over a shared .git, which the new test for it was doing. The sweep moved to the _ROOT assignment, runs once per process, and uses os.scandir so is_dir/stat cost no syscall beyond the listing. The docstring now states that the git call is five per run under -n 4 rather than the true-but-misleading "one per process", and names the conftest duplication as the follow-on. Why this does not reuse scripts/coord/lock.ps1 is recorded: PowerShell (a spawn inside a spawn remedy), exclusive-only where this needs shared/exclusive, and loud-failing where this must fail open. AN UNRELATED PRE-EXISTING FLAKE WAS OBSERVED AND IS NOT FIXED HERE, recorded so the next reader does not attribute it to this change: test_coord_lock.py::test_lock_is_shared_between_the_primary_and_its_worktrees failed 2 of 6 parallel runs on this box, INCLUDING the control arm where this module was absent entirely (the three touched files reverted to their pre-change state). It passes in isolation. It is load-dependent, it is in a file this branch touches, and it is not this branch's. Checks: ruff check and ruff format clean; mypy strict clean on both modules and on messagefoundry (258 files). tests/test_spawn_lock.py 15 passed. The two #1304 launch-timeout diagnostic rows in test_worktree_gate_control_plane.py pass through the guarded wrapper, which is the row that would have caught the seam change silently disarming them. 224 passed at `-n 4 --dist loadfile` over the storm, victim, partition and lock files at 2 python and 19 pwsh resident, with the pre-existing coord_lock flake above as the only failure. --- tests/_spawn_lock.py | 145 +++++++++++++++++++++++++++++++++++---- tests/test_spawn_lock.py | 70 ++++++++++++++++++- 2 files changed, 199 insertions(+), 16 deletions(-) diff --git a/tests/_spawn_lock.py b/tests/_spawn_lock.py index 7acb58cda..110b45346 100644 --- a/tests/_spawn_lock.py +++ b/tests/_spawn_lock.py @@ -29,10 +29,29 @@ still reports green. ``tests/_dead_pid.py`` records the same lesson for a sibling flake: converting a loud false-failure into a quiet always-pass is worse than the flake it replaces. -WHY NOT AN XDIST GROUP. ``--dist loadgroup`` would separate the files that are spawn-heavy TODAY, and -it lives in the pytest invocation in ``.github/workflows/ci.yml`` rather than beside the code it -governs. This module binds the constraint to the call site, so a new bulk spawner opts in by wrapping -itself rather than by someone remembering to edit a workflow. +WHY NOT AN XDIST GROUP, stated precisely because the obvious reading of ``--dist loadgroup`` is wrong. +It does not serialise groups against each other; it PINS same-group tests to one worker. Putting the +spawn-heavy files in one group would therefore stop them overlapping each other, at the cost of +collapsing the tier's four heaviest files onto a single worker that then sets the wall clock -- and +it would still leave the other three workers launching pwsh throughout the storm. It also lives in +the pytest invocation in ``.github/workflows/ci.yml`` rather than beside the code it governs, and it +separates only the files that are spawn-heavy TODAY. This module binds the constraint to the call +site instead, so a new bulk spawner opts in by wrapping itself. + +WHY NOT ``scripts/coord/lock.ps1``, which is this repository's own cross-session mutex. Three +independent reasons: it is PowerShell, so every lock operation would spawn a ``pwsh`` inside the +remedy for too many spawns; it is exclusive-only, and this needs shared/exclusive because the 16 +racers must still run concurrently; and it fails LOUDLY on timeout by design, which is the opposite +of the fail-open posture below. + +WHAT THIS DOES NOT COVER, recorded so the next reader does not assume the tier is now safe. +``scripts/coord/overlap.ps1`` defaults ``ParallelLimit = 16`` and several manifest files invoke it, +each able to hold 16 runspaces spawning ``git``; ``test_announce_hook.py`` runs a 2-way pwsh pool. +Those are unwrapped: they were found by sweeping the tier, not by CI evidence, and this change +deliberately does not wrap on a hunch. Roughly 66 other files in the tier launch ``pwsh`` without +taking the shared side at all, so a storm does not wait for them. The missing abstraction is a shared +``run_pwsh`` launcher that every site uses; until that exists, ``_note`` below is what makes the next +occurrence tell you which of those gaps it came from. EVERY FAILURE MODE HERE DEGRADES TO TODAY'S BEHAVIOUR, WHICH IS THE PROPERTY THAT MAKES IT SAFE TO LAND. No lock directory, a saturated wait, a stale entry reaped while its owner is in fact alive, an @@ -55,7 +74,9 @@ from __future__ import annotations import os +import shutil import subprocess +import sys import threading import time from collections.abc import Iterator, Sequence @@ -93,6 +114,16 @@ #: its own test at ``@pytest.mark.timeout(300)`` with per-racer ``timeout=240``, so 360s clears it. _BURST_STALE_S: Final = 360.0 +#: A run directory older than this belongs to a process that is long gone. Far above any run length, +#: so it cannot reap a live peer; see ``_reap_finished_runs``. +_REAP_RUNS_AFTER_S: Final = 86400.0 + +#: Commands ``run_single`` will hold a ticket across. A PowerShell start carries Windows' process +#: spawn tax and is measured in seconds here, which is what makes serialising it worth a lock; a +#: ``git`` call in this tier is milliseconds and is not. See ``run_single`` for what routing the +#: cheap ones through the lock would silently do to it. +_LOCKED_INTERPRETERS: Final = frozenset({"pwsh", "powershell"}) + _POLL_S: Final = 0.05 #: Distinguishes concurrent readers inside ONE process. xdist workers are separate processes, so the @@ -106,12 +137,28 @@ def _run_id() -> str: return os.environ.get("PYTEST_XDIST_TESTRUNUID") or f"pid-{os.getpid()}" +def _age(path: Path) -> float | None: + """Seconds since ``path`` was created, or ``None`` if it is gone or unreadable.""" + try: + return time.time() - path.stat().st_mtime + except OSError: + return None + + def _lock_root() -> Path | None: """Machine-global for the repo, then narrowed to this run. ``None`` means run without the lock. The git common dir is shared by every worktree of the checkout, which is the same directory - ``tests/conftest.py`` anchors its slots to. Resolving it costs one ``git`` call per process, so - the result is cached in ``_ROOT`` below rather than recomputed per launch. + ``tests/conftest.py`` anchors its slots to. PURE QUERY: it resolves and creates, and does NOT + reap -- ``_ROOT`` below does that once, so a caller asking only whether the path resolves cannot + trigger a recursive delete over a shared ``.git`` as a side effect. + + IT COSTS ONE ``git`` CALL PER PROCESS, WHICH UNDER ``-n 4`` IS FIVE PER RUN, and that is worth + stating plainly in a module whose subject is too many processes. The result is cached in + ``_ROOT``, so it is five at import and none per launch. ``tests/conftest.py`` already resolves + the same value in the same processes; collapsing the two into one shared, side-effect-free + helper is the right follow-on and is not done here, because importing a conftest re-runs its + slot-claiming import side effects. """ try: common = subprocess.run( @@ -133,15 +180,39 @@ def _lock_root() -> Path | None: return root -_ROOT: Final = _lock_root() +def _reap_finished_runs(runs: Path) -> None: + """Drop the directories of runs that ended long ago. + The key is per-RUN, so without this every pytest run would leave a directory behind forever in a + checkout's shared ``.git`` -- ``tests/conftest.py``'s slots do not accumulate because they reuse + 32 fixed names, and this would. A day is far longer than any run, so a directory that old belongs + to a process that is gone; and deleting one that somehow is not costs only the lock, per the + fail-open rule in the module docstring. Best-effort: a peer reaping the same directory + concurrently, or a file held open, is ignored rather than raised. -def _age(path: Path) -> float | None: - """Seconds since ``path`` was created, or ``None`` if it is gone or unreadable.""" + ``os.scandir`` rather than ``iterdir``: it serves ``is_dir()`` and ``stat()`` from the directory + read that already happened, so this costs no syscall per entry beyond the one listing. + """ + cutoff = time.time() - _REAP_RUNS_AFTER_S + mine = _run_id() try: - return time.time() - path.stat().st_mtime + with os.scandir(runs) as entries: + stale = [ + e.path + for e in entries + if e.name != mine and e.is_dir() and e.stat().st_mtime < cutoff + ] except OSError: - return None + return + for path in stale: + shutil.rmtree(path, ignore_errors=True) + + +_ROOT: Final = _lock_root() + +if _ROOT is not None: + # Once per process, at the one place that should ever sweep -- never from a query. + _reap_finished_runs(_ROOT.parent) def _turnstile_blocks(root: Path) -> bool: @@ -177,6 +248,29 @@ def _live_readers(root: Path) -> int: return live +def _note(message: str) -> None: + """Record a fail-open event where the NEXT #1304 occurrence will be read. + + THE FIX IS DELIBERATELY PARTIAL -- other spawn sources in this tier are unwrapped -- so when a + launch times out again the log has to separate three outcomes that otherwise look identical: the + lock did not cover that source, the lock covered it and fell open, or the cause is something + else. Without this the turnstile's label is written and never read by anything. + + stderr, because pytest captures it per test and surfaces it on failure, which is exactly when it + is wanted. Never raises: a diagnostic that can fail a run is worse than no diagnostic. + """ + with suppress(OSError, ValueError): + print(f"[spawn-lock] {message}", file=sys.stderr) + + +def _turnstile_holder(root: Path) -> str: + """The label a storm wrote, for the diagnostic above. ``unknown`` rather than a raise.""" + try: + return (root / "burst.lock").read_text(encoding="utf-8", errors="replace").strip() or "?" + except OSError: + return "no holder (it finished while we waited)" + + @contextmanager def single_spawn() -> Iterator[None]: """Hold the SHARED side across one process launch. @@ -190,7 +284,8 @@ def single_spawn() -> Iterator[None]: yield return - deadline = time.monotonic() + _SINGLE_WAIT_S + started = time.monotonic() + deadline = started + _SINGLE_WAIT_S ticket = root / "readers" / f"{os.getpid()}-{threading.get_ident()}-{next(_TICKET)}.lock" held = False try: @@ -212,6 +307,10 @@ def single_spawn() -> Iterator[None]: ticket.unlink(missing_ok=True) held = False if time.monotonic() >= deadline: + _note( + f"single launch waited {time.monotonic() - started:.1f}s behind " + f"{_turnstile_holder(root)} and proceeded UNSYNCHRONISED" + ) break time.sleep(_POLL_S) yield @@ -253,10 +352,14 @@ def spawn_burst(label: str) -> Iterator[None]: time.sleep(_POLL_S) except OSError: break # cannot take it at all: run unsynchronised rather than fail the test + if not held: + _note(f"burst {label!r} could not take the turnstile; running UNSYNCHRONISED") try: if held: while time.monotonic() < deadline and _live_readers(root): time.sleep(_POLL_S) + if _live_readers(root): + _note(f"burst {label!r} started with in-flight launches it could not drain") yield finally: if held: @@ -265,16 +368,32 @@ def spawn_burst(label: str) -> Iterator[None]: def run_single(cmd: Sequence[str], **kwargs: Any) -> subprocess.CompletedProcess[str]: - """``subprocess.run`` for ONE launch, held on the shared side of the lock. + """``subprocess.run`` for ONE INTERPRETER launch, held on the shared side of the lock. A drop-in at the call site so wrapping a launch is a one-word edit rather than a re-indent of the block around it -- which keeps this change off the same lines as the open work on these files. + IT REFUSES ANYTHING BUT AN INTERPRETER, AND THAT GUARD IS THE POINT RATHER THAN TIDINESS. The + lock's cost model only holds for a spawn expensive enough to be worth serialising. Route this + tier's hundreds of cheap ``git`` calls through here and every held ticket extends every + concurrent burst's drain wait, so bursts stop draining, hit ``_BURST_DRAIN_S`` and proceed + unsynchronised -- the fix disables ITSELF, fails open exactly as designed, and nothing goes red. + ``test_spawn_lock.py`` pins the storm counts against weakening the writers; this pins the reader + population against weakening them. A convention in a docstring would not have held that line. + ``subprocess.run`` is looked up on the MODULE at call time, deliberately. Module objects are singletons, so ``test_worktree_gate_control_plane.py``'s ``monkeypatch.setattr(harness.subprocess, "run", ...)`` -- which drives the launch-timeout diagnostic -- still intercepts this call. A ``from subprocess import run`` here would silently bypass that test's patch and the test would stop proving anything. """ + binary = Path(cmd[0]).name.lower().removesuffix(".exe") if cmd else "" + if binary not in _LOCKED_INTERPRETERS: + raise ValueError( + f"run_single is for an interpreter launch, not {cmd[0]!r}. Only " + f"{sorted(_LOCKED_INTERPRETERS)} are expensive enough to be worth the lock; holding a " + "ticket across a cheap call starves every concurrent burst's drain and silently " + "disables this module. Call subprocess.run directly." + ) with single_spawn(): return cast("subprocess.CompletedProcess[str]", subprocess.run(cmd, **kwargs)) diff --git a/tests/test_spawn_lock.py b/tests/test_spawn_lock.py index 000f75076..44000db15 100644 --- a/tests/test_spawn_lock.py +++ b/tests/test_spawn_lock.py @@ -16,6 +16,7 @@ from __future__ import annotations import os +import shutil import subprocess import threading import time @@ -205,14 +206,38 @@ def never_returns(*args: object, **kwargs: object) -> None: assert seen, "run_single did not route through the patched subprocess.run" +@pytest.mark.skipif(shutil.which("pwsh") is None, reason="pwsh (PowerShell 7) not on PATH") def test_run_single_returns_what_subprocess_run_returns(lock_root: Path) -> None: """The wrapper must be transparent -- it adds a lock, not a behaviour change.""" - proc = run_single(["git", "--version"], capture_output=True, text=True, check=False, timeout=60) + proc = run_single( + ["pwsh", "-NoProfile", "-NonInteractive", "-Command", "Write-Output ok"], + capture_output=True, + text=True, + check=False, + timeout=120, + ) assert proc.returncode == 0 - assert "git" in proc.stdout.lower() + assert "ok" in proc.stdout + + +def test_run_single_refuses_a_cheap_command(lock_root: Path) -> None: + """THE SEAM IS TYPED, NOT CONVENTIONAL, and this is the failure that makes that worth enforcing. + + ``run_single`` is otherwise a total ``subprocess.run`` passthrough, so nothing would stop this + tier's hundreds of cheap ``git`` calls being routed through it. Every held ticket extends every + concurrent burst's drain wait, so bursts would stop draining, hit ``_BURST_DRAIN_S`` and proceed + unsynchronised -- the lock disabling itself, failing open exactly as designed, with nothing red. + """ + with pytest.raises(ValueError, match="interpreter launch"): + run_single(["git", "--version"], capture_output=True, text=True) + + # The allowlist is on the BINARY NAME, so a full path and a .exe suffix must still be accepted. + assert frozenset({"pwsh", "powershell"}) == _spawn_lock._LOCKED_INTERPRETERS + for spelling in (r"C:\Program Files\PowerShell\7\pwsh.exe", "/usr/bin/pwsh", "PowerShell.EXE"): + assert Path(spelling).name.lower().removesuffix(".exe") in _spawn_lock._LOCKED_INTERPRETERS -def test_the_storm_counts_are_unchanged(lock_root: Path) -> None: +def test_the_storm_counts_are_unchanged() -> None: """THE REMEDY MUST NOT HAVE WEAKENED WHAT IT PROTECTS, and this is where that is pinned. Cutting ``RACERS`` was the cheap candidate fix for #1304 and it is the wrong one: ``_race`` @@ -228,6 +253,45 @@ def test_the_storm_counts_are_unchanged(lock_root: Path) -> None: assert DRAINS == 8, "DRAINS moved; the same argument applies" +def test_a_finished_run_directory_is_reaped_but_a_live_one_is_not(tmp_path: Path) -> None: + """The key is per-RUN, so without reaping every pytest run leaks a directory into a shared .git. + + The LIVE arm is the half that matters: a reaper that also deleted the current run's directory + would take the lock out from under the run using it, and every test would still pass because the + module fails open. So both arms are asserted, not just the deletion. + """ + runs = tmp_path / "pwsh-burst" + stale = runs / "old-run" + fresh = runs / "recent-run" + mine = runs / _spawn_lock._run_id() + for d in (stale, fresh, mine): + (d / "readers").mkdir(parents=True) + old = time.time() - (_spawn_lock._REAP_RUNS_AFTER_S + 3600) + os.utime(stale, (old, old)) + os.utime(mine, (old, old)) # even an OLD-looking current run must survive + + _spawn_lock._reap_finished_runs(runs) + + assert not stale.exists(), "a finished run's directory was left behind" + assert fresh.exists(), "a recent run's directory was reaped" + assert mine.exists(), "the CURRENT run's own directory was reaped out from under it" + + +def test_the_real_lock_root_resolves() -> None: + """THE SILENT NO-OP GUARD, and the reason it exists is that every other test here monkeypatches + ``_ROOT``. If ``_lock_root`` returned None in the real checkout the lock would be inert + everywhere, the module would fail open exactly as designed, and the whole suite would still be + green -- a fix that is not there, reported as one. + + Asserted against the real repository rather than a fixture, because resolving the git common dir + is the step that would break. + """ + root = _spawn_lock._lock_root() + assert root is not None, "the lock root did not resolve, so the lock is inert in this checkout" + assert (root / "readers").is_dir() + assert root.name == _spawn_lock._run_id() + + def test_the_run_id_is_shared_by_xdist_workers_and_private_otherwise( monkeypatch: pytest.MonkeyPatch, ) -> None: From 432a4eb03814eb2eec04652e624715bbbe1363db Mon Sep 17 00:00:00 2001 From: wshallwshall Date: Wed, 16 Sep 2026 19:59:10 -0500 Subject: [PATCH 3/4] fix(test): parse the interpreter allowlist on both path separators (BACKLOG #1304) run_single refused a Windows-spelled pwsh path on a POSIX host. Path(cmd[0]).name is PurePosixPath there, which does not treat a backslash as a separator, so the whole spelling came back as the binary name and the allowlist rejected it. The ubuntu harness leg raised exactly that: assert 'c:\program files\powershell\7\pwsh' in frozenset({'powershell', 'pwsh'}) Parse with a plain string split instead, so the result cannot vary by host. test_run_single_refuses_a_cheap_command re-implemented that parse rather than calling run_single, so it exercised pathlib and never the seam, agreeing with the host instead of with the function. It now drives run_single with subprocess.run patched, asserting each spelling is accepted and arrives unaltered, and pins the refuted PurePosixPath value beside the fixed one. The ValueError names the offending argument through a local, removing an IndexError on an empty cmd. --- tests/_spawn_lock.py | 12 ++++++++-- tests/test_spawn_lock.py | 47 ++++++++++++++++++++++++++++++++-------- 2 files changed, 48 insertions(+), 11 deletions(-) diff --git a/tests/_spawn_lock.py b/tests/_spawn_lock.py index 110b45346..37db8b800 100644 --- a/tests/_spawn_lock.py +++ b/tests/_spawn_lock.py @@ -387,10 +387,18 @@ def run_single(cmd: Sequence[str], **kwargs: Any) -> subprocess.CompletedProcess diagnostic -- still intercepts this call. A ``from subprocess import run`` here would silently bypass that test's patch and the test would stop proving anything. """ - binary = Path(cmd[0]).name.lower().removesuffix(".exe") if cmd else "" + # SPLIT ON BOTH SEPARATORS REGARDLESS OF HOST, which pathlib alone does not. PurePosixPath + # does not treat a backslash as a separator, so on Linux the .name of a Windows-spelled pwsh + # path is the WHOLE SPELLING and this allowlist then refuses a launch it should take. That is + # measured on the ubuntu leg, which is where it failed. The tier writes Windows spellings and + # this module is imported on both platforms, so the parse cannot be the host path flavour. + # test_spawn_lock.py pins the refuted value beside the fixed one, so a later simplification + # back to pathlib has to argue with it rather than rediscover it on a red leg. + spelling = cmd[0] if cmd else "" + binary = spelling.replace("\\", "/").rsplit("/", 1)[-1].lower().removesuffix(".exe") if binary not in _LOCKED_INTERPRETERS: raise ValueError( - f"run_single is for an interpreter launch, not {cmd[0]!r}. Only " + f"run_single is for an interpreter launch, not {spelling!r}. Only " f"{sorted(_LOCKED_INTERPRETERS)} are expensive enough to be worth the lock; holding a " "ticket across a cheap call starves every concurrent burst's drain and silently " "disables this module. Call subprocess.run directly." diff --git a/tests/test_spawn_lock.py b/tests/test_spawn_lock.py index 44000db15..695da648b 100644 --- a/tests/test_spawn_lock.py +++ b/tests/test_spawn_lock.py @@ -20,7 +20,8 @@ import subprocess import threading import time -from pathlib import Path +from collections.abc import Sequence +from pathlib import Path, PurePosixPath from typing import Any import pytest @@ -220,21 +221,49 @@ def test_run_single_returns_what_subprocess_run_returns(lock_root: Path) -> None assert "ok" in proc.stdout -def test_run_single_refuses_a_cheap_command(lock_root: Path) -> None: +def test_run_single_refuses_a_cheap_command( + lock_root: Path, monkeypatch: pytest.MonkeyPatch +) -> None: """THE SEAM IS TYPED, NOT CONVENTIONAL, and this is the failure that makes that worth enforcing. - ``run_single`` is otherwise a total ``subprocess.run`` passthrough, so nothing would stop this - tier's hundreds of cheap ``git`` calls being routed through it. Every held ticket extends every - concurrent burst's drain wait, so bursts would stop draining, hit ``_BURST_DRAIN_S`` and proceed - unsynchronised -- the lock disabling itself, failing open exactly as designed, with nothing red. + ``run_single`` is otherwise a total ``subprocess.run`` passthrough, so nothing would stop + this tier's hundreds of cheap ``git`` calls being routed through it. Every held ticket + extends every concurrent burst's drain wait, so bursts would stop draining, hit + ``_BURST_DRAIN_S`` and proceed unsynchronised -- the lock disabling itself, failing open + exactly as designed, with nothing red. + + THE ACCEPT ARM CALLS ``run_single`` RATHER THAN RE-IMPLEMENTING ITS PARSE, and + re-implementing it is why this row was red. The first version copied + ``Path(cmd[0]).name.lower()`` into the assertion, so it exercised ``pathlib`` and never the + seam. That copy passes on Windows, where ``Path`` is ``WindowsPath`` and splits on both + separators; on Linux ``PurePosixPath`` splits on neither backslash nor drive, so the Windows + spelling below parsed to ITSELF and the ubuntu leg raised ``AssertionError``. A test that + re-implements the function it checks agrees with that function by construction and disagrees + with the host instead, which is the wrong argument to be having. """ with pytest.raises(ValueError, match="interpreter launch"): run_single(["git", "--version"], capture_output=True, text=True) - # The allowlist is on the BINARY NAME, so a full path and a .exe suffix must still be accepted. assert frozenset({"pwsh", "powershell"}) == _spawn_lock._LOCKED_INTERPRETERS - for spelling in (r"C:\Program Files\PowerShell\7\pwsh.exe", "/usr/bin/pwsh", "PowerShell.EXE"): - assert Path(spelling).name.lower().removesuffix(".exe") in _spawn_lock._LOCKED_INTERPRETERS + + # THE REFUTED VALUE, pinned rather than described. ``PurePosixPath`` is host-independent by + # construction, so this computes the same everywhere and keeps the reason the parse cannot be + # ``pathlib``'s sitting beside the parse that replaced it. + windows_pwsh = r"C:\Program Files\PowerShell\7\pwsh.exe" + assert PurePosixPath(windows_pwsh).name.lower().removesuffix(".exe") != "pwsh" + + # The allowlist is on the BINARY NAME, so a full path and a .exe suffix must still be ACCEPTED, + # and must reach ``subprocess.run`` unaltered -- ``run_single`` adds a lock, not a rewrite. + spellings = [windows_pwsh, "/usr/bin/pwsh", "PowerShell.EXE"] + seen: list[str] = [] + + def record(cmd: Sequence[str], **kwargs: object) -> None: + seen.append(cmd[0]) + + monkeypatch.setattr(subprocess, "run", record) + for spelling in spellings: + run_single([spelling, "-NoProfile", "-Command", "exit 0"]) + assert seen == spellings, "a valid interpreter spelling was refused or rewritten" def test_the_storm_counts_are_unchanged() -> None: From ec8875012f2c83cda1d5b1b2875e4a6b88d32f13 Mon Sep 17 00:00:00 2001 From: wshallwshall Date: Wed, 16 Sep 2026 20:08:37 -0500 Subject: [PATCH 4/4] fix(test): wait out the storm CI measured, not the one a 20-core box showed Addresses the windows-2025 leg of PR 1203. BACKLOG #1304. The ubuntu leg's path defect is NOT touched here: 432a4eb03 fixed it while this was being written, and its rsplit-on-both-separators parse is equivalent to the PureWindowsPath one that would have replaced it. Rewriting a peer's landed fix to swap one correct expression for another is churn, and two sessions editing one block is how they collide at merge. Dropped in favour of what the remote still lacked. WHAT THE WINDOWS LOG ACTUALLY SHOWED. Both failures there are the original #1304 launch timeout, not the path defect, which could only ever fail off Windows. The fail-open diagnostic added in 35d18ff3a reported the cause directly, which is the first time this flake has named its own holder: [spawn-lock] single launch waited 30.4s behind session_mail._race claimed x16 pid=1064 ... and proceeded UNSYNCHRONISED [spawn-lock] single launch waited 30.1s behind session_mail._race claimed x16 pid=1064 ... and proceeded UNSYNCHRONISED Same storm and same pid caught both launches. Each waited `_SINGLE_WAIT_S` out, gave up while the turnstile was still held, launched into the storm and blew its caller's 45s bound. So the lock engaged and then disarmed itself at the ceiling. The old 30.0 was sized from a 20-core box's 26.5s of bursts, while the same comment block already recorded CI's window as 30-39s. The ceiling sat at the bottom of the range it had to cover, and a 4-vCPU runner's storm is not faster than a 20-core one's. Raised to 90.0, roughly 2.3x the top of the only measured window, staying under both the storm's own 300s test bound and the 360s turnstile reap so an ABANDONED turnstile is still cleared by staleness rather than by a waiter giving up on a live one. THIS IS NOT THE "RAISING THE CEILING" THE MODULE DOCSTRING REFUTES, and the comment now says so where the next reader will hit it. That refutation is about GATE_TIMEOUT_S, the bound on a launch already running: a launch that never returns does not return sooner for being given longer. This constant is the opposite end, how long a launch waits BEFORE it starts, so that it starts on an idle machine instead of inside a storm. Raising it cannot push a launch past its own timeout either -- the wait runs before subprocess.run is called, so the caller's timeout clock starts at process launch. A waiter holds nothing, registering its reader ticket only once the turnstile clears, and the poll exits the instant it does, so a run with no storm pays nothing. A wait shorter than the storm is worse than no wait: it pays the full delay and still lands in the contention. Nothing failed when the constant was too small, because the module fails open by design -- the symptom surfaced as somebody else's timeout on another leg. The new pin asserts the wait against the MEASURED window rather than a literal, so re-sizing on new evidence stays free while dropping it back under the storm does not. It fails at the shipped value with `assert 39.0 < 30.0`, verified. Checks: ruff check, ruff format --check, mypy strict clean on messagefoundry (275 files) and on both changed test modules. pytest green on test_spawn_lock + test_coord_lock + test_tooling_partition (32) and on test_session_mail + test_worktree_gate (194). Every local run reports INCOMPLETE RUN -- the `vault` extra is absent -- so none of them establishes a green full suite. This 20-core box carried 28 resident pwsh and 0 competing python processes and cannot reproduce a 4-vCPU contention failure; no timing here was tuned to make a local run pass. --- tests/_spawn_lock.py | 37 ++++++++++++++++++++++++++++++++++++- tests/test_spawn_lock.py | 28 ++++++++++++++++++++++++++++ 2 files changed, 64 insertions(+), 1 deletion(-) diff --git a/tests/_spawn_lock.py b/tests/_spawn_lock.py index 37db8b800..32a7b1a8e 100644 --- a/tests/_spawn_lock.py +++ b/tests/_spawn_lock.py @@ -98,7 +98,42 @@ #: THE BURSTS DO NOT OVERLAP EACH OTHER: all four live in one file, and ``--dist loadfile`` gives a #: file to ONE worker, which runs its tests in sequence. So a waiting test queues behind at most one #: burst, and this bound is a per-test bound in practice rather than only a per-call one. -_SINGLE_WAIT_S: Final = 30.0 +#: +#: WAS 30.0, AND CI MEASURED THAT TOO SMALL -- raised 2026-09-16 on the evidence the ``_note`` below +#: was added to collect, from job 104922278187 on PR 1203. Two launches each waited the ceiling out +#: and gave up while the storm still held the turnstile:: +#: +#: [spawn-lock] single launch waited 30.4s behind session_mail._race claimed x16 pid=1064 ... +#: [spawn-lock] single launch waited 30.1s behind session_mail._race claimed x16 pid=1064 ... +#: +#: Same storm, same pid, both launches. Each then launched INTO it and blew its caller's 45s bound. +#: The old value was sized from the 20-core box's 26.5s of bursts above, while the SAME paragraph +#: already recorded CI's window as 30-39s -- so the ceiling sat at the bottom of the range it had to +#: cover. A storm is not faster on a smaller runner, which is the direction that matters here. +#: +#: THIS IS NOT THE "RAISING THE CEILING" THE MODULE DOCSTRING REFUTES, and the two are easy to fuse +#: because both are seconds. That refutation is about ``GATE_TIMEOUT_S``, the caller's bound on a +#: launch ALREADY RUNNING: a launch that never returns does not return any sooner for being given +#: longer, so raising it only delays the same failure. This constant is the opposite end -- how long +#: a launch WAITS BEFORE IT STARTS, so that it starts on an idle machine instead of inside a storm. +#: Raising it removes the contention rather than tolerating more of it. +#: +#: RAISING THIS CANNOT PUSH A LAUNCH PAST ITS OWN TIMEOUT, which is the objection to check before +#: believing that. The wait happens in ``single_spawn`` BEFORE ``subprocess.run`` is called, so the +#: caller's ``timeout=`` clock starts at process launch and never includes the wait. Nor does a +#: waiter hold anything: it registers its reader ticket only once the turnstile is clear, so a long +#: wait cannot be reaped by ``_READER_STALE_S`` and cannot stall a storm's drain. +#: +#: WAITING IS ALSO CHEAPER THAN THE FAILURE IT REPLACES. The poll exits the instant the turnstile +#: clears, so a run with no storm in flight pays nothing at all. The observed failure cost 30s of +#: waiting plus a 45s timeout; waiting the storm out instead costs its remaining seconds plus a +#: launch at the ~2s median recorded below. +#: +#: 90.0 IS DELIBERATELY GENEROUS RATHER THAN TIGHT, because a tight ceiling is what produced this +#: failure. It is ~2.3x the top of the only measured window, and stays well under both the storm's +#: own ``@pytest.mark.timeout(300)`` bound and the 360s ``_BURST_STALE_S`` reap -- so an ABANDONED +#: turnstile is still cleared by staleness, never by a waiter giving up on a live one. +_SINGLE_WAIT_S: Final = 90.0 #: Longest a storm will wait for in-flight single launches to drain before starting anyway. A single #: hold is one ``pwsh`` launch, bounded by its caller at 45s but observed at a ~2s median, so this is diff --git a/tests/test_spawn_lock.py b/tests/test_spawn_lock.py index 695da648b..7f9f01a01 100644 --- a/tests/test_spawn_lock.py +++ b/tests/test_spawn_lock.py @@ -282,6 +282,34 @@ def test_the_storm_counts_are_unchanged() -> None: assert DRAINS == 8, "DRAINS moved; the same argument applies" +def test_the_single_wait_outlasts_the_storm_window_ci_measured() -> None: + """THE CEILING MUST EXCEED THE STORM, and nothing caught it the first time it did not. + + ``_SINGLE_WAIT_S`` shipped at 30.0, sized from a 20-core box's 26.5s of bursts, while the same + comment block already recorded CI's own overlap window as 30-39s. So it was set AT THE BOTTOM of + the range it exists to cover, and on a 4-vCPU runner two launches waited it out, gave up while + the storm still held the turnstile, launched into it and blew their caller's 45s bound. + + A WAIT SHORTER THAN THE STORM IS WORSE THAN NO WAIT: it pays the full delay and still lands in + the contention, which is the shape the job log showed. Nothing failed when the constant was too + small -- the module fails open by design, so the symptom surfaced as somebody else's timeout on + a different leg. That is exactly the defect a pin is for. + + The bound is asserted against the MEASURED window rather than a literal, so re-sizing the wait on + new evidence is free while dropping it back under the storm is not. + """ + ci_overlap_window_top_s = 39.0 # tests/_spawn_lock.py: 2.4-3.1 percent of a ~1250s CI run + + assert ci_overlap_window_top_s < _spawn_lock._SINGLE_WAIT_S, ( + "a single launch gives up before CI's measured storm ends, so it launches into the " + "contention anyway -- the #1304 failure this constant exists to remove" + ) + assert _spawn_lock._SINGLE_WAIT_S < _spawn_lock._BURST_STALE_S, ( + "a waiter must give up before the turnstile reap, or an ABANDONED storm is waited out " + "instead of being cleared by staleness" + ) + + def test_a_finished_run_directory_is_reaped_but_a_live_one_is_not(tmp_path: Path) -> None: """The key is per-RUN, so without reaping every pytest run leaks a directory into a shared .git.