Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -0,0 +1,16 @@
---
bump: patch
---

### Fixed

- read a cut-short artifact listing again after every wait, as a 5xx is

The verify-evidence reader read a whole listing cut short (`unexpected end
of JSON input`) once more at most, so two cut-short reads in a row refused
the pull request with `verify:unreadable`. It now reads it again after each
listing wait while time is left, and a page body cut short while gh exits 0
(`page N is not JSON`) or that the reader cannot parse counts as cut short
too. A rate-limit answer is still never read again, and a listing that
keeps failing still refuses. A whole listing still cut short after its
waits is noted for the job, so later Readers refuse without paging it again.
Original file line number Diff line number Diff line change
Expand Up @@ -567,9 +567,8 @@ def _overcount_refusal(outcome: str) -> str:
"unexpected eof",
"unexpected end of json input",
)
# A whole listing cut short has already paged up to every artifact, so it is
# read once more at most, not after every wait (`Reader._read_listing`).
CUT_SHORT = "unexpected end of json input"
# A page body cut short while gh exits 0, as babysit_gh._run_pages reports it.
PAGE_NOT_JSON = re.compile(r"\bpage \d+ is not json$")
FAIL = "verify:fail"
EARLIER_FAIL = "verify:earlier-fail"
REPEATED_FAIL = "verify:repeated-fail"
Expand Down Expand Up @@ -939,14 +938,22 @@ class _Transient(_Unreadable):
"""A failed read that may succeed if repeated."""


class _CutShort(_Transient):
"""A page body cut short: read again like a 5xx, but noted for the job
once its waits run out, since each later Reader would page the whole
listing again."""


def _transient(detail: str) -> bool:
"""A 5xx, or a network error with no HTTP response. A rate limit is not:
a fixed short wait outlasts neither a Retry-After nor an hourly reset, and
more requests can extend a secondary limit."""
"""A 5xx, a network error with no HTTP response, or a page body cut
short. A rate limit is not: a fixed short wait outlasts neither a
Retry-After nor an hourly reset, and more requests can extend a secondary
limit."""
status = gh_http_status(detail)
if status is not None:
return status >= 500
return any(phrase in detail.casefold() for phrase in NETWORK_ERRORS)
text = detail.casefold()
return any(p in text for p in NETWORK_ERRORS) or bool(PAGE_NOT_JSON.search(text))
Comment thread
kyle-sexton marked this conversation as resolved.
Resolved


def listing_pages(total_count: int) -> int:
Expand Down Expand Up @@ -1459,7 +1466,9 @@ def _current_listing(self) -> list[dict[str, Any]]:
self._listing_error = str(exc)
if self._overcount_mine:
self._note_overcount(self._listing_error)
if self._whole_paged and not isinstance(exc, _Transient):
if self._whole_paged and (
isinstance(exc, _CutShort) or not isinstance(exc, _Transient)
):
self._note_failed_listing(self._listing_error)
raise _Unreadable(self._listing_error) from exc
if self._overcount_mine:
Expand Down Expand Up @@ -2154,12 +2163,11 @@ def _live_count(self, timeout: float | None = None) -> int:
def _read_listing(
self, deadline: float | None = None, budget: float = LISTING_TIMEOUT_SECONDS
) -> Any:
"""The listing payload, read again after a 5xx or a fast network
error while time is left: every page, read and wait fits in
`budget`, so a retry adds no time to the run's worst
case. A read cut short (`CUT_SHORT`) is read once more, and that
read's failure refuses. A `deadline` set by an earlier read is kept;
this read's is saved as `_read_deadline`."""
"""The listing payload, read again after each of `LISTING_WAITS` on a
5xx, a fast network error or a page body cut short while time is
left: every page, read and wait fits in `budget`, so a retry adds no
time to the run's worst case. A `deadline` set by an earlier read is
kept; this read's is saved as `_read_deadline`."""
args = [
"api",
f"repos/{self.repo}/actions/artifacts?per_page=100",
Expand All @@ -2177,16 +2185,14 @@ def _read_listing(
for wait in LISTING_WAITS:
try:
return self._actions(args, "repository artifacts", timeout)
except _Transient as exc:
except _Transient:
if deadline - _listing_clock() - wait <= 0:
raise
_listing_sleep(wait)
# Recomputed after the sleep, which may return late.
timeout = deadline - _listing_clock()
if timeout <= 0:
raise
if CUT_SHORT in str(exc).casefold():
break
return self._actions(args, "repository artifacts", timeout)

def _env(self) -> dict[str, str] | None:
Expand All @@ -2206,11 +2212,16 @@ def _actions(
raise _Unreadable(f"{label}: {exc}") from exc
if proc.returncode != 0:
detail = f"{label}: {(proc.stderr or '').strip() or proc.returncode}"
raise (_Transient if _transient(detail) else _Unreadable)(detail)
if not _transient(detail):
raise _Unreadable(detail)
text = detail.casefold()
cut = PAGE_NOT_JSON.search(text) or "unexpected end of json input" in text
raise (_CutShort if cut else _Transient)(detail)
try:
return json.loads(proc.stdout) if proc.stdout.strip() else None
except ValueError as exc:
raise _Unreadable(f"{label}: {exc}") from exc
# A body cut short while gh exits 0.
raise _CutShort(f"{label}: {exc}") from exc
Comment thread
kyle-sexton marked this conversation as resolved.
Resolved

def _contains(self, sha: str, *, shared: bool = False) -> bool:
"""Whether the branch holds `sha`, read under the Actions token (a
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -3653,9 +3653,14 @@ def timed_out() -> RuntimeError:
return error


class CutBody(str):
"""A listing body gh printed cut short while exiting 0."""


class FlakyListing(FakeGitHub):
"""Fails the artifact listing with each of `errors` in turn: a string is
gh's stderr on exit 1, an exception is raised from `gh_capture`."""
gh's stderr on exit 1, a `CutBody` is its stdout on exit 0, an exception
is raised from `gh_capture`."""

def __init__(self, errors: list[str | BaseException]):
fake = passing()
Expand All @@ -3673,6 +3678,8 @@ def __call__(
error = self.errors.pop(0)
if isinstance(error, BaseException):
raise error
if isinstance(error, CutBody):
return subprocess.CompletedProcess(args, 0, error, "")
return subprocess.CompletedProcess(args, 1, "", error)
return super().__call__(args, **kwargs)

Expand All @@ -3698,8 +3705,12 @@ class ATransientListingFailureIsReadAgain(unittest.TestCase):
# A page body cut short: Go's JSON decoder error, as gh printed it in
# pr-merge run 40819274416 (skip step, 2026-10-29T04:59:05Z).
"unexpected end of JSON input",
# A page body cut short while gh exits 0 (babysit_gh._run_pages).
"page 2 is not JSON",
)
NOT_TRANSIENT: tuple[str | BaseException, ...] = (
# A rate limit stays a rate limit when gh also printed a parse error.
"unexpected end of JSON input\ngh: API rate limit exceeded (HTTP 403)",
"gh: Not Found (HTTP 404)",
"gh: Bad credentials (HTTP 401)",
"gh: Validation Failed (HTTP 422)",
Expand Down Expand Up @@ -3751,15 +3762,24 @@ def test_a_persistent_transient_failure_refuses_after_three_reads(self) -> None:
self.assertEqual(fake.listings(), 3)
self.assertEqual(sleeps, [2.0, 4.0])

def test_a_whole_listing_cut_short_is_read_once_more_at_most(self) -> None:
# Each cut-short read may have paged every artifact: two whole reads,
# never three, then the refusal.
def test_a_whole_listing_cut_short_every_time_refuses_after_three_reads(
self,
) -> None:
# ci-status run 41475913026 refused #12404 after two cut-short reads;
# a cut short is read again after every wait, as a 5xx is.
fake = FlakyListing(["unexpected end of JSON input"] * 3)
evidence, sleeps = self.judge(fake)
self.assertEqual(evidence.refusal, "verify:unreadable")
self.assertIn("unexpected end of JSON input", evidence.detail or "")
self.assertEqual(fake.listings(), 2)
self.assertEqual(sleeps, [2.0])
self.assertEqual(fake.listings(), 3)
self.assertEqual(sleeps, [2.0, 4.0])

def test_two_cut_short_reads_then_a_listing_reads_the_verdict(self) -> None:
fake = FlakyListing(["unexpected end of JSON input"] * 2)
evidence, sleeps = self.judge(fake)
self.assertIsNone(evidence.refusal)
self.assertEqual(fake.listings(), 3)
self.assertEqual(sleeps, [2.0, 4.0])

def timed(self, clock: list[float]) -> FlakyListing:
"""Three 502s, the clock reading `clock` in turn, a 60s listing timeout
Expand Down Expand Up @@ -3837,6 +3857,34 @@ def send(args, *, timeout_seconds, env_overrides, binary):
self.assertEqual(len(pages), self.PAGES)
self.assertEqual(len(sent), self.PAGES)

def test_a_page_body_cut_short_reads_the_listing_again(self) -> None:
# gh exits 0 with page 2's body cut short on the first listing only.
sent: list[str] = []

def send(args, *, timeout_seconds, env_overrides, binary):
sent.append(args[1])
named = re.search(r"[?&]page=(\d+)", args[1])
page = int(named[1]) if named else 1
link = (
"<https://api.github.com/repositories/1/actions/artifacts"
f'?per_page=100&page={page + 1}>; rel="next"'
if page < 3
else ""
)
body = json.dumps({"total_count": 3, "artifacts": [{"id": page}]})
if page == 2 and len(sent) == 2:
body = body[:20]
return subprocess.CompletedProcess(args, 0, body, ""), {"link": link}

with (
mock.patch.object(gh, "_send", side_effect=send),
mock.patch.object(ve, "_listing_sleep") as sleep,
):
pages = ve.Reader(REPO, "main", now=NOW)._read_listing()
self.assertEqual([p["artifacts"][0]["id"] for p in pages], [1, 2, 3])
self.assertEqual(len(sent), 5)
self.assertEqual([c.args[0] for c in sleep.call_args_list], [2.0])


class TheWholeListingTimeoutGrowsWithItsPages(unittest.TestCase):
"""The whole listings' shared timeout comes from GitHub's live
Expand Down Expand Up @@ -5133,6 +5181,24 @@ def test_a_whole_listing_lost_to_a_5xx_is_not_noted_for_the_job(self) -> None:
self.assertIsNone(evidence.refusal, evidence.detail)
self.assertEqual(fake.listings(), 4)

def test_a_whole_listing_cut_short_after_its_waits_is_noted(self) -> None:
# Each later Reader in the job would page the whole listing again.
for detail in (
"unexpected end of JSON input",
"page 2 is not JSON",
CutBody('{"total_count": 1, "art'),
):
with self.subTest(detail):
self.failed.unlink(missing_ok=True)
fake = FlakyListing([detail] * 6)
_, evidence = self.judge(fake)
self.assertEqual(evidence.refusal, "verify:unreadable")
self.assertEqual(fake.listings(), 3)
self.assertTrue(self.failed.exists())
_, evidence = self.judge(fake)
self.assertEqual(evidence.refusal, "verify:unreadable")
self.assertEqual(fake.listings(), 3)

def test_a_whole_listing_failure_not_the_callers_is_noted(self) -> None:
# A timeout of the whole cap's own budget (60 s for five artifacts),
# and a top-up page 404, with or without a caller's time left.
Expand Down
Loading