diff --git a/.changes/source-control/fix-verify-listing-exact-count-fail-e7080d66.md b/.changes/source-control/fix-verify-listing-exact-count-fail-e7080d66.md new file mode 100644 index 00000000000..c4786d0b1d9 --- /dev/null +++ b/.changes/source-control/fix-verify-listing-exact-count-fail-e7080d66.md @@ -0,0 +1,7 @@ +--- +bump: patch +--- + +### Fixed + +- **babysit-prs**: the pr-verify verdict reader re-reads the pages around kept artifact-listing entries near expiry even when the listing holds exactly GitHub's live count. An entry GitHub deleted early could stand in for a FAIL the listing skipped, so the count matched and the FAIL was left out. A count those reads cannot settle now refuses instead of allowing; a 5xx that outlasts its waits, a count left unsettled only by the near-expiry read caps, or a listing whose time runs out after those reads began, refuses as transient and is not noted for the job; the last two print a `babysit-listing-miss` line with `cause` `near-expiry-cap` or `near-expiry-deadline`. diff --git a/plugins/source-control/skills/babysit-prs/scripts/babysit_verify_evidence.py b/plugins/source-control/skills/babysit-prs/scripts/babysit_verify_evidence.py index 3c7aa015447..ff39ac71a11 100755 --- a/plugins/source-control/skills/babysit-prs/scripts/babysit_verify_evidence.py +++ b/plugins/source-control/skills/babysit-prs/scripts/babysit_verify_evidence.py @@ -152,15 +152,21 @@ `LISTING_OVERLAP` before the base was read, and keeps the base's entries below the lowest id those pages hold, less those expired or past `expires_at` by the first page's `Date`. GitHub can delete an artifact up to an hour before its -`expires_at`, in no expiry order (`EARLY_DELETION_LEAD`), so when that holds -more than the live count the pages around the kept entries near expiry are -read again and decide every id they span, an id they omit by its own read -(`Reader._near_expiry`), at a few pages a group whatever the repository's -total and at most `NEAR_EXPIRY_PAGE_CAP` a listing; a count those pages do not -settle goes to the one whole listing, and a page or id read still failing on a -5xx after `LISTING_WAITS` fails the listing as transient. Such a listing could hide a FAIL by leaving it out, so -it is kept only when it holds exactly the first page's `total_count`, GitHub's -live count of the repository's artifacts. Across 17 first-page reads on +`expires_at`, in no expiry order (`EARLY_DELETION_LEAD`), so when a listing +holds the live count or more and a kept entry expires within it, the pages +around the kept entries near expiry are read again and decide every id they +span, an id they omit by its own read (`Reader._near_expiry`), at a few pages +a group whatever the repository's total and at most `NEAR_EXPIRY_PAGE_CAP` a +listing. They are read on an exact count too: an entry deleted early can stand +in for a FAIL the pages skipped. An over-count those pages do not settle goes +to the one whole listing, an exact count they do not settle fails the +listing (as transient when only `NEAR_EXPIRY_PAGE_CAP` or +`NEAR_EXPIRY_ID_READ_CAP` left it so, so a later Reader may list), a count they leave short goes to a whole listing with no wait, and a +page or id read still failing on a 5xx after `LISTING_WAITS` fails it as +transient. Such a listing +could hide a FAIL by leaving it out, so it is kept only when it holds exactly +the first page's `total_count`, GitHub's live count of the repository's +artifacts. Across 17 first-page reads on 2026-10-27 that count moved by exactly the uploads since the last read less the artifacts whose `expires_at` had passed by the response's `Date`. Three incremental listings that day each held exactly that count and every artifact @@ -406,20 +412,28 @@ def verdict_name(name: str) -> re.Match[str] | None: # (judgment on that data). EARLY_DELETION_LEAD = timedelta(hours=2) # The most pages `Reader._near_expiry` reads for one listing, its incremental -# read and top-up together; past it the over-count stands and goes to the one -# whole listing. On the 2026-11-01 carry behind #11903's refusal it read 12 -# pages; twice that (judgment on that data), at `LISTING_PAGE_SECONDS` a page, -# stays well inside verify-cap.mjs's 120 s limit and a fifth of that day's -# 133-page whole listing. +# read and top-up together; past it an over-count stands and goes to the one +# whole listing, and an exact count fails the listing. On the 2026-11-01 +# carry behind #11903's refusal it read 12 pages; twice that (judgment on +# that data), at `LISTING_PAGE_SECONDS` a page, stays well inside +# verify-cap.mjs's 120 s limit and a fifth of that day's 133-page whole +# listing. NEAR_EXPIRY_PAGE_CAP = 24 # The most artifacts `Reader._near_expiry` reads by id for one listing, its # incremental read and top-up together: each id its pages did not show is # dropped only on a 404 or an expired record. It drops at most the listing's # surplus over the live count, which was 31 to 34 in the three over-counts -# behind #11903's refusal; the largest (judgment on that data). Past it the -# over-count stands. Both caps reset with each listing the Reader reads, as -# after `refresh()`; pr-require-checks.yml's cold_cost counts them once. +# behind #11903's refusal; the largest (judgment on that data). Past it an +# over-count stands and an exact count fails the listing. Both caps reset +# with each listing the Reader reads, as after `refresh()`; +# pr-require-checks.yml's cold_cost counts them once. NEAR_EXPIRY_ID_READ_CAP = 34 +# The `cause` a `LISTING_MISS_PREFIX` line names when the caps above alone +# leave an exact count unsettled: refused, but not noted for the job. +NEAR_EXPIRY_CAP_CAUSE = "near-expiry-cap" +# The `cause` when the listing's deadline runs out after its near-expiry reads +# began, which `listing_timeout` does not size for: refused, but not noted. +NEAR_EXPIRY_DEADLINE_CAUSE = "near-expiry-deadline" # The waits between incremental reads on one base. A count that misses the # live total can stay off for longer than an immediate re-read takes, while a # page boundary settles; bounded waits let it settle before the reader pages @@ -450,8 +464,9 @@ class _CountMissed: """`Reader._incremental`'s answer when its pages read whole but do not hold the live count: `COUNT_MISSED` (fewer), the one case read again on the same base, or `COUNT_OVER` (more, or any count once the pages near - expiry were read again), which goes to one whole listing, since no wait - removes an entry GitHub no longer counts.""" + expiry were read again, except a top-up's exact count left short), which + goes to the whole listings, since no wait removes an entry GitHub no + longer counts.""" # Fewer than the live count: the pages skipped an artifact, which another @@ -1258,6 +1273,10 @@ class Reader: # The last `_incremental_page` that read nothing failed on a 5xx, a # network error or a body cut short, after its waits. _page_transient: bool = False + # Whether `_incremental`'s last None came from the near-expiry caps or the + # deadline running out after near-expiry reads began + # (`NEAR_EXPIRY_CAP_CAUSE`, `NEAR_EXPIRY_DEADLINE_CAUSE`). + _near_expiry_spent: bool = False # This listing's pages held more than the live count, so it takes one # whole listing at most. _over_counted: bool = False @@ -1512,7 +1531,14 @@ def _whole_listings(self, budget: float) -> list[dict[str, Any]]: reads += 1 read_at = _wall_clock() self._whole_paged = True - payload = self._read_listing(deadline, budget) + try: + payload = self._read_listing(deadline, budget) + except _Unreadable as exc: + if isinstance(exc, _Transient) or not self._near_expiry_out_of_time( + deadline, "whole-listing", reads + ): + raise + raise _Transient(str(exc)) from exc deadline = self._read_deadline for item in flatten_paginated_items( payload, "repository artifacts", items_key="artifacts" @@ -1536,9 +1562,16 @@ def _whole_listings(self, budget: float) -> list[dict[str, Any]]: else: cause = "never held" noun = "listing" if reads == 1 else "listings" - # A top-up page lost to a 5xx or network error is transient: not - # noted for the job (`_note_failed_listing`). - transient = listing is None and self._page_transient + # A top-up page lost to a 5xx or network error, or a count left + # unsettled only by the near-expiry caps or the time they took, or a + # top-up page out of time after near-expiry reads began, is transient: + # not noted for the job (`_note_failed_listing`), so a later Reader can + # list again. + transient = listing is None and ( + self._page_transient + or self._near_expiry_spent + or self._near_expiry_out_of_time(deadline, "top-up", reads) + ) raise (_Transient if transient else _Unreadable)( f"repository artifacts: {reads} whole {noun} {cause} " "GitHub's live artifact count" @@ -1565,21 +1598,28 @@ def _incremental( copy) included; below it the base's entries stand, less each one expired or past its `expires_at` by the first page's `Date` (one with no `expires_at` stands unless expired). A result that holds more than - the live count has the ids around its kept entries near expiry - decided by the pages that hold them now (`_near_expiry`). The + the live count, or exactly it while a kept entry is near expiry, has + the ids around its kept entries near expiry decided by the pages that + hold them now (`_near_expiry`); an exact count they leave unsettled + gives None, since an entry deleted early may stand in for a FAIL. The result must hold exactly the first page's `total_count` artifacts, GitHub's live count: fewer gives `COUNT_MISSED`, which - `_current_listing` reads again on the same base after a wait, and more, - or any count the pages near expiry left unsettled, gives `COUNT_OVER`, - which goes to one whole listing, since no wait removes an entry GitHub - no longer counts; either prints one + `_current_listing` reads again on the same base after a wait, and + more, or any count once the pages near expiry were read (a top-up's + exact count left short aside, which another whole listing can + restore), gives `COUNT_OVER`, which goes to the whole listings (one, + after an over-count), since no wait removes an entry GitHub no + longer counts; either prints one `LISTING_MISS_PREFIX` line on stderr naming `stage`, the counts and the pages read. No base, an entry or page of another shape, a missing `Date`, or any failed read gives None (`_page_transient` says whether the failed read was a 5xx or network error). `base` replaces `_incremental_base` and `deadline` its own - `LISTING_TIMEOUT_SECONDS` (`_complete_listing`'s top-up).""" - self._page_transient = False + `LISTING_TIMEOUT_SECONDS` (`_complete_listing`'s top-up). + An exact count left unsettled prints the same line with its `cause` + and sets `_near_expiry_spent` when only the caps, or the deadline + running out during those reads, left it so.""" + self._page_transient = self._near_expiry_spent = False if base is not None and not all(_listed_entry(a) for a in base[1]): return None base = base or self._incremental_base() @@ -1635,21 +1675,24 @@ def _incremental( ] listing = sorted([*fresh.values(), *kept], key=lambda a: -a["id"]) regions = 0 + unsettled: str | None = None over = len(listing) > total - if over: + limit = server_now + EARLY_DELETION_LEAD + near = len(listing) == total and any( + a["expires_at"] is not None and _when(a["expires_at"]) <= limit + for a in kept + ) + if over or near: # GitHub can delete an artifact before its expires_at: read again - # the pages around the kept entries near expiry. - self._over_counted = True + # the pages around the kept entries near expiry. An exact count + # can hide one there standing in for a FAIL the pages skipped. + self._over_counted |= over reread = self._near_expiry( listing, len(fresh), len(listing) - total, server_now, deadline ) if reread is None: return None - listing, regions = reread - if len(listing) == total: - return listing - # Fewer than the live count: the pages skipped an artifact. More: the - # base holds one GitHub no longer lists below the pages read. + listing, regions, unsettled = reread miss = { "stage": stage, "listed": len(listing), @@ -1660,13 +1703,36 @@ def _incremental( "region_pages": regions, "base_age_seconds": round((server_now - base_at).total_seconds()), } + if unsettled == NEAR_EXPIRY_DEADLINE_CAUSE or (near and unsettled): + # Unsettled, an exact count may still lack a FAIL. Refused only + # for want of the caps or their time, it is not noted for the job. + self._near_expiry_spent = unsettled in ( + NEAR_EXPIRY_CAP_CAUSE, + NEAR_EXPIRY_DEADLINE_CAUSE, + ) + miss["cause"] = unsettled + print( + f"{LISTING_MISS_PREFIX} {json.dumps(miss, sort_keys=True)}", + file=sys.stderr, + flush=True, + ) + return None + if len(listing) == total: + return listing + # Fewer than the live count: the pages skipped an artifact. More: the + # base holds one GitHub no longer lists below the pages read. print( f"{LISTING_MISS_PREFIX} {json.dumps(miss, sort_keys=True)}", file=sys.stderr, flush=True, ) - # Once the pages near expiry were read, no wait can settle the count. - return COUNT_OVER if over else COUNT_MISSED + # Once the pages near expiry were read, no wait on this base settles + # the count: the base still holds what they dropped. A top-up's exact + # count left short goes to another whole listing, which can restore a + # skip outside those pages. + if over or len(listing) > total or (near and stage != "top-up"): + return COUNT_OVER + return COUNT_MISSED def _near_expiry( self, @@ -1675,11 +1741,13 @@ def _near_expiry( surplus: int, server_now: datetime, deadline: float, - ) -> tuple[list[dict[str, Any]], int] | None: + ) -> tuple[list[dict[str, Any]], int, str | None] | None: """`listing` with the ids around its entries from `start` on that expire within `EARLY_DELETION_LEAD` of `server_now` decided by the - pages that hold them now, and the pages read; None for a failed page - read or an id read that stays transient past its waits. + pages that hold them now, the pages read, and None when every such + entry was decided, else why not (`NEAR_EXPIRY_CAP_CAUSE`, "unbracketed" + or "id-answer"); None for a failed page read or an id read that + stays transient past its waits. Such entries are grouped where they lie within a page of each other. Each group is read from the page its top entry would be on with @@ -1694,7 +1762,7 @@ def _near_expiry( A group it cannot bracket within those pages, a read past `NEAR_EXPIRY_PAGE_CAP` or `NEAR_EXPIRY_ID_READ_CAP` for this listing, or an id read with any other answer that is not transient leaves - `listing` as it was.""" + `listing` as it was, unsettled.""" size = LISTING_PAGE_SIZE limit = server_now + EARLY_DELETION_LEAD near = [ @@ -1721,12 +1789,12 @@ def _near_expiry( ended = False while True: if self._near_expiry_reads >= NEAR_EXPIRY_PAGE_CAP: - return listing, reads + return listing, reads, NEAR_EXPIRY_CAP_CAUSE read = self._incremental_page(page, deadline) reads += 1 self._near_expiry_reads += 1 if read is None: - return None + return self._out_of_time(listing, reads, deadline) items = read[0].get("artifacts") if not is_json_array(items) or not all(map(_listed_entry, items)): return None @@ -1745,7 +1813,7 @@ def _near_expiry( downs -= 1 page += 1 if not seen or (not ended and min(seen) > bottom): - return listing, reads + return listing, reads, "unbracketed" spans.append((0 if ended else min(seen), max(seen))) decided.update(seen) gone: set[int] = set() @@ -1755,16 +1823,58 @@ def _near_expiry( ): continue if self._artifact_reads >= NEAR_EXPIRY_ID_READ_CAP: - return listing, reads + return listing, reads, NEAR_EXPIRY_CAP_CAUSE self._artifact_reads += 1 answer = self._artifact_gone(a["id"], deadline) if answer is None: # A transient answer fails the read, as a lost page does. - return None if self._page_transient else (listing, reads) + if self._page_transient: + return None + return self._out_of_time(listing, reads, deadline) or ( + listing, + reads, + "id-answer", + ) if answer: gone.add(a["id"]) merged = {a["id"]: a for a in listing if a["id"] not in gone} | decided - return sorted(merged.values(), key=lambda a: -a["id"]), reads + return sorted(merged.values(), key=lambda a: -a["id"]), reads, None + + def _out_of_time( + self, listing: list[dict[str, Any]], reads: int, deadline: float + ) -> tuple[list[dict[str, Any]], int, str] | None: + """`_near_expiry`'s answer when a read gave nothing: unsettled for + `NEAR_EXPIRY_DEADLINE_CAUSE` when the deadline ran out (a 5xx past its + waits stays transient), else None.""" + if self._page_transient or deadline - _listing_clock() > 0: + return None + return listing, reads, NEAR_EXPIRY_DEADLINE_CAUSE + + def _near_expiry_out_of_time( + self, deadline: float | None, stage: str, reads: int + ) -> bool: + """Whether a whole listing or top-up page that failed did so for want + of time after this listing's near-expiry reads began, which + `listing_timeout` does not size for: then it prints a + `LISTING_MISS_PREFIX` line with + `NEAR_EXPIRY_DEADLINE_CAUSE`, and is refused as transient.""" + if ( + deadline is None + or deadline - _listing_clock() > 0 + or not (self._near_expiry_reads or self._artifact_reads) + ): + return False + miss = { + "stage": stage, + "whole_listings": reads, + "cause": NEAR_EXPIRY_DEADLINE_CAUSE, + } + print( + f"{LISTING_MISS_PREFIX} {json.dumps(miss, sort_keys=True)}", + file=sys.stderr, + flush=True, + ) + return True def _artifact_gone(self, artifact_id: int, deadline: float) -> bool | None: """Whether GitHub no longer holds the artifact: True on a 404 or an diff --git a/plugins/source-control/skills/babysit-prs/scripts/tests/test_babysit_verify_evidence.py b/plugins/source-control/skills/babysit-prs/scripts/tests/test_babysit_verify_evidence.py index ab4632b7712..2fcbe4d8f94 100644 --- a/plugins/source-control/skills/babysit-prs/scripts/tests/test_babysit_verify_evidence.py +++ b/plugins/source-control/skills/babysit-prs/scripts/tests/test_babysit_verify_evidence.py @@ -4243,6 +4243,8 @@ def test_a_failed_read_of_the_pages_near_expiry_lists_every_page(self) -> None: # Page 3, the one around 500 and 400, answers a 502 on every read: # past the page's own retries (`LISTING_WAITS`), like any failed # incremental read, every page is listed with no `INCREMENTAL_WAITS`. + # The top-up's count is exact, but 400 is near expiry, so it reads + # page 3 too and refuses as transient: nothing noted for the job. base = self.tail((500, 30), (400, 40)) self.write_carry(base) fake = self.fake(base=[a for a in base if a["id"] != 500]) @@ -4258,11 +4260,14 @@ def page(args: list[str], **kwargs: Any) -> Any: mock.patch.object(ve, "gh_api_with_headers", side_effect=page), ): reader = ve.Reader(REPO, "main", now=NOW) - reader.evidence(PR, HEAD, pull()) + evidence = reader.evidence(PR, HEAD, pull()) self.assertEqual(reader.listing_mode, "full") self.assertEqual(fake.full_listings(), 1) waits = [c.args[0] for c in self.sleep.call_args_list] - self.assertEqual(waits, list(ve.LISTING_WAITS)) + self.assertEqual(waits, list(ve.LISTING_WAITS) * 2) + self.assertEqual(evidence.refusal, "verify:unreadable") + self.assertIn("could not be checked against", evidence.detail or "") + self.assertFalse(self.failed.exists()) def test_a_deletion_far_from_expiry_still_lists_every_page(self) -> None: # 300 expires in 90 days but GitHub no longer lists it, and nothing @@ -4416,13 +4421,16 @@ def test_the_region_walk_stops_at_its_upward_bound(self) -> None: def test_the_pages_near_expiry_stop_at_their_cap(self) -> None: # Out of expiry order, the region takes two pages (3 and 4). Capped # at one, the count stays over: one whole listing, whose top-up - # (page 1) holds the count, and no INCREMENTAL_WAITS. + # (page 1) holds the count, and no INCREMENTAL_WAITS. That top-up + # keeps 500, near expiry, with the cap spent: an exact count it + # cannot settle may lack a FAIL, so the gate refuses. base = self.tail((500, 30), (400, 20)) self.write_carry(base) fake = self.fake(base=[a for a in base if a["id"] != 400]) with mock.patch.object(ve, "NEAR_EXPIRY_PAGE_CAP", 1): reader, evidence = self.judge(fake) - self.assertIsNone(evidence.refusal, evidence.detail) + self.assertEqual(evidence.refusal, "verify:unreadable") + self.assertIn("could not be checked against", evidence.detail or "") self.assertEqual(reader.listing_mode, "full") self.assertEqual(fake.full_listings(), 1) # Page 1, one capped region page, then the top-up's page 1. @@ -5274,6 +5282,262 @@ def test_the_refresh_before_an_allow_holds_the_live_count_too(self) -> None: ) +class AnExactCountChecksItsEntriesNearExpiry(unittest.TestCase): + """A listing that holds exactly the live count can still lack a FAIL: a + kept entry GitHub deleted early (`EARLY_DELETION_LEAD`) stands in for it. + So kept entries near expiry are decided by the pages that hold them now + and by their own reads even when the count matches, a count those reads + do not settle is refused, and a listing with none near expiry reads + nothing more.""" + + setUp = TheListingBuildsOnACarriedOne.setUp + write_carry = TheListingBuildsOnACarriedOne.write_carry + fake = TheListingBuildsOnACarriedOne.fake + judge = TheListingBuildsOnACarriedOne.judge + + def entry(self, artifact_id: int, expires: timedelta | None = None) -> Any: + """An old gate cursor, expiring `expires` after the runner's clock.""" + old = self.base_at - timedelta(days=2) + return dated( + "pr-merge-gate-cursor", + 3, + artifact_id, + old, + expires=None if expires is None else LISTED_AT + expires, + ) + + def earlier_fail(self, artifact_id: int) -> Any: + """An earlier head's FAIL of this pull request, two days old.""" + return dated( + named(EARLIER, "fail"), 2, artifact_id, self.base_at - timedelta(days=2) + ) + + @staticmethod + def by_id(fake: FakeGitHub) -> list[list[str]]: + """The reads of one artifact by id (`_artifact_gone`).""" + by_id = re.compile(r"/actions/artifacts/[0-9]+$") + return [c for c in fake.calls if by_id.search(c[-1])] + + def skipped(self, fail: int = 650) -> FakeGitHub: + """No carry: the first whole listing skips FAIL `fail` at a page + boundary and holds 600, expiring in 30 minutes, which GitHub then + deletes early: the union holds exactly the live count, with 600 in + the FAIL's place.""" + dropping = self.entry(600, timedelta(minutes=30)) + fake = self.fake(self.earlier_fail(fail), dropping) + fake.full_skips = [{fail}] + listed = fake.listed + + def drops_during_the_listing() -> list[dict[str, Any]]: + items = listed() + fake.artifacts = [a for a in fake.artifacts if a is not dropping] + return items + + fake.listed = drops_during_the_listing # type: ignore[method-assign] + return fake + + def test_a_whole_listing_that_skips_a_fail_beside_an_early_deletion( + self, + ) -> None: + # The top-up's page 1 (1000, 900) keeps 800, 700 and 600: five, the + # live count. 600 is near expiry, so page 3 is read (650 alone), + # bringing the FAIL back, and 600, which it omits, answers 404. + fake = self.skipped() + reader, evidence = self.judge(fake) + self.assertEqual(evidence.refusal, "verify:earlier-fail", evidence.detail) + self.assertEqual(reader.listing_mode, "full") + self.assertEqual(fake.full_listings(), 1) + self.assertEqual(len(self.by_id(fake)), 1) + ids = [a["id"] for a in json.loads(self.saved.read_text())["artifacts"]] + self.assertEqual(ids, [1000, 900, 800, 700, 650]) + + def test_a_stale_carry_whose_early_deletion_hides_a_missed_fail(self) -> None: + # The carry lacks FAIL 750 and still holds 600, which GitHub deleted + # 30 minutes before its expiry: five against a live count of five. + # Page 3 (700) does not reach 750, but 600's own read answers 404, + # so the count is one short and the whole listing holds the FAIL. + # No wait on this base could restore it: no INCREMENTAL_WAITS. + self.write_carry([*self.base, self.entry(600, timedelta(minutes=30))]) + fake = self.fake(self.earlier_fail(750)) + reader, evidence = self.judge(fake) + self.assertEqual(evidence.refusal, "verify:earlier-fail", evidence.detail) + self.assertEqual(reader.listing_mode, "full") + self.assertEqual(fake.full_listings(), 1) + self.assertEqual(len(self.by_id(fake)), 1) + self.assertEqual(self.sleep.call_args_list, []) + # An exact count is not an over-count: the job's slot stays free. + overcount = pathlib.Path(f"{self.saved}{ve.OVERCOUNT_FALLBACK_SUFFIX}") + self.assertFalse(overcount.exists()) + ids = [a["id"] for a in json.loads(self.saved.read_text())["artifacts"]] + self.assertEqual(ids, [1000, 900, 800, 750, 700]) + + def test_a_top_up_left_short_reads_another_whole_listing(self) -> None: + # The first whole listing skips FAIL 850, far from 600's page: the + # top-up keeps 600, whose read answers 404, and is one short. A + # second whole listing, not a refusal, restores the FAIL. + fake = self.skipped(850) + reader, evidence = self.judge(fake) + self.assertEqual(evidence.refusal, "verify:earlier-fail", evidence.detail) + self.assertEqual(reader.listing_mode, "full") + self.assertEqual(fake.full_listings(), 2) + self.assertFalse(self.failed.exists()) + + def test_a_dropped_entry_does_not_spend_the_top_ups_page_cap(self) -> None: + # As above, with 650 live and near expiry too: the incremental read + # takes pages 3 and 4, and the whole listing's top-up, which keeps + # 650, takes page 3 again: three of a cap of six. Re-read after each + # wait on the same base, the incremental read would take all six and + # leave the top-up unsettled. + near = self.entry(650, timedelta(minutes=30)) + self.write_carry([*self.base, near, self.entry(600, timedelta(minutes=30))]) + fake = self.fake(self.earlier_fail(750), near) + with mock.patch.object(ve, "NEAR_EXPIRY_PAGE_CAP", 6): + reader, evidence = self.judge(fake) + self.assertEqual(evidence.refusal, "verify:earlier-fail", evidence.detail) + self.assertEqual(reader.listing_mode, "full") + self.assertEqual(self.sleep.call_args_list, []) + self.assertEqual(reader._near_expiry_reads, 3) + self.assertFalse(self.failed.exists()) + + def test_a_short_count_reads_no_pages_near_expiry(self) -> None: + # The carry lacks FAIL 750 and 600 is live, near expiry: five of six. + # A short count is never kept, so it waits and reads again as before; + # only the whole listing's exact top-up reads 600's page. + near = self.entry(600, timedelta(minutes=30)) + self.write_carry([*self.base, near]) + fake = self.fake(self.earlier_fail(750), near) + reader, evidence = self.judge(fake) + self.assertEqual(evidence.refusal, "verify:earlier-fail", evidence.detail) + self.assertEqual(reader.listing_mode, "full") + waits = [c.args[0] for c in self.sleep.call_args_list] + self.assertEqual(waits, list(ve.INCREMENTAL_WAITS)) + self.assertEqual(reader._near_expiry_reads, 1) + self.assertEqual(self.by_id(fake), []) + + def test_an_exact_count_with_none_near_expiry_reads_nothing_more(self) -> None: + # 600 expires three hours on, past EARLY_DELETION_LEAD: page 1 alone. + self.write_carry([*self.base, self.entry(600, timedelta(hours=3))]) + fake = self.fake(self.entry(600, timedelta(hours=3))) + reader, evidence = self.judge(fake) + self.assertIsNone(evidence.refusal, evidence.detail) + self.assertEqual(reader.listing_mode, "incremental") + self.assertEqual((fake.pages(), fake.full_listings()), (1, 0)) + self.assertEqual(self.by_id(fake), []) + + def test_an_exact_count_the_pages_near_expiry_cannot_settle_refuses( + self, + ) -> None: + # 600, live and expiring in 30 minutes, is on page 3: read, it settles + # the count. With no page left under the cap, neither the incremental + # read nor the whole listing's top-up can, and the gate refuses. The + # caps alone left it unsettled, so nothing is noted for the job and + # the next Reader, its caps fresh, settles the count and allows. + near = self.entry(600, timedelta(minutes=30)) + self.write_carry([*self.base, near]) + fake = self.fake(near) + stderr = io.StringIO() + with ( + mock.patch.object(ve, "NEAR_EXPIRY_PAGE_CAP", 0), + contextlib.redirect_stderr(stderr), + ): + reader, evidence = self.judge(fake) + self.assertEqual(evidence.refusal, "verify:unreadable", evidence.detail) + self.assertIn("could not be checked against", evidence.detail or "") + self.assertEqual(reader.listing_mode, "full") + self.assertEqual(fake.full_listings(), 1) + self.assertEqual(self.by_id(fake), []) + self.assertFalse(self.failed.exists()) + misses = [ + json.loads(line.split(" ", 1)[1]) + for line in stderr.getvalue().splitlines() + if line.startswith(ve.LISTING_MISS_PREFIX) + ] + self.assertEqual( + [(m["stage"], m.get("cause")) for m in misses], + [ + ("incremental", ve.NEAR_EXPIRY_CAP_CAUSE), + ("top-up", ve.NEAR_EXPIRY_CAP_CAUSE), + ], + ) + fake = self.fake(near) + reader, evidence = self.judge(fake) + self.assertIsNone(evidence.refusal, evidence.detail) + self.assertEqual(reader.listing_mode, "incremental") + self.assertEqual(fake.full_listings(), 0) + + def test_near_expiry_reads_out_of_the_listings_time_are_not_noted( + self, + ) -> None: + # The skipped listing, each read taking `step` seconds of the whole + # listings' 60 s (`listing_timeout` for five artifacts), the caps out + # of reach. The first top-up reads 600's page and id and comes out + # short; at 15 s a read the second whole listing finds no time left, + # at 12 s the second top-up's page 1 does, and at 10 s its page near + # expiry does. Each way the time ran out after near-expiry reads + # began: refused, not noted. `whole` marks the miss line printed for + # a failed whole listing or top-up page, not a region read. + for step, stage, whole in ( + (15.0, "whole-listing", True), + (12.0, "top-up", True), + (10.0, "top-up", False), + ): + with self.subTest(step=step): + self.failed.unlink(missing_ok=True) + fake = self.skipped(850) + now = [0.0] + + def listing(args: list[str], **kwargs: Any) -> Any: + now[0] += step + return fake(args, **kwargs) + + def page(args: list[str], **kwargs: Any) -> Any: + now[0] += step + return fake(args, **kwargs), {"date": DATE} + + stderr = io.StringIO() + with ( + mock.patch.object(ve, "NEAR_EXPIRY_PAGE_CAP", 1000), + mock.patch.object(ve, "NEAR_EXPIRY_ID_READ_CAP", 1000), + mock.patch.object(ve, "_elapsed", return_value=0.0), + mock.patch.object( + ve, "_listing_clock", side_effect=lambda: now[0] + ), + mock.patch.object(postmerge, "gh_capture", side_effect=listing), + mock.patch.object(ve, "gh_api_with_headers", side_effect=page), + contextlib.redirect_stderr(stderr), + ): + evidence = ve.Reader(REPO, "main", now=NOW).evidence( + PR, HEAD, pull() + ) + self.assertEqual(evidence.refusal, "verify:unreadable") + self.assertFalse(self.failed.exists()) + causes = [ + (m["stage"], m.get("cause"), "whole_listings" in m) + for m in ( + json.loads(line.split(" ", 1)[1]) + for line in stderr.getvalue().splitlines() + if line.startswith(ve.LISTING_MISS_PREFIX) + ) + ] + self.assertIn((stage, ve.NEAR_EXPIRY_DEADLINE_CAUSE, whole), causes) + + def test_a_5xx_on_an_exact_count_id_read_refuses_as_transient(self) -> None: + # The skipped listing, with 600's read by id answering 502 through its + # waits: the Reader refuses, nothing is noted for the job, and the + # next Reader, the blip over, judges the FAIL. + fake = self.skipped() + fake.fail = {"artifacts/600"} + reader, evidence = self.judge(fake) + self.assertEqual(evidence.refusal, "verify:unreadable") + self.assertIn("could not be checked against", evidence.detail or "") + self.assertEqual(reader.listing_mode, "full") + self.assertEqual(len(self.by_id(fake)), 1 + len(ve.LISTING_WAITS)) + self.assertFalse(self.failed.exists()) + fake.fail = set() + _, again = self.judge(fake) + self.assertEqual(again.refusal, "verify:earlier-fail", again.detail) + + class TheColdReadHeadroomCoversTheListingCaps(unittest.TestCase): """ci-status holds a cold reader unless GITHUB_TOKEN's pool has one cold read's worst case per queue entry (pr-require-checks.yml), which it works