From f655703b9adf2bfcb448c59ed27573c62c77456d Mon Sep 17 00:00:00 2001 From: wshallwshall Date: Sat, 1 Aug 2026 18:40:28 -0500 Subject: [PATCH 1/3] ci: report pull requests that are green, armed, and can never merge Measured on this repo 2026-08-01: nine open pull requests with zero failing checks and zero pending checks, not one of which could merge. Six had auto-merge ARMED, which will never fire. #74 had been in that state since 2026-07-30 and was found only because somebody went hunting for "stuck CI" by hand. The mechanism is that `strict = true` plus no merge queue plus a ~20-minute suite makes merging a race: a PR is mergeable only between going green and the next thing landing on main. Losing that race is silent. Armed auto-merge does NOT update a BEHIND branch -- it waits on checks that already passed -- so the PR sits with no failing check, no notification, and no run in flight. No existing signal can see it, because every existing signal is a check OUTCOME and nothing has failed. nightly-notice.yml watches CI runs and there is no failing run to watch; the author's last signal was a full pass. A green dashboard and a wedged repository are indistinguishable unless something asks "can this still merge at all?". This does not fix the race -- only a merge queue does, filed separately as BACKLOG #340. It converts a SILENT failure into a LOUD one, which is the part that let #74 sit for days. Scheduled rather than per-PR: the stall arrives when a DIFFERENT pull request merges, so the affected PR has no run to hang a check on. Advisory by placement and must never become required -- it reports on OTHER pull requests, so a stall on #71 would block #128, wedging the repo with the tool meant to unwedge it. Verified against the live repo: 14 scanned, 8 stalled, 6 armed, exit 1. The count differs from the hand survey's 9 because #120 was re-synced in between, which the check correctly excluded. Tests carry a positive control (the exact stall shape MUST be detected) alongside negative controls for failing, pending, BLOCKED, DIRTY and closed PRs, and assert that an unclassifiable rollup node counts as unsettled rather than green. --- .github/workflows/stalled-prs.yml | 57 ++++++++ scripts/ci/check_stalled_prs.py | 220 ++++++++++++++++++++++++++++++ tests/test_stalled_prs.py | 172 +++++++++++++++++++++++ 3 files changed, 449 insertions(+) create mode 100644 .github/workflows/stalled-prs.yml create mode 100644 scripts/ci/check_stalled_prs.py create mode 100644 tests/test_stalled_prs.py diff --git a/.github/workflows/stalled-prs.yml b/.github/workflows/stalled-prs.yml new file mode 100644 index 00000000..0bf58b3c --- /dev/null +++ b/.github/workflows/stalled-prs.yml @@ -0,0 +1,57 @@ +name: Stalled PRs + +# A pull request can be finished, green, armed to merge -- and unable to merge, forever, silently. +# +# THE DEFECT THIS EXISTS FOR — measured on this repo, 2026-08-01: NINE open pull requests with zero +# failing checks and zero pending checks, not one of which could merge. Six had auto-merge ARMED, which +# will never fire. PR #74 had been in that state since 2026-07-30 and was found only because somebody +# went looking for "stuck CI" by hand. +# +# THE MECHANISM. Branch protection sets `required_status_checks.strict = true` and there is no merge +# queue, so a PR that goes green must finish while `main` holds still. When anything else lands first it +# flips to BEHIND and stops. Armed auto-merge does NOT update a BEHIND branch — it waits on checks that +# already passed. Nothing re-syncs it and nothing reports it. +# +# WHY NO EXISTING SIGNAL CATCHES IT. Every other signal is a check OUTCOME, and no check has failed — +# that is the whole problem. `nightly-notice.yml` watches CI runs and there is no failing run to watch. +# The author's last signal was a full pass, so they have no reason to look. A green dashboard and a +# wedged repository are indistinguishable unless something asks "can this still merge at all?". +# +# SCHEDULED, not per-PR, deliberately: the stall arrives when a DIFFERENT pull request merges, so the +# affected PR has no run in flight to hang a check on. It becomes true while the repo is idle. +# +# ADVISORY BY PLACEMENT — this must never become a required context. It reports on OTHER pull requests, +# so a stall on #71 would block #128, which is both wrong and a way to wedge the repo with the very +# tool meant to unwedge it. See .github/required-contexts.txt for the required-but-absent trap. +# +# This does NOT fix the race; only a merge queue does. It converts a SILENT failure into a LOUD one, +# which is the part that let #74 sit for days. If a merge queue is enabled, this goes quiet on its own. +on: + schedule: + # 07:05 UTC — just after `Required workflow state`, so the two merge-health checks report together. + - cron: "5 7 * * *" + workflow_dispatch: + +permissions: + contents: read + +jobs: + stalled: + name: open PRs can still reach a merge + runs-on: ubuntu-latest + permissions: + contents: read + pull-requests: read # list PRs + their merge state; no write scope anywhere + steps: + - uses: actions/checkout@3d3c42e5aac5ba805825da76410c181273ba90b1 # v7.0.1 + with: + persist-credentials: false + - uses: actions/setup-python@5fda3b95a4ea91299a34e894583c3862153e4b97 # v7.0.0 + with: + python-version: "3.14" + # No pip install: the script is stdlib-only and shells out to `gh`, which is preinstalled on the + # runner. Nothing here parses the repo, so there is no PyYAML dependency to pin. + - name: Report pull requests that are green but cannot merge + env: + GH_TOKEN: ${{ github.token }} + run: python scripts/ci/check_stalled_prs.py --repo "$GITHUB_REPOSITORY" diff --git a/scripts/ci/check_stalled_prs.py b/scripts/ci/check_stalled_prs.py new file mode 100644 index 00000000..081efb6f --- /dev/null +++ b/scripts/ci/check_stalled_prs.py @@ -0,0 +1,220 @@ +#!/usr/bin/env python3 +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""A pull request can be finished, green, armed to merge — and unable to merge, forever, silently. + +THE DEFECT THIS EXISTS FOR — measured on this repo, 2026-08-01. Nine open pull requests had zero +failing checks and zero pending checks. Not one of them could merge. Six had auto-merge ARMED, which +will never fire. PR #74 had been sitting in that state since 2026-07-30 and was found only because +somebody went looking for "stuck CI" by hand. + +THE MECHANISM. Branch protection sets ``required_status_checks.strict = true`` (a PR must be up to +date with ``main`` to merge) and there is no merge queue. The suite takes ~20 minutes. So a PR that +goes green has to win a race: it must finish while ``main`` holds still. When it loses — when anything +else lands first — it flips to ``BEHIND`` and stops. Armed auto-merge does NOT update a ``BEHIND`` +branch; it only waits on checks, which are already green. Nothing re-syncs it. Nothing reports it. + +WHY NOTHING ELSE CATCHES IT. Every existing signal is a check outcome, and no check has failed — that +is the whole problem. ``statusCheckRollup`` is all green, ``nightly-notice.yml`` watches CI runs (there +is no failing run), and the author has no reason to look because their last signal was a full pass. +The state is indistinguishable from "merging shortly" except by asking a question nobody asks: +*is this PR still able to merge at all?* A green dashboard and a wedged repository look identical. + +THE SIGNATURE is exact and decidable from one API call:: + + state = OPEN AND mergeStateStatus = BEHIND AND failing = 0 AND pending = 0 + +An ARMED PR matching it is worse than an unarmed one: the arming is a promise to the author that it +will land by itself, and that promise is false. Unarmed matches are merely waiting on a human. + +WHAT THIS DOES NOT FIX. The race itself. Only a merge queue removes it — this converts a SILENT +failure into a LOUD one, which is the part that let #74 sit for days. If a merge queue is enabled, +this check costs nothing and goes quiet on its own. + +WHY SCHEDULED AND NOT PER-PR. The stall arrives when a DIFFERENT pull request merges, so the affected +PR has no run in flight and nothing to hang a per-PR check on. It becomes true while the repository is +idle, which is exactly when nobody is looking. + +USAGE + python scripts/ci/check_stalled_prs.py # uses gh's auth + python scripts/ci/check_stalled_prs.py --repo owner/name + python scripts/ci/check_stalled_prs.py --prs-json prs.json # offline/testing + python scripts/ci/check_stalled_prs.py --warn-only # report, always exit 0 +""" + +from __future__ import annotations + +import argparse +import json +import subprocess +import sys +from dataclasses import dataclass +from pathlib import Path + +#: The merge state that means "head is behind base". GitHub computes this server-side; it is not +#: derivable from the check rollup, which is why the rollup alone cannot see this defect. +_BEHIND = "BEHIND" + +#: Conclusions that count as a failure. A stalled PR has NONE of these — that is the point. +_FAILING = frozenset({"FAILURE", "TIMED_OUT", "CANCELLED", "ACTION_REQUIRED", "STARTUP_FAILURE"}) + +#: Statuses that mean a check has not settled yet. +_UNSETTLED = frozenset({"QUEUED", "IN_PROGRESS", "WAITING", "PENDING", "REQUESTED"}) + +#: The fields this check needs. Kept beside the parser so the two cannot drift. +PR_FIELDS = "number,title,state,mergeStateStatus,autoMergeRequest,statusCheckRollup,headRefName" + + +@dataclass(frozen=True) +class Stall: + """One pull request that is green and cannot merge.""" + + number: int + title: str + branch: str + armed: bool + + def line(self) -> str: + # ASCII only: this string lands in GitHub Actions annotations and in operator consoles whose + # code page is cp1252, where a non-ASCII dash renders as a replacement char. + flag = "ARMED -- auto-merge will never fire" if self.armed else "not armed" + return f"#{self.number} [{self.branch}] {self.title[:60]} ({flag})" + + +def _counts(rollup: object) -> tuple[int, int]: + """``(failing, unsettled)`` over a ``statusCheckRollup`` payload. + + Tolerates both node shapes GitHub returns: CheckRun (``status``/``conclusion``) and StatusContext + (``state``). A node whose shape is unrecognised is counted as UNSETTLED rather than ignored — + "I could not classify this" must not read as "this is green", which is the failure mode this whole + script exists to catch. + """ + if not isinstance(rollup, list): + return (0, 0) + failing = unsettled = 0 + for node in rollup: + if not isinstance(node, dict): + unsettled += 1 + continue + status = str(node.get("status") or "").upper() + conclusion = str(node.get("conclusion") or "").upper() + state = str(node.get("state") or "").upper() + verdict = conclusion or state + if status in _UNSETTLED or state in _UNSETTLED: + unsettled += 1 + elif verdict in _FAILING: + failing += 1 + elif not verdict and not status: + unsettled += 1 + return (failing, unsettled) + + +def scan(prs: list[dict[str, object]]) -> list[Stall]: + """Every open PR matching the stall signature, most recently opened first. + + Pure: no network, no git. The CLI supplies the payload so tests drive THIS function rather than a + re-implementation of the rule — a test asserting a copy of the rule proves nothing about the rule. + """ + found: list[Stall] = [] + for pr in prs: + if str(pr.get("state") or "").upper() != "OPEN": + continue + if str(pr.get("mergeStateStatus") or "").upper() != _BEHIND: + continue + failing, unsettled = _counts(pr.get("statusCheckRollup")) + if failing or unsettled: + continue + # Narrow rather than coerce: int() would raise, turning a surprising payload into a + # crash instead of a finding. A PR whose number is unreadable still gets reported, as #0. + raw_number = pr.get("number") + found.append( + Stall( + number=raw_number if isinstance(raw_number, int) else 0, + title=str(pr.get("title") or ""), + branch=str(pr.get("headRefName") or ""), + armed=pr.get("autoMergeRequest") is not None, + ) + ) + return sorted(found, key=lambda s: s.number, reverse=True) + + +def _fetch(repo: str | None, prs_json: Path | None) -> list[dict[str, object]]: + if prs_json is not None: + payload = json.loads(prs_json.read_text(encoding="utf-8")) + return list(payload) if isinstance(payload, list) else [] + cmd = ["gh", "pr", "list", "--state", "open", "--limit", "100", "--json", PR_FIELDS] + if repo: + cmd += ["--repo", repo] + # B603: fixed argv, no shell. The only variable element is --repo, an operator-typed CLI argument + # on a CI runner — not message, config, or network data. Same posture as + # check_required_workflow_state.py; see the note there. + out = subprocess.run( # noqa: S603 # nosec B603 — fixed argv, no shell, operator-supplied repo + cmd, capture_output=True, text=True, timeout=180 + ) + if out.returncode != 0: + raise RuntimeError(f"gh pr list failed ({out.returncode}): {out.stderr.strip()[:400]}") + payload = json.loads(out.stdout) + return list(payload) if isinstance(payload, list) else [] + + +def main(argv: list[str] | None = None) -> int: + parser = argparse.ArgumentParser( + description=__doc__, formatter_class=argparse.RawDescriptionHelpFormatter + ) + parser.add_argument("--repo", default=None, help="owner/name; defaults to gh's current repo") + parser.add_argument("--prs-json", type=Path, default=None, help="a saved payload (testing)") + parser.add_argument( + "--warn-only", + action="store_true", + help="report and exit 0 — for adoption, before the backlog of existing stalls is cleared", + ) + args = parser.parse_args(argv) + + try: + prs = _fetch(args.repo, args.prs_json) + except (RuntimeError, json.JSONDecodeError, subprocess.SubprocessError, OSError) as exc: + # FAIL CLOSED. "I could not list the PRs" must never render as "nothing is stalled" — that is + # this script's own defect class, one level up. + print( + f"::error::could not list pull requests ({exc!r}). Treating as a FAILURE.", + file=sys.stderr, + ) + return 2 + + stalls = scan(prs) + armed = [s for s in stalls if s.armed] + + # Liveness receipt: say what was EXAMINED. "no stalls" and "nothing was scanned" are otherwise + # indistinguishable from the exit code, and an empty sweep reporting success is the exact shape + # this check is meant to make impossible. + print(f"stalled-prs: scanned {len(prs)} open pull request(s); {len(stalls)} stalled") + if not prs: + print( + "::error::ZERO open pull requests came back. That is a broken query, not a clean repo — " + "refusing to report success.", + file=sys.stderr, + ) + return 2 + + if not stalls: + print("stalled-prs: every open PR can still reach a merge.") + return 0 + + for stall in stalls: + print(f"::warning::green but cannot merge: {stall.line()}") + + if armed: + print( + f"::error::{len(armed)} pull request(s) are green, ARMED for auto-merge, and BEHIND. Armed " + "auto-merge does not update a BEHIND branch -- it waits on checks that already passed, so " + "these will never merge and nothing else will say so. Re-sync each from the base branch " + "(merge or rebase, then push) and it will land. The durable fix is a merge queue, which " + "removes the race these are losing.", + file=sys.stderr, + ) + + return 0 if args.warn_only else (1 if armed else 0) + + +if __name__ == "__main__": + raise SystemExit(main()) diff --git a/tests/test_stalled_prs.py b/tests/test_stalled_prs.py new file mode 100644 index 00000000..9bb83c2d --- /dev/null +++ b/tests/test_stalled_prs.py @@ -0,0 +1,172 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""The stalled-PR check must fire on the real shape and stay silent on everything adjacent to it. + +These drive the REAL ``scan()`` and the REAL ``main()`` against payloads, not a re-statement of the +rule. The distinction matters more than usual here: this check exists because a green signal was +mistaken for a healthy one, so a test that cannot demonstrate the check FAILING would reproduce the +very defect it guards. +""" + +from __future__ import annotations + +import importlib.util +import json +import sys +from pathlib import Path +from types import ModuleType +from typing import Any + +import pytest + +_ROOT = Path(__file__).resolve().parents[1] +_SCRIPT = _ROOT / "scripts" / "ci" / "check_stalled_prs.py" + + +def _load() -> ModuleType: + spec = importlib.util.spec_from_file_location("check_stalled_prs", _SCRIPT) + assert spec is not None and spec.loader is not None + mod = importlib.util.module_from_spec(spec) + sys.modules[spec.name] = mod + spec.loader.exec_module(mod) + return mod + + +sp = _load() + + +def _pr( + number: int = 1, + *, + state: str = "OPEN", + merge_state: str = "BEHIND", + armed: bool = True, + # Deliberately list[Any], not list[dict[...]]: one test feeds a NON-dict node to prove an + # unreadable rollup entry is not silently treated as green. + rollup: list[Any] | None = None, +) -> dict[str, Any]: + """A PR payload defaulting to the STALL shape, so each test perturbs exactly one field.""" + return { + "number": number, + "title": f"pr {number}", + "headRefName": f"branch-{number}", + "state": state, + "mergeStateStatus": merge_state, + "autoMergeRequest": {"mergeMethod": "SQUASH"} if armed else None, + "statusCheckRollup": [{"status": "COMPLETED", "conclusion": "SUCCESS", "name": "t"}] + if rollup is None + else rollup, + } + + +# --- the positive control: it MUST fire ------------------------------------------------------------ + + +def test_the_exact_stall_shape_is_detected() -> None: + """Open + BEHIND + nothing failing + nothing pending. This is #74 and the six armed PRs.""" + found = sp.scan([_pr(74)]) + assert [s.number for s in found] == [74] + assert found[0].armed is True + + +def test_an_unarmed_stall_is_still_reported() -> None: + """Unarmed is still unmergeable — it just isn't lying to its author about it.""" + found = sp.scan([_pr(60, armed=False)]) + assert [s.number for s in found] == [60] + assert found[0].armed is False + + +# --- the negative controls: each must NOT fire ----------------------------------------------------- + + +@pytest.mark.parametrize("conclusion", ["FAILURE", "TIMED_OUT", "CANCELLED", "ACTION_REQUIRED"]) +def test_a_failing_check_is_not_a_stall(conclusion: str) -> None: + """A red PR is already loud. This check is only for the ones nothing else reports.""" + rollup = [{"status": "COMPLETED", "conclusion": conclusion, "name": "t"}] + assert sp.scan([_pr(rollup=rollup)]) == [] + + +@pytest.mark.parametrize("status", ["QUEUED", "IN_PROGRESS"]) +def test_a_pending_check_is_not_a_stall(status: str) -> None: + """Mid-suite is the normal path to green, not a stall — and it is where BEHIND flaps.""" + assert sp.scan([_pr(rollup=[{"status": status, "conclusion": None, "name": "t"}])]) == [] + + +@pytest.mark.parametrize("merge_state", ["CLEAN", "BLOCKED", "DIRTY", "UNKNOWN", "UNSTABLE"]) +def test_only_behind_counts(merge_state: str) -> None: + """BLOCKED means checks aren't green yet; DIRTY is a conflict. Neither is this defect.""" + assert sp.scan([_pr(merge_state=merge_state)]) == [] + + +@pytest.mark.parametrize("state", ["CLOSED", "MERGED"]) +def test_a_closed_pr_is_not_a_stall(state: str) -> None: + assert sp.scan([_pr(state=state)]) == [] + + +# --- the shape that made the original bug invisible ------------------------------------------------ + + +def test_an_unclassifiable_node_counts_as_unsettled_not_green() -> None: + """A node we cannot read must never be silently treated as passing. + + This is the script's own defect class turned inward: 'I could not classify this' rendering as + 'this is fine' is precisely how a green signal stops meaning anything. + """ + assert sp.scan([_pr(rollup=[{"weird": "shape"}])]) == [] + assert sp.scan([_pr(rollup=["not-a-dict"])]) == [] + + +def test_statuscontext_nodes_are_understood() -> None: + """GitHub returns two node shapes; a StatusContext carries `state`, not `status`/`conclusion`.""" + assert sp.scan([_pr(rollup=[{"state": "SUCCESS", "context": "legacy"}])]) != [] + assert sp.scan([_pr(rollup=[{"state": "FAILURE", "context": "legacy"}])]) == [] + assert sp.scan([_pr(rollup=[{"state": "PENDING", "context": "legacy"}])]) == [] + + +# --- exit codes, driven through main() ------------------------------------------------------------- + + +def _run(tmp_path: Path, prs: list[dict[str, Any]], *argv: str) -> int: + payload = tmp_path / "prs.json" + payload.write_text(json.dumps(prs), encoding="utf-8") + return int(sp.main(["--prs-json", str(payload), *argv])) + + +def test_armed_stalls_fail_the_check(tmp_path: Path) -> None: + assert _run(tmp_path, [_pr(74), _pr(96)]) == 1 + + +def test_unarmed_stalls_alone_do_not_fail(tmp_path: Path) -> None: + """Unarmed stalls warn. They need a human, but nothing is falsely promising to merge them.""" + assert _run(tmp_path, [_pr(60, armed=False)]) == 0 + + +def test_warn_only_never_fails(tmp_path: Path) -> None: + assert _run(tmp_path, [_pr(74)], "--warn-only") == 0 + + +def test_a_healthy_repo_passes(tmp_path: Path) -> None: + assert _run(tmp_path, [_pr(1, merge_state="CLEAN"), _pr(2, merge_state="BLOCKED")]) == 0 + + +def test_an_empty_result_fails_closed(tmp_path: Path) -> None: + """Zero PRs is a broken query, not a clean repo. + + The repo has had open PRs continuously; a sweep that finds none has failed to look. Reporting + success there is the 'nothing pending means all settled' error this codebase keeps re-learning. + """ + assert _run(tmp_path, []) == 2 + + +def test_an_unreadable_payload_fails_closed(tmp_path: Path) -> None: + bad = tmp_path / "bad.json" + bad.write_text("{not json", encoding="utf-8") + assert int(sp.main(["--prs-json", str(bad)])) == 2 + + +def test_the_receipt_names_what_was_scanned( + tmp_path: Path, capsys: pytest.CaptureFixture[str] +) -> None: + """'no stalls' and 'nothing was examined' must not be indistinguishable.""" + _run(tmp_path, [_pr(1, merge_state="CLEAN")]) + assert "scanned 1 open pull request" in capsys.readouterr().out From 87f9fdf8d76fa11db9dfe828dcdf209f07707dfd Mon Sep 17 00:00:00 2001 From: wshallwshall Date: Sat, 1 Aug 2026 18:51:23 -0500 Subject: [PATCH 2/3] ci: raise the Windows step cap, which had 1.06x margin while claiming 2x PR #119 was killed at 26:07 against ci.yml's 26:00 `step_timeout` with ZERO tests failing. What moved was the suite, not the code under test: #74 landed tests/test_worktree_prune_merged.py (1,506 lines) and windows-2025 went 19:35 -> 26:07 on the same branch. The comment beside the cap said the Windows legs were "unchanged because 26 min against the same suite is still ~2x headroom". Measured over the 11 PASSING windows-2025 runs on 2026-08-01: leg max passing step old cap old margin ubuntu-latest 12:27 19:00 1.53x windows-2022 18:39 26:00 1.39x windows-2025 24:35 26:00 1.06x windows-2025 had already PASSED at 24:35 -- 85 seconds of margin -- before #119 died. The "2x" figure matched no leg when it was written. The same file records this exact failure happening on the ubuntu leg on 2026-07-31 (775s green against a 780s cap) and concludes a watchdog that cannot separate "deadlocked" from "slow today" becomes a coin flip; ubuntu's budget was raised then and Windows was left alone on the false claim. Raised to step_timeout 36 (1.46x over the 24:35 max) and job_timeout 40, preserving the nesting invariant that the step must expire strictly before the job. Both Windows legs take the same number: windows-2022 is faster, so sizing on windows-2025 only leaves it more room. The replacement comment states the measured value and its date rather than a multiple -- a bare multiple is what let this rot undetected. Timing note recorded in the comment because it cost two sessions an error during triage: step_timeout gates the STEP, not the job. c53f752b's JOB ran 28:41 and PASSED, against job cap 30 / step cap 26. Also files BACKLOG #340 (enable a merge queue -- 9 green PRs could not merge, 6 armed and never firing) and #344 (fixed wall-clock bounds as a class, with this cap as instance 1 and test_stage_dispatcher.py's hardcoded 8.0s poll budget against an injected ManualClock as instance 2). COORDINATION: ci.yml and docs/BACKLOG.md were each held by another live session, and the collision gate (scripts/hooks/collision_gate.ps1) refuses an Edit while a live session's BRANCH carries a diff to the file -- it cannot represent "coordinated, verified disjoint". Both counterparties gave explicit written consent before these edits were applied outside the Edit tool: zizmor-1280-adoption ("You land it. I'm standing down on ci.yml timeouts", its only hunk being a one-line pin comment ~160 lines away) and ha-construct-pickle-sandbox ("Go ahead with #340 now -- append after #338 exactly as you planned. I'll absorb the conflict"). No hooks were skipped; this commit ran the full pre-commit suite. --- .github/workflows/ci.yml | 41 ++++++++++++++++++++++--- docs/BACKLOG.md | 66 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 103 insertions(+), 4 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index c28844ef..fd4280d3 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -222,8 +222,41 @@ jobs: # green in 775s against a 780s cap -- 5s of margin -- and the step was killed anyway, reported as # a failure on a run whose last line was "9598 passed, 855 skipped". A watchdog that cannot # separate "deadlocked" from "slow today" stops being a watchdog and becomes a coin flip, so the - # ubuntu budget is raised here. Re-check the margin when the suite grows; the Windows legs are - # unchanged because 26 min against the same suite is still ~2x headroom. + # ubuntu budget is raised here. Re-check the margin when the suite grows. + # + # It then happened again on WINDOWS, 2026-08-01, because the sentence that used to close this + # paragraph asserted the Windows legs held "~2x headroom" and nobody re-derived it. PR #119 was + # killed at 26:07 against the 26:00 cap with ZERO tests failing. What moved was the suite, not the + # code under test: #74 landed tests/test_worktree_prune_merged.py (1,506 lines) and windows-2025 + # went 19:35 -> 26:07 on the same branch. The claim was already false when it was written. + # + # Measured over the 11 PASSING windows-2025 runs on 2026-08-01, timing the `Tests (pytest)` STEP, + # which is what step_timeout gates. NOT the job: the job is ~3 min longer and capped separately, + # and two sessions misread job durations as step durations while triaging this (c53f752b's JOB ran + # 28:41 and PASSED, because job cap 30 vs step cap 26). + # + # leg max passing step old cap old margin + # ubuntu-latest 12:27 19:00 1.53x + # windows-2022 18:39 26:00 1.39x + # windows-2025 24:35 26:00 1.06x + # + # windows-2025 had already PASSED at 24:35 -- 85 seconds of margin -- before #119 died. The "2x" + # figure matched no leg. State the MEASURED value and its DATE, never a round multiple: a bare + # multiple gives the next reader no way to tell when it has rotted, which is how this one survived. + # + # 36:00 is 1.46x over that 24:35 maximum -- the margin ubuntu already runs with. Both Windows legs + # take the same number: windows-2022 is the faster of the two, so sizing on windows-2025 only + # leaves it more room, and one value is one thing to re-derive. job_timeout moves 30 -> 40 to keep + # the nesting invariant above: the step must still expire strictly BEFORE the job. + # + # This cap is NOT what catches a hung test; pytest_timeout (120s) is, per test. The step cap only + # catches a whole-process deadlock both in-process watchdogs miss, which is why it can sit well + # above a healthy run. Sizing it tight buys no detection and costs false failures on green suites, + # twice now. + # + # The remaining margin is a SHARED budget across every PR that lands and nothing accounts for it: + # three PRs each adding a minute of Windows time reproduce #119's death, individually blameless. + # A mechanical guard for that is BACKLOG #341; the underlying slowness is #320. - name: Tests (pytest) if: needs.changes.outputs.code == 'true' || github.event_name == 'push' || github.event_name == 'workflow_dispatch' timeout-minutes: ${{ matrix.step_timeout }} @@ -382,8 +415,8 @@ jobs: # expression interpolation into the run body), so it is zizmor-safe and cannot be misparsed as # an Actions expression the way a literal double-brace token in a run: block would be. U='{"os":"ubuntu-latest","python-version":"3.14","hosted":["ubuntu-latest"],"job_timeout":22,"step_timeout":19,"pytest_timeout":60,"fault_timeout":90}' - W22='{"os":"windows-2022","python-version":"3.14","hosted":["windows-2022"],"job_timeout":30,"step_timeout":26,"pytest_timeout":120,"fault_timeout":150}' - W25='{"os":"windows-2025","python-version":"3.14","hosted":["windows-2025"],"job_timeout":30,"step_timeout":26,"pytest_timeout":120,"fault_timeout":150}' + W22='{"os":"windows-2022","python-version":"3.14","hosted":["windows-2022"],"job_timeout":40,"step_timeout":36,"pytest_timeout":120,"fault_timeout":150}' + W25='{"os":"windows-2025","python-version":"3.14","hosted":["windows-2025"],"job_timeout":40,"step_timeout":36,"pytest_timeout":120,"fault_timeout":150}' if [ "${GITHUB_REPOSITORY:-}" = "MEFORORG/MessageFoundry" ]; then echo "matrix={\"include\":[$U,$W22,$W25]}" >> "$GITHUB_OUTPUT" else diff --git a/docs/BACKLOG.md b/docs/BACKLOG.md index 2371d9ce..43d8a665 100644 --- a/docs/BACKLOG.md +++ b/docs/BACKLOG.md @@ -8242,3 +8242,69 @@ Separately: the docstring argues *"the return value is the point"*, but all six **Source:** public-repo disclosure audit, 2026-08-01. Re-verified and re-measured at HEAD on the same date. --- + +## 340. Enable a GitHub merge queue: strict + no queue makes every merge a race that fails silently + +> 🔢 **Filed 2026-08-01 — not started.** Value **8/10** · Difficulty **3/10** · _fill-in_. `strict = true` with no merge queue and a ~20-minute suite means a PR must go green *and* have `main` hold still, or it flips to `BEHIND` and stops. Measured this date: **9 open PRs green (0 failing, 0 pending) and none able to merge**, 6 with auto-merge armed that will never fire. + +**Cluster:** Developer Experience & CI. **Priority:** P2. **Verdict:** build. **Severity:** medium. + +**What:** branch protection on `main` sets `required_status_checks.strict = true` — a PR must be up to date with the base to merge — and the repo has **no merge queue** (`repository.mergeQueue` is null; `allow_auto_merge` is true). The slowest required leg runs ~20–25 minutes. Those three facts compose into a race: a PR is mergeable only in the window between its checks going green and the next thing landing on `main`. + +Losing that race is **silent**. Armed auto-merge does *not* update a `BEHIND` branch — it waits on checks that already passed — so the PR sits armed and stalled with no failing check, no notification, and no run in flight. Measured 2026-08-01: + +``` +PR mergeState failing pending auto-merge +#128 BEHIND 0 0 ARMED +#125 BEHIND 0 0 ARMED +#107 BEHIND 0 0 - +#106 BEHIND 0 0 ARMED +#101 BEHIND 0 0 ARMED +#96 BEHIND 0 0 ARMED +#71 BEHIND 0 0 ARMED +#60 BEHIND 0 0 - +``` + +(Nine at the hand survey; eight when [`check_stalled_prs.py`](../scripts/ci/check_stalled_prs.py) ran ~20 minutes later, because #120 had been re-synced in between. The set moves — the condition does not.) + +Two worked instances the same day. **#74** went green on 2026-07-30 and sat unmergeable until 2026-08-01, found only by someone hunting "stuck CI" by hand; it took three merges from `main` to land. **#119** was green with 25 passing checks and armed, stalled, was re-synced, and lost the window again. A hand-coordinated merge freeze across five sessions *did* hold `main` still for a full window — and #119 still failed, on an unrelated timeout (#344) — which is the evidence that hand coordination is not the fix. + +**Why:** the cost is finished work sitting undelivered while everyone believes it is landing. This is the repo's recurring defect shape — a signal accurate about what it looks at and silent about what it does not ([`Secure_Development_Standards`](Secure_Development_Standards.md) §3) — but the worst variant, because every other instance has *someone waiting on a result*. Here the author already had their full pass and has no reason to look again. It also scales the wrong way: the more sessions working in parallel, the more often `main` moves, so the race gets harder to win exactly as throughput rises. + +**Proposed:** +1. Enable a merge queue on `main` (branch protection → *Require merge queue*), squash method to match the existing history. +2. Reconcile the required set against it: a queue runs checks on a `gh-readonly-queue/**` ref, so any workflow that must gate the queue needs a `merge_group:` trigger. Every context in [`.github/required-contexts.txt`](../.github/required-contexts.txt) lacking one will never report there — that file's own required-but-absent trap, in a new place. +3. Decide the interaction with `strict = true`. A queue makes it largely redundant; leaving both on is safe but keeps the re-sync burden for anything bypassing the queue. +4. Once landed, [`check_stalled_prs.py`](../scripts/ci/check_stalled_prs.py) goes quiet on its own. Keep it — it is the detector for this class returning. + +**Related:** [`scripts/ci/check_stalled_prs.py`](../scripts/ci/check_stalled_prs.py) + [`.github/workflows/stalled-prs.yml`](../.github/workflows/stalled-prs.yml) (built alongside this filing — it reports the condition, it does not remove it); [`.github/required-contexts.txt`](../.github/required-contexts.txt); [`scripts/ci/check_required_workflow_state.py`](../scripts/ci/check_required_workflow_state.py) (sibling: "can this context ever report?" to this one's "can this PR ever merge?"); #344 (the wall-clock bounds that actually killed #119); #320. + +**Source:** stuck-CI triage, 2026-08-01. Measured live against `MEFORORG/MessageFoundry` branch protection and the open-PR set that date; independently reached by three parallel sessions from separate evidence. + +--- + +## 344. Fixed wall-clock bounds have drifted out of proportion to the work they bound + +> 🔢 **Filed 2026-08-01 — not started.** Value **6/10** · Difficulty **4/10** · _fill-in_. Hardcoded real-time budgets — a CI `step_timeout`, a test helper's poll deadline — were sized when the work was smaller or the machine faster, and nothing re-derives them. Two confirmed instances; each presents as an unrelated flake. + +**Cluster:** Developer Experience & CI. **Priority:** P2. **Verdict:** build. **Severity:** medium. + +**What:** a fixed wall-clock bound with no relationship to the work it bounds fails the day the work grows, and it fails as a **timeout with zero assertion failures** — which reads as a broken branch when nothing is broken. + +*Instance 1 (fixed 2026-08-01, this filing).* `ci.yml`'s Windows `step_timeout: 26`. windows-2025's max PASSING `Tests (pytest)` step was **24:35** over 11 runs — 1.06x margin — and PR #119 was killed at 26:07 with zero test failures after #74 added a 1,506-line test file. The comment beside the cap asserted "~2x headroom", a figure that matched no leg. Raised to 36:00 (1.46x) with the measurement and its date recorded in place of the multiple. + +*Instance 2 (open).* `tests/test_stage_dispatcher.py`'s `_wait_until` (:356) polls `loop.time()` against a hardcoded **8.0s** budget while the dispatcher under test is driven by an injected `ManualClock`. On PR #129 — whose diff is provably AST-identical to main, docstrings only — `test_adr0070_9_content_retry_is_not_an_infra_fault[sqlserver]` failed on that bound alone against a Dockerised SQL Server; every logic assertion in the same loop passed. A real-time deadline gating a virtual-clock system has no principled value. + +**Why:** these fail *individually blameless*. The remaining CI margin is a **shared budget nobody accounts for** — three PRs each adding a minute of Windows time reproduce #119's death, with no single PR at fault. And this repo has twice mislabelled such a failure: the two famous "flakes" turned out to be a livelock and a test that was right. A timeout with no failing assertion is the exact signature that invites the wrong diagnosis. + +**Proposed:** +1. **A mechanical margin check** (suggested by the ASVS-scorecard session, whose framing this is): compare each leg's actual `Tests (pytest)` step duration against its configured `step_timeout` and fail below ~1.3x. Computable from data CI already emits. It would have flagged windows-2025 *before* #119 died — it was already at 1.06x and nothing said a word — and unlike the "re-check the margin when the suite grows" instruction in `ci.yml`, it does not depend on anyone remembering. Two traps for whoever builds it: time the **STEP**, not the job (the job is ~3 min longer with its own cap — `c53f752b`'s job ran 28:41 and passed against job cap 30 / step cap 26, and two sessions misread job for step while triaging this); and size against the **max passing** run, not the mean (windows-2025's mean ~21 min looks comfortable, its max passing 24:35 is what bites). +2. Size the remaining bounds: `grep` hardcoded `timeout=` / deadline floats under `tests/` and judge each against the work it bounds. +3. Where a virtual clock drives the system under test, the poll deadline should follow that clock, not `loop.time()` — instance 2 is the worked example. +4. Prefer bounds expressed as a measured ratio with a date over round multiples, per instance 1's post-mortem. + +**Related:** [`.github/workflows/ci.yml`](../.github/workflows/ci.yml) §*Tests (pytest)* (instance 1 and its measurement table); `tests/test_stage_dispatcher.py`:356 (instance 2); #320 (windows-2025 slowness — the capacity fact that shrinks every Windows margin); #340 (the other half of this triage); [`Secure_Development_Standards`](Secure_Development_Standards.md) §3 (prose asserting a margin the numbers do not support — five instances found on 2026-08-01 alone). + +**Source:** stuck-CI triage, 2026-08-01. Instance 1 measured across 11 windows-2025 runs; instance 2 reported and diagnosed by the HA-construct-recheck session from PR #129's sqlserver leg. + +--- From 7c800a66b91d919baccb9e024d930b561237c012 Mon Sep 17 00:00:00 2001 From: wshallwshall Date: Sat, 1 Aug 2026 19:05:44 -0500 Subject: [PATCH 3/3] ci: record that #119's leg passed on a re-run at the same cap The ADR-0154 session re-ran #119's windows-2025 leg on the SAME commit against the SAME 26:00 cap. Attempt 1 was killed at the cap; attempt 2 concluded success. Same code, same config, same ceiling, two outcomes. This closes the one gap in the case for raising the cap: it rules out "that PR's tests are just slow". The leg was not failing, it was coin-flipping against the ceiling -- which is precisely the state the ubuntu note above already names, now demonstrated rather than argued. It also disposes of "re-run it and see" as a diagnosis. A green re-run at 26:00 does not show the suite fits; it shows that runner was fast enough that time. Recorded in the comment so the next person reaching for a retry knows what a green retry does and does not prove. Evidence contributed by the session holding #119, which is deliberately holding its branch update until this lands so it re-rolls under the raised cap rather than spending another coin flip at 26. Merged main (8f01cef8, #120) in the same push: #131 had gone BEHIND, which is the stall this PR exists to report -- the fix for the cap has to survive the cap, and the fix for silent stalls can itself stall silently. --- .github/workflows/ci.yml | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index fd4280d3..bbc5f74f 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -244,6 +244,13 @@ jobs: # figure matched no leg. State the MEASURED value and its DATE, never a round multiple: a bare # multiple gives the next reader no way to tell when it has rotted, which is how this one survived. # + # PROOF IT WAS THE CAP, NOT THE BRANCH. #119's windows-2025 leg was RE-RUN on the SAME commit + # against the SAME 26:00 cap: attempt 1 was killed at the cap, attempt 2 concluded SUCCESS. Same + # code, same config, same ceiling, two outcomes. The leg was not failing -- it was coin-flipping + # against the cap, exactly the state the ubuntu note above names, and the reason "re-run it and + # see" is not a diagnosis here. A green re-run at 26:00 does not mean the suite fits; it means + # that runner was fast enough that time. + # # 36:00 is 1.46x over that 24:35 maximum -- the margin ubuntu already runs with. Both Windows legs # take the same number: windows-2022 is the faster of the two, so sizing on windows-2025 only # leaves it more room, and one value is one thing to re-derive. job_timeout moves 30 -> 40 to keep