diff --git a/README.md b/README.md index b8f1028..acdc163 100644 --- a/README.md +++ b/README.md @@ -34,6 +34,15 @@ step guarded by `if: failure()`. On a red run you get an annotation like `python-test-failure (confidence 0.89) — guide: getpatchrail.com/fix/...` plus a job summary block. +When no rule matches the log, the class stays `unknown` — PatchRail does not +guess — but the annotation hands back the line the runner itself flagged for the +failing step, so you still land on the error instead of on "no signal found": + +``` +unknown (confidence 0.15) — runner reported: "github-token" length must be less +than or equal to 100 characters long — guide: getpatchrail.com/fix +``` + ### Capturing the log correctly The capture step above is deliberate in two ways, and both matter: diff --git a/action.yml b/action.yml index 82ae815..8802605 100644 --- a/action.yml +++ b/action.yml @@ -58,10 +58,13 @@ runs: # `latest-patchrail` job in .github/workflows/test.yml runs this same # path against the newest release, so the range moves deliberately. # - # Floor is 0.5.0: every release below it reads a tool the job merely - # named — a `GRADLE_HOME=` line, a `Collecting mypy` from pip — as the - # cause of death, so it annotates the PR with a confident wrong answer. - python -m pip install --quiet "patchrail>=0.5.0,<0.6.0" + # Floor is 0.6.0. Below it, a release reads a tool the job merely named — + # a `GRADLE_HOME=` line, a `Collecting mypy` from pip, a tool named inside + # a filename — as the cause of death, and annotates the PR with a confident + # wrong answer. 0.6.0 also reports the runner's own `##[error]` line on an + # `unknown` verdict, which is the only thing that makes an unclassified run + # worth annotating at all; `scripts/annotate.py` surfaces it. + python -m pip install --quiet "patchrail>=0.6.0,<0.7.0" fi - name: Explain failure and annotate diff --git a/scripts/annotate.py b/scripts/annotate.py index dba82dd..d16ec0f 100644 --- a/scripts/annotate.py +++ b/scripts/annotate.py @@ -20,6 +20,12 @@ # red. Refuse a schema we do not know instead of inventing a classification. RESULT_SCHEMA = "patchrail.ci_result.v1" +# What one `unknown` verdict may drag into the annotation. patchrail already +# de-duplicates and caps `runner_errors`, but the content is log text: a matrix +# build emits one annotation per leg, and a single line can be a whole stack trace. +RUNNER_ERROR_LIMIT = 3 +RUNNER_ERROR_MAX_CHARS = 200 + # Shown whenever there is no log to classify. Both halves matter: without # `2>&1` a tool that reports only on stderr leaves an empty log, and without # pipefail (`shell: bash`) a failing command piped into `tee` exits 0, so the @@ -78,6 +84,49 @@ def guide_url(failure_class: str) -> str: return FIX_GUIDE_BASE +def runner_errors(result: dict) -> list[str]: + """The lines the runner itself flagged, as patchrail 0.6.0 reports them. + + Only present on an `unknown` result: when no rule matches, patchrail hands back + the runner's own annotation for the failing step (`##[error]…`), so the job can + say *where* it died even when PatchRail cannot say *why*. Without this, `unknown` + annotates a red run with `inspect CI log and run the failing job locally` — the + user learns nothing they would not have learned by never running the action. + + Absent on a classified result (its `signals` already explain it) and on any + patchrail below 0.6.0, which the `patchrail-version` input still allows: an + older release simply has no such key and this returns nothing. + """ + reported = result.get("runner_errors") + if not isinstance(reported, list): + return [] + lines = [] + for entry in reported[:RUNNER_ERROR_LIMIT]: + # Log text, so it arrives with whatever shape the failing build gave it. + line = " ".join(str(entry).split()) + if not line: + continue + if len(line) > RUNNER_ERROR_MAX_CHARS: + line = line[: RUNNER_ERROR_MAX_CHARS - 1].rstrip() + "…" + lines.append(line) + return lines + + +def annotation_safe(text: str) -> str: + """Escape log text for a workflow command, `%` first. + + GitHub decodes `%0A` in a `::warning::` message back into a newline, and this + text is a line from a build any PR author can write. Left raw, a log containing + `%0A::error::` would close our annotation and forge a second one. + """ + return text.replace("%", "%25").replace("\r", "%0D").replace("\n", "%0A") + + +def summary_safe(text: str) -> str: + """Keep log text inside its code span in the job summary, instead of formatting it.""" + return text.replace("`", "'") + + def write_kv(path_env: str, lines: list[str]) -> None: path = os.environ.get(path_env) if not path: @@ -162,13 +211,15 @@ def main() -> int: subsystem = result.get("likely_subsystem") or "unknown" repro = result.get("reproduction_command") or "" strategy = result.get("minimal_repair_strategy") or "" + reported = runner_errors(result) url = guide_url(failure_class) - # GitHub annotation (shows up inline on the run). - print( - f"::warning title=PatchRail CI Triage::{failure_class} " - f"(confidence {confidence}) — guide: {url}" - ) + # GitHub annotation (shows up inline on the run). One line, always: GitHub reads + # one annotation per line, so the runner's line is escaped, never appended raw. + headline = f"{failure_class} (confidence {confidence})" + if reported: + headline += f" — runner reported: {annotation_safe(reported[0])}" + print(f"::warning title=PatchRail CI Triage::{headline} — guide: {url}") # Job summary. summary = [ @@ -178,6 +229,11 @@ def main() -> int: f"- **Confidence:** `{confidence}`", f"- **Subsystem:** {subsystem}", ] + # On an `unknown` verdict this is the only line in the summary worth reading, so + # it goes above the generic "reproduce it locally" advice, not below it. + if reported: + summary.append("- **Errors the runner reported:**") + summary += [f" - `{summary_safe(line)}`" for line in reported] if repro: summary.append(f"- **Reproduce:** `{repro}`") if strategy: diff --git a/tests/test_runner_errors.py b/tests/test_runner_errors.py new file mode 100644 index 0000000..16d96d7 --- /dev/null +++ b/tests/test_runner_errors.py @@ -0,0 +1,175 @@ +"""An `unknown` verdict must hand back the line the runner flagged, and nothing else. + +Before this, an unclassified run got the worst annotation the action can produce: +`unknown (confidence 0.15)`, subsystem `unknown`, and the advice to "inspect CI log +and run the failing job locally" — on a red run, from a tool the user installed +precisely so they would not have to. patchrail 0.6.0 reports the runner's own +`##[error]` line for the failing step in `runner_errors`, so the action can at least +say *where* the job died when it cannot say *why*. It was already in the JSON the +action reads; the action was dropping it on the floor. + +The lines are log text from a build any PR author can write, so they are untrusted: +they reach a `::warning` workflow command, where GitHub decodes `%0A` back into a +newline, and a job summary, which is Markdown. Escaped on the way out, both times. +""" +from __future__ import annotations + +import json +import subprocess +import sys +from pathlib import Path + +import pytest + +ANNOTATE = Path(__file__).resolve().parent.parent / "scripts" / "annotate.py" +GUIDE_INDEX = "https://getpatchrail.com/fix" + +# What patchrail 0.6.0 emits for a log no rule matches. The runner error is the real +# one from psf/requests run 29295524780, the run that motivated the patchrail fix. +UNKNOWN_RESULT = { + "schema_version": "patchrail.ci_result.v1", + "failure_class": "unknown", + "confidence": 0.15, + "likely_subsystem": "unknown", + "reproduction_command": "inspect CI log and run the failing job locally", + "minimal_repair_strategy": "Do not auto-repair until the failing subsystem is identified.", + "runner_errors": ['"github-token" length must be less than or equal to 100 characters long'], +} + +# A log that classifies: its `signals` explain it, and patchrail reports no +# `runner_errors` at all. Also what every patchrail below 0.6.0 emits. +CLASSIFIED_RESULT = { + "schema_version": "patchrail.ci_result.v1", + "failure_class": "python_test_failure", + "confidence": 0.95, + "likely_subsystem": "Python tests", + "reproduction_command": "python -m pytest -q", + "minimal_repair_strategy": "Reproduce the failing test and patch the drift.", +} + + +@pytest.fixture() +def annotate(tmp_path): + def run(result: dict) -> tuple[subprocess.CompletedProcess, str, str]: + result_path = tmp_path / "patchrail-ci-result.json" + result_path.write_text(json.dumps(result), encoding="utf-8") + output = tmp_path / "output" + summary = tmp_path / "summary" + output.touch() + summary.touch() + proc = subprocess.run( + [sys.executable, str(ANNOTATE), str(result_path)], + capture_output=True, + text=True, + env={ + "PATH": "/usr/bin:/bin", + "GITHUB_OUTPUT": str(output), + "GITHUB_STEP_SUMMARY": str(summary), + }, + ) + return proc, output.read_text(), summary.read_text() + + return run + + +def with_errors(*errors: object) -> dict: + return {**UNKNOWN_RESULT, "runner_errors": list(errors)} + + +def test_the_runner_line_reaches_the_annotation(annotate) -> None: + """The whole point: the red run now names the line it died on.""" + proc, _, _ = annotate(UNKNOWN_RESULT) + assert proc.returncode == 0, proc.stderr + assert '"github-token" length must be less than or equal to 100' in proc.stdout + + +def test_the_runner_line_reaches_the_job_summary(annotate) -> None: + _, _, summary = annotate(UNKNOWN_RESULT) + assert "**Errors the runner reported:**" in summary + assert '"github-token" length must be less than or equal to 100' in summary + + +def test_the_runner_line_outranks_the_generic_advice(annotate) -> None: + """On `unknown` it is the only line worth reading, so it must not sit under + "inspect CI log and run the failing job locally".""" + _, _, summary = annotate(UNKNOWN_RESULT) + assert summary.index("Errors the runner reported") < summary.index("Reproduce") + + +def test_an_unknown_verdict_is_still_unknown(annotate) -> None: + """An annotation says where the job died, not why. Reporting it must not be + allowed to look like a classification: patchrail does not know this log.""" + proc, output, _ = annotate(UNKNOWN_RESULT) + assert "failure-class=unknown" in output + assert "confidence=0.15" in output + assert f"guide-url={GUIDE_INDEX}" in output.strip().splitlines() # index, not a 404 + + +def test_a_classified_result_is_untouched(annotate) -> None: + """patchrail sends no `runner_errors` when a rule matched, and neither does any + patchrail below 0.6.0, which `patchrail-version` still lets a user pin.""" + proc, output, summary = annotate(CLASSIFIED_RESULT) + assert proc.returncode == 0, proc.stderr + assert "runner reported" not in proc.stdout + assert "Errors the runner reported" not in summary + assert "python_test_failure (confidence 0.95)" in proc.stdout + assert f"guide-url={GUIDE_INDEX}/python-test-failure" in output + + +def test_a_log_line_cannot_forge_a_second_annotation(annotate) -> None: + """GitHub decodes `%0A` in a workflow command back into a newline. Raw, this log + line would end our warning and open an `::error::` of the author's choosing.""" + proc, _, _ = annotate(with_errors("boom%0A::error::forged by the log")) + commands = [ln for ln in proc.stdout.splitlines() if ln.startswith("::")] + assert len(commands) == 1 + assert commands[0].startswith("::warning title=PatchRail CI Triage::") + # The `%` is escaped, so GitHub renders `%0A` as those two literal characters + # instead of decoding it into the newline that would start the forged command. + assert "%250A" in commands[0] + assert "%0A::error::" not in commands[0] + + +def test_the_annotation_stays_on_one_line(annotate) -> None: + """GitHub reads one annotation per line; a wrapped message would be truncated.""" + proc, _, _ = annotate(with_errors("first line\nsecond line\r\nthird")) + warnings = [ln for ln in proc.stdout.splitlines() if ln.startswith("::warning")] + assert len(warnings) == 1 + assert "first line second line third" in warnings[0] + + +def test_a_log_line_cannot_break_out_of_its_code_span(annotate) -> None: + """The job summary is Markdown, and this is text from someone else's build.""" + _, _, summary = annotate(with_errors("`# not a heading, and no either")) + reported = next(ln for ln in summary.splitlines() if "not a heading" in ln) + assert reported.startswith(" - `") + assert reported.endswith("`") + assert reported.count("`") == 2 + + +def test_a_matrix_build_cannot_flood_the_annotation(annotate) -> None: + """One failing leg per matrix entry, each with its own annotation.""" + _, _, summary = annotate(with_errors(*[f"leg {i} died" for i in range(9)])) + assert summary.count("leg ") == 3 + + +def test_a_stack_trace_on_one_line_is_truncated(annotate) -> None: + _, _, summary = annotate(with_errors("x" * 5000)) + reported = next(ln for ln in summary.splitlines() if "xxx" in ln) + assert len(reported) < 260 + assert reported.endswith("…`") + + +def test_junk_in_the_field_is_ignored_rather_than_annotated(annotate) -> None: + """`.get()` never raises, so a future patchrail that reshapes this field would + otherwise annotate a red run with a stringified dict.""" + for junk in ["a bare string", {"error": "a dict"}, 17, None]: + proc, _, summary = annotate(with_errors() | {"runner_errors": junk}) + assert proc.returncode == 0, proc.stderr + assert "runner reported" not in proc.stdout + assert "Errors the runner reported" not in summary + + +def test_empty_and_blank_entries_never_become_a_bullet(annotate) -> None: + proc, _, summary = annotate(with_errors("", " ", "\n")) + assert "runner reported" not in proc.stdout + assert "Errors the runner reported" not in summary diff --git a/tests/test_schema_guard.py b/tests/test_schema_guard.py index 5fcd607..cf9995a 100644 --- a/tests/test_schema_guard.py +++ b/tests/test_schema_guard.py @@ -26,7 +26,7 @@ # test agree with any future edit to it, which is the drift it exists to catch. SUPPORTED_SCHEMA = "patchrail.ci_result.v1" -# What patchrail emits today (verified against 0.3.1, 0.4.0 and 0.5.0). +# What patchrail emits today (verified against 0.3.1, 0.4.0, 0.5.0 and 0.6.0). V1_RESULT = { "schema_version": SUPPORTED_SCHEMA, "failure_class": "python_test_failure",