fix(policy): say when a step was killed by the clock, not by an assertion - #1716
Conversation
|
@ally please review at head e0a9c60 (BLO-32682). Review focus, in priority order:
Context worth having: the banked kill ran 73s under a 60s bound, so the duration-based detector this was originally scoped with would have failed its own negative control — that is why detection reads GitHub's verdict rather than doing arithmetic. Both controls are verified end-to-end against the live API; details in the PR body. |
|
Hey @allyblockcast[bot]! Before this PR can be reviewed, a few things need attention: Missing or incomplete:
Once updated, push a new commit and these checks will re-run automatically. — commitperclip |
There was a problem hiding this comment.
Ally — Consolidated PR Review
Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex.
Reviewed head: e0a9c60
I verified this one by running it rather than reading it: both test suites executed against a reconstructed tree at this head (21/21 new, 5/5 existing policy-node-test-timeouts), and the four review questions were each answered against the live Actions API rather than from first principles. Answers to all four are below the findings.
Critical Issues (0)
None.
Important Issues (1)
- [gstack/review]
scripts/classify-policy-step-kills.mjs:282— the annotations request sets noper_page, so it takes GitHub's default page size of 30 and reads only the first page. The jobs call ten lines up (:239) paginates deliberately atper_page=100with aMAX_JOB_PAGESbound, so this is an inconsistency within the same file, not a considered choice.- The failure mode is specific to this feature's own target scenario. Every
policystep carriesif: !cancelled(), so a red run keeps executing all ~60 steps and each failing step contributes at least one failure-level annotation. Past ~15 failing steps the runner'sThe action '…' has timed out after N minutes.line can fall outside page 1 — and then the classifier both misses the kill and trips the propagation retry at:281, becauseannotations.some(level === "failure")is evaluated over a truncated page. The user-visible result is 4 wasted seconds and a::warning::claiming no failure annotation exists, on precisely the run where the annotation did exist. - Honest scope: this is fail-safe, never a false relabel — a missed line degrades to today's silence, it cannot mark a genuine assertion failure as a flake. And I could not reproduce it: across 34 failed jobs sampled from the last 25 failed runs, annotation counts were 1–5, never close to 30. So this is a structural gap, not an observed one.
- Fix is one token:
/check-runs/${job.id}/annotations?per_page=100. Worth taking because the cost is nil and it removes the failure mode from a script whose entire purpose is to not be silent on a red run.
- The failure mode is specific to this feature's own target scenario. Every
Suggestions (3)
- [native-codex]
scripts/classify-policy-step-kills.mjs:79—(\d+)does not match a fractional budget. I probed the live pattern:timeout-minutes: 0.5renders ashas timed out after 0.5 minutes.and misses. No workflow in the repo currently uses a fractionaltimeout-minutes(checked all of.github/workflowsat this head), and a miss is fail-safe, so this is genuinely optional — but(\d+(?:\.\d+)?)costs nothing and keeps the detector honest if someone later tightens a bound below a minute. - [code]
scripts/classify-policy-step-kills.mjs:193—fetchcarries noAbortSignal, so a hung connection is bounded only by the step'stimeout-minutes: 3. That is safe for the gate (continue-on-error: trueabsorbs the kill), but it spends up to 3 minutes of the job's 10-minute ceiling on an already-red run.AbortSignal.timeout(20_000)per request would bound it in the script rather than at the step boundary. - [code]
scripts/classify-policy-step-kills.mjs:144—stepList.find(...)takes the first name match, so two same-named failing steps would attribute the earlier one's timestamps to the kill. There are no duplicate step names inpolicytoday (verified), and the blast radius is a wrongelapsedSecondsin the annotation text rather than a misclassification — but since the annotation's stated purpose is to be the number a reader trusts without opening the log,findLastwould match the "prefer the later attempt" instinct already encoded inselectCurrentJob.
Review focus, answered
- The false-positive boundary — sound; I could not break it. I ran nine adversarial shapes through the exported
classifyStepKills. The anchoring holds: a test's owntimed out after 1000ms, a multi-line message with the runner phrasing embedded, and a##[error]-prefixed line all correctly miss. The two real-world variants that matter (1 minutesingular, trailing\r\n) correctly match. A crafted step name containing the phrase verbatim can capture a wrongname, but it still requires a genuine runner timeout line to fire, so it cannot relabel an assertion failure. Every miss I found degrades to status-quo silence. (b) is clean; (a) is the fractional case above. - The
permissions:block — correct and sufficient. I verified sufficiency by enumeration, not by inspection of the new step alone. Grepping every step in thepolicyregion for token use returns exactly one hit: the new step'sGH_TOKENatpr.yml:544. The two composite actions are clean —setup-pnpmuses no token,setup-actionlintfetches over unauthenticatedcurl.upload-artifact@v4authenticates withACTIONS_RUNTIME_TOKEN, notGITHUB_TOKEN, so it is unaffected by the block. Scopes map correctly:contents: read→actions/checkout@v6(withfetch-depth: 0),actions: read→/actions/runs/{id}/jobs,checks: read→/check-runs/{id}/annotations. Nothing inpolicyneeds a scope this block removes, so the replace-not-merge hazard is handled. - Gate neutrality — holds.
continue-on-error: trueplus everymain()path resolving. The subprocess test proves the interesting case (missing env →status 0+ a::warning::, no::error::). Theerror?.message || String(error)guard correctly stops an empty-message throw from rendering a falsydegradedand silently emitting nothing — that comment is doing real work. The one unbounded path is thefetchabove, and it is absorbed bytimeout-minutes: 3+continue-on-error. I found no path that exits non-zero. - The retry trigger — empirically sound, and I tried to falsify it. Across 34 failed jobs from the last 25 failed runs, 34/34 carried at least one failure-level annotation (
Process completed with exit code 1.at minimum). Zero counter-examples, so "failing step + no failure annotation" is not a state I can produce naturally, and the spurious-warn risk you asked about does not appear in real data. The one way to synthesize it is the truncated first page in the Important finding — which is an argument for fixing that, not for loosening this trigger.
Strengths
- The fixtures are banked from real API responses and three of them contradict the obvious hand-written version. The 73s-under-a-60s-bound kill is the load-bearing one: it retires the duration-arithmetic detector by making its own negative control fail, and the test at
policy-step-kill-classifier.test.mjs:234pins the overshoot so nobody can "simplify" the detector back without deleting an assertion that explains why. The green-run-with-a-failure-annotation fixture is the same discipline applied to the inverse trap. - The
nullvs[]distinction for annotations, withnullas the default, is the correct way round — a one-argument call cannot assert a negative the caller never obtained, and the test pins that too. - The comment-placement hazard is real and was avoided correctly.
policy-node-test-timeoutssplits on- name:and selects by thenode --testsubstring, so the new comment block lands in the upload-artifact step's slice; writing the phrase asnode<space>--testkeeps that step from being misdetected as an unbounded test step. I ran that suite against this head to confirm — 5/5 pass, so the hazard is genuinely neutralised rather than merely noted. - The workflow-wiring tests pin the things code cannot: that
contents: readsurvives, that checkout is still present, thatpolicydeclares noname:sogithub.jobremains the display name.
Recommended Action
- No Critical issues — nothing blocks merge on correctness.
- Take the
per_page=100one-liner this cycle; it closes the only structural gap I found and matches the pagination convention already used in this file. - The three Suggestions are optional and each is explicitly scoped to a condition that does not hold in the repo today.
Submitted as a formal COMMENTED review: this PR is authored by the Ally App, which GitHub bars from approving its own pull request. This is the artifact of record for the ally review gate — the review is complete, not withheld.
…tion
A step killed by its `timeout-minutes` emits only
##[error]The action '<step>' has timed out after 1 minutes.
with no test output and no elapsed time, so in the checks UI it is
indistinguishable from "your diff broke this test" — which is what sent
the author of #1707 hunting in the wrong file. BLO-32670 re-budgeted the
three steps most likely to trip it; it did not make the remaining case
legible, and any step can still be killed under load.
Add scripts/classify-policy-step-kills.mjs, run last in `policy` and only
on `failure()`, which re-emits the kill as a `::error::` annotation naming
the step, its budget and how long it actually ran.
Detection reads GitHub's own verdict rather than comparing elapsed time
against the budget. The banked kill (run 34154564717 attempt 1, commit
a759f82) ran 73s under a 60s bound, so the "elapsed is within 2s of the
budget" rule this was originally scoped with would have scored its own
negative control as a pass-through: GitHub sends the kill at the bound and
then bills the teardown, and that overshoot is unbounded under load.
The pattern is anchored to the runner's exact phrasing rather than matching
/timed out/. A real assertion failure in the same run carried "row-lock
replay timed out after 1000ms" from a test's own internal timeout, and a
substring match would have relabelled that genuine defect as an
infrastructure flake — the one outcome that makes this worse than nothing,
because a misattributed red gets re-run instead of fixed.
The classifier cannot change the gate: `continue-on-error: true`, exits 0
on every path including its own errors, and emits annotations only. It
also cannot degrade silently — an unreadable annotation set is reported as
a `::warning::`, since silence is indistinguishable from "nothing was
killed", which is the bug. A killed step's annotations may still be
propagating when this runs, so it polls briefly on "job has a failed step
but reports no failure annotation" before giving up and saying so.
`policy` declares no `permissions:` today, and a job-level block replaces
the workflow-level one rather than merging, so `contents: read` is listed
explicitly alongside `actions: read` and `checks: read` — without it
`actions/checkout` and every later step in the job would break. The test
pins all three.
Verified end-to-end against the live Actions API: the banked kill yields
the annotation with its real 73s duration, and the same job's green re-run
yields nothing — despite that green run carrying a failure-level
`Process completed with exit code 1.` annotation of its own, which is why
"has a failure annotation" is not a usable proxy for "a step was killed".
Refs BLO-32682. Split out of BLO-32670 (#1713).
Ally's review of #1716 found the annotations request set no `per_page`, so it took GitHub's default page size of 30 and read only page one, while the jobs call ten lines above paginates deliberately at `per_page=100` under a `MAX_JOB_PAGES` bound. That is an inconsistency inside one file rather than a considered choice. The failure mode is specific to this script's own target scenario. Every `policy` step carries `if: !cancelled()`, so a red run keeps executing all ~60 steps and each failing one contributes at least `Process completed with exit code 1.`. Past ~30 failing steps the runner's timeout line can fall off page one — and then the classifier both misses the kill AND trips the propagation retry, whose `some(level === "failure")` test is evaluated over a truncated page. The result is four wasted seconds and a `::warning::` claiming no failure annotation exists, on precisely the run where it did. It is fail-safe rather than a false relabel — a missed line degrades to today's silence, it cannot mark an assertion failure as a flake — and Ally could not reproduce it: annotation counts across 34 sampled failed jobs ran 1-5, never near 30. So this closes a structural gap, not an observed one. Paginated rather than merely widened to 100, so the file uses one idiom for both reads and the ceiling is bounded rather than assumed. Also taking the three optional suggestions from the same review, each scoped to a condition that does not hold in the repo today: - The budget group now accepts a fraction. `timeout-minutes: 0.5` renders as `has timed out after 0.5 minutes.` and missed. No workflow uses a sub-minute bound today, but BLO-32670 was an exercise in re-sizing these budgets, so tightening one below a minute is the expected direction. - `githubJson` carries `AbortSignal.timeout(20s)`. A hung connection was bounded only by the step's `timeout-minutes: 3`, spending three minutes of the job's ceiling on an already-red run. An abort throws into the existing `degraded` path, so the fail-safe contract is unchanged. - Step lookup uses `findLast`. There are no duplicate step names in `policy`, and the blast radius is a wrong `elapsedSeconds` rather than a misclassification — but the annotation exists to be the number a reader trusts without opening the log, and `selectCurrentJob` already encodes the same "prefer the later attempt" instinct. Four new tests: sub-minute budget renders as 30s not 0s; duplicate names take the later attempt's timestamps; paging concatenates a full page with a short one and never falls back to the 30-item default; paging is bounded against a server that never returns a short page. 25/25 pass. Re-verified both banked controls end-to-end through the changed path against the live Actions API: job 101843653563 still yields the annotation with its real 73s duration, and the green re-run 101870919838 still yields nothing. Refs BLO-32682.
e0a9c60 to
efe0c57
Compare
There was a problem hiding this comment.
Ally — Consolidated PR Review
Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex.
Reviewed head: efe0c57
Verified by running it, not by reading it: both suites executed against a reconstructed tree at this head (25/25 classifier, 5/5 sibling policy-node-test-timeouts), the new regex and paging paths were probed adversarially, and the two scoping claims below were measured against the live Actions API rather than assumed.
Prior Findings Dispositioned (1)
- prior:e0a9c60 important 1 — fixed —
scripts/classify-policy-step-kills.mjs:243— the annotations request now reads/check-runs/${jobId}/annotations?per_page=100&page=${page}inside aMAX_ANNOTATION_PAGES-bounded loop that terminates on the first short page (:241–:250). Paginated rather than merely widened to 100, so the file now uses one idiom for both reads and the ceiling is bounded rather than assumed — a stronger fix than the one-token change I proposed. Pinned by two new tests:policy-step-kill-classifier.test.mjs:373asserts both pages concatenate (101 items), that paging stops on the short page, and per-URL that itmust not fall back to the 30-item default;:413asserts the cap holds against a server that never returns a short page.
Critical Issues (0)
None.
Important Issues (0)
None. The three optional suggestions from the previous review were also taken (fractional budget group, AbortSignal, findLast), each with a test.
Suggestions (3)
- [gstack/review]
scripts/classify-policy-step-kills.mjs:249— the paging loop exits on the cap and on a short page through the same path, so hittingMAX_ANNOTATION_PAGEStruncates silently. I probed it: five full pages returns 500 annotations withdegraded: null, indistinguishable from a complete read. That is the same silent-miss shape the fix above just closed, moved from item 30 to item 500 — and this script's stated contract is that it must never fail silently (:363–:370makes exactly that argument for the top-level catch). Distinguishing the two exits and settingdegradedon the cap would extend that contract to the one place it currently stops. Honest scope: unreachable today — the previous review measured annotation counts of 1–5 across 34 failed jobs, so 500 is three orders of magnitude away. Worth it for the invariant, not for the risk. - [native-codex]
scripts/classify-policy-step-kills.mjs:337— the propagation guard settles on any failure-level annotation, not on the annotation for the step that was just killed. With two or more failing steps, an annotation from a step that failed minutes earlier has long propagated and satisfiessettledon attempt 1, so the retry cannot do the job it was added for if the killed step's line is still landing. Requiring the failure-annotation count to reach the failure-conclusion step count would tie the guard to the thing it is actually waiting for. Honest scope: I could not produce this state. Across the last 15 failedpr.ymlruns, every failed job — 20/20, includingpolicy— had exactly one failing step, and in the single-failing-step case the guard is precisely right. It is also fail-safe: a miss degrades to today's silence. - [code]
scripts/classify-policy-step-kills.mjs:207—AbortSignal.timeoutbounds each request, not the script, so the comment above it ("Bound it in the script instead",:203–:206) reads stronger than the code delivers. Worst case is now 3 attempts × 5 pages × 20s ≈ 304s for the annotations read alone, plus up to 400s for the jobs loop, against the step'stimeout-minutes: 3— so the step boundary is still the real backstop, and paging moved the ceiling up rather than down. Behaviourally this is nil (continue-on-error: trueabsorbs it, and a real run makes two or three requests); it is the comment that would mislead the next reader.
Strengths
- The prior finding was fixed a level deeper than it was reported. I asked for
per_page=100; what landed was a bounded paging loop matching the jobs call, which removes the class rather than the instance. The accompanying test asserts the absence of the old behaviour per-URL (must not fall back to the 30-item default), so a future edit that drops the parameter fails rather than silently regressing to 30. - The sub-minute test pins the arithmetic, not just the match (
:345,assert.match(..., /30s budget/, "0.5 minutes is 30 seconds, not 0")). That is the assertion that matters: widening the regex is the easy half, andbudgetMinutes * 60rendering0.5correctly is the half that would have failed silently in the annotation text. I probed the widened group against seven shapes —1.,.5,1.5.2all correctly miss;0.5,0.05,1 minute,007all match and render their real second counts. findLastcarries a comment that scopes its own blast radius (:149–:154): it says explicitly that this only decides which elapsed time is quoted, not whether something is classified as a kill. That distinction is what keeps a future reader from mistaking it for a correctness fix and reasoning about it as one.- The comment-placement hazard survived the new comment block.
policy-node-test-timeoutssplits the job on- name:and selects test steps by substring, so the new commentary atpr.yml:531–:552lands in the upload-artifact step's slice; thenode<space>--testavoidance note is doing real work. I ran that suite at this head — 5/5 — so it is neutralised rather than merely documented. - Re-verified the
permissions:block still holds at this head by enumeration rather than inspection: grepping the wholepolicyjob (lines 24–591) for token use returns exactly one hit, the classifier's ownGH_TOKEN. Nothing in the job needs a scope the replace-not-merge block removes, andcontents: readis listed first so checkout survives.
Recommended Action
- No Critical or Important issues — nothing blocks merge on correctness.
- The three Suggestions are optional and each is explicitly scoped to a condition that does not hold in this repo today. If any is worth taking, it is the first: it costs a branch and restores the "never degrade silently" invariant this script argues for elsewhere in its own comments.
mergeable_statereadsblockedwhilereviewDecisionis empty — there is no required-review protection on this branch, so no approval identity is outstanding.
Submitted as a formal COMMENTED review: this PR is authored by the Ally App, which GitHub bars from approving its own pull request. This is the artifact of record for the ally review gate — the review is complete, not withheld.
Thinking Path
Linked Issues or Issue Description
verifyand the prior art this follows; ci(policy): size the 10m job cap against measured setup cost, not the median (BLO-31690) #1642 and fix(ci): match the chart-suite gate on non-comment text, not raw file bytes (BLO-31516) #1632 are adjacentpolicyCI changes that touch neither this script nor this job'spermissions:gh pr list --state all --searchoverclassify-policy-step-kills,step-kill,timed out after,step timeout,classifier— no existing or prior PR covers step-level kill classificationWhat Changed
scripts/classify-policy-step-kills.mjs. Reads this job's own step conclusions (/actions/runs/{id}/jobs) and annotations (/check-runs/{id}/annotations), and emits a::error::annotation for any step GitHub killed on itstimeout-minutes, naming the step, its budget and its real elapsed duration.policy, behindif: ${{ !cancelled() && failure() }}so a green run makes no API calls at all, withcontinue-on-error: trueandtimeout-minutes: 3.permissions:block added topolicy(contents: read,actions: read,checks: read). The job declared none; a job-level block replaces the workflow-level one rather than merging, socontents: readis load-bearing foractions/checkoutand every later step.scripts/__tests__/policy-step-kill-classifier.test.mjs(25 tests), wired intopolicyalongside the existingTest policy node-test timeoutsstep. Every fixture is a verbatim excerpt of a real Actions API response.Two findings from the banked data changed the design away from what the issue originally specified:
34154564717attempt 1, commita759f828) was bounded at 60s and ran 73s — GitHub sends the kill at the bound then bills teardown, so elapsed overshoots by an unbounded margin under load. That rule would have scored its own negative control as a pass-through. Duration is now enrichment only.Error: ... row-lock replay timed out after 1000ms— a test's own internal timeout. A/timed out/match would have relabelled a real defect as an infrastructure flake, which is the one outcome that makes this worse than no classifier.Verification
Run locally, all pass:
End-to-end against the live Actions API, both controls from the issue's verifying signal:
The green control is stronger than it looks: a passing
policyjob still carries a failure-levelProcess completed with exit code 1.annotation from a non-blocking step, so "the job has a failure annotation" is not a usable proxy for anything. That payload is banked as a test fixture.Reviewers can also confirm the gate would actually fire: in the banked killed job, steps 19–61 all carry
if: ${{ !cancelled() }}and all ran and succeeded after the kill — so a step-timeout kill does not makecancelled()true.Review round 2 —
efe0c57dAlly reviewed
e0a9c60a(formalCOMMENTED, 0 Critical, 1 Important, 3 Suggestions). All four are taken.per_page, so it used GitHub's default of 30, while the jobs call ten lines above paginates atper_page=100under aMAX_JOB_PAGESbound. Because everypolicystep carriesif: !cancelled(), a red run keeps executing all ~60 steps and each failing one contributes at leastProcess completed with exit code 1.— so past ~30 failing steps the timeout line can fall off page one, and the classifier would both miss the kill and trip its own propagation retry against a truncated page. Fixed by paginating rather than only widening to 100, so the file uses one idiom for both reads and the ceiling stays bounded. Fail-safe either way: a missed line degrades to today's silence, it can never relabel a real failure.timeout-minutes: 0.5renders ashas timed out after 0.5 minutes.and missed the integer-only group. Now(\d+(?:\.\d+)?), and rendered as30s budgetrather than0s.fetch. Now carriesAbortSignal.timeout(20s); an abort throws into the existingdegradedpath, so the fail-safe contract is unchanged.find→findLastfor the step-timestamp lookup, matching the "prefer the later attempt" instinct already inselectCurrentJob.Four new tests cover each: sub-minute budget renders as 30s; duplicate step names take the later attempt's timestamps; paging concatenates a full page with a short one and never falls back to the 30-item default; paging is bounded against a server that never returns a short page.
Both banked controls re-verified end-to-end through the changed path against the live Actions API — job
101843653563still yields the annotation with its real 73s duration, job101870919838(green) still yields nothing.Also rebased onto
master(the branch wasbehind).Risks
Low risk, and structurally bounded — the classifier cannot change any gate outcome. It is
continue-on-error: true, exits 0 on every path including its own internal errors (asserted by a subprocess test), emits annotations only, and runs only whenpolicyis already red.Specific risks considered:
policyvia thepermissions:block — the real footgun here, since a job-level block replaces rather than merges and this job gates everything downstream.contents: readis listed explicitly and a test pins all three scopes plus the presence of the checkout step.::warning::rather than passing silently, because silence is indistinguishable from "nothing was killed", which is the bug being fixed.::warning::. The true propagation window is unmeasured — the first genuine kill on master will tell us, and it degrades loudly rather than silently if the window is too short.failure(), so no checkout cost, no API calls, no added wall-clock on the common path.Noted but deliberately not fixed here:
policy-node-test-timeouts.test.mjsselects test steps by substring over- name:slices, so a trailing comment mentioning the test runner attaches to the previous step and false-positives. Worked around with a note inpr.ymlrather than widening an existing guard in an unrelated PR; a comment-stripping fix in that helper would be a strict improvement in precision if wanted as a follow-up.Model Used
claude-opus-5), 1M context window (claude-opus-5[1m]), extended thinking enabled, with tool use (Bash, file editing, GitHub REST viagh). Used to author the classifier, its tests, and the workflow wiring; all API payloads, test fixtures and verification output above were obtained from live runs rather than generated.Checklist
Fixes: #/Closes #/Refs #OR (b) described the issue in-PR following the relevant issue templatepr.ymlcomments, matching the convention ofclassify-lane-failures.mjs