diff --git a/.github/cursor-review/post-review.py b/.github/cursor-review/post-review.py index 8d82c41..05c701b 100644 --- a/.github/cursor-review/post-review.py +++ b/.github/cursor-review/post-review.py @@ -314,6 +314,22 @@ def neutralize_mentions(text: str) -> str: GH_POST_REVIEW_TIMEOUT_SECONDS = 60 +def _as_text(captured) -> str: + """A captured stdout/stderr as `str`, whatever `subprocess` handed back. + + `subprocess.run(..., text=True)` decodes only on the NORMAL-completion path: when + the child is killed on a timeout, `TimeoutExpired.stdout` is the raw BYTES read off + the pipe before the kill. A `CompletedProcess` built from one therefore carries + bytes where every reader here expects str, and `"".split` on it raises `TypeError` + — which, on a path whose whole job is to report a failure, would replace the + diagnostic with a traceback and lose the findings it was protecting. So the decode + happens once, here, and the str readers go through it too. + """ + if isinstance(captured, (bytes, bytearray)): + return bytes(captured).decode("utf-8", errors="replace") + return captured or "" + + def gh_post_review(repo: str, pr_number: str, payload: str) -> subprocess.CompletedProcess: """POST the review, keeping the RESPONSE HEADERS (BE-12691). @@ -353,11 +369,15 @@ def gh_post_review(repo: str, pr_number: str, payload: str) -> subprocess.Comple return subprocess.CompletedProcess( args=argv, returncode=124, - # Whatever `gh` had written before the kill. Headers are only readable once - # the status line has arrived, and `gh_response_headers` returns {} short - # of that, so a partial capture degrades to "no headers" rather than to a - # wrong `Retry-After`. - stdout=exc.stdout or "", + # Whatever `gh` had written before the kill, DECODED: `TimeoutExpired` + # carries the raw BYTES the pipe had buffered even under `text=True` — + # CPython decodes only on the normal-completion path — so handing + # `exc.stdout` straight through would make every str reader of this result + # (`gh_status_line`, `gh_response_headers`) raise `TypeError` the moment a + # timeout killed `gh` after it wrote anything. `errors="replace"` because a + # kill can sever a multi-byte character mid-sequence, and a diagnostic must + # never be the thing that raises. + stdout=_as_text(exc.stdout), stderr=( f"gh api timed out after {GH_POST_REVIEW_TIMEOUT_SECONDS}s posting the " f"review to {repo}#{pr_number} — whether the write was served is " @@ -387,7 +407,7 @@ def gh_response_headers(result: subprocess.CompletedProcess) -> dict[str, str]: must not have to guess which spelling arrived. A repeated header keeps its LAST value, which is what an HTTP client would use. """ - blob = result.stdout or "" + blob = _as_text(result.stdout) lines = blob.split("\n") if not _GH_STATUS_LINE_RE.match(lines[0].rstrip("\r")): return {} @@ -784,6 +804,116 @@ def gh_error_line(result: subprocess.CompletedProcess) -> str: return blob[start:] if end == -1 else blob[start:end] +def gh_status_line(result: subprocess.CompletedProcess) -> str: + """The `HTTP/x.y nnn Reason` line `gh -i` wrote to STDOUT, or "". + + `gh -i` renders the response's status line first thing on stdout, so its PRESENCE + is proof a response arrived, however GitHub then answered. Its ABSENCE proves only + that none was CAPTURED, and is not evidence the write went unserved: a `gh` + predating `-i` or invoked without it writes a bare JSON body, a stub writes + whatever it likes, and a timeout can kill `gh` after GitHub already served the + write. Read it one way only — asserting "no reply reached GitHub" from an empty + return would invite the duplicate review the landed-review read exists to avoid. + Empty for anything that is not a status line, gated by the same + `_GH_STATUS_LINE_RE` the header parser uses, so a bare JSON body's first line is + never mistaken for one. + """ + first = _as_text(result.stdout).split("\n", 1)[0].rstrip("\r") + return first if _GH_STATUS_LINE_RE.match(first) else "" + + +# The response headers worth surfacing beside a POST failure: they say whether the +# failure was a throttle and how long a retry must wait. Lower-cased to match +# `gh_response_headers`, which canonicalizes to Go's casing. +_POST_FAILURE_HEADERS = ("retry-after", "x-ratelimit-remaining", "x-ratelimit-reset") + + +# Go's `encoding/json` wordings `gh` surfaces when it cannot parse a JSON document — +# the ONLY failures for which "request-side or response-side?" is even a question. A +# 403 throttle, a 422 anchor rejection and a 500 involve no decode at all, so on those +# the request-body self-check may report what it checked and nothing more. +_JSON_DECODE_WORDINGS = ( + "unexpected end of json input", + "invalid character", + "cannot unmarshal", +) + + +def _looks_like_json_decode_failure(result: subprocess.CompletedProcess) -> bool: + """Whether `gh` failed DECODING JSON, rather than merely reporting an HTTP error.""" + blob = (result.stderr or "").lower() + return any(wording in blob for wording in _JSON_DECODE_WORDINGS) + + +def format_post_failure( + context: str, result: subprocess.CompletedProcess, payload: str | None = None +) -> str: + """The ` POST failed:` diagnostic, keeping what `gh -i` put on STDOUT + (BE-15634). + + stderr carries only `gh`'s error line; the status line and the response headers + that say whether GitHub was even reached — and, on a throttle, how long to wait — + go to stdout, and reporting stderr alone threw them away at the one moment they + are needed. `unexpected end of JSON input` is the case that motivated this: on + stderr alone it cannot be told apart from a request GitHub never received, but the + stdout status line settles it. When `payload` is given, a `json.loads` self-check + settles the OTHER half — whether the body we sent was well-formed JSON — so the + same error can be attributed to the response decode rather than our request. + + Every claim here is bounded by what was actually observed: a missing status line is + reported as "not captured" and cross-checked against the stderr status rather than + asserted to mean nothing was served, and the request-body check attributes a decode + error only when `gh` reported one. + + Reads headers through `gh_response_headers`, which stops at the blank line, so a + finding body that quotes a `Retry-After:` header can never reach this diagnostic. + """ + parts = [f"{context} POST failed: {result.stderr}"] + status_line = gh_status_line(result) + if status_line: + parts.append(f" response status: {status_line}") + else: + # An absent status line is NOT proof nothing was served — see `gh_status_line`. + # `gh_http_status` reads the `(HTTP nnn)` gh renders on stderr, and a status + # there settles it from the other side, so the two are reported together + # rather than the stdout half alone being read as a verdict. + reported = gh_http_status(result) + parts.append( + f" response status: no status line captured on stdout, but gh reported " + f"HTTP {reported} on stderr — a reply DID arrive" + if reported is not None + else " response status: no status line captured on stdout and no HTTP " + "status on stderr — whether the write was served is UNKNOWN; ask the PR, " + "do not re-trigger blind" + ) + headers = gh_response_headers(result) + surfaced = [f"{name}: {headers[name]}" for name in _POST_FAILURE_HEADERS if name in headers] + if surfaced: + parts.append(" response headers: " + "; ".join(surfaced)) + if payload is not None: + # Attribution is claimed ONLY when `gh` actually failed to decode JSON. Both + # call sites hand over a `json.dumps` result, so the valid branch always wins; + # printing "the decode error is response-side" unconditionally would announce a + # decode error on every 403, 422 and 500 — misdirecting the triage this exists + # to serve. Absent a decode failure it reports what it checked, and stops. + decode_failure = _looks_like_json_decode_failure(result) + try: + json.loads(payload) + except (ValueError, TypeError) as exc: + parts.append( + f" request body: INVALID JSON ({exc}) — the decode error is request-side" + if decode_failure + else f" request body: INVALID JSON ({exc})" + ) + else: + parts.append( + " request body: valid JSON — so the decode error is response-side" + if decode_failure + else " request body: valid JSON" + ) + return "\n".join(parts) + + # 4xx statuses that are NOT evidence the request was rejected before it was written. # The no-read short-circuit rests on a 4xx meaning "GitHub validated this and refused # it", which holds for the rejections it was built for (422 over an inline position, @@ -1237,7 +1367,7 @@ def report_posted(): emit_delivery(False) write_step_summary(summary_markdown) return True - print(f"{context} POST failed: {result.stderr}", file=sys.stderr) + print(format_post_failure(context, result, payload), file=sys.stderr) # A nonzero `gh` is not proof the write was refused. Once the throttle wordings # stopped being read as a read-only token (BE-12612), the 403 GitHub raises on a # request it went on to SERVE reaches here — and every caller answers a False by @@ -2928,7 +3058,7 @@ def finish_posted_review(): write_step_summary(prose_body) return - print(f"Review POST failed: {result.stderr}", file=sys.stderr) + print(format_post_failure("Review", result, payload), file=sys.stderr) if not comments: # There is no inline half to drop, so a fallback POST would carry the same # findings as the request that just failed (only the demotion intro and the diff --git a/.github/cursor-review/tests/test_post_review.py b/.github/cursor-review/tests/test_post_review.py index 908e225..3e7ade2 100644 --- a/.github/cursor-review/tests/test_post_review.py +++ b/.github/cursor-review/tests/test_post_review.py @@ -1472,6 +1472,30 @@ def test_a_transport_error_with_no_http_status_goes_through_the_read(self): # Once for the inline POST, once for the fallback the stub fails identically. self.assertEqual(calls, [("o/r", "1"), ("o/r", "1")]) + def test_a_status_less_failure_still_lands_the_findings_in_the_summary(self): + """The BE-15634 scenario: both POSTs fail with a status-less transport error + (`gh: unexpected end of JSON input`), the read confirms the review is absent, + and the run must NOT drop the findings. They reach the job summary — the run + artifact is no longer their only surviving copy — under the POST-failed note, + and the step goes red.""" + outputs, summaries, notes, calls = {}, [], [], [] + driver = EndToEndPostTest() + driver.run_main( + self.ANCHORED, + post_returncode=1, + stderr="gh: unexpected end of JSON input", + existing_reviews=[], + list_calls=calls, + outputs=outputs, + summaries=summaries, + notes=notes, + ) + self.assertEqual(outputs["delivered"], "false") + self.assertEqual(len(summaries), 1, "the findings reached the job summary") + self.assertIn("finding on app.py:11", summaries[0], "and the findings are in it") + self.assertIn(PR.POST_FAILED_SUMMARY_NOTE, notes) + self.assertEqual(driver.exit_code, 1, "the step goes red") + def test_the_consolidated_marker_matches_gate_unresolved(self): """One discriminator, three readers (the gate, the ledger, and now this) — so a reword that moved only one of them would make this path stop recognizing the @@ -2312,6 +2336,123 @@ def test_a_header_block_with_no_body_still_parses(self): self.assertEqual(headers, {"retry-after": "60"}) +class PostFailureDiagnosticTest(unittest.TestCase): + """What a ` POST failed:` line carries (BE-15634). + + The failure that motivated this reported stderr alone — `gh: unexpected end of + JSON input` — and discarded the stdout `-i` captured, which is the one place the + status line and rate-limit headers live. Two identical failures 1.4s apart could + not then be told apart from a request GitHub never received. These pin that the + status line, the throttle headers, and the request-body self-check all reach the + log. + """ + + # `gh` fails an empty error body exactly this way, and it is the case where the + # status line on stdout is the only thing that says a reply arrived at all. + EMPTY_JSON_STDERR = "gh: unexpected end of JSON input" + + def test_the_stdout_status_line_is_surfaced(self): + line = PR.format_post_failure( + "Review", + gh_result(stdout=GH_INCLUDE_STDOUT, stderr=self.EMPTY_JSON_STDERR), + ) + self.assertIn(self.EMPTY_JSON_STDERR, line) + self.assertIn("response status: HTTP/2.0 404 Not Found", line) + + def test_rate_limit_headers_are_surfaced_when_present(self): + throttled_stdout = response( + "Retry-After: 42", + "X-Ratelimit-Remaining: 0", + status="HTTP/2.0 403 Forbidden", + ) + line = PR.format_post_failure( + "Fallback review", + gh_result( + stdout=throttled_stdout, + stderr="gh: You have exceeded a secondary rate limit. (HTTP 403)", + ), + ) + self.assertIn("retry-after: 42", line) + self.assertIn("x-ratelimit-remaining: 0", line) + + def test_a_missing_status_line_is_reported_as_not_captured_not_as_no_reply(self): + """Saying the status line is absent is the point — it distinguishes 'GitHub + rejected us' from 'we cannot tell', which the old stderr-only line could not + do. But absence is NOT proof nothing was served: a `gh` without `-i` and a + timeout that killed `gh` after GitHub served the write both land here, so the + outcome is reported as UNKNOWN rather than asserted to be a non-delivery a + maintainer would answer by re-triggering into a duplicate review.""" + line = PR.format_post_failure( + "Review", gh_result(stdout="", stderr="gh: dial tcp: i/o timeout") + ) + self.assertIn("no status line captured on stdout", line) + self.assertIn("UNKNOWN", line) + self.assertNotIn( + "no reply reached gh", line, "absence of a status line proves no such thing" + ) + + def test_a_stderr_status_is_cross_checked_when_stdout_carried_no_status_line(self): + """`gh` invoked without `-i` — or any stub — writes a bare body, so stdout has + no status line while stderr's `(HTTP nnn)` says plainly that GitHub answered. + Reporting the stdout half alone would call that a non-delivery.""" + line = PR.format_post_failure( + "Review", + gh_result( + stdout='{"message":"Unprocessable Entity"}', + stderr="gh: Unprocessable Entity (HTTP 422)", + ), + ) + self.assertIn("no status line captured on stdout", line) + self.assertIn("HTTP 422", line) + self.assertIn("a reply DID arrive", line) + self.assertNotIn("UNKNOWN", line) + + def test_a_failure_with_no_decode_error_claims_no_decode_attribution(self): + """A 403 throttle, a 422 rejection and a 500 involve no JSON decode at all. + Both call sites always hand over a `json.dumps` result, so an unconditional + "the decode error is response-side" would fire on EVERY failure and announce a + decode error that never happened — misdirecting the triage this exists for.""" + line = PR.format_post_failure( + "Review", + gh_result(stderr="gh: You have exceeded a secondary rate limit. (HTTP 403)"), + payload=json.dumps({"body": "x", "event": "COMMENT"}), + ) + self.assertIn("request body: valid JSON", line) + self.assertNotIn("decode error", line) + + def test_a_well_formed_payload_points_the_finger_at_the_response(self): + line = PR.format_post_failure( + "Review", + gh_result(stderr=self.EMPTY_JSON_STDERR), + payload=json.dumps({"body": "x", "event": "COMMENT"}), + ) + self.assertIn("request body: valid JSON", line) + self.assertIn( + "response-side", line, + "gh DID report a decode failure here, so the attribution is earned", + ) + + def test_a_malformed_payload_points_the_finger_at_the_request(self): + line = PR.format_post_failure( + "Review", gh_result(stderr=self.EMPTY_JSON_STDERR), payload="{not json" + ) + self.assertIn("request body: INVALID JSON", line) + self.assertIn("request-side", line) + + def test_a_finding_that_quotes_a_retry_after_cannot_forge_a_header(self): + """The response body is past the blank line, so `gh_response_headers` never + reads it — a finding body echoed into the JSON response cannot dictate what + this diagnostic reports as a throttle window.""" + spoof = response( + "Retry-After: 1", + status="HTTP/2.0 422 Unprocessable Entity", + body='{"message":"Retry-After: 3600 X-Ratelimit-Remaining: 0"}', + ) + line = PR.format_post_failure("Review", gh_result(stdout=spoof)) + self.assertIn("retry-after: 1", line) + self.assertNotIn("3600", line) + + class ThrottleDelayTest(unittest.TestCase): """How long a throttled write waits, and why it is never longer than that. @@ -2801,6 +2942,41 @@ def test_a_timeout_becomes_an_undecided_result_not_an_exception(self): self.assertNotEqual(result.returncode, 0) self.assertIn("timed out", result.stderr) + def test_a_timeout_that_captured_output_decodes_it_instead_of_carrying_bytes(self): + """`TimeoutExpired.stdout` is the RAW BYTES the pipe had buffered even under + `text=True` — CPython decodes only when the child exits normally. Carrying that + through would hand a bytes-bearing `CompletedProcess` to str readers, and since + `format_post_failure` now runs on EVERY POST failure, the resulting `TypeError` + would skip the landed-review read, the fallback POST and the job-summary write + — losing the findings on the very path built to preserve them. + """ + partial = b"HTTP/2.0 403 Forbidden\r\nRetry-After: 60\r\n\r\n" + with mock.patch.object( + PR.subprocess, "run", + side_effect=subprocess.TimeoutExpired(cmd=["gh"], timeout=60, output=partial), + ): + result = PR.gh_post_review("o/r", "1", "{}") + self.assertIsInstance(result.stdout, str, "decoded at the source, once") + self.assertEqual(PR.gh_status_line(result), "HTTP/2.0 403 Forbidden") + self.assertEqual(PR.gh_response_headers(result).get("retry-after"), "60") + # The whole point: the diagnostic renders rather than raising. + line = PR.format_post_failure("Review", result, payload="{}") + self.assertIn("HTTP/2.0 403 Forbidden", line) + self.assertIn("retry-after: 60", line) + + def test_a_severed_multibyte_capture_degrades_rather_than_raising(self): + """A kill can land mid-character. A diagnostic must never be the thing that + raises, so the decode replaces rather than strict-errors.""" + with mock.patch.object( + PR.subprocess, "run", + side_effect=subprocess.TimeoutExpired( + cmd=["gh"], timeout=60, output=b"HTTP/2.0 502 Bad Gateway\r\n\r\n\xe2\x82", + ), + ): + result = PR.gh_post_review("o/r", "1", "{}") + self.assertIsInstance(result.stdout, str) + self.assertIn("502", PR.format_post_failure("Review", result)) + def test_a_timed_out_post_takes_the_undecided_path(self): """It carries no HTTP status, so it is neither a throttle nor a read-only token — it is genuinely undecided, and the PR gets asked."""