From e06960884eab36cd990286adb15285775b6f2cdd Mon Sep 17 00:00:00 2001 From: Luke Curley Date: Wed, 21 Oct 2026 22:38:49 -0700 Subject: [PATCH 1/3] chore(quest): claim quest/m0/helpers/wait-gaps.md Quest-Claim: 88f9fc2005c19464 From 8fcf4308fa97a0e687aba057ce3b98741b93f3d3 Mon Sep 17 00:00:00 2001 From: Luke Curley Date: Wed, 21 Oct 2026 23:12:21 -0700 Subject: [PATCH 2/3] fix(wait): read the last interval before a timeout and pages past a full one A timed wait polled only on its 5-minute schedule, so a 540 s wait never read its last 240 s; it now polls once more 30 s before the timeout. A full last page answered every conditional poll with a 304, which has no Link header, so a new next page was never seen; full pages are now reread unconditionally. Co-Authored-By: Claude Opus 5.5 --- quest/m0/helpers/README.md | 1 - quest/m0/helpers/wait-gaps.md | 25 ------------------ src/cli/main.ts | 2 +- src/cli/wait.ts | 26 ++++++++++++++----- test/wait.test.ts | 49 +++++++++++++++++++++++++++++++++++ 5 files changed, 70 insertions(+), 33 deletions(-) delete mode 100644 quest/m0/helpers/wait-gaps.md diff --git a/quest/m0/helpers/README.md b/quest/m0/helpers/README.md index 71061094..2dda56c6 100644 --- a/quest/m0/helpers/README.md +++ b/quest/m0/helpers/README.md @@ -64,7 +64,6 @@ commands from Sep-Oct. Session counts in each child come from that window. - [Complete loop](/quest/m0/helpers/complete-loop.md) - `/quest-complete` re-scans PRs, keeps picks and holds, and counts rounds per PR - [Headless agents](/quest/m0/helpers/headless-agents.md) - `/quest-spawn api` launches, resumes, and stops billed agents through one command auto mode allows - [Upstream claims](/quest/m0/helpers/claims.md) - claims and readiness read from the upstream tree, ignoring merged branches -- [Wait gaps](/quest/m0/helpers/wait-gaps.md) - `quest wait` reports every event after its starting point exactly once - [Guard in CI](/quest/m0/helpers/ci-guard.md) - pull request CI runs the landed-quest guard ## Related diff --git a/quest/m0/helpers/wait-gaps.md b/quest/m0/helpers/wait-gaps.md deleted file mode 100644 index ced7ad96..00000000 --- a/quest/m0/helpers/wait-gaps.md +++ /dev/null @@ -1,25 +0,0 @@ -# [S] Never miss events in quest wait - -## Goal - -Every review, comment, and check result after the wait's starting point is -reported exactly once, however long after a push the wait starts and however -close to its timeout the event lands. - -## Plan - -Decided 2026-10-21 from merge agents' reports that day: - -- A wait started without `--since` about a minute after a push timed out after - 540 s without reporting a Codex review that landed in that window - ([kixelated/quest#127](https://github.com/kixelated/quest/pull/127)). Waits - started with `--since` from before the push reported it every time. - Reproduce it, find the root cause (for example the default point resolving to - the wrong push time, or update-time filtering), and fix it. -- Check that an event landing in the last poll interval before the timeout is - either reported or left for the returned cursor, never dropped. -- A merge agent saw the resume cursor as `Q1.` while the CLI accepts only - `q1.` ([kixelated/quest#172](https://github.com/kixelated/quest/pull/172)). - Confirm whether `quest wait` ever prints it that way; if not, record it as a - display quirk and change nothing. -- Add regression tests for each confirmed cause. diff --git a/src/cli/main.ts b/src/cli/main.ts index 44c2a2d9..26e3e358 100644 --- a/src/cli/main.ts +++ b/src/cli/main.ts @@ -288,7 +288,7 @@ export function main(argv: string[], out: Output): number | Promise { .summary("Wait for pull request activity on GitHub") .description( "Wait for a review, comment, review-thread reply, reaction to the PR or a review, push, merge, close, " + - "merge-queue removal, disabled auto-merge, or required CI result. Polls every 5 minutes; rate limits delay requests. No timeout by default.\n\n" + + "merge-queue removal, disabled auto-merge, or required CI result. Polls every 5 minutes, and once more 30 seconds before the timeout; rate limits delay requests. No timeout by default.\n\n" + "Prints one plain line per event: timestamp (or commit SHA), type, actor, URL; the last line adds a resume cursor. " + "Reactions print as reacted:, such as reacted:thumbs_up. " + "The head's first failing required check prints as checks:failed, and every required check passing as checks:passed, " + diff --git a/src/cli/wait.ts b/src/cli/wait.ts index 5ee98532..613b110f 100644 --- a/src/cli/wait.ts +++ b/src/cli/wait.ts @@ -14,6 +14,14 @@ import { import { classifyCheck } from "./status"; const POLL = 5 * 60_000; +/** + * The last poll before a timeout starts this long before it, leaving time for its few requests; + * activity after it is left for the returned cursor. Polling only on the 5-minute schedule left + * up to 5 minutes before a timeout unread. + */ +const FINAL_POLL = 30_000; +/** The REST page size. A full last page cannot show by itself that a next page has appeared. */ +const PAGE = 100; const SHA = /^[a-f\d]{7,40}$/i; /** The timeline records a force push a few seconds after repository activity (1-2s observed). */ const TIMELINE_LAG = 60_000; @@ -264,7 +272,11 @@ async function watch( const mark = cursor.marks[source]; return event.time > mark.time || (event.time === mark.time && !seen[source].has(event.id)); }; - /** Read every page once, then poll the last page conditionally, following it when it fills. */ + /** + * Read every page once, then poll the last page conditionally, following it when it fills. A 304 + * has no Link header and the ETag covers only the body, so a full last page is reread whole to + * learn of a next one. + */ const pager = (first: string) => { let path = first; let etag: string | undefined; @@ -276,10 +288,11 @@ async function watch( if (!etag) throw new Error("unexpected GitHub 304 without a cached response"); return rows; } - rows.push(...array(await response.json())); + const page = array(await response.json()); + rows.push(...page); const next = link(response, "next"); if (!next) { - etag = response.headers.get("etag") ?? undefined; + etag = page.length < PAGE ? (response.headers.get("etag") ?? undefined) : undefined; return rows; } path = next; @@ -365,11 +378,11 @@ async function watch( return found; }; - const timeline = pager(`${base}/issues/${pr.number}/timeline?per_page=100`); + const timeline = pager(`${base}/issues/${pr.number}/timeline?per_page=${PAGE}`); // `since` excludes its own instant and filters by update time, which is never before // creation; start a second early so unseen replies at the mark's second are still read. const comments = pager( - `${base}/pulls/${pr.number}/comments?per_page=100&since=${new Date(cursor.marks.replies.time - 1000).toISOString()}`, + `${base}/pulls/${pr.number}/comments?per_page=${PAGE}&since=${new Date(cursor.marks.replies.time - 1000).toISOString()}`, ); const found: Record = { timeline: historical, replies: [], reactions: [] }; for (;;) { @@ -455,7 +468,8 @@ async function watch( `${event.point} ${event.type} ${event.actor} ${event.url}${index === unique.length - 1 ? ` ${nextCursor}` : ""}`, ); } - await github.pause(github.pollInterval); + const remaining = deadline - deps.now(); + await github.pause(remaining > FINAL_POLL ? Math.min(github.pollInterval, remaining - FINAL_POLL) : remaining); } } diff --git a/test/wait.test.ts b/test/wait.test.ts index 9c9da9b4..caf748be 100644 --- a/test/wait.test.ts +++ b/test/wait.test.ts @@ -482,6 +482,55 @@ test("all initial timeline pages are read, and the last known page is polled bef expect(fixture.calls.at(-1)!.headers.has("if-none-match")).toBe(false); }); +test("a full last page is reread whole, since a 304 cannot show that a next page appeared", async () => { + const labeled = Array.from({ length: 99 }, (_, id) => ({ event: "labeled", id, created_at: POINT })); + const full = [committed(A), ...labeled]; + const page2 = `https://api.github.com${timeline}&page=2`; + const fixture = setup([ + pull(), + response([pushed()]), + response(full, { etag: '"full"' }), + response(full, { etag: '"full"', link: `<${page2}>; rel="next"` }), + response([reviewed(1, "2026-10-07T12:12:00Z")]), + ]); + const lines = await waitForActivity(pr, {}, fixture.deps); + expect(lines).toHaveLength(1); + expect(lines[0]).toMatch(/^2026-10-07T12:12:00Z reviewed /); + expect(fixture.calls[4].headers.has("if-none-match")).toBe(false); +}); + +test("a review landing after the last scheduled poll is reported by a final poll before the timeout", async () => { + // 540 s polls at 0 and 300 s; the final poll at 510 s reads a review from 480 s. + const fixture = setup([ + pull(), + response([pushed()]), + response([committed(A)], { etag: '"e"' }), + response(null, {}, 304), + response([committed(A), reviewed(1, "2026-10-07T12:18:00Z")]), + ]); + const lines = await waitForActivity(pr, { timeout: 540 }, fixture.deps); + expect(lines).toHaveLength(1); + expect(lines[0]).toMatch(/^2026-10-07T12:18:00Z reviewed /); + expect(fixture.sleeps).toEqual([300_000, 210_000]); +}); + +test("a review landing after the final poll is left for the timeout's cursor, never dropped", async () => { + const first = setup([ + pull(), + response([pushed()]), + response([committed(A)], { etag: '"e"' }), + response(null, {}, 304), + response(null, {}, 304), + ]); + const timeout = await waitForActivity(pr, { timeout: 540 }, first.deps).catch((error: unknown) => error); + expect(timeout).toBeInstanceOf(WaitTimeout); + expect(first.sleeps).toEqual([300_000, 210_000, 30_000]); + const second = setup([response([committed(A), reviewed(1, "2026-10-07T12:18:50Z")])]); + const lines = await waitForActivity(pr, { since: (timeout as WaitTimeout).cursor }, second.deps); + expect(lines).toHaveLength(1); + expect(lines[0]).toMatch(/^2026-10-07T12:18:50Z reviewed /); +}); + test("older initial pages are not skipped even when the last page has no recent activity", async () => { const page2 = `https://api.github.com${timeline}&page=2`; const fixture = setup( From 768245b41c4f5c882f1bab58bb415bfd41bf83cd Mon Sep 17 00:00:00 2001 From: Luke Curley Date: Thu, 22 Oct 2026 08:55:09 -0700 Subject: [PATCH 3/3] fix(wait): never poll sooner than GitHub's X-Poll-Interval The final poll before a timeout shortened any interval, including a longer one GitHub asked for. Only the default 5-minute schedule is shortened now; when a server interval runs past the final poll, the wait skips it and times out with its cursor instead. Co-Authored-By: Claude Opus 5.5 --- src/cli/main.ts | 2 +- src/cli/wait.ts | 9 ++++++--- test/wait.test.ts | 7 +++++++ 3 files changed, 14 insertions(+), 4 deletions(-) diff --git a/src/cli/main.ts b/src/cli/main.ts index 93e15abf..9f4db910 100644 --- a/src/cli/main.ts +++ b/src/cli/main.ts @@ -312,7 +312,7 @@ export function main(argv: string[], out: Output): number | Promise { .summary("Wait for pull request activity on GitHub") .description( "Wait for a review, comment, review-thread reply, reaction to the PR or a review, push, merge, close, " + - "merge-queue removal, disabled auto-merge, or required CI result. Polls every 5 minutes, and once more 30 seconds before the timeout; rate limits delay requests. No timeout by default.\n\n" + + "merge-queue removal, disabled auto-merge, or required CI result. Polls every 5 minutes, and once more 30 seconds before the timeout; rate limits and longer GitHub poll intervals delay requests. No timeout by default.\n\n" + "Prints one plain line per event: timestamp (or commit SHA), type, actor, URL; the last line adds a resume cursor. " + "Reactions print as reacted:, such as reacted:thumbs_up. " + "The head's first failing required check prints as checks:failed, and every required check passing as checks:passed, " + diff --git a/src/cli/wait.ts b/src/cli/wait.ts index 613b110f..0bc2306f 100644 --- a/src/cli/wait.ts +++ b/src/cli/wait.ts @@ -17,7 +17,7 @@ const POLL = 5 * 60_000; /** * The last poll before a timeout starts this long before it, leaving time for its few requests; * activity after it is left for the returned cursor. Polling only on the 5-minute schedule left - * up to 5 minutes before a timeout unread. + * up to 5 minutes before a timeout unread. A longer X-Poll-Interval from GitHub still wins. */ const FINAL_POLL = 30_000; /** The REST page size. A full last page cannot show by itself that a next page has appeared. */ @@ -386,7 +386,7 @@ async function watch( ); const found: Record = { timeline: historical, replies: [], reactions: [] }; for (;;) { - github.pollInterval = POLL; + github.pollInterval = 0; for (const row of await timeline()) { const type = string(row.event); if (type === "committed") { @@ -468,8 +468,11 @@ async function watch( `${event.point} ${event.type} ${event.actor} ${event.url}${index === unique.length - 1 ? ` ${nextCursor}` : ""}`, ); } + // GitHub's X-Poll-Interval is a floor: the final poll shortens only the default schedule, + // and is skipped when that interval runs past it. const remaining = deadline - deps.now(); - await github.pause(remaining > FINAL_POLL ? Math.min(github.pollInterval, remaining - FINAL_POLL) : remaining); + const next = Math.min(Math.max(POLL, github.pollInterval), remaining - FINAL_POLL); + await github.pause(next > 0 && next >= github.pollInterval ? next : remaining); } } diff --git a/test/wait.test.ts b/test/wait.test.ts index caf748be..aa0934d7 100644 --- a/test/wait.test.ts +++ b/test/wait.test.ts @@ -589,6 +589,13 @@ test("primary rate limit reset and server poll intervals are honored", async () expect(fixture.sleeps).toEqual([60_000, 600_000]); }); +test("a server poll interval past the final poll skips it rather than polling early", async () => { + // A 600 s X-Poll-Interval outlasts a 540 s timeout, so no final poll runs at 510 s. + const fixture = setup([pull(), response([pushed()]), response([], { "x-poll-interval": "600" })]); + await expect(waitForActivity(pr, { timeout: 540 }, fixture.deps)).rejects.toBeInstanceOf(WaitTimeout); + expect(fixture.sleeps).toEqual([540_000]); +}); + test("persistent rate limiting eventually fails loudly instead of masking an error", async () => { const fixture = setup(Array.from({ length: 7 }, () => response({ message: "secondary rate limit" }, {}, 403))); await expect(waitForActivity(pr, {}, fixture.deps)).rejects.toThrow("rate limit persisted");