Skip to content

Commit 8d16c0b

Browse files
wshallwshallwshallwshallclaude
authored
fix(ci): read the ci-red label back, and unflake the arm that ejected PR 669 (BACKLOG #1385) (#789)
* fix(ci): read the ci-red label back, and unflake the arm that ejected PR 669 (BACKLOG #1385) THE CENSUS IN #1385 IS WRONG BY ONE. There were FOUR failing merge_group CI runs on PR 669, not three. An unpaginated per_page=100 query returns 100 of total_count 190 and silently drops half the population; --paginate finds 33249679477, 33250553925, 33253197221 and 33253973185. Each is attributed below from its own job log, not inferred. 11:15:01Z test (windows-2025) hung 55 min, no FAILED line 11:37:13Z test (windows-2025) test_a_fast_handler_is_untouched -- assert 503 == 200 12:42:51Z windows + sql server 2022 hostile-disposition ratio; cipher-invocations upsert 13:01:54Z windows + sql server 2025 dr/connscale; cipher-invocations upsert So "three DIFFERENT reasons with no overlap" is not what the logs say: the SQL Server test failed in BOTH of the last two runs, identically. TWO THINGS BUILT. 1. tests/test_api_request_timeout.py. The 0.1s deadline is gone from the arms asserting a prompt handler is UNTOUCHED -- the arm that actually ejected #669 at 11:37 with assert 503 == 200. A trivial handler's real cost is ~1ms, so 0.1s was not a margin, it was inside the range of a GC pause on a shared runner. The arms asserting the bound FIRES keep 0.1s, because there the margin runs the forgiving way: a stall can only delay a refusal, never turn it into a pass. Raising it costs no discrimination, and that is checked rather than asserted. Mutation A (refuse unconditionally) reds test_a_fast_handler_is_untouched at the new 5.0s deadline: 3 failed, 6 passed. While in the file: test_a_disabled_deadline_lets_a_slow_handler_finish asked the FAST route, so it could not fail for its stated reason. It asks the slow route now. Proven with a controlled arm -- Mutation B (clamp a disabled deadline instead of disabling it) with the NEW body reds 1 of 9; with the OLD body, same mutation, 9 passed. One variable, mutation held constant. 2. scripts/ci/report_ci_red.py plus 15 tests. failure-signal.yml has written the ci-red label since PR #716 and nothing read it. This reads it back and names the run, marking merge_group runs as NOT VISIBLE ON THE PR PAGE -- which is the finding, because that is the state PR 669 was in. It copies three rules from the writer on purpose: the watched workflow list, failure-only (a cancelled run is not a red), and the attribution order -- pull_requests[0] first, then the pr-<N> ref parse GATED ON event == merge_group. That gate is a security control: a branch name is chosen by whoever opens the branch, and a fork cannot raise a merge_group event. Mutation C (drop the gate) reds the spoof test; mutation D (count cancelled) reds the cancellation test. Proven firing, not just unit-tested. Live against this repo it found PR 764, attributed it to backlog-hygiene run 33802457076, exit 1 -- verified against the API (event=pull_request, pull_requests=[764]). Against PR 669's real captured runs it reports the merge_group ejection and the hidden-run error. ALREADY FIXED BY #738, NOT REBUILT HERE. test_cipher_invocations_upsert_is_atomic_and_additive failed StoreAcquireTimeout after 30s because the aioodbc pool shared the loop's default executor (8 threads on a 4-vCPU runner) against pool_size 40, so 20 concurrent upserts deadlocked on the executor queue. cc5e09e (2026-09-02) gave the store its own executor and names this exact test and error. STILL OPEN. test_hostile_disposition_header_parses_in_linear_time was waved through as "already a ratio assertion". It is one, and it ejected #669 anyway, at ratio 8.02 against a bound of 8.0. Left alone per the brief; recorded in the item because the dismissal does not survive the log. ruff, ruff format and mypy strict clean; 57 tests green across the touched and neighbouring suites. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> * test(tooling): classify the new harness test in the manifest tests/test_tooling_partition.py::test_every_non_engine_test_is_classified reds all three required test legs when a test that does not import the engine is absent from tests/tooling_manifest.txt. This PR adds such a test, so CI could not go green as it stood. The manifest is read as a set, so this is a single inserted line at its alphabetical slot; no existing line moves. --------- Co-authored-by: wshallwshall <mefordev@messagefoundry.org> Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
1 parent 88009b5 commit 8d16c0b

5 files changed

Lines changed: 592 additions & 13 deletions

File tree

docs/BACKLOG.md

Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18686,6 +18686,44 @@ today's instance and leaves the instrument exactly as blind.**
1868618686
> is a different set of runs the PR page does not surface.
1868718687
>
1868818688
> **Scored 2026-09-03 -> P2.** Value **6/10** · Difficulty **3/10** · _quick win_. Partly shipped, and more has landed since filing than the first pass credited. The visibility half is in -- .github/workflows/failure-signal.yml:71 recovers the pull request number from a merge_group ref and :92 applies ci-red, so an ejection is recorded, though nothing in this tree reads that label (grep for ci-red returns the writing workflow plus prose at CLAUDE.md:302 and docs/METHOD.md:365). The windows-2025 hang limb is no longer undiagnosed either: .github/workflows/ci.yml:852 now passes --max-worker-restart=0, landed 2026-09-02 in 042ef7ff5, and the comment from :826 to :850 reads the mechanism out of the pinned pytest-xdist and records four hangs of 25 to 46 minutes with the inner watchdogs armed, which is this row's process-level deadlock below pytest. What is left is two tests -- tests/test_api_request_timeout.py:99 still runs a route against a 0.1 second deadline, and tests/test_sqlserver_store.py:4039 is unchanged and runs at ci.yml:1772 under a wrapper that retries only a native crash (ci.yml:1769), never exit 1; the hostile-disposition test the row names was already a ratio assertion before filing (tests/test_multipart.py:142). Difficulty falls to 3 because the hard limb landed and the seams exist -- pyproject.toml:195 already ships pytest-rerunfailures and tests/test_load_failover_sqlserver.py:71 marks a sibling flaky -- with the SQL Server arm provable only on the gated CI leg.
18689+
>
18690+
> **WORKED 2026-09-03. Two limbs closed, one was already closed by somebody else, and the run
18691+
> census in this item is wrong by one -- there were FOUR failing `merge_group` CI runs, not three.**
18692+
> Read from the Actions API with `--paginate`; an unpaginated `per_page=100` query returns 100 of
18693+
> `total_count` 190 and silently drops half the population, which is the truncation trap #1417's
18694+
> notes already record. The corrected census, each attributed from its own job log:
18695+
>
18696+
> | run | id | failing job | failing test |
18697+
> |---|---|---|---|
18698+
> | 11:15:01Z | 33249679477 | test (windows-2025) | hung 55 min, no FAILED line |
18699+
> | 11:37:13Z | 33250553925 | test (windows-2025) | `test_api_request_timeout.py::test_a_fast_handler_is_untouched` -- `assert 503 == 200` |
18700+
> | 12:42:51Z | 33253197221 | test (windows-2025) + sql server 2022 | `test_multipart.py::test_hostile_disposition_header_parses_in_linear_time`; `test_cipher_invocations_upsert_is_atomic_and_additive` |
18701+
> | 13:01:54Z | 33253973185 | test (windows-2025) + sql server 2025 | `test_dr_activation`, `test_connscale_smoke` x2; `test_cipher_invocations_upsert_is_atomic_and_additive` |
18702+
>
18703+
> **So "three DIFFERENT reasons with no overlap" is not what the logs say.** The SQL Server test
18704+
> failed in BOTH of the last two runs, identically. The no-overlap claim held only across the three
18705+
> runs the original pass sampled.
18706+
>
18707+
> **Closed here.** (1) `tests/test_api_request_timeout.py` -- the 0.1s deadline is gone from the arms
18708+
> that assert a prompt handler is UNTOUCHED, which is the arm that actually ejected #669 at 11:37.
18709+
> The arms asserting the bound FIRES keep 0.1s, because there the margin runs the forgiving way.
18710+
> While in the file, `test_a_disabled_deadline_lets_a_slow_handler_finish` asked the FAST route, so
18711+
> it could not fail for its stated reason; it asks the slow route now. (2) `scripts/ci/report_ci_red.py`
18712+
> reads the `ci-red` label back and names the run, marking `merge_group` runs as invisible on the PR
18713+
> page -- the half that was missing since PR #716 wrote the label.
18714+
>
18715+
> **Already closed by #738, not by this item.** `test_cipher_invocations_upsert_is_atomic_and_additive`
18716+
> failed `StoreAcquireTimeout` after 30s because the aioodbc pool shared the event loop's default
18717+
> executor (8 threads on a 4-vCPU runner) against a `pool_size` of 40, so 20 concurrent upserts
18718+
> deadlocked on the executor queue. `cc5e09e1e` (2026-09-02) gave the store its own executor and names
18719+
> this exact test and error in its message. Nothing was rebuilt here.
18720+
>
18721+
> **STILL OPEN, and it is the one the earlier pass waved through.**
18722+
> `test_multipart.py::test_hostile_disposition_header_parses_in_linear_time` was dismissed as "already
18723+
> a ratio assertion". It is one, and it ejected #669 anyway: it failed at ratio **8.02 against a bound
18724+
> of 8.0**, a 0.25 percent margin. The best-of-3 sampling it relies on landed 2026-07-28 in
18725+
> `db53fd45d`, so the code that failed is the code in the tree today. Being a ratio rather than a
18726+
> wall-clock budget did not save it, and this needs its own read.
1868918727

1869018728
**Cluster:** CI / merge queue. **Priority:** P2. **Verdict:** build.
1869118729
**Severity:** a PR whose every required check is green cannot land, and nothing on the PR says why.

scripts/ci/report_ci_red.py

Lines changed: 278 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,278 @@
1+
#!/usr/bin/env python3
2+
# SPDX-License-Identifier: AGPL-3.0-or-later
3+
# Copyright (C) 2026 MessageFoundry Organization and contributors
4+
"""Read the ``ci-red`` label back, and say WHICH run reddened each pull request (BACKLOG #1385).
5+
6+
``failure-signal.yml`` writes the label. Until this script, **nothing read it** -- a grep for
7+
``ci-red`` returned the writing workflow plus prose in ``CLAUDE.md`` and ``docs/METHOD.md`` saying so.
8+
A signal nobody reads is not a signal, and this is the other half.
9+
10+
THE DEFECT IT EXISTS FOR, measured on PR 669. That pull request entered the merge queue and was
11+
ejected, twice, while **its own required contexts were green on the PR page**. The failures were in
12+
``merge_group`` runs -- the branch merged with ``main``, a different set of runs the PR page does not
13+
surface at all. Three full CI cycles were spent discovering that by hand. The attribution was
14+
recoverable from the API the whole time; nothing asked.
15+
16+
WHAT THIS PRINTS that ``gh pr view`` structurally cannot: for each labelled pull request, the newest
17+
FAILING run attributed to it, marked ``[merge_group]`` when the run is one the PR page cannot show.
18+
That mark is the finding, not decoration -- it is the difference between "your change is broken" and
19+
"your change conflicts with what landed since", and the PR page renders the second as green.
20+
21+
TWO RULES ARE COPIED FROM THE WRITER ON PURPOSE, because a reader that classifies differently from
22+
the writer reports causes the label was never applied for:
23+
24+
* **The watched workflows** (``_WATCHED``) match ``failure-signal.yml``'s ``workflows:`` list. CLA
25+
Assistant is excluded there, deliberately, and so is excluded here.
26+
* **Only ``failure`` counts** (``_RED``). A CANCELLED run is not a red -- branch protection gates on
27+
the latest head, so a cancelled predecessor says nothing about the current one. Counting it would
28+
misattribute every merge-queue ejection, which cancels its siblings on the way out.
29+
30+
AND THE ATTRIBUTION RULE IS THE WRITER'S, IN THE WRITER'S ORDER. ``pull_requests[0]`` where GitHub
31+
supplies it; otherwise the ``pr-<N>-`` parse off the ref, **gated on ``event == "merge_group"``**.
32+
That gate is a security control, not a tidiness one: a branch name is chosen by whoever opened the
33+
branch, and a fork cannot produce a ``merge_group`` event. A ref named ``pr-999-whatever`` on any
34+
other event resolves to nothing here, exactly as it does in the workflow.
35+
36+
A LABELLED PULL REQUEST WITH NO FAILING RUN IS REPORTED, NOT DROPPED. It reads ``UNATTRIBUTED``. The
37+
common cause is benign -- the run aged out of the API window, or the label outlived the run it was
38+
applied for -- but "I could not attribute this" must never render as "this is fine", which is the
39+
defect class this whole signal chain exists to close.
40+
41+
USAGE
42+
python scripts/ci/report_ci_red.py # uses gh's auth
43+
python scripts/ci/report_ci_red.py --repo owner/name
44+
python scripts/ci/report_ci_red.py --warn-only # report, always exit 0
45+
python scripts/ci/report_ci_red.py \\
46+
--prs-json prs.json --runs-json runs.json # offline/testing
47+
48+
EXIT
49+
0 nothing carries the label (or --warn-only)
50+
1 at least one pull request carries it -- there is a red to attribute
51+
2 the query itself failed; fail closed rather than report a clean repo
52+
"""
53+
54+
from __future__ import annotations
55+
56+
import argparse
57+
import json
58+
import re
59+
import subprocess
60+
from dataclasses import dataclass
61+
from pathlib import Path
62+
63+
#: The label ``failure-signal.yml`` applies. One string, so the reader and any future writer edit
64+
#: cannot silently disagree about which label is being talked about.
65+
CI_RED_LABEL = "ci-red"
66+
67+
#: Workflows whose failure earns the label. Mirrors ``failure-signal.yml``'s ``workflows:`` list --
68+
#: see the module docstring for why CLA Assistant is not in it.
69+
_WATCHED = frozenset({"CI", "Security", "CodeQL", "backlog-hygiene"})
70+
71+
#: The only conclusion that is a red. Mirrors the writer's ``conclusion == 'failure'`` gate.
72+
_RED = "failure"
73+
74+
#: ``gh-readonly-queue/<base>/pr-<N>-<sha>``. Anchored on a path segment so a branch merely CONTAINING
75+
#: the text (``feature/pr-12-notes``) cannot match -- and read only for a ``merge_group`` run anyway.
76+
_MERGE_QUEUE_REF = re.compile(r"(?:\A|/)pr-(\d+)-[0-9a-f]+\Z")
77+
78+
#: The pull-request fields this reader needs. Beside the parser so the two cannot drift.
79+
PR_FIELDS = "number,title,state,headRefName"
80+
81+
82+
@dataclass(frozen=True)
83+
class Red:
84+
"""One pull request carrying the label, and the run it was earned by (if that is recoverable)."""
85+
86+
number: int
87+
title: str
88+
run_name: str | None = None
89+
run_event: str | None = None
90+
run_url: str | None = None
91+
created_at: str | None = None
92+
93+
@property
94+
def attributed(self) -> bool:
95+
return self.run_name is not None
96+
97+
@property
98+
def hidden_from_the_pr_page(self) -> bool:
99+
"""True when the run is one the pull request's own checks list does not show.
100+
101+
This is the whole point of the report. A ``merge_group`` run tests the branch MERGED WITH the
102+
base, which is not the head the PR page reports on, so the page can read fully green while
103+
this is the thing blocking the merge.
104+
"""
105+
return self.run_event == "merge_group"
106+
107+
def line(self) -> str:
108+
# ASCII only: this lands in operator consoles whose code page is cp1252, where a non-ASCII
109+
# dash renders as a replacement character.
110+
if not self.attributed:
111+
return (
112+
f"#{self.number} {self.title[:60]} -- UNATTRIBUTED: no failing run for this pull "
113+
f"request in the window queried (aged out, or the label outlived its run)"
114+
)
115+
where = (
116+
" [merge_group -- NOT VISIBLE ON THE PR PAGE]" if self.hidden_from_the_pr_page else ""
117+
)
118+
return f"#{self.number} {self.title[:60]} -- {self.run_name} failed{where} {self.run_url}"
119+
120+
121+
def _pr_for_run(run: dict[str, object]) -> int | None:
122+
"""The pull request a run belongs to, by the writer's rule in the writer's order.
123+
124+
Returns ``None`` rather than guessing. In particular a ``pr-<N>-`` ref on any event other than
125+
``merge_group`` resolves to ``None``: that ref is only trustworthy because a fork cannot raise a
126+
``merge_group`` event, and dropping the gate would let a branch name anybody can choose steer the
127+
attribution.
128+
"""
129+
supplied = run.get("pull_requests")
130+
if isinstance(supplied, list) and supplied:
131+
first = supplied[0]
132+
if isinstance(first, dict) and isinstance(first.get("number"), int):
133+
return int(first["number"])
134+
if str(run.get("event") or "") != "merge_group":
135+
return None
136+
found = _MERGE_QUEUE_REF.search(str(run.get("head_branch") or ""))
137+
return int(found.group(1)) if found else None
138+
139+
140+
def attribute(prs: list[dict[str, object]], runs: list[dict[str, object]]) -> list[Red]:
141+
"""Join labelled pull requests to the newest failing run of a watched workflow.
142+
143+
Pure: no network, no git. The CLI supplies both payloads so tests drive THIS function rather than
144+
a re-implementation of the rule -- a test asserting a copy of the rule proves nothing about the
145+
rule. Ordering is newest-run-first by ``created_at``; a run with no timestamp sorts last rather
146+
than being dropped.
147+
"""
148+
newest: dict[int, dict[str, object]] = {}
149+
for run in runs:
150+
if not isinstance(run, dict):
151+
continue
152+
if str(run.get("name") or "") not in _WATCHED:
153+
continue
154+
if str(run.get("conclusion") or "").lower() != _RED:
155+
continue
156+
number = _pr_for_run(run)
157+
if number is None:
158+
continue
159+
stamp = str(run.get("created_at") or "")
160+
held = newest.get(number)
161+
if held is None or stamp > str(held.get("created_at") or ""):
162+
newest[number] = run
163+
164+
found: list[Red] = []
165+
for pr in prs:
166+
if not isinstance(pr, dict):
167+
continue
168+
raw = pr.get("number")
169+
# Narrow rather than coerce: a surprising payload must become a finding, never a crash.
170+
number = raw if isinstance(raw, int) else 0
171+
run = newest.get(number)
172+
found.append(
173+
Red(
174+
number=number,
175+
title=str(pr.get("title") or ""),
176+
run_name=str(run.get("name") or "") if run else None,
177+
run_event=str(run.get("event") or "") if run else None,
178+
run_url=str(run.get("html_url") or "") if run else None,
179+
created_at=str(run.get("created_at") or "") if run else None,
180+
)
181+
)
182+
return sorted(found, key=lambda r: r.number, reverse=True)
183+
184+
185+
def _gh(cmd: list[str]) -> object:
186+
# B603: fixed argv, no shell. The only variable element is --repo, an operator-typed CLI argument.
187+
# Same posture as check_stalled_prs.py; see the note there.
188+
out = subprocess.run( # noqa: S603 # nosec B603 - fixed argv, no shell, operator-supplied repo
189+
cmd, capture_output=True, text=True, timeout=180
190+
)
191+
if out.returncode != 0:
192+
raise RuntimeError(
193+
f"{cmd[0]} {cmd[1]} failed ({out.returncode}): {out.stderr.strip()[:400]}"
194+
)
195+
return json.loads(out.stdout)
196+
197+
198+
def _fetch_prs(repo: str | None) -> list[dict[str, object]]:
199+
cmd = ["gh", "pr", "list", "--label", CI_RED_LABEL, "--state", "open"]
200+
cmd += ["--limit", "100", "--json", PR_FIELDS]
201+
if repo:
202+
cmd += ["--repo", repo]
203+
payload = _gh(cmd)
204+
return [p for p in payload if isinstance(p, dict)] if isinstance(payload, list) else []
205+
206+
207+
def _fetch_runs(repo: str | None) -> list[dict[str, object]]:
208+
slug = repo or ":owner/:repo"
209+
# per_page=100 deliberately: any gh api list route DEFAULTS TO 30, and a reader that silently
210+
# cannot see two thirds of its own corpus reports a clean repo. (BACKLOG #1385's own notes record
211+
# a session that concluded a label had never been re-applied off exactly that truncation.)
212+
cmd = ["gh", "api", f"repos/{slug}/actions/runs?status=failure&per_page=100"]
213+
payload = _gh(cmd)
214+
if not isinstance(payload, dict):
215+
return []
216+
runs = payload.get("workflow_runs")
217+
return [r for r in runs if isinstance(r, dict)] if isinstance(runs, list) else []
218+
219+
220+
def main(argv: list[str] | None = None) -> int:
221+
parser = argparse.ArgumentParser(
222+
description=__doc__, formatter_class=argparse.RawDescriptionHelpFormatter
223+
)
224+
parser.add_argument("--repo", default=None, help="owner/name; defaults to gh's current repo")
225+
parser.add_argument("--prs-json", type=Path, default=None, help="a saved payload (testing)")
226+
parser.add_argument("--runs-json", type=Path, default=None, help="a saved payload (testing)")
227+
parser.add_argument(
228+
"--warn-only", action="store_true", help="report and exit 0 rather than 1 on a finding"
229+
)
230+
args = parser.parse_args(argv)
231+
232+
try:
233+
if args.prs_json is not None:
234+
loaded = json.loads(args.prs_json.read_text(encoding="utf-8"))
235+
prs = [p for p in loaded if isinstance(p, dict)] if isinstance(loaded, list) else []
236+
else:
237+
prs = _fetch_prs(args.repo)
238+
if args.runs_json is not None:
239+
loaded = json.loads(args.runs_json.read_text(encoding="utf-8"))
240+
runs = [r for r in loaded if isinstance(r, dict)] if isinstance(loaded, list) else []
241+
else:
242+
runs = _fetch_runs(args.repo) if prs else []
243+
except (RuntimeError, json.JSONDecodeError, subprocess.SubprocessError, OSError) as exc:
244+
# FAIL CLOSED. "I could not ask" must never render as "nothing is red" -- that is this
245+
# script's own defect class, one level up.
246+
print(f"::error::could not read the {CI_RED_LABEL} state ({exc!r}). Treating as a FAILURE.")
247+
return 2
248+
249+
# Liveness receipt: say what was EXAMINED. "nothing is red" and "the query returned nothing"
250+
# are otherwise indistinguishable from the exit code alone.
251+
# "run(s)", not "failing run(s)": the live fetch asks for status=failure, but --runs-json takes
252+
# whatever the caller supplies, and a receipt must not assert a property of its input it did not
253+
# check. `attribute` applies the conclusion filter itself.
254+
print(
255+
f"ci-red: {len(prs)} open pull request(s) carry {CI_RED_LABEL}; "
256+
f"scanned {len(runs)} run(s) for attribution"
257+
)
258+
if not prs:
259+
print("ci-red: no pull request is carrying a red.")
260+
return 0
261+
262+
reds = attribute(prs, runs)
263+
for red in reds:
264+
print(f"::warning::{red.line()}")
265+
266+
hidden = [r for r in reds if r.hidden_from_the_pr_page]
267+
if hidden:
268+
print(
269+
f"::error::{len(hidden)} pull request(s) were reddened by a merge_group run. Their own "
270+
"checks can read GREEN on the PR page: a merge-queue run tests the branch MERGED WITH the "
271+
"base, which is not the head the page reports on. Read the run linked above, not the PR's "
272+
"check list -- re-queueing without reading it spends a full CI cycle to learn nothing."
273+
)
274+
return 0 if args.warn_only else 1
275+
276+
277+
if __name__ == "__main__":
278+
raise SystemExit(main())

0 commit comments

Comments
 (0)