From b8e042dd2f380a8b91030240483b1d0b4471b6bb Mon Sep 17 00:00:00 2001 From: Ian Rohde Date: Tue, 29 Sep 2026 16:03:54 -0700 Subject: [PATCH 1/4] Re-read pulls updated in the last 20 minutes, dropped webhook or not QA and CR stamps go missing from the board when a webhook never arrives, and GitHub doesn't resend it. Until now only a restart or the card's refresh button re-read the pull, and a restart only covers repos listed in config.repos. #502 has the pulls the board missed on 2026-09-29, including 8 in repos the config leaves out. Every 20 minutes the server now searches each owner in config.repos for pulls updated since the previous sweep started, open or closed: user:ifixit is:pr updated:>=2026-09-29T22:37:07Z and refreshes each hit through refresh.pull, one at a time. Searching by owner reaches every repo that owner holds, configured or not. Search returns closed pulls too, so a dropped close webhook heals within one sweep. Each window starts 5 minutes before the previous sweep started, since GitHub doesn't document how long search indexing takes. The first sweep runs 20 minutes after startup and reaches back to 25 minutes before startup, so it also covers a restart shorter than that. A failed search keeps its window for the next sweep. A pull that fails to refresh is logged by refresh.pull and waits for its next update. The issue suggested 10 minutes; this uses 20. That's 3 search calls an hour plus the re-reads, 8 to 15 REST calls per pull by #502's count. It runs one search per owner instead of joining the qualifiers. With advanced_search=true, "user:iFixit user:octocat" is an AND: it found 0 pulls where the default search found 38. Verified against the live API with the new searchUpdatedPulls: a search since 2026-09-26 00:00Z paged through all 234 pulls GitHub counted, and a first sweep refreshed the same 6 pulls gh's search returned. Note: every hit is re-read, including old closed pulls that get a late comment or label. In that 234-pull sample, 9 were closed more than 25 minutes before their last update. A bulk edit of many old pulls would re-read every one of them in a single sweep. Connects to #502 Claude-Session: https://claude.ai/code/session_01Loy5Y4CXz9jacGkTPFENdw --- app.js | 3 +- lib/git-manager.js | 25 ++++++++ lib/refresh.js | 51 ++++++++++++++++ test/recent-pulls-sweep.test.js | 105 ++++++++++++++++++++++++++++++++ 4 files changed, 183 insertions(+), 1 deletion(-) create mode 100644 test/recent-pulls-sweep.test.js diff --git a/app.js b/app.js index 42bf37c7..180c8f59 100644 --- a/app.js +++ b/app.js @@ -4,7 +4,7 @@ import bodyParser from 'body-parser'; import expressSession from 'express-session'; import authManager from './lib/authentication.js'; import socketAuthenticator from './lib/socket-auth.js'; -import refresh from './lib/refresh.js'; +import refresh, { startRecentPullsSweep } from './lib/refresh.js'; import pullManager from './lib/pull-manager.js'; import git from './lib/git-manager.js'; import dbManager from './lib/db-manager.js'; @@ -96,6 +96,7 @@ dbManager .then(function () { debug('Refreshing all open pulls from the API'); refresh.openPulls(); + startRecentPullsSweep(refresh, config.repos); }) .done(); diff --git a/lib/git-manager.js b/lib/git-manager.js index 722d9b11..3fdf8ddd 100644 --- a/lib/git-manager.js +++ b/lib/git-manager.js @@ -170,6 +170,31 @@ export default { ); }, + /** + * Resolves to `{ repo, number }` for every pull, open or closed, updated at + * or after `since` in any repo `owner` holds, configured or not. + */ + searchUpdatedPulls: function (owner, since) { + const updatedSince = since.toISOString().slice(0, 19) + 'Z'; + return logErrors( + github + .paginate(githubRest.search.issuesAndPullRequests, { + q: `user:${owner} is:pr updated:>=${updatedSince}`, + per_page: 100, + }) + .then(items => + items.map(item => ({ + // Search results carry only the API URL, .../repos/owner/repo + repo: item.repository_url.split('/').slice(-2).join('/'), + number: item.number, + })) + ), + 'Searching pulls in %s updated since %s', + owner, + updatedSince + ); + }, + /** * Get *all* pull requests for a repo. * diff --git a/lib/refresh.js b/lib/refresh.js index e09fec5e..a6145c6c 100644 --- a/lib/refresh.js +++ b/lib/refresh.js @@ -4,6 +4,7 @@ import utils from './utils.js'; import NotifyQueue from 'notify-queue'; import debug from './debug.js'; import Promise from 'bluebird'; +import _ from 'underscore'; import { createPacer, noopPacer } from './pacer.js'; const refreshDebug = debug('pulldasher:refresh'); @@ -141,6 +142,56 @@ export function createRefresh({ pacer = noopPacer } = {}) { // bins build their own paced instance via createPacedRefresh. export default createRefresh(); +const SWEEP_INTERVAL_MS = 20 * 60 * 1000; +// Search's indexing delay isn't documented, so each sweep reaches this far back +// into the window the previous sweep already covered. +const SWEEP_OVERLAP_MS = 5 * 60 * 1000; + +/** + * GitHub never resends a dropped webhook. Searching by owner also reaches repos + * missing from config.repos, which the startup refresh skips. + */ +export function startRecentPullsSweep(refreshApi, repos) { + const sweep = createRecentPullsSweep(refreshApi, repoOwners(repos)); + const scheduleNext = () => setTimeout(() => sweep().then(scheduleNext), SWEEP_INTERVAL_MS); + scheduleNext(); +} + +export function repoOwners(repos) { + return _.uniq(repos.map(repo => repo.name.split('/')[0].toLowerCase())); +} + +/** + * The sweep never rejects. A failed search keeps its window for the next sweep; + * a failed pull refresh is logged by refreshApi.pull and not retried. + */ +export function createRecentPullsSweep(refreshApi, owners, now = Date.now) { + // The first sweep also covers a restart shorter than one interval. + let lastStart = now() - SWEEP_INTERVAL_MS; + return async function sweep() { + const startedAt = now(); + const since = new Date(lastStart - SWEEP_OVERLAP_MS); + let pulls = []; + try { + for (const owner of owners) { + pulls = pulls.concat(await gitManager.searchUpdatedPulls(owner, since)); + } + } catch (err) { + console.error( + 'Failed to search for pulls updated since %s: %s', + since.toISOString(), + (err && err.message) || err + ); + return; + } + refreshDebug('refreshing %s pulls updated since %s', pulls.length, since.toISOString()); + for (const { repo, number } of pulls) { + await refreshApi.pull(repo, number).catch(() => {}); + } + lastStart = startedAt; + }; +} + /** * Build the refresh API a CLI backfill bin runs against. One per-process pacer * is installed as a rate-limit observer on the GitHub client (so every diff --git a/test/recent-pulls-sweep.test.js b/test/recent-pulls-sweep.test.js new file mode 100644 index 00000000..280611bd --- /dev/null +++ b/test/recent-pulls-sweep.test.js @@ -0,0 +1,105 @@ +import { test } from "node:test"; +import assert from "node:assert/strict"; +import gitManager from "../lib/git-manager.js"; +import { createRecentPullsSweep, repoOwners } from "../lib/refresh.js"; + +const MINUTE = 60 * 1000; + +function fakeClock(start) { + let time = start; + const now = () => time; + now.advance = (ms) => (time += ms); + return now; +} + +test("repoOwners lists each owner once, ignoring case", () => { + const repos = [ + { name: "iFixit/ifixit" }, + { name: "ifixit/expo" }, + { name: "other/repo" }, + ]; + assert.deepEqual(repoOwners(repos), ["ifixit", "other"]); +}); + +// Each window starts 5 minutes before the previous sweep started, and the +// first one reaches back a full interval so it covers a short restart. +test("the sweep refreshes every pull the search finds and advances its window", async (t) => { + const searches = []; + t.mock.method(gitManager, "searchUpdatedPulls", (owner, since) => { + searches.push(`${owner} ${since.toISOString()}`); + return Promise.resolve( + owner === "a" + ? [{ repo: "a/one", number: 1 }] + : [{ repo: "b/two", number: 2 }] + ); + }); + const refreshed = []; + const refreshApi = { + pull: (repo, number) => { + refreshed.push(`${repo}#${number}`); + return Promise.resolve(); + }, + }; + const now = fakeClock(Date.parse("2026-09-29T12:00:00Z")); + const sweep = createRecentPullsSweep(refreshApi, ["a", "b"], now); + + await sweep(); + now.advance(20 * MINUTE); + await sweep(); + + assert.deepEqual(searches, [ + "a 2026-09-29T11:35:00.000Z", + "b 2026-09-29T11:35:00.000Z", + "a 2026-09-29T11:55:00.000Z", + "b 2026-09-29T11:55:00.000Z", + ]); + assert.deepEqual(refreshed, ["a/one#1", "b/two#2", "a/one#1", "b/two#2"]); +}); + +test("a failed search keeps its window for the next sweep", async (t) => { + const searches = []; + let fail = true; + t.mock.method(gitManager, "searchUpdatedPulls", (owner, since) => { + searches.push(since.toISOString()); + return fail ? Promise.reject(new Error("search 503")) : Promise.resolve([]); + }); + t.mock.method(console, "error", () => {}); + const now = fakeClock(Date.parse("2026-09-29T12:00:00Z")); + const sweep = createRecentPullsSweep( + { pull: () => Promise.resolve() }, + ["a"], + now + ); + + await sweep(); + fail = false; + now.advance(20 * MINUTE); + await sweep(); + + assert.deepEqual(searches, [ + "2026-09-29T11:35:00.000Z", + "2026-09-29T11:35:00.000Z", + ]); +}); + +test("one pull failing to refresh doesn't stop the sweep", async (t) => { + t.mock.method(gitManager, "searchUpdatedPulls", () => + Promise.resolve([ + { repo: "a/one", number: 1 }, + { repo: "a/one", number: 2 }, + ]) + ); + const refreshed = []; + const refreshApi = { + pull: (repo, number) => { + refreshed.push(number); + return number === 1 + ? Promise.reject(new Error("transient 500")) + : Promise.resolve(); + }, + }; + + await createRecentPullsSweep(refreshApi, ["a"])(); + + assert.deepEqual(refreshed, [1, 2]); +}); From db5e626e2bbe44ae9ed733a8ce7189bb3377545a Mon Sep 17 00:00:00 2001 From: Ian Rohde Date: Tue, 29 Sep 2026 17:25:57 -0700 Subject: [PATCH 2/4] Catch up on webhooks missed while the server was down The first sweep after a restart only reached back to 25 minutes before startup. Events dropped during a longer outage stayed lost in repos the startup refresh skips. Closes from the morning before cominor was rebuilt on 2026-08-28 (ops#765 at 03:38Z, DocHarvestor#242 at 03:53Z, host booted at 16:46Z) are still open on the board. At boot the server now reads MAX(pulls.date_updated) before any webhook or the startup refresh saves a pull. That is about when the previous run last saved a pull. The first sweep's window starts 5 minutes before it instead of 25 minutes before startup, but never more than 24 hours back. When the newest update is less than 20 minutes old, nothing changes. #502 counted 111 org pulls changed in 24 hours, so a full day of catch-up is 900 to 1,700 REST calls at 8 to 15 per pull, inside the 5,000 an hour quota. An outage the process stays up through was already covered. A failed search keeps its window, so the first sweep once the network is back reaches back to the last sweep that worked. That was the 2026-09-29 case, when cominor lost its network from about 10:50Z to 14:55Z. Note: date_updated is only written when pulldasher saves the pull row, not for a comment, so MAX can be older than the last event handled. That makes the window longer, never shorter. Connects to #502 Claude-Session: https://claude.ai/code/session_016ZaR6H662c518wQxrq7kBC --- app.js | 14 +++++++++++--- lib/db-manager.js | 11 +++++++++++ lib/refresh.js | 18 ++++++++++++++---- test/recent-pulls-sweep.test.js | 26 ++++++++++++++++++++++++++ 4 files changed, 62 insertions(+), 7 deletions(-) diff --git a/app.js b/app.js index 180c8f59..eba49b44 100644 --- a/app.js +++ b/app.js @@ -82,9 +82,17 @@ app.get('/api/v1/pulls', apiAuth, apiController.getPulls); // the lookup. git.getBotLogin(); -debug('Loading all recent pulls from the DB'); +// Read before webhooks and the startup refresh write any pull: the first sweep +// reaches back to it, so events dropped while the server was down get re-read. +let latestPullUpdate = null; + dbManager - .getRecentPulls(pullManager.getOldestAllowedPullTimestamp()) + .getLatestPullUpdate() + .then(function (latest) { + latestPullUpdate = latest; + debug('Loading all recent pulls from the DB'); + return dbManager.getRecentPulls(pullManager.getOldestAllowedPullTimestamp()); + }) .then(function (pulls) { debug('Loaded %s pulls', pulls.length); pullQueue.pause(); @@ -96,7 +104,7 @@ dbManager .then(function () { debug('Refreshing all open pulls from the API'); refresh.openPulls(); - startRecentPullsSweep(refresh, config.repos); + startRecentPullsSweep(refresh, config.repos, latestPullUpdate); }) .done(); diff --git a/lib/db-manager.js b/lib/db-manager.js index fa10d41d..e8d437a5 100644 --- a/lib/db-manager.js +++ b/lib/db-manager.js @@ -401,6 +401,17 @@ const dbManager = { return db.query('SELECT repo, number FROM pulls WHERE state = ?', ['open']); }, + /** + * Returns a promise which resolves to the newest `date_updated` (epoch + * seconds) of any pull in the DB, or null when there are no pulls. + */ + getLatestPullUpdate: function () { + dbDebug('Calling getLatestPullUpdate'); + return db + .query('SELECT MAX(date_updated) AS latest FROM pulls') + .then(rows => rows[0].latest); + }, + /** * Returns a promise which resolves to a pull's number for the given head * commit sha. diff --git a/lib/refresh.js b/lib/refresh.js index a6145c6c..abe3b1ca 100644 --- a/lib/refresh.js +++ b/lib/refresh.js @@ -146,13 +146,19 @@ const SWEEP_INTERVAL_MS = 20 * 60 * 1000; // Search's indexing delay isn't documented, so each sweep reaches this far back // into the window the previous sweep already covered. const SWEEP_OVERLAP_MS = 5 * 60 * 1000; +// How far back the first sweep after a restart may reach. A day of changed +// pulls is a few hundred re-reads, well inside the hourly quota. +const SWEEP_MAX_CATCH_UP_MS = 24 * 60 * 60 * 1000; /** * GitHub never resends a dropped webhook. Searching by owner also reaches repos * missing from config.repos, which the startup refresh skips. + * + * `lastSeen` is the newest pull `date_updated` (epoch seconds) the DB held at + * boot, which is about when the previous run stopped hearing from GitHub. */ -export function startRecentPullsSweep(refreshApi, repos) { - const sweep = createRecentPullsSweep(refreshApi, repoOwners(repos)); +export function startRecentPullsSweep(refreshApi, repos, lastSeen = null) { + const sweep = createRecentPullsSweep(refreshApi, repoOwners(repos), Date.now, lastSeen); const scheduleNext = () => setTimeout(() => sweep().then(scheduleNext), SWEEP_INTERVAL_MS); scheduleNext(); } @@ -165,9 +171,13 @@ export function repoOwners(repos) { * The sweep never rejects. A failed search keeps its window for the next sweep; * a failed pull refresh is logged by refreshApi.pull and not retried. */ -export function createRecentPullsSweep(refreshApi, owners, now = Date.now) { - // The first sweep also covers a restart shorter than one interval. +export function createRecentPullsSweep(refreshApi, owners, now = Date.now, lastSeen = null) { + // The first sweep also covers a restart shorter than one interval. After a + // longer outage it reaches back to `lastSeen`, but no further than a day. let lastStart = now() - SWEEP_INTERVAL_MS; + if (lastSeen !== null) { + lastStart = Math.max(now() - SWEEP_MAX_CATCH_UP_MS, Math.min(lastStart, lastSeen * 1000)); + } return async function sweep() { const startedAt = now(); const since = new Date(lastStart - SWEEP_OVERLAP_MS); diff --git a/test/recent-pulls-sweep.test.js b/test/recent-pulls-sweep.test.js index 280611bd..b50ab327 100644 --- a/test/recent-pulls-sweep.test.js +++ b/test/recent-pulls-sweep.test.js @@ -82,6 +82,32 @@ test("a failed search keeps its window for the next sweep", async (t) => { ]); }); +// After an outage, the first window starts 5 minutes before the newest update +// the DB held at boot, but never more than a day back. +test("the first sweep after a restart reaches back to the newest update the DB held", async (t) => { + const searches = []; + t.mock.method(gitManager, "searchUpdatedPulls", (owner, since) => { + searches.push(since.toISOString()); + return Promise.resolve([]); + }); + const refreshApi = { pull: () => Promise.resolve() }; + const now = fakeClock(Date.parse("2026-09-29T15:00:00Z")); + const at = (iso) => Date.parse(iso) / 1000; + + // The 2026-09-29 cominor outage: nothing written after 10:28:56Z. + await createRecentPullsSweep(refreshApi, ["a"], now, at("2026-09-29T10:28:56Z"))(); + // Down for three days: capped at a day. + await createRecentPullsSweep(refreshApi, ["a"], now, at("2026-09-26T15:00:00Z"))(); + // Updated a minute before the restart: the usual 20-minute window. + await createRecentPullsSweep(refreshApi, ["a"], now, at("2026-09-29T14:59:00Z"))(); + + assert.deepEqual(searches, [ + "2026-09-29T10:23:56.000Z", + "2026-09-28T14:55:00.000Z", + "2026-09-29T14:35:00.000Z", + ]); +}); + test("one pull failing to refresh doesn't stop the sweep", async (t) => { t.mock.method(gitManager, "searchUpdatedPulls", () => Promise.resolve([ From ad078489e91095578eb23c609c8e029da6b2964c Mon Sep 17 00:00:00 2001 From: Ian Rohde Date: Tue, 29 Sep 2026 17:42:16 -0700 Subject: [PATCH 3/4] Sweep: reach back an hour, skip pulls already re-read GitHub search can find an update late. Its results show a pull's current updated_at, but the updated: filter runs on an index that can lag behind it. At 00:36Z on 2026-09-30, 2 of 17 org pulls updated in the previous 30 minutes weren't findable by their own updated_at. Both had a comment as their newest event, which is how a QA or CR stamp arrives: iFixit/ops#1119 updated 00:22:23Z, findable about 15 min later iFixit/ifixit#64954 updated 00:07:59Z, not findable 33 min later With a 20-minute interval and a 5-minute overlap, an update that shows up L minutes late is caught only if the next sweep starts within 25 minutes of it. L = 15 is a coin flip, and L >= 25 is never caught. A dropped comment webhook in that gap stayed dropped. The overlap is now 60 minutes. Each sweep remembers the updated_at every pull had when it re-read it, and skips a hit with the same updated_at. The wider window costs search results, not REST calls. A 25-minute window at 00:31Z held 14 pulls, so an 80-minute one should still fit in one page of 100. A pull whose refresh fails isn't marked as re-read, so the next sweep that finds it tries again. Solutions considered: - Widen the overlap alone: every changed pull would be re-read up to 4 times, at 8 to 15 REST calls each. - Skip search and list recently updated pulls per repo: #502 option 4, which misses repos not in config.repos. Connects to #502 Claude-Session: https://claude.ai/code/session_016ZaR6H662c518wQxrq7kBC --- lib/git-manager.js | 7 ++- lib/refresh.js | 38 ++++++++++++--- test/recent-pulls-sweep.test.js | 82 +++++++++++++++++++++++++++------ 3 files changed, 103 insertions(+), 24 deletions(-) diff --git a/lib/git-manager.js b/lib/git-manager.js index 3fdf8ddd..5a793bbe 100644 --- a/lib/git-manager.js +++ b/lib/git-manager.js @@ -171,8 +171,10 @@ export default { }, /** - * Resolves to `{ repo, number }` for every pull, open or closed, updated at - * or after `since` in any repo `owner` holds, configured or not. + * Resolves to `{ repo, number, updatedAt }` for every pull, open or closed, + * updated at or after `since` in any repo `owner` holds, configured or not. + * `updatedAt` is GitHub's current updated_at, which can be newer than the + * time the search matched on. */ searchUpdatedPulls: function (owner, since) { const updatedSince = since.toISOString().slice(0, 19) + 'Z'; @@ -187,6 +189,7 @@ export default { // Search results carry only the API URL, .../repos/owner/repo repo: item.repository_url.split('/').slice(-2).join('/'), number: item.number, + updatedAt: item.updated_at, })) ), 'Searching pulls in %s updated since %s', diff --git a/lib/refresh.js b/lib/refresh.js index abe3b1ca..3fa57886 100644 --- a/lib/refresh.js +++ b/lib/refresh.js @@ -143,9 +143,12 @@ export function createRefresh({ pacer = noopPacer } = {}) { export default createRefresh(); const SWEEP_INTERVAL_MS = 20 * 60 * 1000; -// Search's indexing delay isn't documented, so each sweep reaches this far back -// into the window the previous sweep already covered. -const SWEEP_OVERLAP_MS = 5 * 60 * 1000; +// Search can index an update late: on 2026-09-30 a comment on iFixit/ops#1119 +// took about 15 minutes to become findable by its updated_at. So each sweep +// reaches this far back into windows earlier sweeps covered, and skips hits it +// already re-read at the same updated_at, which keeps the overlap from costing +// re-reads. +const SWEEP_OVERLAP_MS = 60 * 60 * 1000; // How far back the first sweep after a restart may reach. A day of changed // pulls is a few hundred re-reads, well inside the hourly quota. const SWEEP_MAX_CATCH_UP_MS = 24 * 60 * 60 * 1000; @@ -169,7 +172,8 @@ export function repoOwners(repos) { /** * The sweep never rejects. A failed search keeps its window for the next sweep; - * a failed pull refresh is logged by refreshApi.pull and not retried. + * a failed pull refresh is logged by refreshApi.pull and retried by the next + * sweep that finds the pull. */ export function createRecentPullsSweep(refreshApi, owners, now = Date.now, lastSeen = null) { // The first sweep also covers a restart shorter than one interval. After a @@ -178,6 +182,8 @@ export function createRecentPullsSweep(refreshApi, owners, now = Date.now, lastS if (lastSeen !== null) { lastStart = Math.max(now() - SWEEP_MAX_CATCH_UP_MS, Math.min(lastStart, lastSeen * 1000)); } + // `repo#number` -> the updated_at a hit had when the sweep last re-read it. + const reread = new Map(); return async function sweep() { const startedAt = now(); const since = new Date(lastStart - SWEEP_OVERLAP_MS); @@ -194,9 +200,27 @@ export function createRecentPullsSweep(refreshApi, owners, now = Date.now, lastS ); return; } - refreshDebug('refreshing %s pulls updated since %s', pulls.length, since.toISOString()); - for (const { repo, number } of pulls) { - await refreshApi.pull(repo, number).catch(() => {}); + const due = pulls.filter(pull => { + const key = `${pull.repo}#${pull.number}`; + return !reread.has(key) || reread.get(key) !== pull.updatedAt; + }); + refreshDebug( + 'refreshing %s of %s pulls updated since %s', + due.length, + pulls.length, + since.toISOString() + ); + for (const { repo, number, updatedAt } of due) { + await refreshApi.pull(repo, number).then( + () => reread.set(`${repo}#${number}`, updatedAt), + () => {} + ); + } + // A hit updated before this window only comes back with a new updated_at. + for (const [key, updatedAt] of reread) { + if (Date.parse(updatedAt) < since.getTime()) { + reread.delete(key); + } } lastStart = startedAt; }; diff --git a/test/recent-pulls-sweep.test.js b/test/recent-pulls-sweep.test.js index b50ab327..a54a27f2 100644 --- a/test/recent-pulls-sweep.test.js +++ b/test/recent-pulls-sweep.test.js @@ -21,16 +21,18 @@ test("repoOwners lists each owner once, ignoring case", () => { assert.deepEqual(repoOwners(repos), ["ifixit", "other"]); }); -// Each window starts 5 minutes before the previous sweep started, and the -// first one reaches back a full interval so it covers a short restart. +// Each window starts an hour before the previous sweep started, and the first +// one reaches back a full interval so it covers a short restart. test("the sweep refreshes every pull the search finds and advances its window", async (t) => { const searches = []; t.mock.method(gitManager, "searchUpdatedPulls", (owner, since) => { searches.push(`${owner} ${since.toISOString()}`); + // A new updated_at on every search, so each sweep re-reads both. + const updatedAt = new Date(now()).toISOString(); return Promise.resolve( owner === "a" - ? [{ repo: "a/one", number: 1 }] - : [{ repo: "b/two", number: 2 }] + ? [{ repo: "a/one", number: 1, updatedAt }] + : [{ repo: "b/two", number: 2, updatedAt }] ); }); const refreshed = []; @@ -48,10 +50,10 @@ test("the sweep refreshes every pull the search finds and advances its window", await sweep(); assert.deepEqual(searches, [ - "a 2026-09-29T11:35:00.000Z", - "b 2026-09-29T11:35:00.000Z", - "a 2026-09-29T11:55:00.000Z", - "b 2026-09-29T11:55:00.000Z", + "a 2026-09-29T10:40:00.000Z", + "b 2026-09-29T10:40:00.000Z", + "a 2026-09-29T11:00:00.000Z", + "b 2026-09-29T11:00:00.000Z", ]); assert.deepEqual(refreshed, ["a/one#1", "b/two#2", "a/one#1", "b/two#2"]); }); @@ -77,13 +79,13 @@ test("a failed search keeps its window for the next sweep", async (t) => { await sweep(); assert.deepEqual(searches, [ - "2026-09-29T11:35:00.000Z", - "2026-09-29T11:35:00.000Z", + "2026-09-29T10:40:00.000Z", + "2026-09-29T10:40:00.000Z", ]); }); -// After an outage, the first window starts 5 minutes before the newest update -// the DB held at boot, but never more than a day back. +// After an outage, the first window starts an hour before the newest update +// the DB held at boot, and its start is never more than a day back. test("the first sweep after a restart reaches back to the newest update the DB held", async (t) => { const searches = []; t.mock.method(gitManager, "searchUpdatedPulls", (owner, since) => { @@ -102,12 +104,62 @@ test("the first sweep after a restart reaches back to the newest update the DB h await createRecentPullsSweep(refreshApi, ["a"], now, at("2026-09-29T14:59:00Z"))(); assert.deepEqual(searches, [ - "2026-09-29T10:23:56.000Z", - "2026-09-28T14:55:00.000Z", - "2026-09-29T14:35:00.000Z", + "2026-09-29T09:28:56.000Z", + "2026-09-28T14:00:00.000Z", + "2026-09-29T13:40:00.000Z", ]); }); +// The overlap finds the same hits again; only a new updated_at re-reads one. +test("a hit already re-read at the same updated_at is skipped", async (t) => { + let hits = [ + { repo: "a/one", number: 1, updatedAt: "2026-09-29T11:50:00Z" }, + { repo: "a/one", number: 2, updatedAt: "2026-09-29T11:50:00Z" }, + ]; + t.mock.method(gitManager, "searchUpdatedPulls", () => Promise.resolve(hits)); + const refreshed = []; + const refreshApi = { + pull: (repo, number) => { + refreshed.push(number); + return Promise.resolve(); + }, + }; + const now = fakeClock(Date.parse("2026-09-29T12:00:00Z")); + const sweep = createRecentPullsSweep(refreshApi, ["a"], now); + + await sweep(); + hits = [hits[0], { ...hits[1], updatedAt: "2026-09-29T12:10:00Z" }]; + now.advance(20 * MINUTE); + await sweep(); + + assert.deepEqual(refreshed, [1, 2, 2]); +}); + +test("a pull that failed to refresh is retried by the next sweep", async (t) => { + t.mock.method(gitManager, "searchUpdatedPulls", () => + Promise.resolve([{ repo: "a/one", number: 1, updatedAt: "2026-09-29T11:50:00Z" }]) + ); + let fail = true; + const attempts = []; + const refreshApi = { + pull: (repo, number) => { + attempts.push(number); + return fail ? Promise.reject(new Error("transient 500")) : Promise.resolve(); + }, + }; + const now = fakeClock(Date.parse("2026-09-29T12:00:00Z")); + const sweep = createRecentPullsSweep(refreshApi, ["a"], now); + + await sweep(); + fail = false; + now.advance(20 * MINUTE); + await sweep(); + now.advance(20 * MINUTE); + await sweep(); + + assert.deepEqual(attempts, [1, 1]); +}); + test("one pull failing to refresh doesn't stop the sweep", async (t) => { t.mock.method(gitManager, "searchUpdatedPulls", () => Promise.resolve([ From a30606d63eabf76ad87e3274dfbcccea2fabcb93 Mon Sep 17 00:00:00 2001 From: Ian Rohde Date: Thu, 1 Oct 2026 15:40:37 -0700 Subject: [PATCH 4/4] Sweep: retry a pull whose re-read failed to save The previous commit marks a pull as re-read once refreshApi.pull resolves, then skips it until its updated_at changes. But refresh.pull also resolves when the re-read fails after the fetch: processPullItem logs a failed parse or DB save and calls next() so the queue keeps draining. https://github.com/iFixit/pulldasher/blob/ad078489e91095578eb23c609c8e029da6b2964c/lib/refresh.js#L396-L407 parse makes 8 or more GitHub calls per pull (comments, reviews, statuses, job runs, events, ...). A 5xx on any one of them left a dropped webhook dropped, and no later sweep tried the pull again. That message's "the next sweep tries again" only held when getPull failed. refresh.pull now takes an optional onFailure and puts it on the queue item, the same collector the bulk refreshes already pass. The sweep marks a pull only when onFailure didn't fire. Webhook and socket refreshes still pass none. Solutions considered: - Make refresh.pull reject when the parse or save fails: the 6 server callers would each log the failure a second time, and it changes refresh.pull for everything outside the sweep. klmork's review caught this: https://github.com/iFixit/pulldasher/pull/503#pullrequestreview-5385890098 Claude-Session: https://claude.ai/code/session_01D9oa6z9J5E9ca6E5i17eGt --- lib/refresh.js | 27 +++++++++++--------- test/recent-pulls-sweep.test.js | 45 ++++++++++++++++++++++++++++++++- 2 files changed, 59 insertions(+), 13 deletions(-) diff --git a/lib/refresh.js b/lib/refresh.js index 3fa57886..198e7ce0 100644 --- a/lib/refresh.js +++ b/lib/refresh.js @@ -80,11 +80,11 @@ export function createRefresh({ pacer = noopPacer } = {}) { /////// Pulls ///////// - pull: function refreshPull(repo, number) { + pull: function refreshPull(repo, number, onFailure = null) { refreshDebug('refresh pull %s', number); return gitManager .getPull(repo, number) - .then(pushOnQueue(pullQueue)) + .then(pushOnQueue(pullQueue, onFailure)) .catch(function (err) { // getPull's rejection (a dead/expired bot token, a 5xx, ...) lands // here before pushOnQueue ever runs -- log it so a single-item @@ -171,9 +171,9 @@ export function repoOwners(repos) { } /** - * The sweep never rejects. A failed search keeps its window for the next sweep; - * a failed pull refresh is logged by refreshApi.pull and retried by the next - * sweep that finds the pull. + * The sweep never rejects. A failed search keeps its window for the next sweep. + * A pull that fails to fetch, parse or save is logged and retried by the next + * sweep that finds it. */ export function createRecentPullsSweep(refreshApi, owners, now = Date.now, lastSeen = null) { // The first sweep also covers a restart shorter than one interval. After a @@ -211,8 +211,10 @@ export function createRecentPullsSweep(refreshApi, owners, now = Date.now, lastS since.toISOString() ); for (const { repo, number, updatedAt } of due) { - await refreshApi.pull(repo, number).then( - () => reread.set(`${repo}#${number}`, updatedAt), + // refreshApi.pull resolves even when the parse or save fails. + let saved = true; + await refreshApi.pull(repo, number, () => (saved = false)).then( + () => saved && reread.set(`${repo}#${number}`, updatedAt), () => {} ); } @@ -268,14 +270,15 @@ export function makeQueueConsumer(pacer, processItem, deps) { * push its first argument to the specified Queue * and return a promise that is fulfilled when the item is fully processed. * - * Single-item refreshes (webhooks, socket) have no end-of-run report, so no - * failure collector is attached — and they aren't quota-paced, so live traffic - * is never delayed. + * Webhook and socket refreshes have no end-of-run report, so they attach no + * failure collector; the recent-pulls sweep passes one to learn whether the + * re-read saved. Single-item refreshes aren't quota-paced, so live traffic is + * never delayed. */ -function pushOnQueue(queue) { +function pushOnQueue(queue, onFailure = null) { return function (githubResponse) { return new Promise(function (resolve) { - queue.push({ response: githubResponse, onFailure: null }); + queue.push({ response: githubResponse, onFailure: onFailure }); queue.push(resolve); }); }; diff --git a/test/recent-pulls-sweep.test.js b/test/recent-pulls-sweep.test.js index a54a27f2..ce7b32b5 100644 --- a/test/recent-pulls-sweep.test.js +++ b/test/recent-pulls-sweep.test.js @@ -1,7 +1,8 @@ import { test } from "node:test"; import assert from "node:assert/strict"; import gitManager from "../lib/git-manager.js"; -import { createRecentPullsSweep, repoOwners } from "../lib/refresh.js"; +import dbManager from "../lib/db-manager.js"; +import { createRecentPullsSweep, createRefresh, repoOwners } from "../lib/refresh.js"; const MINUTE = 60 * 1000; @@ -160,6 +161,48 @@ test("a pull that failed to refresh is retried by the next sweep", async (t) => assert.deepEqual(attempts, [1, 1]); }); +// refreshApi.pull resolves after a failed parse or save, so the sweep learns +// about it only through the onFailure it passes. +test("a pull that failed to save is retried by the next sweep", async (t) => { + t.mock.method(gitManager, "searchUpdatedPulls", () => + Promise.resolve([{ repo: "a/one", number: 1, updatedAt: "2026-09-29T11:50:00Z" }]) + ); + let fail = true; + const attempts = []; + const refreshApi = { + pull: (repo, number, onFailure) => { + attempts.push(number); + if (fail) onFailure(repo, number); + return Promise.resolve(); + }, + }; + const now = fakeClock(Date.parse("2026-09-29T12:00:00Z")); + const sweep = createRecentPullsSweep(refreshApi, ["a"], now); + + await sweep(); + fail = false; + now.advance(20 * MINUTE); + await sweep(); + now.advance(20 * MINUTE); + await sweep(); + + assert.deepEqual(attempts, [1, 1]); +}); + +test("refresh.pull reports a failed save to its onFailure and still resolves", async (t) => { + t.mock.method(gitManager, "getPull", (repo, number) => + Promise.resolve({ number, base: { repo: { full_name: repo } } }) + ); + t.mock.method(gitManager, "parse", (response) => Promise.resolve(response)); + t.mock.method(dbManager, "updateAllPullData", () => Promise.reject(new Error("db down"))); + t.mock.method(console, "error", () => {}); + const failures = []; + + await createRefresh().pull("a/one", 1, (repo, number) => failures.push(`${repo}#${number}`)); + + assert.deepEqual(failures, ["a/one#1"]); +}); + test("one pull failing to refresh doesn't stop the sweep", async (t) => { t.mock.method(gitManager, "searchUpdatedPulls", () => Promise.resolve([