From 401893521b21a38c1eb9584c70a5264901f4859b Mon Sep 17 00:00:00 2001 From: Matt Miller Date: Mon, 27 Jul 2026 18:49:31 -0700 Subject: [PATCH 1/6] fix(groom): a PRE-agent finder failure no longer counts as a spent audit (BE-4814) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The interval gate counted ANY finder job concluding `success` or `failure` as "this scope was audited", so a job that died before the billed agent step — checkout, the asset load, the prompt build, a runner hiccup — advanced the cadence clock. On a scheduled caller that suppressed every tick for a whole GROOM_INTERVAL_DAYS window, hiding a typo'd input or a broken caller for days instead of letting it recur daily until someone noticed. The gate is fail-OPEN by design everywhere else; this was the one branch that failed closed. A `failure` now needs positive evidence that the agent step ran: the runs-jobs API's per-job `steps[]` must show `Run finder` started. A post-agent failure still counts (that half is why failures counted at all — a run that spent money must not re-spend tomorrow); a `success` is trusted on the job conclusion alone. Every ambiguity — no `steps[]`, empty, step absent, still queued, or skipped — reads as NOT audited, i.e. re-run. The step name is the producer half of a matched literal, so groom.yml carries a load-bearing comment, interval.py owns the literal (`agent_step_name()`), and the suite pins both halves — with groom.yml added to test-groom-scripts.yml's trigger paths so a rename there actually runs the test that catches it. --- .github/groom/README.md | 15 +++ .github/groom/interval.py | 98 ++++++++++++-- .github/groom/tests/test_interval.py | 157 ++++++++++++++++++++++- .github/workflows/groom.yml | 9 ++ .github/workflows/test-groom-scripts.yml | 17 ++- 5 files changed, 277 insertions(+), 19 deletions(-) diff --git a/.github/groom/README.md b/.github/groom/README.md index 0921c06..f5dbe02 100644 --- a/.github/groom/README.md +++ b/.github/groom/README.md @@ -199,6 +199,21 @@ real groom, so a skipped tick costs ~nothing (it never reaches the finder). interval-skip ticks in between never reset the clock. (A repo variable would need a `Variables: write` credential the run doesn't carry, and a missing grant would fail *silently* into a daily over-spend — run history has no such trap.) +- **A FAILED finder job counts only if it actually spent the audit** (BE-4814). + A failure that reached the agent and died later (the JSON assert, an upload) + still counts — otherwise a run that cost money re-spends on tomorrow's tick. + But the job can also die *before* the agent (checkout, asset load, prompt + build), and those bill nothing, so counting them would advance the clock and + suppress every tick for a whole `GROOM_INTERVAL_DAYS` — hiding a typo'd input + or a broken caller for a week rather than letting it recur daily until someone + notices. The gate therefore requires **positive evidence**: the jobs API's + per-job `steps[]` must show the agent step (`Run finder`, pinned as + `interval.agent_step_name()`) actually started. Every ambiguity — no `steps[]`, + an empty one, the step absent, still `queued`, or `skipped` — reads as **not + audited**, i.e. re-run. A duplicated audit costs one run; a suppressed one + hides a broken caller for a full interval. A `success` needs no such check (the + agent step is upstream of everything that could still fail, and no `if:` + guards it). - **`workflow_dispatch` bypasses THIS gate** — a manual dispatch is never interval-throttled. It is not a blanket "always runs": the volume gate is a second, independent throttle, so a live dispatch into a quiescent repo can diff --git a/.github/groom/interval.py b/.github/groom/interval.py index e162c54..0cadfa8 100644 --- a/.github/groom/interval.py +++ b/.github/groom/interval.py @@ -18,9 +18,12 @@ variable would need an extra `Variables: write` credential the run does not otherwise carry, and a missing grant would fail *silently* into a daily over-spend). A prior run "counts" as a real groom only if it actually reached the -finder (its `Audit — finder` job ran, i.e. was not `skipped` by this very gate), -so the interval-skip ticks in between never reset the clock. Run history is -durable across the stateless CI runs and readable with only `actions: read`. +finder (its `Audit — finder` job ran, i.e. was not `skipped` by this very gate) +AND actually spent the audit — a job that failed BEFORE its agent step (checkout, +asset load, prompt build) billed nothing, so it must not advance the clock +(BE-4814, see `run_audited`). The interval-skip ticks in between never reset it +either. Run history is durable across the stateless CI runs and readable with +only `actions: read`. The gate is **fail-open**, matching the volume gate: any error deriving the last run (API hiccup, unparseable timestamp, no history) RUNS the audit rather than @@ -64,11 +67,40 @@ # `skipped`, so it never matches the audited conclusions below. _FINDER_JOB_HINTS = ("finder", "audit_find") -# A finder job that reached success OR failure spent the (billed) audit, so both -# count as a real run: counting a failure keeps a run that spent money but died -# at a later step (e.g. filing) from re-spending on the very next daily tick. -# `skipped` (the interval-skip case), `cancelled`, and a null conclusion do not. -_AUDITED_CONCLUSIONS = {"success", "failure"} +# A finder job that reached `success` spent the (billed) audit — nothing else to +# check, the agent step is upstream of every step that could still fail. +# `skipped` (the interval-skip case), `cancelled`, and a null conclusion never +# count. `failure` is the interesting one, and it needs EVIDENCE — see below. +_AUDITED_CONCLUSIONS = {"success"} + +# A `failure` counts as a spent audit only if the billed agent step actually +# started (BE-4814). Counting every failure keeps a run that spent money but died +# at a LATER step (e.g. the JSON assert) from re-spending on the very next daily +# tick — that half is still wanted. But the finder job can also die far BEFORE +# the agent: checkout, the asset load, the prompt build, the runner itself. Those +# spend nothing, and counting them advances the cadence clock, so a typo'd input +# or a broken caller goes quiet for a whole GROOM_INTERVAL_DAYS window instead of +# recurring (and being noticed) daily. This gate is fail-OPEN everywhere else; +# that was the one branch that failed closed. +_AGENT_EVIDENCE_CONCLUSIONS = {"failure"} + +# The billed agent step inside the finder job, matched EXACTLY (after strip) +# against the `steps[]` the runs-jobs API returns per job. The literal lives here, +# next to the matcher that consumes it, so the producing `- name:` in groom.yml +# and this comparison cannot drift apart silently (`test_interval.py` pins both +# halves). Exact, not substring: the same job also has `Build finder prompt`, +# `Assert finder produced JSON` and `Upload finder candidates`, none of which is +# evidence that a single token was billed. +_AGENT_STEP_NAME = "Run finder" + +# Step states that mean the agent step never STARTED. GitHub reports an unreached +# step either as still `queued` (job died before it) or as `completed` with a +# `skipped` conclusion, and which one you get depends on where the job died — so +# both forms are checked rather than trusting either shape. `cancelled` likewise +# bills nothing. Anything else (in_progress, or completed with success/failure) +# means the agent ran and the audit is spent. +_UNSTARTED_STEP_STATUSES = {"queued", "waiting", "pending", "requested"} +_UNSTARTED_STEP_CONCLUSIONS = {"skipped", "cancelled", "canceled"} # Default cadence when GROOM_INTERVAL_DAYS is unset/blank/garbage — 7 days keeps # the documented weekly behavior (AC: unset variable stays weekly, matching today). @@ -176,11 +208,57 @@ def days_since(then_iso: str, now: datetime) -> float: return (now - then).total_seconds() / 86400.0 +def agent_step_name() -> str: + """The groom.yml finder step whose start proves the (billed) audit happened. + + Kept next to the matcher that reads it, so the producing `- name:` in + groom.yml and the consuming comparison cannot drift apart silently + (`test_interval.py` pins both halves against this). + """ + return _AGENT_STEP_NAME + + +def agent_step_started(job) -> bool: + """True if this job's `steps[]` show the billed agent step actually started. + + Positive evidence only, and fail-OPEN on every ambiguity: a missing, empty or + unmatched `steps[]` reads as "the agent never ran", which makes the run NOT + count and leaves the next tick due. A duplicated audit costs one run; a + suppressed one hides a broken caller for a full interval. + """ + for step in job.get("steps") or []: + if (step.get("name") or "").strip() != _AGENT_STEP_NAME: + continue + status = (step.get("status") or "").strip().lower() + conclusion = (step.get("conclusion") or "").strip().lower() + if status in _UNSTARTED_STEP_STATUSES or conclusion in _UNSTARTED_STEP_CONCLUSIONS: + continue + if not status and not conclusion: + # A name and nothing else says nothing about whether it ran. The API + # always sends `status`, so this is the malformed/unknown-shape case: + # no evidence -> not audited, same direction as every other branch. + continue + return True + return False + + def run_audited(jobs) -> bool: - """True if a run's jobs show the finder actually ran (not an interval-skip).""" + """True if a run's jobs show the finder actually ran (not an interval-skip). + + A `success` counts on the job conclusion alone. A `failure` counts only with + positive evidence that the agent step started (BE-4814) — the job can fail + long before it (checkout, asset load, prompt build), and those runs bill + nothing, so treating them as a spent audit would advance the cadence clock + and hide the breakage for a whole interval. + """ for job in jobs or []: name = (job.get("name") or "").lower() - if any(hint in name for hint in _FINDER_JOB_HINTS) and job.get("conclusion") in _AUDITED_CONCLUSIONS: + if not any(hint in name for hint in _FINDER_JOB_HINTS): + continue + conclusion = job.get("conclusion") + if conclusion in _AUDITED_CONCLUSIONS: + return True + if conclusion in _AGENT_EVIDENCE_CONCLUSIONS and agent_step_started(job): return True return False diff --git a/.github/groom/tests/test_interval.py b/.github/groom/tests/test_interval.py index 773ebc4..f5ce339 100644 --- a/.github/groom/tests/test_interval.py +++ b/.github/groom/tests/test_interval.py @@ -22,6 +22,7 @@ import io import json import os +import re import unittest from datetime import datetime, timezone @@ -62,8 +63,26 @@ def _run(cmd, **kwargs): return _run -def finder_job(conclusion="success"): - return {"name": "groom / Audit — finder", "conclusion": conclusion} +def agent_step(status="completed", conclusion="success"): + """The finder's billed agent step, shaped as the runs-jobs API returns it.""" + return {"name": interval.agent_step_name(), "number": 6, "status": status, "conclusion": conclusion} + + +def pre_agent_step(name="Checkout target repo (clean default branch)", conclusion="failure"): + return {"name": name, "number": 2, "status": "completed", "conclusion": conclusion} + + +def finder_job(conclusion="success", steps=None): + """A finder job. `steps=None` omits `steps[]` entirely (the API can, too).""" + job = {"name": "groom / Audit — finder", "conclusion": conclusion} + if steps is not None: + job["steps"] = steps + return job + + +def billed_finder_job(conclusion="failure"): + """A finder job that DID reach the agent — a post-agent failure, i.e. spent.""" + return finder_job(conclusion, [pre_agent_step(conclusion="success"), agent_step()]) class ParseIntervalDaysTest(unittest.TestCase): @@ -127,9 +146,15 @@ def test_cli_mode_with_missing_value_falls_back_to_default(self): class RunAuditedTest(unittest.TestCase): - def test_finder_success_or_failure_counts(self): + def test_finder_success_counts(self): self.assertTrue(interval.run_audited([finder_job("success")])) - self.assertTrue(interval.run_audited([finder_job("failure")])) + + def test_finder_failure_counts_only_with_agent_evidence(self): + # BE-4814: a failure that reached the agent spent the audit and counts; a + # failure with no evidence the agent ever started does NOT (see + # PreAgentFailureTest for the full matrix). + self.assertTrue(interval.run_audited([billed_finder_job()])) + self.assertFalse(interval.run_audited([finder_job("failure")])) def test_matches_job_id_form(self): # Robust to GitHub rendering the nested job by id rather than display name. @@ -143,6 +168,130 @@ def test_skipped_or_missing_does_not_count(self): self.assertFalse(interval.run_audited([])) +class PreAgentFailureTest(unittest.TestCase): + """THE headline assertion for BE-4814. + + The finder job can die long before the billed agent step — checkout, the + asset load, the prompt build, a runner hiccup. Those runs spend nothing, so + counting them as "this scope was audited" advances the cadence clock and + suppresses the next `GROOM_INTERVAL_DAYS` worth of ticks: a typo'd input or a + broken caller goes quiet for a week instead of recurring (and being noticed) + daily. Everywhere else this gate fails OPEN; this was the one branch that + failed closed. + + The rule is positive evidence, and every ambiguity resolves to NOT audited: a + duplicated audit costs one run, a suppressed one hides a broken caller for a + full interval. + """ + + def test_failure_before_the_agent_step_is_not_a_spent_audit(self): + # The job died in checkout: the agent step is present but still `queued`. + job = finder_job("failure", [pre_agent_step(), agent_step(status="queued", conclusion=None)]) + self.assertFalse(interval.run_audited([job])) + + def test_failure_with_the_agent_step_reported_as_skipped_is_not_spent(self): + # The other shape GitHub uses for an unreached step: `completed`/`skipped`. + job = finder_job("failure", [pre_agent_step(), agent_step(conclusion="skipped")]) + self.assertFalse(interval.run_audited([job])) + cancelled = finder_job("failure", [pre_agent_step(), agent_step(conclusion="cancelled")]) + self.assertFalse(interval.run_audited([cancelled])) + + def test_failure_with_the_agent_step_truncated_out_of_steps_is_not_spent(self): + # A job that died early can report only the steps it reached. + job = finder_job("failure", [pre_agent_step()]) + self.assertFalse(interval.run_audited([job])) + + def test_failure_with_no_steps_at_all_falls_open(self): + # Missing key, empty list — both read as "no evidence", i.e. re-run. + self.assertFalse(interval.run_audited([finder_job("failure")])) + self.assertFalse(interval.run_audited([finder_job("failure", [])])) + + def test_failure_after_the_agent_step_completed_IS_a_spent_audit(self): + # The half that must NOT regress: a run that paid for the agent and then + # died at a later step (the JSON assert, the artifact upload) still counts, + # so it can't re-spend on tomorrow's tick. Both agent outcomes qualify — + # an agent that ran and failed was still billed. + self.assertTrue(interval.run_audited([billed_finder_job()])) + agent_failed = finder_job("failure", [pre_agent_step(conclusion="success"), + agent_step(conclusion="failure")]) + self.assertTrue(interval.run_audited([agent_failed])) + in_progress = finder_job("failure", [agent_step(status="in_progress", conclusion=None)]) + self.assertTrue(interval.run_audited([in_progress])) + + def test_success_counts_regardless_of_the_steps_payload(self): + # A success is trusted on the job conclusion alone — the agent step is + # upstream of every step that could still fail, and no `if:` guards it. + for steps in (None, [], [pre_agent_step()], [agent_step(conclusion="skipped")]): + self.assertTrue(interval.run_audited([finder_job("success", steps)]), steps) + + def test_agent_step_is_matched_exactly_not_by_substring(self): + # The same job carries `Build finder prompt` / `Assert finder produced + # JSON`; neither is evidence that a token was billed. + # `Post Run finder` is real — the runs API reports post-action steps that + # way — and it is the one a substring match would swallow. + for name in ("Build finder prompt", "Assert finder produced JSON", + "Run finder (retry)", "Post Run finder"): + job = finder_job("failure", [{"name": name, "status": "completed", "conclusion": "failure"}]) + self.assertFalse(interval.run_audited([job]), name) + + def test_malformed_step_entries_are_no_evidence_and_do_not_crash(self): + # A bare name with neither status nor conclusion is an unknown shape, not + # proof the agent ran — no evidence resolves to NOT audited, like every + # other ambiguity here. And the walk must not raise on junk entries: an + # exception would be caught upstream and fail open anyway, but the cheap + # history scan should not lean on that backstop. + job = finder_job("failure", [{}, {"name": None}, {"name": interval.agent_step_name()}]) + self.assertFalse(interval.run_audited([job])) + + def test_a_pre_agent_failure_does_not_advance_the_cadence_clock(self): + # End-to-end: yesterday's tick died in checkout (billing nothing) and the + # last REAL groom was 8 days ago on a 7-day interval. The tick must RUN, + # anchored on the 8-day-old run — not skip for another week. + runs = [ + {"id": 100, "status": "in_progress", "run_started_at": iso(0)}, # current, excluded + {"id": 99, "status": "completed", "run_started_at": iso(1)}, # died pre-agent + {"id": 90, "status": "completed", "run_started_at": iso(8)}, # last REAL run + ] + jobs = { + "99": [finder_job("failure", [pre_agent_step(), agent_step(status="queued", conclusion=None)])], + "90": [finder_job("success")], + } + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, run=make_gh_stub(runs, jobs)) + self.assertTrue(d["should_run"], d["reason"]) + self.assertEqual(d["last_run_at"], iso(8)) + + def test_a_post_agent_failure_still_throttles_the_next_tick(self): + # The symmetric half: yesterday's run paid for the agent and died at the + # JSON assert, so today's tick must still SKIP — no re-spend. + runs = [ + {"id": 100, "status": "in_progress", "run_started_at": iso(0)}, + {"id": 99, "status": "completed", "run_started_at": iso(1)}, + {"id": 90, "status": "completed", "run_started_at": iso(8)}, + ] + jobs = {"99": [billed_finder_job()], "90": [finder_job("success")]} + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, run=make_gh_stub(runs, jobs)) + self.assertFalse(d["should_run"], d["reason"]) + self.assertEqual(d["last_run_at"], iso(1)) + + def test_groom_yml_names_exactly_the_agent_step_this_module_matches(self): + # The producer (a YAML `- name:`) and the consumer (this module) live in + # different files and can only be kept honest by pinning the literal. + # Scoped to the `audit_find:` job so the pin means what it claims: the + # BILLED step is named this, not merely that the string appears somewhere. + # (Matched as text rather than parsed — PyYAML is not stdlib and this repo + # is stdlib-only, so a parse would add a CI dependency for a literal pin.) + wf = os.path.join(os.path.dirname(__file__), "..", "..", "workflows", "groom.yml") + with open(wf, encoding="utf-8") as f: + text = f.read() + self.assertEqual(interval.agent_step_name(), "Run finder") + finder_block = re.split(r"(?m)^ (?=[A-Za-z_][A-Za-z0-9_-]*:\s*$)", text) + finder_block = [b for b in finder_block if b.startswith("audit_find:")] + self.assertEqual(len(finder_block), 1, "could not isolate the audit_find job in groom.yml") + # Exactly one step in that job carries the name — otherwise "did the agent + # start?" stops having a single answer. + self.assertEqual(finder_block[0].count(f"- name: {interval.agent_step_name()}\n"), 1) + + class IntervalThresholdTest(unittest.TestCase): def test_full_day_intervals_lose_a_half_tick(self): self.assertEqual(interval.interval_threshold(7.0), 6.5) diff --git a/.github/workflows/groom.yml b/.github/workflows/groom.yml index 4ddf88f..7d5f863 100644 --- a/.github/workflows/groom.yml +++ b/.github/workflows/groom.yml @@ -616,6 +616,15 @@ jobs: # `.git` all fail EACCES. /tmp is untouched, so $FINDER_OUT still works. run: chmod -R a-w "$GROOM_CLONE" + # NAME IS LOAD-BEARING — `interval.py` matches this step name EXACTLY + # (`_AGENT_STEP_NAME`) against the runs-jobs API's `steps[]` to decide + # whether a FAILED finder job actually spent its (billed) audit and may + # therefore advance the GROOM_INTERVAL_DAYS cadence clock (BE-4814). A + # rename here without the matching one there makes every failed run read as + # "agent never started", i.e. the cadence stops throttling failures — so + # `test_interval.py` pins both halves. Same for adding an `if:` to this + # step: a conditionally-skipped agent inside a SUCCEEDING job would still + # count, because a success is trusted on the job conclusion alone. - name: Run finder # Invoked as the CLI directly, NOT via the anthropics composite action # (BE-4202/BE-4214): the action cannot set a working directory, so the diff --git a/.github/workflows/test-groom-scripts.yml b/.github/workflows/test-groom-scripts.yml index 3cc9ae9..faf27ae 100644 --- a/.github/workflows/test-groom-scripts.yml +++ b/.github/workflows/test-groom-scripts.yml @@ -1,20 +1,27 @@ name: Test groom scripts -# Runs the unit tests for the groom dedup/rejection ledger (ledger.py). The -# ledger is the durable memory that stops the stateless groom CI run from -# re-filing already-filed or human-rejected findings every run, so a regression -# here would silently re-open the spam it exists to prevent — cheap to guard -# with a unit run on change. +# Runs the unit tests for the groom dedup/rejection ledger (ledger.py) and the +# runtime cadence gate (interval.py). The ledger is the durable memory that stops +# the stateless groom CI run from re-filing already-filed or human-rejected +# findings every run, so a regression here would silently re-open the spam it +# exists to prevent — cheap to guard with a unit run on change. +# +# `groom.yml` is a trigger path too (BE-4814): the suite pins literals the +# workflow PRODUCES and interval.py CONSUMES — today the finder's agent step name +# — so a rename there has to run these tests to be caught, not merge unwatched +# because the change touched no file under .github/groom/. on: pull_request: paths: - '.github/groom/**' + - '.github/workflows/groom.yml' - '.github/workflows/test-groom-scripts.yml' push: branches: [main] paths: - '.github/groom/**' + - '.github/workflows/groom.yml' - '.github/workflows/test-groom-scripts.yml' permissions: From 142f013750f1ff97174a805a844dc6a81d3233a9 Mon Sep 17 00:00:00 2001 From: Matt Miller Date: Mon, 27 Jul 2026 19:11:45 -0700 Subject: [PATCH 2/6] fix(groom): count a timed-out/cancelled finder as a spent audit (BE-4814) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review follow-ups on the pre-agent-failure gate. All four are the same bug class the PR set out to fix, in the two directions it can point. - `timed_out`/`cancelled` join `failure` on the evidence path. The finder job runs under `timeout-minutes: 40`, so a hung agent bills the FULL window and only then trips the timeout — the costliest outcome there is. Those conclusions could never count, so that spend was forgotten and repeated on every subsequent daily tick. - A `cancelled` STEP is no longer read as "never started": GitHub stamps an in-flight step `cancelled` when the job is cancelled or times out. The conclusion can't separate that from a step never reached, so the timestamps do — `started_at` strictly before `completed_at` proves it ran; no span is no evidence (fail-open, as everywhere else here). - Evidence is looked for across a run's earlier ATTEMPTS. The jobs endpoint reports only the latest, so a manual re-run that dies in checkout erased the record of an attempt that had reached the agent. Bounded at 5 and skipped entirely for the `run_attempt: 1` norm. - Junk payloads: every API field now reads through `_text()` and non-dict job/step entries are skipped, making good on the docstring's promise that the scan doesn't raise. Job `conclusion` is normalized like the step fields so a casing variance can't pass one check but not the other. The half that must not regress is pinned throughout: a run that ended before the agent still bills nothing and still may not advance the clock, under every one of the widened conclusions. --- .github/groom/README.md | 19 ++- .github/groom/interval.py | 176 ++++++++++++++++++++----- .github/groom/tests/test_interval.py | 188 ++++++++++++++++++++++++++- 3 files changed, 339 insertions(+), 44 deletions(-) diff --git a/.github/groom/README.md b/.github/groom/README.md index f5dbe02..f61d50d 100644 --- a/.github/groom/README.md +++ b/.github/groom/README.md @@ -199,10 +199,10 @@ real groom, so a skipped tick costs ~nothing (it never reaches the finder). interval-skip ticks in between never reset the clock. (A repo variable would need a `Variables: write` credential the run doesn't carry, and a missing grant would fail *silently* into a daily over-spend — run history has no such trap.) -- **A FAILED finder job counts only if it actually spent the audit** (BE-4814). - A failure that reached the agent and died later (the JSON assert, an upload) - still counts — otherwise a run that cost money re-spends on tomorrow's tick. - But the job can also die *before* the agent (checkout, asset load, prompt +- **A NON-SUCCESS finder job counts only if it actually spent the audit** + (BE-4814). A failure that reached the agent and died later (the JSON assert, an + upload) still counts — otherwise a run that cost money re-spends on tomorrow's + tick. But the job can also die *before* the agent (checkout, asset load, prompt build), and those bill nothing, so counting them would advance the clock and suppress every tick for a whole `GROOM_INTERVAL_DAYS` — hiding a typo'd input or a broken caller for a week rather than letting it recur daily until someone @@ -214,6 +214,17 @@ real groom, so a skipped tick costs ~nothing (it never reaches the finder). hides a broken caller for a full interval. A `success` needs no such check (the agent step is upstream of everything that could still fail, and no `if:` guards it). + - `timed_out` and `cancelled` take the same evidence path as `failure`, and + are the expensive members of it: the finder job runs under + `timeout-minutes: 40`, so a **hung agent bills the whole window** and only + then trips the timeout. GitHub stamps that in-flight step `cancelled` — + indistinguishable *by conclusion* from a step that was never reached, so the + gate reads the step's **timestamps**: a `started_at` strictly before its + `completed_at` proves it ran; no span is no evidence (fail-open). + - Evidence is looked for across a run's **earlier attempts**, not just the + latest. The jobs endpoint reports only the newest attempt, so a manual + re-run that dies in checkout would otherwise erase the record of an earlier + attempt that did reach the agent — and re-spend that audit. - **`workflow_dispatch` bypasses THIS gate** — a manual dispatch is never interval-throttled. It is not a blanket "always runs": the volume gate is a second, independent throttle, so a live dispatch into a quiescent repo can diff --git a/.github/groom/interval.py b/.github/groom/interval.py index 0cadfa8..3c8af59 100644 --- a/.github/groom/interval.py +++ b/.github/groom/interval.py @@ -19,10 +19,11 @@ otherwise carry, and a missing grant would fail *silently* into a daily over-spend). A prior run "counts" as a real groom only if it actually reached the finder (its `Audit — finder` job ran, i.e. was not `skipped` by this very gate) -AND actually spent the audit — a job that failed BEFORE its agent step (checkout, +AND actually spent the audit — a job that ended BEFORE its agent step (checkout, asset load, prompt build) billed nothing, so it must not advance the clock -(BE-4814, see `run_audited`). The interval-skip ticks in between never reset it -either. Run history is durable across the stateless CI runs and readable with +(BE-4814, see `run_audited`). Conversely a job that hung and tripped its +40-minute timeout billed the most of any outcome, so it must. The interval-skip +ticks in between never reset it either. Run history is durable across the stateless CI runs and readable with only `actions: read`. The gate is **fail-open**, matching the volume gate: any error deriving the last @@ -73,16 +74,25 @@ # count. `failure` is the interesting one, and it needs EVIDENCE — see below. _AUDITED_CONCLUSIONS = {"success"} -# A `failure` counts as a spent audit only if the billed agent step actually -# started (BE-4814). Counting every failure keeps a run that spent money but died -# at a LATER step (e.g. the JSON assert) from re-spending on the very next daily -# tick — that half is still wanted. But the finder job can also die far BEFORE -# the agent: checkout, the asset load, the prompt build, the runner itself. Those -# spend nothing, and counting them advances the cadence clock, so a typo'd input -# or a broken caller goes quiet for a whole GROOM_INTERVAL_DAYS window instead of -# recurring (and being noticed) daily. This gate is fail-OPEN everywhere else; -# that was the one branch that failed closed. -_AGENT_EVIDENCE_CONCLUSIONS = {"failure"} +# A non-success ending counts as a spent audit only if the billed agent step +# actually started (BE-4814). Counting every failure keeps a run that spent money +# but died at a LATER step (e.g. the JSON assert) from re-spending on the very +# next daily tick — that half is still wanted. But the finder job can also die +# far BEFORE the agent: checkout, the asset load, the prompt build, the runner +# itself. Those spend nothing, and counting them advances the cadence clock, so a +# typo'd input or a broken caller goes quiet for a whole GROOM_INTERVAL_DAYS +# window instead of recurring (and being noticed) daily. This gate is fail-OPEN +# everywhere else; that was the one branch that failed closed. +# +# `timed_out` and `cancelled` belong here alongside `failure` and are the +# EXPENSIVE members of the set: the finder job carries `timeout-minutes: 40`, so +# an agent that hangs bills the full window and *then* trips the job timeout — +# the single costliest outcome this module sees. Leaving those conclusions out of +# the evidence path meant they could never count, so that 40 minutes of billing +# was forgotten and re-spent on every subsequent daily tick. They still need the +# same per-step evidence as a `failure` (a run cancelled during checkout bills +# nothing), which is exactly what `agent_step_started` supplies. +_AGENT_EVIDENCE_CONCLUSIONS = {"failure", "timed_out", "cancelled", "canceled"} # The billed agent step inside the finder job, matched EXACTLY (after strip) # against the `steps[]` the runs-jobs API returns per job. The literal lives here, @@ -96,11 +106,23 @@ # Step states that mean the agent step never STARTED. GitHub reports an unreached # step either as still `queued` (job died before it) or as `completed` with a # `skipped` conclusion, and which one you get depends on where the job died — so -# both forms are checked rather than trusting either shape. `cancelled` likewise -# bills nothing. Anything else (in_progress, or completed with success/failure) -# means the agent ran and the audit is spent. +# both forms are checked rather than trusting either shape. Anything else +# (in_progress, or completed with success/failure) means the agent ran and the +# audit is spent. _UNSTARTED_STEP_STATUSES = {"queued", "waiting", "pending", "requested"} -_UNSTARTED_STEP_CONCLUSIONS = {"skipped", "cancelled", "canceled"} +_UNSTARTED_STEP_CONCLUSIONS = {"skipped"} + +# `cancelled` is the ambiguous conclusion and must NOT be read as "never started": +# GitHub stamps an already-RUNNING step `cancelled` when the workflow is cancelled +# or the job trips its `timeout-minutes`, so a hung agent that billed for 40 +# minutes lands here — reading that as unstarted forgets the most expensive audit +# there is. It equally stamps some unreached steps `cancelled` on the way down. +# The conclusion alone cannot separate them; the TIMESTAMPS can. A step that +# actually ran has a `started_at` strictly before its `completed_at`; an unreached +# one carries no span (null timestamps, or both stamped at the same cancellation +# instant). No demonstrable span -> no evidence -> not audited, which is the same +# fail-open direction every other branch here takes. +_CANCELLED_STEP_CONCLUSIONS = {"cancelled", "canceled"} # Default cadence when GROOM_INTERVAL_DAYS is unset/blank/garbage — 7 days keeps # the documented weekly behavior (AC: unset variable stays weekly, matching today). @@ -145,6 +167,12 @@ # (fail-open). Far more than any sane interval's worth of daily skip-ticks. _MAX_RUNS_SCANNED = 100 +# How many attempts of a single run to read back before giving up (fail-open). +# Only reached for a run somebody re-ran by hand, which is already rare; the cap +# keeps a pathological re-run count from turning this cheap gate into a storm of +# API calls. See `run_audited_across_attempts`. +_MAX_ATTEMPTS_SCANNED = 5 + def parse_interval_days(raw, default: float = _DEFAULT_INTERVAL_DAYS): """Parse the GROOM_INTERVAL_DAYS value; fall back to the weekly default. @@ -218,6 +246,35 @@ def agent_step_name() -> str: return _AGENT_STEP_NAME +def _text(value) -> str: + """A trimmed string for any JSON value; non-strings (and None) read as blank. + + Every field this module reads off the API is compared as text, and the whole + history scan is meant not to raise on a junk payload (the upstream handler + would fail open anyway, but the cheap scan should not lean on that backstop). + Funnelling each read through here makes a `None`, number, list or dict where a + string was expected degrade to "no evidence" instead of an AttributeError. + """ + return value.strip() if isinstance(value, str) else "" + + +def _step_has_elapsed_span(step) -> bool: + """True if the step's timestamps prove it actually ran for some time. + + The discriminator for a `cancelled` step (see _CANCELLED_STEP_CONCLUSIONS): + cancelled mid-flight (billed) vs finalized on the way down (never reached). + Missing, unparseable or zero-width timestamps are no evidence, not proof of + absence — same fail-open direction as the rest of the gate. + """ + started, completed = _text(step.get("started_at")), _text(step.get("completed_at")) + if not started or not completed: + return False + try: + return parse_iso8601_utc(completed) > parse_iso8601_utc(started) + except ValueError: + return False + + def agent_step_started(job) -> bool: """True if this job's `steps[]` show the billed agent step actually started. @@ -226,13 +283,24 @@ def agent_step_started(job) -> bool: count and leaves the next tick due. A duplicated audit costs one run; a suppressed one hides a broken caller for a full interval. """ - for step in job.get("steps") or []: - if (step.get("name") or "").strip() != _AGENT_STEP_NAME: + if not isinstance(job, dict): + return False + steps = job.get("steps") + for step in steps if isinstance(steps, list) else []: + if not isinstance(step, dict): + continue + if _text(step.get("name")) != _AGENT_STEP_NAME: continue - status = (step.get("status") or "").strip().lower() - conclusion = (step.get("conclusion") or "").strip().lower() + status = _text(step.get("status")).lower() + conclusion = _text(step.get("conclusion")).lower() if status in _UNSTARTED_STEP_STATUSES or conclusion in _UNSTARTED_STEP_CONCLUSIONS: continue + if conclusion in _CANCELLED_STEP_CONCLUSIONS: + # Only the timestamps say whether this cancellation caught a running + # agent (billed) or a step that was never reached (billed nothing). + if _step_has_elapsed_span(step): + return True + continue if not status and not conclusion: # A name and nothing else says nothing about whether it ran. The API # always sends `status`, so this is the malformed/unknown-shape case: @@ -245,17 +313,22 @@ def agent_step_started(job) -> bool: def run_audited(jobs) -> bool: """True if a run's jobs show the finder actually ran (not an interval-skip). - A `success` counts on the job conclusion alone. A `failure` counts only with - positive evidence that the agent step started (BE-4814) — the job can fail - long before it (checkout, asset load, prompt build), and those runs bill - nothing, so treating them as a spent audit would advance the cadence clock - and hide the breakage for a whole interval. + A `success` counts on the job conclusion alone. A `failure`/`timed_out`/ + `cancelled` counts only with positive evidence that the agent step started + (BE-4814) — the job can end long before it (checkout, asset load, prompt + build), and those runs bill nothing, so treating them as a spent audit would + advance the cadence clock and hide the breakage for a whole interval. """ - for job in jobs or []: - name = (job.get("name") or "").lower() + for job in jobs if isinstance(jobs, list) else []: + if not isinstance(job, dict): + continue + name = _text(job.get("name")).lower() if not any(hint in name for hint in _FINDER_JOB_HINTS): continue - conclusion = job.get("conclusion") + # Normalized exactly like the step fields below it: the API returns these + # lowercase today, but one normalization for both halves means a casing or + # whitespace variance can never slip past only one of the two checks. + conclusion = _text(job.get("conclusion")).lower() if conclusion in _AUDITED_CONCLUSIONS: return True if conclusion in _AGENT_EVIDENCE_CONCLUSIONS and agent_step_started(job): @@ -334,14 +407,48 @@ def fetch_workflow_runs(repo: str, workflow_file: str, run=subprocess.run): return payload.get("workflow_runs", []) if isinstance(payload, dict) else [] -def fetch_run_jobs(repo: str, run_id, run=subprocess.run): - """The jobs of one workflow run (single page).""" +def fetch_run_jobs(repo: str, run_id, run=subprocess.run, attempt=None): + """The jobs of one workflow run (single page). + + `attempt=None` asks the plain endpoint, which reports only the run's LATEST + attempt; pass an attempt number to read an earlier one (see + `run_audited_across_attempts`). + """ if not _REPO_RE.match(repo or ""): raise ValueError(f"invalid repo {repo!r}: expected owner/name") - payload = _api_json([f"/repos/{repo}/actions/runs/{run_id}/jobs?per_page=100"], run) + base = f"/repos/{repo}/actions/runs/{run_id}" + if attempt is not None: + base = f"{base}/attempts/{int(attempt)}" + payload = _api_json([f"{base}/jobs?per_page=100"], run) return payload.get("jobs", []) if isinstance(payload, dict) else [] +def run_audited_across_attempts(repo, wf_run, run=subprocess.run) -> bool: + """`run_audited` for a run, counting a spent audit on ANY of its attempts. + + The plain jobs endpoint returns only the latest attempt. A re-run that dies + before the agent would therefore erase the evidence of an earlier attempt that + DID reach it, and the already-paid audit would repeat on the next tick — the + same forgotten-spend bug as a pre-agent failure, one level up. So when the + latest attempt shows nothing and the run has earlier ones, walk them back. + + Costs nothing in the normal case: `run_attempt` is 1 for every run nobody + re-ran by hand, and the loop is skipped entirely. + """ + if run_audited(fetch_run_jobs(repo, wf_run.get("id"), run=run)): + return True + try: + attempts = int(wf_run.get("run_attempt") or 1) + except (TypeError, ValueError): + attempts = 1 + # Newest-first, excluding the latest (already read above), and bounded so a + # pathologically re-run entry can't turn the cheap gate into a request storm. + for attempt in range(min(attempts, _MAX_ATTEMPTS_SCANNED) - 1, 0, -1): + if run_audited(fetch_run_jobs(repo, wf_run.get("id"), run=run, attempt=attempt)): + return True + return False + + def find_last_audited_run_at(repo, workflow_file, current_run_id, run=subprocess.run): """`run_started_at` of the most recent completed run that ran the finder. @@ -351,12 +458,13 @@ def find_last_audited_run_at(repo, workflow_file, current_run_id, run=subprocess """ current = str(current_run_id) if current_run_id is not None else None for wf_run in fetch_workflow_runs(repo, workflow_file, run=run): + if not isinstance(wf_run, dict): + continue if current is not None and str(wf_run.get("id")) == current: continue if wf_run.get("status") != "completed": continue - jobs = fetch_run_jobs(repo, wf_run.get("id"), run=run) - if run_audited(jobs): + if run_audited_across_attempts(repo, wf_run, run=run): return wf_run.get("run_started_at") return None diff --git a/.github/groom/tests/test_interval.py b/.github/groom/tests/test_interval.py index f5ce339..71003f4 100644 --- a/.github/groom/tests/test_interval.py +++ b/.github/groom/tests/test_interval.py @@ -50,22 +50,36 @@ def __init__(self, stdout="", returncode=0, stderr=""): self.stderr = stderr -def make_gh_stub(runs, jobs_by_run): - """A `gh api` stub: routes /runs vs /runs//jobs by URL.""" +def make_gh_stub(runs, jobs_by_run, jobs_by_attempt=None): + """A `gh api` stub: routes /runs vs /runs/[/attempts/]/jobs by URL. + + `jobs_by_attempt` is keyed `"/"` and answers the per-attempt + endpoint; `jobs_by_run` answers the plain one (the LATEST attempt), exactly as + the real API splits them. + """ + jobs_by_attempt = jobs_by_attempt or {} def _run(cmd, **kwargs): url = cmd[-1] if "/jobs" in url: - run_id = url.split("/actions/runs/")[1].split("/jobs")[0] - return Result(stdout=json.dumps({"jobs": jobs_by_run.get(run_id, [])})) + tail = url.split("/actions/runs/")[1].split("/jobs")[0] + if "/attempts/" in tail: + run_id, attempt = tail.split("/attempts/") + return Result(stdout=json.dumps({"jobs": jobs_by_attempt.get(f"{run_id}/{attempt}", [])})) + return Result(stdout=json.dumps({"jobs": jobs_by_run.get(tail, [])})) return Result(stdout=json.dumps({"workflow_runs": runs})) return _run -def agent_step(status="completed", conclusion="success"): +def agent_step(status="completed", conclusion="success", started_at=None, completed_at=None): """The finder's billed agent step, shaped as the runs-jobs API returns it.""" - return {"name": interval.agent_step_name(), "number": 6, "status": status, "conclusion": conclusion} + step = {"name": interval.agent_step_name(), "number": 6, "status": status, "conclusion": conclusion} + if started_at is not None: + step["started_at"] = started_at + if completed_at is not None: + step["completed_at"] = completed_at + return step def pre_agent_step(name="Checkout target repo (clean default branch)", conclusion="failure"): @@ -193,6 +207,8 @@ def test_failure_with_the_agent_step_reported_as_skipped_is_not_spent(self): # The other shape GitHub uses for an unreached step: `completed`/`skipped`. job = finder_job("failure", [pre_agent_step(), agent_step(conclusion="skipped")]) self.assertFalse(interval.run_audited([job])) + # A `cancelled` step with no timestamp span is likewise unreached — the + # spanned case is the opposite verdict, see CancelledAndTimedOutTest. cancelled = finder_job("failure", [pre_agent_step(), agent_step(conclusion="cancelled")]) self.assertFalse(interval.run_audited([cancelled])) @@ -243,6 +259,28 @@ def test_malformed_step_entries_are_no_evidence_and_do_not_crash(self): job = finder_job("failure", [{}, {"name": None}, {"name": interval.agent_step_name()}]) self.assertFalse(interval.run_audited([job])) + def test_non_dict_entries_are_skipped_rather_than_raising(self): + # The docstring promises the walk survives junk, so feed it genuinely + # non-dict entries — a bare None, a string, a list — not just odd dicts. + # A real payload never looks like this; the point is that the scan cannot + # AttributeError its way into the upstream fail-open backstop. + junk = [None, "Run finder", ["Run finder"], 7, {"name": ["Run finder"]}] + self.assertFalse(interval.run_audited([finder_job("failure", junk)])) + # ...and a valid entry AFTER the junk is still reached and honored. + self.assertTrue(interval.run_audited([finder_job("failure", [*junk, agent_step()])])) + # Junk at the job level, and a `steps[]` that isn't even a list. + self.assertFalse(interval.run_audited([None, "job", 7])) + self.assertFalse(interval.run_audited([finder_job("failure", "not-a-list")])) + self.assertFalse(interval.run_audited("not-a-list")) + + def test_job_conclusion_is_normalized_like_the_step_fields(self): + # The job conclusion and the step fields are compared against the same + # kind of membership set, so they must be normalized the same way — a + # casing/whitespace variance must not slip past one check but not the other. + self.assertTrue(interval.run_audited([finder_job(" SUCCESS ")])) + self.assertTrue(interval.run_audited([finder_job("Failure", [agent_step(conclusion=" Success ")])])) + self.assertFalse(interval.run_audited([finder_job("Failure", [agent_step(conclusion=" SKIPPED ")])])) + def test_a_pre_agent_failure_does_not_advance_the_cadence_clock(self): # End-to-end: yesterday's tick died in checkout (billing nothing) and the # last REAL groom was 8 days ago on a 7-day interval. The tick must RUN, @@ -292,6 +330,144 @@ def test_groom_yml_names_exactly_the_agent_step_this_module_matches(self): self.assertEqual(finder_block[0].count(f"- name: {interval.agent_step_name()}\n"), 1) +class CancelledAndTimedOutTest(unittest.TestCase): + """The most EXPENSIVE ending must count, and it is not `failure`. + + The finder job carries `timeout-minutes: 40`. An agent that hangs bills that + whole window and then trips the job timeout, so the job ends `timed_out` (or + `cancelled`, if someone kills the run) and GitHub stamps the in-flight agent + step `cancelled`. Reading either level as "never started" forgets the single + costliest audit there is and re-spends it on tomorrow's tick, every tick. + + The conclusion alone cannot tell a cancellation that caught a RUNNING agent + from one that finalized a step never reached; the timestamps can, so an + elapsed span is the evidence, and no span stays fail-open (not audited). + """ + + def cancelled_mid_flight(self): + """The agent step as GitHub stamps it when a 40-minute run is killed.""" + return agent_step(conclusion="cancelled", + started_at="2026-07-21T09:00:00Z", completed_at="2026-07-21T09:40:00Z") + + def test_timed_out_job_with_an_in_flight_agent_is_a_spent_audit(self): + job = finder_job("timed_out", [pre_agent_step(conclusion="success"), self.cancelled_mid_flight()]) + self.assertTrue(interval.run_audited([job])) + + def test_cancelled_job_with_an_in_flight_agent_is_a_spent_audit(self): + for conclusion in ("cancelled", "canceled"): + job = finder_job(conclusion, [pre_agent_step(conclusion="success"), self.cancelled_mid_flight()]) + self.assertTrue(interval.run_audited([job]), conclusion) + + def test_cancelled_job_that_died_before_the_agent_is_not_spent(self): + # The half that must not regress with the widened conclusion set: a run + # cancelled during checkout bills nothing, so it still may not advance the + # clock. Both unreached shapes, under both endings. + for conclusion in ("timed_out", "cancelled"): + queued = finder_job(conclusion, [pre_agent_step(), agent_step(status="queued", conclusion=None)]) + self.assertFalse(interval.run_audited([queued]), conclusion) + skipped = finder_job(conclusion, [pre_agent_step(), agent_step(conclusion="skipped")]) + self.assertFalse(interval.run_audited([skipped]), conclusion) + self.assertFalse(interval.run_audited([finder_job(conclusion)]), conclusion) + + def test_a_cancelled_agent_step_without_a_span_stays_fail_open(self): + # No timestamps, one timestamp, or a zero-width span (both stamped at the + # same cancellation instant) are all "no evidence" — the unreached step + # GitHub finalized on the way down looks exactly like that. + instant = "2026-07-21T09:00:00Z" + for started, completed in ((None, None), (instant, None), (None, instant), + (instant, instant), ("garbage", instant)): + step = agent_step(conclusion="cancelled", started_at=started, completed_at=completed) + self.assertFalse(interval.run_audited([finder_job("timed_out", [step])]), (started, completed)) + + def test_a_timed_out_agent_does_not_re_spend_on_the_next_tick(self): + # End-to-end, the harm this closes: yesterday's run hung and burned the + # full 40-minute timeout. Today's tick must SKIP — the audit was paid. + runs = [ + {"id": 100, "status": "in_progress", "run_started_at": iso(0)}, + {"id": 99, "status": "completed", "run_started_at": iso(1)}, + {"id": 90, "status": "completed", "run_started_at": iso(8)}, + ] + jobs = {"99": [finder_job("timed_out", [pre_agent_step(conclusion="success"), + self.cancelled_mid_flight()])], + "90": [finder_job("success")]} + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, run=make_gh_stub(runs, jobs)) + self.assertFalse(d["should_run"], d["reason"]) + self.assertEqual(d["last_run_at"], iso(1)) + + +class EarlierAttemptTest(unittest.TestCase): + """A re-run must not erase the evidence that an earlier attempt billed. + + The plain jobs endpoint reports only a run's LATEST attempt. If attempt 1 + reached the agent and attempt 2 (a manual re-run) died in checkout, reading + only the latest attempt forgets the paid audit and re-spends it next tick — + the same bug BE-4814 fixes at the step level, one level up. + """ + + def runs(self, attempt_count): + return [ + {"id": 100, "status": "in_progress", "run_started_at": iso(0)}, + {"id": 99, "status": "completed", "run_started_at": iso(1), "run_attempt": attempt_count}, + {"id": 90, "status": "completed", "run_started_at": iso(8)}, + ] + + def test_an_earlier_attempt_that_billed_still_counts(self): + latest = {"99": [finder_job("failure", [pre_agent_step()])], "90": [finder_job("success")]} + by_attempt = {"99/1": [billed_finder_job()], "99/2": latest["99"]} + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, + run=make_gh_stub(self.runs(2), latest, by_attempt)) + self.assertFalse(d["should_run"], d["reason"]) + self.assertEqual(d["last_run_at"], iso(1)) + + def test_no_attempt_that_billed_still_falls_open(self): + # Every attempt died pre-agent: nothing was spent, so the clock stays + # anchored on the 8-day-old real run and today's tick RUNS. + latest = {"99": [finder_job("failure", [pre_agent_step()])], "90": [finder_job("success")]} + by_attempt = {"99/1": latest["99"], "99/2": latest["99"]} + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, + run=make_gh_stub(self.runs(2), latest, by_attempt)) + self.assertTrue(d["should_run"], d["reason"]) + self.assertEqual(d["last_run_at"], iso(8)) + + def test_single_attempt_runs_make_no_extra_api_calls(self): + # The common case must stay exactly as cheap as before: `run_attempt` 1 + # (or absent) must never hit the per-attempt endpoint. + seen = [] + base = make_gh_stub(self.runs(1), {"99": [finder_job("failure", [pre_agent_step()])], + "90": [finder_job("success")]}) + + def spy(cmd, **kwargs): + seen.append(cmd[-1]) + return base(cmd, **kwargs) + + interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, run=spy) + self.assertFalse([u for u in seen if "/attempts/" in u], seen) + + def test_the_attempt_walk_is_bounded(self): + # A pathological re-run count can't turn the cheap gate into a request + # storm — the walk is capped, newest-first. + seen = [] + latest = {"99": [finder_job("failure", [pre_agent_step()])], "90": [finder_job("success")]} + base = make_gh_stub(self.runs(50), latest, {}) + + def spy(cmd, **kwargs): + seen.append(cmd[-1]) + return base(cmd, **kwargs) + + interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, run=spy) + attempts_hit = [u for u in seen if "/attempts/" in u] + self.assertEqual(len(attempts_hit), interval._MAX_ATTEMPTS_SCANNED - 1, attempts_hit) + + def test_a_garbage_run_attempt_degrades_to_the_latest_attempt_only(self): + latest = {"99": [billed_finder_job()], "90": [finder_job("success")]} + for raw in (None, "", "lots", {}): + runs = self.runs(1) + runs[1]["run_attempt"] = raw + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, + run=make_gh_stub(runs, latest, {})) + self.assertFalse(d["should_run"], (raw, d["reason"])) + + class IntervalThresholdTest(unittest.TestCase): def test_full_day_intervals_lose_a_half_tick(self): self.assertEqual(interval.interval_threshold(7.0), 6.5) From 5ccf951ebf69a52d3533ccd4ec3e7746124cde2c Mon Sep 17 00:00:00 2001 From: Matt Miller Date: Mon, 27 Jul 2026 19:14:12 -0700 Subject: [PATCH 3/6] docs(groom): refresh the _AUDITED_CONCLUSIONS note for the widened evidence set (BE-4814) --- .github/groom/interval.py | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/.github/groom/interval.py b/.github/groom/interval.py index 3c8af59..bbb221d 100644 --- a/.github/groom/interval.py +++ b/.github/groom/interval.py @@ -69,9 +69,10 @@ _FINDER_JOB_HINTS = ("finder", "audit_find") # A finder job that reached `success` spent the (billed) audit — nothing else to -# check, the agent step is upstream of every step that could still fail. -# `skipped` (the interval-skip case), `cancelled`, and a null conclusion never -# count. `failure` is the interesting one, and it needs EVIDENCE — see below. +# check, the agent step is upstream of every step that could still fail. `skipped` +# (the interval-skip case) and a null conclusion never count at all. Every other +# ending — `failure`, `timed_out`, `cancelled` — may or may not have spent the +# audit, so it needs EVIDENCE; see _AGENT_EVIDENCE_CONCLUSIONS below. _AUDITED_CONCLUSIONS = {"success"} # A non-success ending counts as a spent audit only if the billed agent step From 259231400138d94b9eed0c2c78dff4c972f29579 Mon Sep 17 00:00:00 2001 From: Matt Miller Date: Mon, 27 Jul 2026 19:33:08 -0700 Subject: [PATCH 4/6] fix(groom): walk the NEWEST earlier attempts and anchor on the audited one (BE-4814) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Second review round. The first fix's attempt-walk had a real direction bug. - `range(min(attempts, CAP) - 1, 0, -1)` scanned attempts 1..4 of a run re-run 50 times — the OLDEST — so a billed audit sitting on attempt 49 was never read and got re-spent, which is the exact forgotten-spend the function exists to prevent. The window now slides with `run_attempt`. The old test asserted only the CALL COUNT, which passes either way and masked it; it now asserts WHICH attempts are fetched (49..46, not 1..4). - When an EARLIER attempt supplies the evidence, the clock anchored on the run's `run_started_at` — which tracks the LATEST attempt. A pre-agent re-run today of a run whose attempt 1 paid a week ago therefore read as "audited today" and suppressed the next full interval: fail-CLOSED, the direction this gate exists to avoid. It now anchors on the audited attempt's own finder-job start, falling back to the run's creation (older anchor = more elapsed = fail-open) rather than the re-run time. - The evidence-conclusion allowlist became a denylist. Only `skipped` (the interval-skip) and an unfinished run are excluded; every other ending, including the rarer `neutral`/`stale`/`action_required`, is decided by the step evidence — if the agent ran, the audit was spent however the job was finally stamped. An allowlist silently forgets what it omits. --- .github/groom/README.md | 15 +++- .github/groom/interval.py | 117 +++++++++++++++++---------- .github/groom/tests/test_interval.py | 81 +++++++++++++++++-- 3 files changed, 159 insertions(+), 54 deletions(-) diff --git a/.github/groom/README.md b/.github/groom/README.md index f61d50d..35fccf2 100644 --- a/.github/groom/README.md +++ b/.github/groom/README.md @@ -214,8 +214,13 @@ real groom, so a skipped tick costs ~nothing (it never reaches the finder). hides a broken caller for a full interval. A `success` needs no such check (the agent step is upstream of everything that could still fail, and no `if:` guards it). - - `timed_out` and `cancelled` take the same evidence path as `failure`, and - are the expensive members of it: the finder job runs under + - Which endings take the evidence path is a **denylist**, not an enumeration: + only `skipped` (this gate's own interval-skip) and an unfinished run are + excluded outright. Everything else — `failure`, `timed_out`, `cancelled`, + and the rarer `neutral`/`stale`/`action_required` — is decided by the step + evidence, because if the agent ran, the audit was spent however the job was + finally stamped. An allowlist would silently forget any ending it missed. + - `timed_out`/`cancelled` are the expensive members: the finder job runs under `timeout-minutes: 40`, so a **hung agent bills the whole window** and only then trips the timeout. GitHub stamps that in-flight step `cancelled` — indistinguishable *by conclusion* from a step that was never reached, so the @@ -224,7 +229,11 @@ real groom, so a skipped tick costs ~nothing (it never reaches the finder). - Evidence is looked for across a run's **earlier attempts**, not just the latest. The jobs endpoint reports only the newest attempt, so a manual re-run that dies in checkout would otherwise erase the record of an earlier - attempt that did reach the agent — and re-spend that audit. + attempt that did reach the agent — and re-spend that audit. The walk is + newest-first and bounded, and when an earlier attempt supplies the evidence + the clock anchors on **that attempt's** finder-job start, not the run's + `run_started_at` (which tracks the re-run and would date a week-old audit to + today). - **`workflow_dispatch` bypasses THIS gate** — a manual dispatch is never interval-throttled. It is not a blanket "always runs": the volume gate is a second, independent throttle, so a live dispatch into a quiescent repo can diff --git a/.github/groom/interval.py b/.github/groom/interval.py index bbb221d..31d4afd 100644 --- a/.github/groom/interval.py +++ b/.github/groom/interval.py @@ -69,31 +69,32 @@ _FINDER_JOB_HINTS = ("finder", "audit_find") # A finder job that reached `success` spent the (billed) audit — nothing else to -# check, the agent step is upstream of every step that could still fail. `skipped` -# (the interval-skip case) and a null conclusion never count at all. Every other -# ending — `failure`, `timed_out`, `cancelled` — may or may not have spent the -# audit, so it needs EVIDENCE; see _AGENT_EVIDENCE_CONCLUSIONS below. +# check, the agent step is upstream of every step that could still fail. _AUDITED_CONCLUSIONS = {"success"} -# A non-success ending counts as a spent audit only if the billed agent step -# actually started (BE-4814). Counting every failure keeps a run that spent money -# but died at a LATER step (e.g. the JSON assert) from re-spending on the very -# next daily tick — that half is still wanted. But the finder job can also die -# far BEFORE the agent: checkout, the asset load, the prompt build, the runner -# itself. Those spend nothing, and counting them advances the cadence clock, so a -# typo'd input or a broken caller goes quiet for a whole GROOM_INTERVAL_DAYS -# window instead of recurring (and being noticed) daily. This gate is fail-OPEN -# everywhere else; that was the one branch that failed closed. +# The two endings that definitively spent NOTHING, so they never even reach the +# evidence path: `skipped` is this very gate's own interval-skip, and a null +# conclusion means the run is not finished. Deliberately a DENYLIST — every other +# ending may or may not have billed, and is resolved by the per-step evidence in +# `agent_step_started`: if the agent step ran, the audit was spent no matter how +# the job was finally stamped. An allowlist here would have to enumerate the whole +# API vocabulary (`failure`, `timed_out`, `cancelled`, and the rarer `neutral` / +# `stale` / `action_required`), and any conclusion it forgot would silently mean +# "billed, but never counted" — i.e. re-spent on every subsequent daily tick. +# +# `timed_out` and `cancelled` are the EXPENSIVE members: the finder job carries +# `timeout-minutes: 40`, so an agent that hangs bills the full window and *then* +# trips the job timeout — the single costliest outcome this module sees. # -# `timed_out` and `cancelled` belong here alongside `failure` and are the -# EXPENSIVE members of the set: the finder job carries `timeout-minutes: 40`, so -# an agent that hangs bills the full window and *then* trips the job timeout — -# the single costliest outcome this module sees. Leaving those conclusions out of -# the evidence path meant they could never count, so that 40 minutes of billing -# was forgotten and re-spent on every subsequent daily tick. They still need the -# same per-step evidence as a `failure` (a run cancelled during checkout bills -# nothing), which is exactly what `agent_step_started` supplies. -_AGENT_EVIDENCE_CONCLUSIONS = {"failure", "timed_out", "cancelled", "canceled"} +# The evidence requirement itself is BE-4814. Counting a failure that spent money +# but died at a LATER step (e.g. the JSON assert) keeps it from re-spending on the +# very next daily tick — that half is wanted. But the finder job can also die far +# BEFORE the agent: checkout, the asset load, the prompt build, the runner itself. +# Those spend nothing, and counting them advances the cadence clock, so a typo'd +# input or a broken caller goes quiet for a whole GROOM_INTERVAL_DAYS window +# instead of recurring (and being noticed) daily. This gate is fail-OPEN +# everywhere else; that was the one branch that failed closed. +_NEVER_AUDITED_CONCLUSIONS = {"skipped", ""} # The billed agent step inside the finder job, matched EXACTLY (after strip) # against the `steps[]` the runs-jobs API returns per job. The literal lives here, @@ -314,11 +315,12 @@ def agent_step_started(job) -> bool: def run_audited(jobs) -> bool: """True if a run's jobs show the finder actually ran (not an interval-skip). - A `success` counts on the job conclusion alone. A `failure`/`timed_out`/ - `cancelled` counts only with positive evidence that the agent step started - (BE-4814) — the job can end long before it (checkout, asset load, prompt - build), and those runs bill nothing, so treating them as a spent audit would - advance the cadence clock and hide the breakage for a whole interval. + A `success` counts on the job conclusion alone. Every other ending except the + two that spent nothing by definition (`skipped`, unfinished) counts only with + positive evidence that the agent step started (BE-4814) — the job can end long + before it (checkout, asset load, prompt build), and those runs bill nothing, + so treating them as a spent audit would advance the cadence clock and hide the + breakage for a whole interval. """ for job in jobs if isinstance(jobs, list) else []: if not isinstance(job, dict): @@ -332,7 +334,7 @@ def run_audited(jobs) -> bool: conclusion = _text(job.get("conclusion")).lower() if conclusion in _AUDITED_CONCLUSIONS: return True - if conclusion in _AGENT_EVIDENCE_CONCLUSIONS and agent_step_started(job): + if conclusion not in _NEVER_AUDITED_CONCLUSIONS and agent_step_started(job): return True return False @@ -424,30 +426,55 @@ def fetch_run_jobs(repo: str, run_id, run=subprocess.run, attempt=None): return payload.get("jobs", []) if isinstance(payload, dict) else [] -def run_audited_across_attempts(repo, wf_run, run=subprocess.run) -> bool: - """`run_audited` for a run, counting a spent audit on ANY of its attempts. +def finder_job_started_at(jobs): + """`started_at` of the finder job in one attempt's jobs payload, or None.""" + for job in jobs if isinstance(jobs, list) else []: + if not isinstance(job, dict): + continue + if any(hint in _text(job.get("name")).lower() for hint in _FINDER_JOB_HINTS): + return _text(job.get("started_at")) or None + return None + + +def audited_run_anchor(repo, wf_run, run=subprocess.run): + """The timestamp to anchor the cadence clock on for a run, or None if unaudited. - The plain jobs endpoint returns only the latest attempt. A re-run that dies - before the agent would therefore erase the evidence of an earlier attempt that - DID reach it, and the already-paid audit would repeat on the next tick — the - same forgotten-spend bug as a pre-agent failure, one level up. So when the - latest attempt shows nothing and the run has earlier ones, walk them back. + `run_audited` for the run, counting a spent audit on ANY of its attempts. The + plain jobs endpoint returns only the latest attempt, so a re-run that dies + before the agent would erase the evidence of an earlier attempt that DID reach + it, and the already-paid audit would repeat on the next tick — the same + forgotten-spend bug as a pre-agent failure, one level up. When the latest + attempt shows nothing and the run has earlier ones, walk them back. Costs nothing in the normal case: `run_attempt` is 1 for every run nobody re-ran by hand, and the loop is skipped entirely. """ - if run_audited(fetch_run_jobs(repo, wf_run.get("id"), run=run)): - return True + run_id = wf_run.get("id") + if run_audited(fetch_run_jobs(repo, run_id, run=run)): + return _text(wf_run.get("run_started_at")) or None try: attempts = int(wf_run.get("run_attempt") or 1) except (TypeError, ValueError): attempts = 1 # Newest-first, excluding the latest (already read above), and bounded so a # pathologically re-run entry can't turn the cheap gate into a request storm. - for attempt in range(min(attempts, _MAX_ATTEMPTS_SCANNED) - 1, 0, -1): - if run_audited(fetch_run_jobs(repo, wf_run.get("id"), run=run, attempt=attempt)): - return True - return False + # The window must slide with `attempts` — capping the START at + # _MAX_ATTEMPTS_SCANNED would scan the OLDEST attempts of a heavily re-run + # entry and miss a billed audit sitting on a recent one. + for attempt in range(attempts - 1, max(0, attempts - _MAX_ATTEMPTS_SCANNED), -1): + jobs = fetch_run_jobs(repo, run_id, run=run, attempt=attempt) + if run_audited(jobs): + # `run_started_at` tracks the LATEST attempt, so anchoring on it here + # would date a week-old paid audit to today's pre-agent re-run and + # suppress the next full interval — the fail-CLOSED direction this + # gate exists to avoid. Prefer the audited attempt's own finder-job + # start; fall back to the run's creation (older anchor = more elapsed + # days = fail-open) rather than the re-run time. + return (finder_job_started_at(jobs) + or _text(wf_run.get("created_at")) + or _text(wf_run.get("run_started_at")) + or None) + return None def find_last_audited_run_at(repo, workflow_file, current_run_id, run=subprocess.run): @@ -456,6 +483,9 @@ def find_last_audited_run_at(repo, workflow_file, current_run_id, run=subprocess Walks the caller workflow's runs newest-first, skips the current run and any still-in-progress run, and returns the first whose finder job actually ran. Returns None if none is found within the scanned window (-> fail-open run). + + The anchor is the run's `run_started_at`, except where only an EARLIER attempt + supplied the evidence — see `audited_run_anchor`. """ current = str(current_run_id) if current_run_id is not None else None for wf_run in fetch_workflow_runs(repo, workflow_file, run=run): @@ -465,8 +495,9 @@ def find_last_audited_run_at(repo, workflow_file, current_run_id, run=subprocess continue if wf_run.get("status") != "completed": continue - if run_audited_across_attempts(repo, wf_run, run=run): - return wf_run.get("run_started_at") + anchor = audited_run_anchor(repo, wf_run, run=run) + if anchor: + return anchor return None diff --git a/.github/groom/tests/test_interval.py b/.github/groom/tests/test_interval.py index 71003f4..81e505f 100644 --- a/.github/groom/tests/test_interval.py +++ b/.github/groom/tests/test_interval.py @@ -379,6 +379,22 @@ def test_a_cancelled_agent_step_without_a_span_stays_fail_open(self): step = agent_step(conclusion="cancelled", started_at=started, completed_at=completed) self.assertFalse(interval.run_audited([finder_job("timed_out", [step])]), (started, completed)) + def test_any_ending_that_is_not_skipped_or_unfinished_takes_the_evidence_path(self): + # The rule is a DENYLIST, not an enumeration of endings: if the agent step + # ran, the audit was spent no matter how the job was finally stamped. An + # allowlist would have to name the whole API vocabulary, and anything it + # forgot would read as "billed but never counted", i.e. re-spent daily. + for conclusion in ("failure", "timed_out", "cancelled", "canceled", + "neutral", "stale", "action_required", "something_new"): + self.assertTrue(interval.run_audited([finder_job(conclusion, [agent_step()])]), conclusion) + self.assertFalse(interval.run_audited([finder_job(conclusion, [pre_agent_step()])]), conclusion) + + def test_the_two_endings_that_spent_nothing_never_reach_the_evidence_path(self): + # `skipped` is this gate's own interval-skip and a null conclusion means + # unfinished — neither can have billed, whatever the steps payload claims. + for conclusion in (None, "", "skipped"): + self.assertFalse(interval.run_audited([finder_job(conclusion, [agent_step()])]), conclusion) + def test_a_timed_out_agent_does_not_re_spend_on_the_next_tick(self): # End-to-end, the harm this closes: yesterday's run hung and burned the # full 40-minute timeout. Today's tick must SKIP — the audit was paid. @@ -443,20 +459,69 @@ def spy(cmd, **kwargs): interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, run=spy) self.assertFalse([u for u in seen if "/attempts/" in u], seen) - def test_the_attempt_walk_is_bounded(self): - # A pathological re-run count can't turn the cheap gate into a request - # storm — the walk is capped, newest-first. + def attempts_fetched(self, runs, latest, by_attempt=None): + """Which attempt numbers the walk actually asked for, in request order.""" seen = [] - latest = {"99": [finder_job("failure", [pre_agent_step()])], "90": [finder_job("success")]} - base = make_gh_stub(self.runs(50), latest, {}) + base = make_gh_stub(runs, latest, by_attempt or {}) def spy(cmd, **kwargs): seen.append(cmd[-1]) return base(cmd, **kwargs) - interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, run=spy) - attempts_hit = [u for u in seen if "/attempts/" in u] - self.assertEqual(len(attempts_hit), interval._MAX_ATTEMPTS_SCANNED - 1, attempts_hit) + decision = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, run=spy) + return [int(u.split("/attempts/")[1].split("/")[0]) for u in seen if "/attempts/" in u], decision + + def test_the_attempt_walk_is_bounded_AND_reads_the_NEWEST_earlier_attempts(self): + # A pathological re-run count can't turn the cheap gate into a request + # storm — but the cap must slide the window with `run_attempt`, not pin it + # to the bottom. Asserting only the COUNT passes either way and would mask + # a walk that scans attempts 1..4 of a 50-attempt run: a billed audit on a + # recent attempt (49) would go unread and be re-spent on the next tick. + latest = {"99": [finder_job("failure", [pre_agent_step()])], "90": [finder_job("success")]} + fetched, _ = self.attempts_fetched(self.runs(50), latest) + self.assertEqual(fetched, [49, 48, 47, 46], fetched) + self.assertEqual(len(fetched), interval._MAX_ATTEMPTS_SCANNED - 1, fetched) + # Under the cap, the walk simply reaches attempt 1 — nothing is skipped. + fetched, _ = self.attempts_fetched(self.runs(3), latest) + self.assertEqual(fetched, [2, 1], fetched) + + def test_a_billed_audit_on_a_recent_attempt_of_a_heavily_re_run_entry_counts(self): + # The harm the direction bug caused, end to end: attempt 49 of 50 paid for + # the agent, so today's tick must SKIP rather than re-spend it. + latest = {"99": [finder_job("failure", [pre_agent_step()])], "90": [finder_job("success")]} + by_attempt = {"99/49": [billed_finder_job()]} + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, + run=make_gh_stub(self.runs(50), latest, by_attempt)) + self.assertFalse(d["should_run"], d["reason"]) + + def test_the_anchor_is_the_audited_attempt_not_the_re_run(self): + # `run_started_at` tracks the LATEST attempt. If the paid attempt ran 8 + # days ago and someone re-ran the entry today (dying pre-agent), anchoring + # on the run means "audited today" and suppresses the next full interval — + # fail-CLOSED, the direction this gate exists to avoid. Anchor on the + # audited attempt's own finder-job start instead, so the tick RUNS. + runs = self.runs(2) + runs[1]["run_started_at"] = iso(0.1) # today's pre-agent re-run + runs[1]["created_at"] = iso(8) + latest = {"99": [finder_job("failure", [pre_agent_step()])], "90": [finder_job("success")]} + billed = billed_finder_job() + billed["started_at"] = iso(8) + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, + run=make_gh_stub(runs, latest, {"99/1": [billed]})) + self.assertTrue(d["should_run"], d["reason"]) + self.assertEqual(d["last_run_at"], iso(8)) + + def test_a_missing_attempt_timestamp_falls_back_to_the_older_anchor(self): + # No finder-job `started_at`: fall back to the run's CREATION, not its + # re-run time. An older anchor means more elapsed days, i.e. fail-open. + runs = self.runs(2) + runs[1]["run_started_at"] = iso(0.1) + runs[1]["created_at"] = iso(8) + latest = {"99": [finder_job("failure", [pre_agent_step()])], "90": [finder_job("success")]} + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, + run=make_gh_stub(runs, latest, {"99/1": [billed_finder_job()]})) + self.assertTrue(d["should_run"], d["reason"]) + self.assertEqual(d["last_run_at"], iso(8)) def test_a_garbage_run_attempt_degrades_to_the_latest_attempt_only(self): latest = {"99": [billed_finder_job()], "90": [finder_job("success")]} From f42b75857227d3d2bd253ee38e17b22caf7d54e2 Mon Sep 17 00:00:00 2001 From: Matt Miller Date: Mon, 27 Jul 2026 19:34:18 -0700 Subject: [PATCH 5/6] docs(groom): follow the audited_run_anchor rename through the comments (BE-4814) --- .github/groom/interval.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/.github/groom/interval.py b/.github/groom/interval.py index 31d4afd..61dd4eb 100644 --- a/.github/groom/interval.py +++ b/.github/groom/interval.py @@ -23,8 +23,8 @@ asset load, prompt build) billed nothing, so it must not advance the clock (BE-4814, see `run_audited`). Conversely a job that hung and tripped its 40-minute timeout billed the most of any outcome, so it must. The interval-skip -ticks in between never reset it either. Run history is durable across the stateless CI runs and readable with -only `actions: read`. +ticks in between never reset it either. Run history is durable across the +stateless CI runs and readable with only `actions: read`. The gate is **fail-open**, matching the volume gate: any error deriving the last run (API hiccup, unparseable timestamp, no history) RUNS the audit rather than @@ -172,7 +172,7 @@ # How many attempts of a single run to read back before giving up (fail-open). # Only reached for a run somebody re-ran by hand, which is already rare; the cap # keeps a pathological re-run count from turning this cheap gate into a storm of -# API calls. See `run_audited_across_attempts`. +# API calls. See `audited_run_anchor`. _MAX_ATTEMPTS_SCANNED = 5 @@ -415,7 +415,7 @@ def fetch_run_jobs(repo: str, run_id, run=subprocess.run, attempt=None): `attempt=None` asks the plain endpoint, which reports only the run's LATEST attempt; pass an attempt number to read an earlier one (see - `run_audited_across_attempts`). + `audited_run_anchor`). """ if not _REPO_RE.match(repo or ""): raise ValueError(f"invalid repo {repo!r}: expected owner/name") From b2aab8994d56aba76b1c42a5dffc7bccb41a3356 Mon Sep 17 00:00:00 2001 From: Matt Miller Date: Mon, 27 Jul 2026 19:55:22 -0700 Subject: [PATCH 6/6] fix(groom): never anchor the cadence clock on a re-run timestamp (BE-4814) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Third review round. - The earlier-attempt fallback chain ended with `run_started_at` — the re-run time the comment directly above it rejects. With no finder-job start and no `created_at` it would date a week-old audit to today and suppress the next full interval: fail-CLOSED. The chain now stops at `created_at`/None, so an unanchorable run is skipped and the scan moves to an older one, which is the fail-open direction. - The latest-attempt branch dropped the whole run when `run_started_at` was missing instead of using the same fallbacks. Both paths now share one chain. - `fetch_run_jobs` guards `run_id` the way it already guarded `repo`, and `find_last_audited_run_at` SKIPS a junk entry rather than letting the raise abort the scan (which would fail open on the whole decision and forget the real history behind it). - `finder_job_started_at` scans past a hint-matching job that carries no timestamp instead of giving up on the first match. - The gate job gets `timeout-minutes: 10` — the only job in groom.yml without a bound, and its cost is data-dependent (up to _MAX_RUNS_SCANNED runs x _MAX_ATTEMPTS_SCANNED attempts at a 30s per-call timeout). - The groom.yml pin test now also asserts the agent step carries no `if:`. A `success` is trusted on the job conclusion ALONE, so a conditionally skipped agent inside a succeeding job would count as a spent audit while billing nothing. That was defended only by a comment; now by a test. --- .github/groom/interval.py | 49 +++++++++++---- .github/groom/tests/test_interval.py | 92 +++++++++++++++++++++++++++- .github/workflows/groom.yml | 7 +++ 3 files changed, 133 insertions(+), 15 deletions(-) diff --git a/.github/groom/interval.py b/.github/groom/interval.py index 61dd4eb..ffd297e 100644 --- a/.github/groom/interval.py +++ b/.github/groom/interval.py @@ -161,6 +161,9 @@ # A workflow file basename the API accepts as a workflow id, e.g. `ci-groom.yml`. _WORKFLOW_FILE_RE = re.compile(r"^[A-Za-z0-9._-]+\.ya?ml$") +# A run id is a bare positive integer — anything else came from a junk payload. +_RUN_ID_RE = re.compile(r"^[0-9]+$") + # Bound each `gh api` call so a stalled connection can't hang the gate until the # coarse job timeout (mirrors ledger.py). _FETCH_TIMEOUT_SECONDS = 30 @@ -419,6 +422,10 @@ def fetch_run_jobs(repo: str, run_id, run=subprocess.run, attempt=None): """ if not _REPO_RE.match(repo or ""): raise ValueError(f"invalid repo {repo!r}: expected owner/name") + # Guarded like `repo`: a junk run payload missing `id` would otherwise + # interpolate `None` into the path and spend a doomed round-trip to find out. + if not _RUN_ID_RE.match(str(run_id or "")): + raise ValueError(f"invalid run id {run_id!r}: expected a positive integer") base = f"/repos/{repo}/actions/runs/{run_id}" if attempt is not None: base = f"{base}/attempts/{int(attempt)}" @@ -427,12 +434,20 @@ def fetch_run_jobs(repo: str, run_id, run=subprocess.run, attempt=None): def finder_job_started_at(jobs): - """`started_at` of the finder job in one attempt's jobs payload, or None.""" + """`started_at` of the finder job in one attempt's jobs payload, or None. + + Keeps scanning past a matching job that carries no usable timestamp rather + than giving up on the first hint match — there is one finder job today, but a + payload that listed a second must not lose the answer to ordering. + """ for job in jobs if isinstance(jobs, list) else []: if not isinstance(job, dict): continue - if any(hint in _text(job.get("name")).lower() for hint in _FINDER_JOB_HINTS): - return _text(job.get("started_at")) or None + if not any(hint in _text(job.get("name")).lower() for hint in _FINDER_JOB_HINTS): + continue + started = _text(job.get("started_at")) + if started: + return started return None @@ -450,8 +465,15 @@ def audited_run_anchor(repo, wf_run, run=subprocess.run): re-ran by hand, and the loop is skipped entirely. """ run_id = wf_run.get("id") - if run_audited(fetch_run_jobs(repo, run_id, run=run)): - return _text(wf_run.get("run_started_at")) or None + latest_jobs = fetch_run_jobs(repo, run_id, run=run) + if run_audited(latest_jobs): + # `run_started_at` tracks the LATEST attempt, which is the audited one + # here, so it is the right anchor — but share the earlier-attempt branch's + # fallbacks rather than dropping the whole run when it is missing. + return (_text(wf_run.get("run_started_at")) + or finder_job_started_at(latest_jobs) + or _text(wf_run.get("created_at")) + or None) try: attempts = int(wf_run.get("run_attempt") or 1) except (TypeError, ValueError): @@ -467,13 +489,12 @@ def audited_run_anchor(repo, wf_run, run=subprocess.run): # `run_started_at` tracks the LATEST attempt, so anchoring on it here # would date a week-old paid audit to today's pre-agent re-run and # suppress the next full interval — the fail-CLOSED direction this - # gate exists to avoid. Prefer the audited attempt's own finder-job - # start; fall back to the run's creation (older anchor = more elapsed - # days = fail-open) rather than the re-run time. - return (finder_job_started_at(jobs) - or _text(wf_run.get("created_at")) - or _text(wf_run.get("run_started_at")) - or None) + # gate exists to avoid. So it is NOT in this chain at all, not even as + # a last resort: prefer the audited attempt's own finder-job start, + # then the run's creation (an older anchor means more elapsed days, + # i.e. fail-open), and otherwise give up on this run entirely — the + # scan moves to an older one, which is again the fail-open direction. + return finder_job_started_at(jobs) or _text(wf_run.get("created_at")) or None return None @@ -491,6 +512,10 @@ def find_last_audited_run_at(repo, workflow_file, current_run_id, run=subprocess for wf_run in fetch_workflow_runs(repo, workflow_file, run=run): if not isinstance(wf_run, dict): continue + # One junk entry skips that run rather than aborting the scan (which + # would fail open on the whole decision and forget real history). + if not _RUN_ID_RE.match(str(wf_run.get("id") or "")): + continue if current is not None and str(wf_run.get("id")) == current: continue if wf_run.get("status") != "completed": diff --git a/.github/groom/tests/test_interval.py b/.github/groom/tests/test_interval.py index 81e505f..690c986 100644 --- a/.github/groom/tests/test_interval.py +++ b/.github/groom/tests/test_interval.py @@ -328,6 +328,27 @@ def test_groom_yml_names_exactly_the_agent_step_this_module_matches(self): # Exactly one step in that job carries the name — otherwise "did the agent # start?" stops having a single answer. self.assertEqual(finder_block[0].count(f"- name: {interval.agent_step_name()}\n"), 1) + # And that step must carry no `if:`. A `success` is trusted on the job + # conclusion ALONE, so a conditionally-skipped agent inside a succeeding + # job would count as a spent audit and suppress the cadence for a full + # interval while billing nothing. groom.yml warns about this in a comment; + # this is the assertion that actually holds the line. + step = finder_block[0].split(f"- name: {interval.agent_step_name()}\n", 1)[1] + step = step.split("\n - name:", 1)[0] + self.assertNotRegex(step, r"(?m)^\s+if:\s", "the pinned agent step must not be conditional") + + def test_the_gate_job_is_time_bounded(self): + # The gate walks run history (and, for re-run entries, per-attempt job + # payloads) at a 30s per-call timeout, so its cost is data-dependent. It + # is the cheap job, but it still needs a hard stop like every other job + # in the file. + wf = os.path.join(os.path.dirname(__file__), "..", "..", "workflows", "groom.yml") + with open(wf, encoding="utf-8") as f: + text = f.read() + gate = re.split(r"(?m)^ (?=[A-Za-z_][A-Za-z0-9_-]*:\s*$)", text) + gate = [b for b in gate if b.startswith("gate:")] + self.assertEqual(len(gate), 1, "could not isolate the gate job in groom.yml") + self.assertRegex(gate[0], r"(?m)^ timeout-minutes: \d+$") class CancelledAndTimedOutTest(unittest.TestCase): @@ -427,14 +448,47 @@ def runs(self, attempt_count): {"id": 90, "status": "completed", "run_started_at": iso(8)}, ] + def billed_attempt(self, days_ago): + """A billed finder job stamped with when that attempt actually ran.""" + job = billed_finder_job() + job["started_at"] = iso(days_ago) + return [job] + def test_an_earlier_attempt_that_billed_still_counts(self): latest = {"99": [finder_job("failure", [pre_agent_step()])], "90": [finder_job("success")]} - by_attempt = {"99/1": [billed_finder_job()], "99/2": latest["99"]} + by_attempt = {"99/1": self.billed_attempt(1), "99/2": latest["99"]} d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, run=make_gh_stub(self.runs(2), latest, by_attempt)) self.assertFalse(d["should_run"], d["reason"]) self.assertEqual(d["last_run_at"], iso(1)) + def test_the_anchor_never_falls_back_to_the_re_run_timestamp(self): + # The fallback chain for an earlier attempt is finder-job start -> + # `created_at` -> give up. `run_started_at` is deliberately NOT the last + # resort: it is the re-run time, so using it would date a week-old audit + # to today and suppress the next full interval (fail-CLOSED). With neither + # timestamp available the run is skipped and the scan moves to an older + # one — here the 8-day-old real run, so the tick RUNS. + runs = self.runs(2) + runs[1]["run_started_at"] = iso(0.1) # today's pre-agent re-run + latest = {"99": [finder_job("failure", [pre_agent_step()])], "90": [finder_job("success")]} + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, + run=make_gh_stub(runs, latest, {"99/1": [billed_finder_job()]})) + self.assertTrue(d["should_run"], d["reason"]) + self.assertEqual(d["last_run_at"], iso(8)) + + def test_an_audited_latest_attempt_missing_run_started_at_still_anchors(self): + # The latest-attempt branch shares the same fallbacks instead of dropping + # the run: `run_started_at` -> finder-job start -> `created_at`. + runs = self.runs(1) + del runs[1]["run_started_at"] + runs[1]["created_at"] = iso(1) + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, + run=make_gh_stub(runs, {"99": self.billed_attempt(1), + "90": [finder_job("success")]})) + self.assertFalse(d["should_run"], d["reason"]) + self.assertEqual(d["last_run_at"], iso(1)) + def test_no_attempt_that_billed_still_falls_open(self): # Every attempt died pre-agent: nothing was spent, so the clock stays # anchored on the 8-day-old real run and today's tick RUNS. @@ -489,10 +543,10 @@ def test_a_billed_audit_on_a_recent_attempt_of_a_heavily_re_run_entry_counts(sel # The harm the direction bug caused, end to end: attempt 49 of 50 paid for # the agent, so today's tick must SKIP rather than re-spend it. latest = {"99": [finder_job("failure", [pre_agent_step()])], "90": [finder_job("success")]} - by_attempt = {"99/49": [billed_finder_job()]} d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, - run=make_gh_stub(self.runs(50), latest, by_attempt)) + run=make_gh_stub(self.runs(50), latest, {"99/49": self.billed_attempt(1)})) self.assertFalse(d["should_run"], d["reason"]) + self.assertEqual(d["last_run_at"], iso(1)) def test_the_anchor_is_the_audited_attempt_not_the_re_run(self): # `run_started_at` tracks the LATEST attempt. If the paid attempt ran 8 @@ -532,6 +586,38 @@ def test_a_garbage_run_attempt_degrades_to_the_latest_attempt_only(self): run=make_gh_stub(runs, latest, {})) self.assertFalse(d["should_run"], (raw, d["reason"])) + def test_a_run_entry_with_a_junk_id_is_skipped_not_fetched(self): + # A missing/garbage `id` would interpolate into the URL and spend a doomed + # round-trip. It must skip that ENTRY, not abort the scan — aborting would + # fail open on the whole decision and forget the real history behind it. + seen = [] + runs = [ + {"id": 100, "status": "in_progress", "run_started_at": iso(0)}, + {"status": "completed", "run_started_at": iso(1)}, # no id + {"id": "99; rm -rf /", "status": "completed", "run_started_at": iso(1)}, + {"id": 90, "status": "completed", "run_started_at": iso(8)}, + ] + base = make_gh_stub(runs, {"90": [finder_job("success")]}) + + def spy(cmd, **kwargs): + seen.append(cmd[-1]) + return base(cmd, **kwargs) + + d = interval.evaluate("o/r", "ci-groom.yml", 100, 7.0, "schedule", NOW, run=spy) + self.assertTrue(d["should_run"], d["reason"]) + self.assertEqual(d["last_run_at"], iso(8)) # the scan reached the real run + self.assertFalse([u for u in seen if "None" in u or "rm -rf" in u], seen) + + def test_finder_job_started_at_scans_past_a_match_with_no_timestamp(self): + stamped = finder_job("success") + stamped["started_at"] = iso(3) + jobs = [{"name": "groom / Gate", "started_at": iso(9)}, + finder_job("skipped"), # matches the hint, no timestamp + stamped] + self.assertEqual(interval.finder_job_started_at(jobs), iso(3)) + self.assertIsNone(interval.finder_job_started_at([finder_job("skipped")])) + self.assertIsNone(interval.finder_job_started_at(None)) + class IntervalThresholdTest(unittest.TestCase): def test_full_day_intervals_lose_a_half_tick(self): diff --git a/.github/workflows/groom.yml b/.github/workflows/groom.yml index 7d5f863..26dc87f 100644 --- a/.github/workflows/groom.yml +++ b/.github/workflows/groom.yml @@ -360,6 +360,13 @@ jobs: gate: name: Gate runs-on: ubuntu-latest + # The one job here that had no bound. It is meant to be cheap — a handful of + # `gh api` reads — but its cost is data-dependent: the interval gate walks up + # to `_MAX_RUNS_SCANNED` runs and, for any that were re-run by hand, up to + # `_MAX_ATTEMPTS_SCANNED` attempts each, at a 30s per-call timeout. A degraded + # API on a pathological history could burn runner minutes before the gate + # fails open. Ten minutes is ~20x the normal case and still a hard stop. + timeout-minutes: 10 permissions: contents: read # The interval gate lists THIS caller's Actions run history to find the