diff --git a/src/github/backfill.ts b/src/github/backfill.ts index aaa3333993..600dd99c85 100644 --- a/src/github/backfill.ts +++ b/src/github/backfill.ts @@ -320,6 +320,25 @@ const DEFAULT_LIMITS: BackfillLimits = { const FRESH_SYNC_MS = 6 * 60 * 60 * 1000; const ERROR_BACKOFF_MS = 60 * 60 * 1000; + +/** Shared freshness/error-backoff decision (#4497): a repo whose last sync is either a fresh success (within + * FRESH_SYNC_MS) or a recent error (within ERROR_BACKOFF_MS) should be skipped rather than re-synced, unless + * the caller explicitly forces a refresh. Returns null when a sync should proceed (never synced, no completed + * timestamp, or the existing sync is stale enough to redo). Shared by backfillRegisteredRepositories (the + * admin-endpoint/test path) and enqueueRepositoryOpenDataBackfill (the real scheduled-cron path) so both + * respect the SAME cadence -- previously only the former checked this, so the scheduled path re-synced every + * registered repo every 30 minutes forever regardless of freshness or a permanent error state. */ +function syncFreshnessSkipReason( + syncState: RepoSyncStateRecord | null, + force: boolean | undefined, +): { freshSuccess: boolean; recentError: boolean } | null { + if (force || !syncState?.lastCompletedAt || syncState.status === "never_synced") return null; + const ageMs = Date.now() - Date.parse(syncState.lastCompletedAt); + const freshSuccess = + (syncState.status === "success" || syncState.status === "partial" || syncState.status === "capped") && Number.isFinite(ageMs) && ageMs < FRESH_SYNC_MS; + const recentError = syncState.status === "error" && Number.isFinite(ageMs) && ageMs < ERROR_BACKOFF_MS; + return freshSuccess || recentError ? { freshSuccess, recentError } : null; +} const SEGMENT_PAGE_BUDGET: Record = { light: 2, full: 10, resume: 10 }; const PR_DETAIL_BATCH_SIZE: Record = { light: 12, full: 40, resume: 40 }; // Caps how many NOT-yet-hydrated merged PRs get a `/pulls/{n}/files` fetch per `recent_merged_pull_requests` @@ -422,26 +441,21 @@ export async function backfillRegisteredRepositories( }; } const syncState = await getRepoSyncState(env, repo.fullName); - if (!options.force && syncState?.lastCompletedAt && syncState.status !== "never_synced") { - const ageMs = Date.now() - Date.parse(syncState.lastCompletedAt); - const freshSuccess = - (syncState.status === "success" || syncState.status === "partial" || syncState.status === "capped") && Number.isFinite(ageMs) && ageMs < FRESH_SYNC_MS; - const recentError = syncState.status === "error" && Number.isFinite(ageMs) && ageMs < ERROR_BACKOFF_MS; - if (freshSuccess || recentError) { - return { - repoFullName: repo.fullName, - status: "skipped", - openIssues: syncState.openIssuesCount, - openPullRequests: syncState.openPullRequestsCount, - recentMergedPullRequests: syncState.recentMergedPullRequestsCount, - warnings: [ - freshSuccess - ? `Recent GitHub sync completed at ${syncState.lastCompletedAt}; use force=true for a manual refresh.` - : `Recent GitHub sync error recorded at ${syncState.lastCompletedAt}; backing off unless force=true.`, - ], - ...(recentError && syncState.errorSummary ? { errorSummary: syncState.errorSummary } : {}), - }; - } + const skipReason = syncFreshnessSkipReason(syncState, options.force); + if (skipReason && syncState) { + return { + repoFullName: repo.fullName, + status: "skipped", + openIssues: syncState.openIssuesCount, + openPullRequests: syncState.openPullRequestsCount, + recentMergedPullRequests: syncState.recentMergedPullRequestsCount, + warnings: [ + skipReason.freshSuccess + ? `Recent GitHub sync completed at ${syncState.lastCompletedAt}; use force=true for a manual refresh.` + : `Recent GitHub sync error recorded at ${syncState.lastCompletedAt}; backing off unless force=true.`, + ], + ...(skipReason.recentError && syncState.errorSummary ? { errorSummary: syncState.errorSummary } : {}), + }; } return backfillRepository(env, repo, limits, mode); }); @@ -457,11 +471,28 @@ export async function enqueueRepositoryOpenDataBackfill( const mode = options.mode ?? "light"; const settings = await resolveRepositorySettings(env, repo.fullName); if (!settings.backfillEnabled) return { ok: true, repoFullName: repo.fullName, status: "skipped", warnings: ["Backfill is disabled for this repository."] }; + // #4497: checked BEFORE any GitHub/DB work below, mirroring backfillRegisteredRepositories's own freshness + // gate -- this is the path the real scheduled cron actually dispatches through (see that function's own + // routing comment), which previously had NO freshness/error-backoff check at all and re-synced every + // registered repo every 30 minutes forever, backing off neither for a fresh success nor a permanent error. + const previous = await getRepoSyncState(env, repo.fullName); + const skipReason = syncFreshnessSkipReason(previous, options.force); + if (skipReason && previous) { + return { + ok: true, + repoFullName: repo.fullName, + status: "skipped", + warnings: [ + skipReason.freshSuccess + ? `Recent GitHub sync completed at ${previous.lastCompletedAt}; use force=true for a manual refresh.` + : `Recent GitHub sync error recorded at ${previous.lastCompletedAt}; backing off unless force=true.`, + ], + }; + } const token = await tokenForRepo(env, repo); const sourceKind: RepoSyncSegmentRecord["sourceKind"] = repo.installationId && token !== env.GITHUB_PUBLIC_TOKEN ? "installation" : "github"; const totals = await repoGithubTotalsForBackfill(env, repo, token, sourceKind); const startedAt = nowIso(); - const previous = await getRepoSyncState(env, repo.fullName); await upsertRepoSyncState(env, { repoFullName: repo.fullName, status: "running", diff --git a/test/unit/backfill.test.ts b/test/unit/backfill.test.ts index 27726a11c0..3d347bd0ab 100644 --- a/test/unit/backfill.test.ts +++ b/test/unit/backfill.test.ts @@ -2239,6 +2239,182 @@ describe("GitHub backfill", () => { ); }); + it("INVARIANT (#4497): skips the scheduled per-repo backfill when the prior sync is a fresh success, without touching GitHub or writing any sync-state/segment jobs", async () => { + const sent: import("../../src/types").JobMessage[] = []; + const env = createTestEnv({ + GITHUB_PUBLIC_TOKEN: "public-token", + JOBS: { + async send(message: import("../../src/types").JobMessage) { + sent.push(message); + }, + } as unknown as Queue, + }); + await seedRegisteredRepo(env); + await upsertRepoSyncState(env, { + repoFullName: "JSONbored/gittensory", + status: "success", + sourceKind: "github", + openIssuesCount: 5, + openPullRequestsCount: 3, + recentMergedPullRequestsCount: 10, + lastCompletedAt: new Date().toISOString(), + warnings: [], + }); + vi.stubGlobal("fetch", async () => new Response("must not be called", { status: 500 })); + + const result = await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" }); + + expect(result).toMatchObject({ status: "skipped", warnings: [expect.stringContaining("Recent GitHub sync completed")] }); + expect(sent).toEqual([]); + // Status stays "success" (unchanged) -- the scheduled path must not stamp "running" over a fresh state. + expect(await listRepoSyncStates(env)).toMatchObject([{ status: "success" }]); + }); + + it("INVARIANT (#4497): a syncState row stamped never_synced (distinct from no row at all) still proceeds with a real sync on the scheduled path", async () => { + const sent: import("../../src/types").JobMessage[] = []; + const env = createTestEnv({ + GITHUB_PUBLIC_TOKEN: "public-token", + JOBS: { + async send(message: import("../../src/types").JobMessage) { + sent.push(message); + }, + } as unknown as Queue, + }); + await seedRegisteredRepo(env); + // A row EXISTS (unlike the "no prior state at all" case above) but its status is the placeholder + // "never_synced" -- e.g. stamped by an unrelated write that only carries over display fields (see + // fetchAndCachePrStateFields-style callers) before any real sync ever completed. This must never be + // mistaken for "a completed sync just happened." + await upsertRepoSyncState(env, { + repoFullName: "JSONbored/gittensory", + status: "never_synced", + sourceKind: "github", + openIssuesCount: 0, + openPullRequestsCount: 0, + recentMergedPullRequestsCount: 0, + lastCompletedAt: new Date().toISOString(), + warnings: [], + }); + vi.stubGlobal("fetch", async (input: RequestInfo | URL) => { + if (input.toString() === "https://api.github.com/graphql") return githubTotalsResponse({ openIssues: 1, openPullRequests: 1, mergedPullRequests: 1, closedPullRequests: 0, labels: 0 }); + return Response.json([]); + }); + + const result = await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" }); + + expect(result.status).toBe("queued"); + expect(sent.filter((message) => message.type === "backfill-repo-segment").length).toBeGreaterThan(0); + }); + + it("INVARIANT (#4497): a syncState past BOTH the fresh-success and error-backoff windows proceeds with a real sync, not a skip", async () => { + const sent: import("../../src/types").JobMessage[] = []; + const env = createTestEnv({ + GITHUB_PUBLIC_TOKEN: "public-token", + JOBS: { + async send(message: import("../../src/types").JobMessage) { + sent.push(message); + }, + } as unknown as Queue, + }); + await seedRegisteredRepo(env); + // 7 hours ago: past FRESH_SYNC_MS (6h) for a success AND past ERROR_BACKOFF_MS (1h) were this an error -- + // stale enough that the backfill must proceed normally rather than skip. + await upsertRepoSyncState(env, { + repoFullName: "JSONbored/gittensory", + status: "success", + sourceKind: "github", + openIssuesCount: 2, + openPullRequestsCount: 1, + recentMergedPullRequestsCount: 3, + lastCompletedAt: new Date(Date.now() - 7 * 60 * 60 * 1000).toISOString(), + warnings: [], + }); + vi.stubGlobal("fetch", async (input: RequestInfo | URL) => { + if (input.toString() === "https://api.github.com/graphql") return githubTotalsResponse({ openIssues: 2, openPullRequests: 1, mergedPullRequests: 3, closedPullRequests: 0, labels: 0 }); + return Response.json([]); + }); + + const result = await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" }); + + expect(result.status).toBe("queued"); + expect(sent.filter((message) => message.type === "backfill-repo-segment").length).toBeGreaterThan(0); + }); + + it("INVARIANT (#4497): backs off the scheduled per-repo backfill when the prior sync errored recently, instead of retrying every tick", async () => { + const sent: import("../../src/types").JobMessage[] = []; + const env = createTestEnv({ + GITHUB_PUBLIC_TOKEN: "public-token", + JOBS: { + async send(message: import("../../src/types").JobMessage) { + sent.push(message); + }, + } as unknown as Queue, + }); + await seedRegisteredRepo(env); + await upsertRepoSyncState(env, { + repoFullName: "JSONbored/gittensory", + status: "error", + sourceKind: "github", + openIssuesCount: 0, + openPullRequestsCount: 0, + recentMergedPullRequestsCount: 0, + lastCompletedAt: new Date().toISOString(), + errorSummary: "rate limited", + warnings: [], + }); + vi.stubGlobal("fetch", async () => new Response("must not be called", { status: 500 })); + + const result = await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" }); + + expect(result).toMatchObject({ status: "skipped", warnings: [expect.stringContaining("backing off")] }); + expect(sent).toEqual([]); + }); + + it("REGRESSION (#4497, endless-scheduled-resync incident): two scheduled dispatches within the freshness window only sync once -- previously every registered repo was re-synced every 30 min forever regardless of freshness or a permanent error state", async () => { + const sent: import("../../src/types").JobMessage[] = []; + const env = createTestEnv({ + GITHUB_PUBLIC_TOKEN: "public-token", + JOBS: { + async send(message: import("../../src/types").JobMessage) { + sent.push(message); + }, + } as unknown as Queue, + }); + await seedRegisteredRepo(env); + vi.stubGlobal("fetch", async (input: RequestInfo | URL) => { + if (input.toString() === "https://api.github.com/graphql") return githubTotalsResponse({ openIssues: 4, openPullRequests: 2, mergedPullRequests: 9, closedPullRequests: 1, labels: 1 }); + return Response.json([]); + }); + + // First scheduled tick: no prior sync state -> a real sync proceeds and stamps a fresh success. + const first = await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" }); + expect(first.status).toBe("queued"); + const segmentJobsAfterFirst = sent.filter((message) => message.type === "backfill-repo-segment").length; + expect(segmentJobsAfterFirst).toBeGreaterThan(0); + await upsertRepoSyncState(env, { + repoFullName: "JSONbored/gittensory", + status: "success", + sourceKind: "github", + openIssuesCount: 4, + openPullRequestsCount: 2, + recentMergedPullRequestsCount: 9, + lastCompletedAt: new Date().toISOString(), + warnings: [], + }); + + // Second scheduled tick, simulating the next ~30-min cron cadence while still fresh: must be skipped, not + // re-synced -- this is the exact incident shape (the scheduled path previously had no freshness check at + // all, so this second tick would have unconditionally re-fetched totals and re-enqueued all 4 segments). + const second = await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" }); + expect(second.status).toBe("skipped"); + expect(sent.filter((message) => message.type === "backfill-repo-segment").length).toBe(segmentJobsAfterFirst); + + // An explicit force still bypasses the freshness gate -- the override path is preserved. + const forced = await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light", force: true }); + expect(forced.status).toBe("queued"); + expect(sent.filter((message) => message.type === "backfill-repo-segment").length).toBeGreaterThan(segmentJobsAfterFirst); + }); + it("reuses a fresh repo totals snapshot when queueing segmented backfills", async () => { vi.useFakeTimers(); vi.setSystemTime(new Date("2026-05-25T00:05:00.000Z"));