emrg: explain a failed run whose only non-success job never started

scripts/read-run-failure.py

@@ -46,11 +46,15 @@
 
 Exit codes
 ----------
-    0  a failed job was found and its cause was printed
-    1  the run has no failed job - a determinate reading, not a failure to measure
+    0  a failed job was found and its cause was printed, **or** the run failed while no job
+       did, and the job that accounts for it was printed instead (a job cancelled before it
+       was assigned a runner is that case: it never started, so there is no step output)
+    1  the run has no failed job **and** no unstarted job to blame - a determinate reading,
+       not a failure to measure
     2  the question could not be answered (bad run id, gh failed, no jobs listed, a job's
-       log could not be fetched or came back empty) - fail loud; never report "no cause"
-       for a log nobody read
+       log could not be fetched or came back empty, a run whose own conclusion could not be
+       read while a job had not succeeded) - fail loud; never report "no cause" for a log
+       nobody read
 
 The empty-log case is the one that looks like a pass and is not: the fetch succeeded, so
 `gh` exits 0 and there is no error to surface, but a failed job with nothing in its log has
@@ -95,6 +99,7 @@
 from __future__ import annotations
 
 import argparse
+import datetime
 import json
 import re
 import subprocess
@@ -278,6 +283,93 @@ def _clean(line: str) -> str:
     return text if len(text) <= _MAX_LINE else text[: _MAX_LINE - 3] + "..."
 
 
+def _run_conclusion(run_id: int, repo: str) -> str:
+    """The run's own `conclusion` - the field that says whether there is a failure at all.
+
+    Read from the run, not inferred from its jobs: a run that succeeded while some jobs were
+    skipped (`workflow_dispatch` on a branch skips `verify-*` and `release` by design) and a
+    run that failed with a cancelled job have the same thing to see in the job list, and the
+    run's conclusion is what tells them apart.
+    """
+    payload = json.loads(_gh_api(f"repos/{repo}/actions/runs/{run_id}"))
+    if not isinstance(payload, dict):
+        raise RuntimeError(f"the run object for {run_id} is not a mapping")
+    conclusion = payload.get("conclusion")
+    status = payload.get("status")
+    if conclusion is None:
+        raise RuntimeError(
+            f"run {run_id} reports status `{status}` and no conclusion yet"
+        )
+    return str(conclusion)
+
+
+def _elapsed(job: dict) -> str:
+    """How long the job held, from its own timestamps; `unknown` when they are absent."""
+    started, ended = job.get("started_at"), job.get("completed_at")
+    if not isinstance(started, str) or not isinstance(ended, str):
+        return "unknown"
+    try:
+        seconds = int(
+            (datetime.datetime.fromisoformat(ended.replace("Z", "+00:00"))
+             - datetime.datetime.fromisoformat(started.replace("Z", "+00:00"))).total_seconds()
+        )
+    except ValueError:
+        return "unknown"
+    if seconds < 0:
+        return "unknown"
+    return f"{seconds // 60}m{seconds % 60:02d}s"
+
+
+def _otherwise_lines(job: dict) -> list[str]:
+    """The lines that explain a job which did not fail but accounts for a failed run.
+
+    The distinction this keeps is the one that decides the remedy: a job **cancelled after a
+    step failed** is a code or environment problem with a log, while a job **cancelled with
+    no step executed and no runner assigned** never started at all - its cause is scheduling,
+    and no amount of reading its (nonexistent) output would find it.
+    """
+    name = str(job.get("name"))
+    conclusion = str(job.get("conclusion") or "(none)")
+    steps = [step for step in (job.get("steps") or []) if isinstance(step, dict)]
+    runner = job.get("runner_name")
+    lines = [f"  {name} [{conclusion}] held {_elapsed(job)}"]
+    if not steps:
+        lines.append(
+            "    no step executed - the job never started, so there is no step output to read"
+        )
+    else:
+        last = steps[-1]
+        lines.append(
+            f"    {len(steps)} step(s) recorded; the last was {last.get('number')}. "
+            f"{last.get('name')} [{last.get('conclusion') or '(none)'}]"
+        )
+    if not runner:
+        lines.append(
+            "    no runner was ever assigned to it (runner_name is null) - this is a "
+            "scheduling outcome, not a step failure, and re-running is what asks the "
+            "scheduler again"
+        )
+    else:
+        lines.append(f"    it ran on {runner}")
+    return lines
+
+
+def _otherwise_report(job: dict) -> dict:
+    """The same explanation, as data, for `--json`."""
+    steps = [step for step in (job.get("steps") or []) if isinstance(step, dict)]
+    return {
+        "name": job.get("name"),
+        "conclusion": job.get("conclusion"),
+        "elapsed": _elapsed(job),
+        "runner_name": job.get("runner_name"),
+        "steps_executed": len(steps),
+        "last_step": (
+            f"{steps[-1].get('number')}. {steps[-1].get('name')} "
+            f"[{steps[-1].get('conclusion') or '(none)'}]" if steps else None
+        ),
+    }
+
+
 def _step_cause(job: dict) -> tuple[list[str], list[str]]:
     """`(the steps that did not succeed, unknown conclusions)` for one job, as names.
 
@@ -480,6 +572,73 @@ def main(argv: list[str] | None = None) -> int:
             print(f"transport: {', '.join(transports_used())}")
 
     if not failed_jobs:
+        # A run can conclude `failure` while **no job's** conclusion is a failure: a job that
+        # was cancelled before it was ever assigned a runner is that case, and it is not
+        # exotic - measured 2026-11-04 on run 41862508461 (the `v0.3.37` release), where
+        # `verify-credentials` was queued from the run's first second, never acquired a
+        # runner, and was cancelled after 15m02s; `build` then ran because its own `if:`
+        # admits a cancelled dependency, and `release` was skipped because it needs `build`,
+        # which needs that job. Answering "nothing to explain" there is the same defect as
+        # reporting "could not measure" as a pass, and it costs more, because the reading
+        # that recommends this command (`check-release-published.py`'s FAULT remedy) is the
+        # one an operator reaches *after* the run has already been reported as failed.
+        #
+        # The run's own conclusion is what separates this from a run that succeeded with
+        # some jobs skipped (`workflow_dispatch` on a branch skips `verify-*` and `release`
+        # by design). It is fetched only here, so the ordinary paths keep one request.
+        if other_jobs:
+            try:
+                run = _run_conclusion(args.run_id, args.repo)
+            except Exception as exc:  # noqa: BLE001 - a report, not a crash
+                print(
+                    f"error: run {args.run_id} lists {len(other_jobs)} job(s) that did not "
+                    f"succeed and its own conclusion could not be read ({exc}) - whether this "
+                    "run failed is exactly the question, so it is unmeasured rather than "
+                    "'nothing to explain'",
+                    file=sys.stderr,
+                )
+                return 2
+            if run != "success":
+                # A `skipped` job is a **consequence**, never a cause: `release` is skipped
+                # exactly because the job it needs did not succeed, and telling a reader that
+                # "re-running asks the scheduler again" about it would send them after the
+                # wrong job. The causes are the ones that were cancelled or otherwise ended
+                # without success; the skipped ones are named, once, as what followed.
+                blocking = [
+                    job for job in other_jobs
+                    if str(job.get("conclusion") or "") != "skipped"
+                ]
+                consequent = [
+                    job for job in other_jobs
+                    if str(job.get("conclusion") or "") == "skipped"
+                ]
+                if args.json:
+                    print(json.dumps({
+                        "run": args.run_id, "repo": args.repo, "failed": True,
+                        "run_conclusion": run, "transport": transports_used(),
+                        "without_a_failed_job": [
+                            _otherwise_report(job) for job in blocking
+                        ],
+                        "skipped_as_a_consequence": [
+                            {"name": job.get("name"),
+                             "conclusion": job.get("conclusion")} for job in consequent
+                        ],
+                    }, indent=2))
+                else:
+                    print(
+                        f"no failed job in run {args.run_id} - the run itself concluded "
+                        f"`{run}`, and the job(s) that account for it are:"
+                    )
+                    for job in blocking:
+                        for line in _otherwise_lines(job):
+                            print(line)
+                    if consequent:
+                        names = ", ".join(str(job.get("name")) for job in consequent)
+                        print(
+                            f"  {names} [skipped] - downstream of the job(s) above, which is "
+                            "what skipping means here; the cause is not in them"
+                        )
+                return 0
         # A determinate reading: nothing failed. Exit 1, not 0 - "no failure" is not the
         # answer this tool was asked for, and a caller scripting it should see the
         # difference rather than a silent success.

tests/test_read_run_failure.py

@@ -110,11 +110,14 @@ class FakeGh:
     """
 
     def __init__(self, jobs: list[dict], logs: dict[int, str] | None = None,
-                 jobs_rc: int = 0, total_count: int | None = None):
+                 jobs_rc: int = 0, total_count: int | None = None,
+                 run_conclusion: str | None = "success", run_rc: int = 0):
         self.jobs = jobs
         self.logs = logs or {}
         self.jobs_rc = jobs_rc
         self.total_count = total_count
+        self.run_conclusion = run_conclusion
+        self.run_rc = run_rc
         self.calls: list[str] = []
 
     def __call__(self, path: str) -> str:
@@ -129,6 +132,14 @@ def __call__(self, path: str) -> str:
             if self.total_count is not None:
                 payload["total_count"] = self.total_count
             return json.dumps(payload)
+        if re.search(r"/actions/runs/\d+$", path):
+            if self.run_rc:
+                raise RuntimeError(
+                    f"gh api {path} failed (rc=1): gh: Server Error (HTTP 502)"
+                )
+            return json.dumps(
+                {"id": 42, "status": "completed", "conclusion": self.run_conclusion}
+            )
         if "/logs" in path:
             job_id = int(path.split("/actions/jobs/")[1].split("/")[0])
             if job_id not in self.logs:
@@ -191,6 +202,130 @@ def test_a_silent_step_is_still_named_by_the_job_payload(mod, monkeypatch, capsy
     assert "APPLE_ID: ***" in out, "the step's own block is what got printed"
 
 
+# --- a run that failed with no failed job -----------------------------------
+#
+# Measured 2026-11-04 on run 41862508461 (the v0.3.37 release): `verify-credentials` was
+# queued from the run's first second, never acquired a runner, and was cancelled after
+# 15m02s. `build` ran anyway - its own `if:` admits a cancelled dependency - and `release`
+# was skipped because it needs `build`, which needs that job. Every job's own conclusion was
+# therefore success, cancelled or skipped, so `failed_jobs` was empty and the tool answered
+# "nothing to explain" about a run whose conclusion is `failure`. The reading that sends an
+# operator here (`check-release-published.py`'s FAULT remedy) is the one reached *after* the
+# failure, so that answer is the whole cause they get.
+
+#: The starved job exactly as the API reports it: no steps, no runner, 15m02s held.
+_STARVED = {
+    "id": 9,
+    "name": "verify-credentials",
+    "conclusion": "cancelled",
+    "runner_name": None,
+    "started_at": "2026-11-04T19:05:01Z",
+    "completed_at": "2026-11-04T19:20:03Z",
+    "steps": [],
+}
+
+
+def test_a_failed_run_whose_only_other_job_never_started_is_explained(
+    mod, monkeypatch, capsys
+):
+    """The run failed, no job did: the unstarted job is the cause, and it must be named.
+
+    Exit 0 because the question *was* answered - not 1, which means "there is nothing to
+    explain".
+    """
+    fake = FakeGh(
+        [_job(name="verify-tag", conclusion="success"), _STARVED],
+        run_conclusion="failure",
+    )
+    rc = _run(mod, monkeypatch, fake, ["42"])
+    out = capsys.readouterr().out
+    assert rc == 0, f"a failed run was reported as having nothing to explain:\n{out}"
+    assert "verify-credentials [cancelled]" in out
+    assert "15m02s" in out, "the elapsed time is the reading that says it was starved"
+    assert "no step executed" in out
+    assert "no runner was ever assigned" in out, (
+        "the distinction that decides the remedy is scheduling, not a step failure, so "
+        "the runner field is the fact to print"
+    )
+    assert "nothing to explain" not in out
+
+
+def test_a_run_that_succeeded_with_skipped_jobs_still_says_nothing_to_explain(
+    mod, monkeypatch, capsys
+):
+    """The control: a branch dispatch skips `verify-*` and `release` by design.
+
+    Without this leg the new branch would fire on every `workflow_dispatch` run and turn a
+    normal skip into a reported failure.
+    """
+    fake = FakeGh(
+        [_job(conclusion="success"), _job(name="release", conclusion="skipped", job_id=2)],
+        run_conclusion="success",
+    )
+    rc = _run(mod, monkeypatch, fake, ["42"])
+    out = capsys.readouterr().out
+    assert rc == 1, "a run that succeeded has no failure to explain"
+    assert "nothing to explain" in out
+
+
+def test_an_unreadable_run_conclusion_is_unmeasured_not_explained(
+    mod, monkeypatch, capsys
+):
+    """Whether the run failed is the question, so failing to read it is exit 2.
+
+    Without this the tool would fall through to "nothing to explain" whenever the second
+    request failed - the same shape as the defect the branch exists to remove.
+    """
+    fake = FakeGh(
+        [_job(conclusion="success"), _STARVED],
+        run_conclusion="failure",
+        run_rc=1,
+    )
+    rc = _run(mod, monkeypatch, fake, ["42"])
+    captured = capsys.readouterr()
+    assert rc == 2, f"an unread run conclusion was answered as a verdict:\n{captured.out}"
+    assert "unmeasured" in captured.err
+    assert "nothing to explain" not in captured.out
+
+
+def test_a_skipped_job_is_named_as_a_consequence_not_a_cause(
+    mod, monkeypatch, capsys
+):
+    """`release` is skipped *because* the job it needs did not succeed.
+
+    Reported as a cause it would send the reader after the wrong job: the line that explains
+    a starved job says re-running asks the scheduler again, which is true of the cancelled
+    preflight and false of a job the graph skipped.
+    """
+    skipped = _job(name="release", conclusion="skipped", job_id=3)
+    skipped["steps"] = []
+    fake = FakeGh([_STARVED, skipped], run_conclusion="failure")
+    rc = _run(mod, monkeypatch, fake, ["42"])
+    out = capsys.readouterr().out
+    assert rc == 0
+    assert "verify-credentials [cancelled]" in out
+    assert "release [skipped]" in out and "downstream" in out
+    consequence_at = out.index("release [skipped]")
+    assert "no runner was ever assigned" not in out[consequence_at:], (
+        "the skipped job was explained with the starved job's reasoning:\n" + out
+    )
+
+
+def test_the_explanation_is_machine_readable(mod, monkeypatch, capsys):
+    """`--json` carries the same facts, so a caller need not parse the prose."""
+    fake = FakeGh([_STARVED], run_conclusion="failure")
+    rc = _run(mod, monkeypatch, fake, ["42", "--json"])
+    out = capsys.readouterr().out
+    assert rc == 0
+    payload = json.loads(out)
+    assert payload["failed"] is True and payload["run_conclusion"] == "failure"
+    job = payload["without_a_failed_job"][0]
+    assert job["name"] == "verify-credentials"
+    assert job["runner_name"] is None
+    assert job["steps_executed"] == 0
+    assert job["elapsed"] == "15m02s"
+
+
 # --- the three-valued outcome ----------------------------------------------