From cc983e1170f1d9e1beae52ba92e25e81a7b1bbf0 Mon Sep 17 00:00:00 2001 From: JSONbored <49853598+JSONbored@users.noreply.github.com> Date: Fri, 31 Jul 2026 05:22:46 -0700 Subject: [PATCH] fix(backfill): gate the open-data crawl on its own segments, not a clock every job bumps enqueueRepositoryOpenDataBackfill measured freshness on repo_sync_state.lastCompletedAt, but refreshRepoSyncStateFromSegments rewrites that repo-wide column at the tail of EVERY segment write path -- including the ~2-minute re-gate sweep's own force:true open_pull_requests refresh and the backfill-pr-details follow-on it enqueues, neither of which dispatches any open-data work. The clock therefore never aged past FRESH_SYNC_MS and the gate never opened: labels, open_issues and recent_merged_pull_requests went undispatched from the moment #4529 shipped (2026-07-09T23:27Z, sixty-eight seconds after the last crawl completed). Only recent_merged_pull_requests showed it. The other three open-data tables have webhook or sweep writers that kept them current and masked the dead crawl, so the table quietly served a three-week-old window to the copycat containment engine, the repo culture profile (whose cache-invalidation signal is the frozen row count, so it never regenerated at all), the maintainer recap, six services, and the public API and MCP surfaces. Freshness now reads the oldest completion across the four segments the fan-out actually dispatches, treating a never-run segment as infinitely old. That measures attempts rather than successes, so #4497's throttle is intact: a repo that genuinely completed a crawl still backs off for six hours. The error-backoff window keeps reading lastCompletedAt -- a repo-level error state is repo-wide by nature. The skip was also invisible: it was reported only as a warnings[] string that the cron caller discards, so three weeks of a starved crawl left no log, metric, or audit trail. It now emits a counter and a log line with the crawl age, and listContributorRecentMergedPullRequests -- a reader with no production callers -- is removed. Closes #10193. --- src/db/repositories.ts | 11 -- src/github/backfill.ts | 66 +++++++-- src/selfhost/metrics.ts | 7 + test/unit/backfill.test.ts | 269 +++++++++++++++++++++++++++++++++++ test/unit/data-spine.test.ts | 2 - 5 files changed, 332 insertions(+), 23 deletions(-) diff --git a/src/db/repositories.ts b/src/db/repositories.ts index 1232119e57..6cf6e4a0bd 100644 --- a/src/db/repositories.ts +++ b/src/db/repositories.ts @@ -5408,17 +5408,6 @@ export async function countRecentMergedPullRequests(env: Env, fullName: string): return Number(row?.count ?? 0); } -export async function listContributorRecentMergedPullRequests(env: Env, login: string): Promise { - const db = getDb(env.DB); - const rows = await db - .select() - .from(recentMergedPullRequests) - .where(loginMatches(recentMergedPullRequests.authorLogin, login)) - .orderBy(desc(recentMergedPullRequests.mergedAt)) - .limit(1000); - return rows.map(toRecentMergedPullRequestRecord); -} - export async function upsertContributor(env: Env, contributor: ContributorRecord): Promise { const db = getDb(env.DB); await db diff --git a/src/github/backfill.ts b/src/github/backfill.ts index 30031edb3b..4884aea8b4 100644 --- a/src/github/backfill.ts +++ b/src/github/backfill.ts @@ -10,6 +10,7 @@ import { getPullRequestDetailSyncState, listRepoGithubTotalsSnapshotHistory, getRepoSyncSegment, + listRepoSyncSegments, getRepoSyncState, listOpenIssueNumbers, listOpenPullRequests, @@ -327,6 +328,25 @@ const DEFAULT_LIMITS: BackfillLimits = { const FRESH_SYNC_MS = 6 * 60 * 60 * 1000; const ERROR_BACKOFF_MS = 60 * 60 * 1000; +/** The segments the open-data fan-out dispatches -- and therefore the only ones whose freshness may gate it. */ +const OPEN_DATA_SEGMENTS: readonly BackfillSegmentName[] = ["labels", "open_issues", "open_pull_requests", "recent_merged_pull_requests"]; +const OPEN_DATA_BACKFILL_SKIPPED_METRIC = "loopover_github_open_data_backfill_skipped_total"; + +/** Age of the OPEN-DATA crawl itself: the oldest completion across the four segments the fan-out below actually + * dispatches. A segment that has never run (no row, or an unparseable completedAt) is infinitely old, so a repo + * still owed its first crawl of any one segment is never treated as fresh. Measures ATTEMPTS, not successes -- + * a segment that ran minutes ago and came back `waiting_rate_limit` is not owed another attempt yet, which is + * exactly the re-sync storm #4497 set out to stop. */ +function openDataCrawlAgeMs(segments: RepoSyncSegmentRecord[], nowMs: number): number { + const completedBySegment = new Map(segments.map((segment) => [segment.segment, segment.completedAt])); + let ageMs = 0; + for (const name of OPEN_DATA_SEGMENTS) { + const completedMs = Date.parse(completedBySegment.get(name) ?? ""); + if (!Number.isFinite(completedMs)) return Number.POSITIVE_INFINITY; + ageMs = Math.max(ageMs, nowMs - completedMs); + } + return ageMs; +} /** 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 @@ -334,16 +354,30 @@ const ERROR_BACKOFF_MS = 60 * 60 * 1000; * 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. */ + * registered repo every 30 minutes forever regardless of freshness or a permanent error state. + * + * The fresh-success window is measured on the open-data SEGMENTS' own completions, not on + * repo_sync_state.lastCompletedAt (#10193). That column is a repo-wide clock that + * refreshRepoSyncStateFromSegments rewrites at the end of EVERY segment write path, including two that run far + * more often than FRESH_SYNC_MS and dispatch no open-data work: the ~2-minute re-gate sweep's own + * open_pull_requests refresh (queue/processors.ts refreshOpenPullRequestsForScheduledSweep, which bypasses this + * gate with force) and the backfill-pr-details follow-on it enqueues. Reading it here made the gate + * self-perpetuating -- it never aged past the window, so labels/open_issues/recent_merged_pull_requests went + * undispatched from the moment #4529 shipped. Only recent_merged_pull_requests showed it, because it is the one + * open-data table with no webhook or sweep writer to mask the frozen crawl. The error-backoff window still reads + * lastCompletedAt: a repo-level error state is repo-wide by nature. */ function syncFreshnessSkipReason( syncState: RepoSyncStateRecord | null, + openDataSegments: RepoSyncSegmentRecord[], 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 nowMs = Date.now(); + const stateAgeMs = nowMs - 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; + (syncState.status === "success" || syncState.status === "partial" || syncState.status === "capped") && + openDataCrawlAgeMs(openDataSegments, nowMs) < FRESH_SYNC_MS; + const recentError = syncState.status === "error" && Number.isFinite(stateAgeMs) && stateAgeMs < ERROR_BACKOFF_MS; return freshSuccess || recentError ? { freshSuccess, recentError } : null; } const SEGMENT_PAGE_BUDGET: Record = { light: 2, full: 10, resume: 10 }; @@ -447,8 +481,8 @@ export async function backfillRegisteredRepositories( warnings, }; } - const syncState = await getRepoSyncState(env, repo.fullName); - const skipReason = syncFreshnessSkipReason(syncState, options.force); + const [syncState, syncSegments] = await Promise.all([getRepoSyncState(env, repo.fullName), listRepoSyncSegments(env, repo.fullName)]); + const skipReason = syncFreshnessSkipReason(syncState, syncSegments, options.force); if (skipReason && syncState) { return { repoFullName: repo.fullName, @@ -482,9 +516,22 @@ export async function enqueueRepositoryOpenDataBackfill( // 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); + const [previous, syncSegments] = await Promise.all([getRepoSyncState(env, repo.fullName), listRepoSyncSegments(env, repo.fullName)]); + const skipReason = syncFreshnessSkipReason(previous, syncSegments, options.force); if (skipReason && previous) { + // #10193: the skip used to be reported ONLY as a warnings[] string, which this function's cron caller + // (queue/job-dispatch.ts's backfill-registered-repos case) discards -- so a repo whose open-data crawl was + // skipped on every 30-minute tick for three weeks left no log line, metric, or audit trail anywhere, and the + // dead crawl was found only by noticing the table it feeds had stopped growing. A starved crawl is now visible. + incr(OPEN_DATA_BACKFILL_SKIPPED_METRIC, { reason: skipReason.freshSuccess ? "fresh_success" : "recent_error" }); + console.log( + JSON.stringify({ + event: "open_data_backfill_skipped", + repoFullName: repo.fullName, + reason: skipReason.freshSuccess ? "fresh_success" : "recent_error", + openDataCrawlAgeMs: openDataCrawlAgeMs(syncSegments, Date.now()), + }), + ); return { ok: true, repoFullName: repo.fullName, @@ -518,9 +565,8 @@ export async function enqueueRepositoryOpenDataBackfill( lastCompletedAt: previous?.lastCompletedAt, warnings: previous?.warnings ?? [], }); - const segments: BackfillSegmentName[] = ["labels", "open_issues", "open_pull_requests", "recent_merged_pull_requests"]; await Promise.all( - segments.map((segment, index) => + OPEN_DATA_SEGMENTS.map((segment, index) => env.JOBS.send( { type: "backfill-repo-segment", requestedBy: options.requestedBy, repoFullName: repo.fullName, ...repoInstallationPayload(repo), segment, mode, ...(options.force === undefined ? {} : { force: options.force }) }, { delaySeconds: index * 15 }, diff --git a/src/selfhost/metrics.ts b/src/selfhost/metrics.ts index 4282f6a343..8b8780280f 100644 --- a/src/selfhost/metrics.ts +++ b/src/selfhost/metrics.ts @@ -147,6 +147,13 @@ export const DEFAULT_METRIC_META: readonly (readonly [string, MetricMeta])[] = [ ["loopover_review_end_to_end_latency_seconds", { help: "Real end-to-end review latency in seconds, from the PR's current head SHA becoming ready for review (open + non-draft) to this pass's comment publish -- distinct from a single queue job's own claim-to-completion latency_ms, this spans every queueing/deferral wait in between.", type: "histogram" }], ["loopover_github_branch_protection_permission_denied_total", { help: "GitHub branch-protection reads denied by permissions.", type: "counter" }], ["loopover_github_pull_request_files_fetch_total", { help: "GitHub pull-request file fetch attempts.", type: "counter" }], + [ + "loopover_github_open_data_backfill_skipped_total", + { + help: "Scheduled open-data backfills skipped by the freshness/error-backoff gate, by reason (fresh_success/recent_error). A repo whose crawl is genuinely starved shows a sustained fresh_success rate with no matching segment progress (#10193).", + type: "counter", + }, + ], ["loopover_pr_state_cache_total", { help: "Pull-request state cache outcomes.", type: "counter" }], ["loopover_ci_state_cache_total", { help: "CI-state snapshot cache outcomes.", type: "counter" }], ["loopover_ops_anomaly_total", { help: "Ops anomaly scan detections (review burst / review failure burst), by repo and kind.", type: "counter" }], diff --git a/test/unit/backfill.test.ts b/test/unit/backfill.test.ts index 5abc43bcb2..71d19d235c 100644 --- a/test/unit/backfill.test.ts +++ b/test/unit/backfill.test.ts @@ -211,6 +211,30 @@ async function seedInstalledAndRegisteredRepo(env: Env) { await seedRegisteredRepo(env); } +// The freshness gate reads the OPEN-DATA segments' own completions, not repo_sync_state.lastCompletedAt +// (#10193), so a test asserting a skip must seed both -- in production a `success`/`partial` sync state only +// ever exists BECAUSE refreshRepoSyncStateFromSegments rolled these four segment rows up into it. +async function seedOpenDataSegments( + env: Env, + completedAt: string, + segments: readonly import("../../src/types").RepoSyncSegmentRecord["segment"][] = ["labels", "open_issues", "open_pull_requests", "recent_merged_pull_requests"], +) { + for (const segment of segments) { + await upsertRepoSyncSegment(env, { + repoFullName: "JSONbored/gittensory", + segment, + status: "complete", + sourceKind: "github", + mode: "light", + fetchedCount: 1, + pageCount: 1, + startedAt: completedAt, + completedAt, + warnings: [], + }); + } +} + async function persistTotalsSnapshot( env: Env, overrides: { @@ -1518,6 +1542,7 @@ describe("GitHub backfill", () => { // than removed, since #5021's own scope is the eligibility filter, not this unrelated branch. const freshEnv = createTestEnv({ GITHUB_PUBLIC_TOKEN: "public-token" }); await seedInstalledAndRegisteredRepo(freshEnv); + await seedOpenDataSegments(freshEnv, new Date().toISOString()); await upsertRepoSyncState(freshEnv, { repoFullName: "JSONbored/gittensory", status: "success", @@ -2624,6 +2649,7 @@ describe("GitHub backfill", () => { } as unknown as Queue, }); await seedInstalledAndRegisteredRepo(env); + await seedOpenDataSegments(env, new Date().toISOString()); await upsertRepoSyncState(env, { repoFullName: "JSONbored/gittensory", status: "success", @@ -2744,6 +2770,245 @@ describe("GitHub backfill", () => { expect(sent).toEqual([]); }); + it("INVARIANT (#10193): every status the fresh-success window covers (success/partial/capped) skips on fresh open-data segments, and every status outside it proceeds", async () => { + for (const status of ["success", "partial", "capped"] as const) { + const env = createTestEnv({ GITHUB_PUBLIC_TOKEN: "public-token", JOBS: { async send() {} } as unknown as Queue }); + await seedInstalledAndRegisteredRepo(env); + await seedOpenDataSegments(env, new Date().toISOString()); + await upsertRepoSyncState(env, { + repoFullName: "JSONbored/gittensory", + status, + sourceKind: "github", + openIssuesCount: 1, + openPullRequestsCount: 1, + recentMergedPullRequestsCount: 0, + lastCompletedAt: new Date().toISOString(), + warnings: [], + }); + vi.stubGlobal("fetch", async () => new Response("must not be called", { status: 500 })); + + expect(await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" })).toMatchObject({ status: "skipped" }); + } + + // rate_limited is in NEITHER window: it is not a fresh success and not an error, so it must proceed rather + // than leak into the skip through a status the gate never meant to cover. + const proceedEnv = createTestEnv({ GITHUB_PUBLIC_TOKEN: "public-token", JOBS: { async send() {} } as unknown as Queue }); + await seedInstalledAndRegisteredRepo(proceedEnv); + await seedOpenDataSegments(proceedEnv, new Date().toISOString()); + await upsertRepoSyncState(proceedEnv, { + repoFullName: "JSONbored/gittensory", + status: "rate_limited", + sourceKind: "github", + openIssuesCount: 1, + openPullRequestsCount: 1, + 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: 0, closedPullRequests: 0, labels: 0 }); + return Response.json([]); + }); + + expect(await enqueueRepositoryOpenDataBackfill(proceedEnv, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" })).toMatchObject({ status: "queued" }); + }); + + it("INVARIANT (#10193): the error-backoff window still reads repo_sync_state's own clock -- an error past the window, or with an unparseable timestamp, proceeds", async () => { + for (const lastCompletedAt of [new Date(Date.now() - 2 * 60 * 60 * 1000).toISOString(), "not-a-timestamp"]) { + const env = createTestEnv({ GITHUB_PUBLIC_TOKEN: "public-token", JOBS: { async send() {} } as unknown as Queue }); + await seedInstalledAndRegisteredRepo(env); + // Segments are stale too, so the ONLY thing that could still force a skip here is the error window. + await seedOpenDataSegments(env, new Date(Date.now() - 21 * 24 * 60 * 60 * 1000).toISOString()); + await upsertRepoSyncState(env, { + repoFullName: "JSONbored/gittensory", + status: "error", + sourceKind: "github", + openIssuesCount: 0, + openPullRequestsCount: 0, + recentMergedPullRequestsCount: 0, + lastCompletedAt, + errorSummary: "rate limited", + warnings: [], + }); + vi.stubGlobal("fetch", async (input: RequestInfo | URL) => { + if (input.toString() === "https://api.github.com/graphql") return githubTotalsResponse({ openIssues: 0, openPullRequests: 0, mergedPullRequests: 0, closedPullRequests: 0, labels: 0 }); + return Response.json([]); + }); + + expect(await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" })).toMatchObject({ status: "queued" }); + } + }); + + it("REGRESSION (#10193, starved-open-data-crawl incident): a repo whose lastCompletedAt is minutes old but whose open-data segments last ran three weeks ago still syncs -- the gate previously read a repo-wide clock the ~2-min sweep kept bumping, so labels/open_issues/recent_merged_pull_requests were never dispatched again", 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 seedInstalledAndRegisteredRepo(env); + // The exact production shape: the open-data segments are frozen weeks back, while repo_sync_state was + // rewritten seconds ago by refreshRepoSyncStateFromSegments at the tail of an UNRELATED write path (the + // sweep's own force:true open_pull_requests refresh and the backfill-pr-details follow-on it enqueues). + await seedOpenDataSegments(env, new Date(Date.now() - 21 * 24 * 60 * 60 * 1000).toISOString()); + 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 (input: RequestInfo | URL) => { + if (input.toString() === "https://api.github.com/graphql") return githubTotalsResponse({ openIssues: 5, openPullRequests: 3, mergedPullRequests: 10, closedPullRequests: 0, labels: 0 }); + return Response.json([]); + }); + + const result = await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" }); + + expect(result.status).toBe("queued"); + // recent_merged_pull_requests specifically: it is the one open-data table with no webhook or sweep writer, + // so it is the segment whose starvation actually froze a table (recent_merged_pull_requests stopped + // growing on 2026-07-09) rather than being masked. + expect(sent).toEqual( + expect.arrayContaining([expect.objectContaining({ type: "backfill-repo-segment", segment: "recent_merged_pull_requests" })]), + ); + }); + + it("INVARIANT (#10193): a repo missing an open-data segment row entirely is never treated as fresh, however recent its sync 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 seedInstalledAndRegisteredRepo(env); + // Three of four are fresh; recent_merged_pull_requests has never run at all. The crawl is still owed, so + // the oldest-completion anchor must read as infinitely stale rather than settling for the fresh three. + await seedOpenDataSegments(env, new Date().toISOString(), ["labels", "open_issues", "open_pull_requests"]); + await upsertRepoSyncState(env, { + repoFullName: "JSONbored/gittensory", + status: "success", + sourceKind: "github", + openIssuesCount: 1, + openPullRequestsCount: 1, + 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: 0, 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).toBe(4); + }); + + it("INVARIANT (#10193): an unparseable segment completedAt reads as never-run, not as fresh", 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 seedInstalledAndRegisteredRepo(env); + await seedOpenDataSegments(env, new Date().toISOString()); + // A legacy/hand-edited row whose completedAt cannot be parsed must fail OPEN (sync proceeds), never + // silently pin the gate shut the way an unmeasurable clock otherwise would. + await upsertRepoSyncSegment(env, { + repoFullName: "JSONbored/gittensory", + segment: "labels", + status: "complete", + sourceKind: "github", + mode: "light", + fetchedCount: 1, + pageCount: 1, + completedAt: "not-a-timestamp", + warnings: [], + }); + await upsertRepoSyncState(env, { + repoFullName: "JSONbored/gittensory", + status: "success", + sourceKind: "github", + openIssuesCount: 1, + openPullRequestsCount: 1, + 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: 0, closedPullRequests: 0, labels: 0 }); + return Response.json([]); + }); + + const result = await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" }); + + expect(result.status).toBe("queued"); + }); + + it("INVARIANT (#10193): the skip is logged with its reason on both the fresh-success and error-backoff paths, instead of only being returned as a discarded warning string", async () => { + const env = createTestEnv({ + GITHUB_PUBLIC_TOKEN: "public-token", + JOBS: { async send() {} } as unknown as Queue, + }); + await seedInstalledAndRegisteredRepo(env); + await seedOpenDataSegments(env, new Date().toISOString()); + await upsertRepoSyncState(env, { + repoFullName: "JSONbored/gittensory", + status: "success", + sourceKind: "github", + openIssuesCount: 1, + openPullRequestsCount: 1, + recentMergedPullRequestsCount: 0, + lastCompletedAt: new Date().toISOString(), + warnings: [], + }); + vi.stubGlobal("fetch", async () => new Response("must not be called", { status: 500 })); + const logged = vi.spyOn(console, "log").mockImplementation(() => {}); + + await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" }); + + const freshEvents = logged.mock.calls.map((call) => String(call[0])).filter((line) => line.includes("open_data_backfill_skipped")); + expect(freshEvents).toHaveLength(1); + expect(JSON.parse(freshEvents[0]!)).toMatchObject({ event: "open_data_backfill_skipped", repoFullName: "JSONbored/gittensory", reason: "fresh_success" }); + // The age is a real measurement, not a placeholder -- a starved crawl is recognisable by it growing. + expect(JSON.parse(freshEvents[0]!).openDataCrawlAgeMs).toBeGreaterThanOrEqual(0); + + logged.mockClear(); + await upsertRepoSyncState(env, { + repoFullName: "JSONbored/gittensory", + status: "error", + sourceKind: "github", + openIssuesCount: 0, + openPullRequestsCount: 0, + recentMergedPullRequestsCount: 0, + lastCompletedAt: new Date().toISOString(), + errorSummary: "rate limited", + warnings: [], + }); + + await enqueueRepositoryOpenDataBackfill(env, { repoFullName: "JSONbored/gittensory", requestedBy: "schedule", mode: "light" }); + + const errorEvents = logged.mock.calls.map((call) => String(call[0])).filter((line) => line.includes("open_data_backfill_skipped")); + expect(errorEvents).toHaveLength(1); + expect(JSON.parse(errorEvents[0]!)).toMatchObject({ reason: "recent_error" }); + logged.mockRestore(); + }); + 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({ @@ -2765,6 +3030,10 @@ describe("GitHub backfill", () => { expect(first.status).toBe("queued"); const segmentJobsAfterFirst = sent.filter((message) => message.type === "backfill-repo-segment").length; expect(segmentJobsAfterFirst).toBeGreaterThan(0); + // The queued segment jobs are captured, not executed (JOBS.send is a stub), so stand in for the segment + // rows a real run would have written -- the fresh sync state below is only reachable in production once + // those exist (#10193). + await seedOpenDataSegments(env, new Date().toISOString()); await upsertRepoSyncState(env, { repoFullName: "JSONbored/gittensory", status: "success", diff --git a/test/unit/data-spine.test.ts b/test/unit/data-spine.test.ts index 54aba53fdc..3d29746ee5 100644 --- a/test/unit/data-spine.test.ts +++ b/test/unit/data-spine.test.ts @@ -10,7 +10,6 @@ import { listCollisionEdges, listContributorIssues, listContributorPullRequests, - listContributorRecentMergedPullRequests, listContributorRepoStats, listInstallationHealth, listInstallations, @@ -196,7 +195,6 @@ describe("data spine repositories", () => { }); expect(await listContributorRepoStats(env, "oktofeesh1")).toMatchObject([{ repoFullName: "JSONbored/loopover", dominantLabels: ["bug"] }]); expect(await listContributorRepoStats(env, "OKTOFEESH1")).toMatchObject([{ repoFullName: "JSONbored/loopover", dominantLabels: ["bug"] }]); - expect(await listContributorRecentMergedPullRequests(env, "OKTOFEESH1")).toMatchObject([{ repoFullName: "JSONbored/loopover", number: 4 }]); await env.DB.prepare( "insert into contributor_repo_stats (id, login, repo_full_name, pull_requests, merged_pull_requests, open_pull_requests, issues, stale_pull_requests, unlinked_pull_requests, dominant_labels_json, last_activity_at) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)", )