diff --git a/app/workflows/__tests__/backfillTrackStep.test.ts b/app/workflows/__tests__/backfillTrackStep.test.ts index ebe77370..6c211ed6 100644 --- a/app/workflows/__tests__/backfillTrackStep.test.ts +++ b/app/workflows/__tests__/backfillTrackStep.test.ts @@ -1,12 +1,14 @@ import { describe, it, expect, vi, beforeEach } from "vitest"; import { backfillTrackStep } from "../backfillTrackStep"; -import { fetchSongstats } from "@/lib/songstats/fetchSongstats"; +import { fetchSongstatsWithBackoff } from "@/lib/songstats/fetchSongstatsWithBackoff"; import { upsertSongMeasurements } from "@/lib/supabase/song_measurements/upsertSongMeasurements"; import { insertSongstatsQuotaLedger } from "@/lib/supabase/songstats_quota_ledger/insertSongstatsQuotaLedger"; import { updateSongstatsBackfillQueue } from "@/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue"; -vi.mock("@/lib/songstats/fetchSongstats", () => ({ fetchSongstats: vi.fn() })); +vi.mock("@/lib/songstats/fetchSongstatsWithBackoff", () => ({ + fetchSongstatsWithBackoff: vi.fn(), +})); vi.mock("@/lib/supabase/song_measurements/upsertSongMeasurements", () => ({ upsertSongMeasurements: vi.fn(), })); @@ -22,22 +24,20 @@ const ROW = { id: "q1", song: "USA2P2015959" } as never; describe("backfillTrackStep", () => { beforeEach(() => { vi.clearAllMocks(); + vi.spyOn(console, "log").mockImplementation(() => {}); vi.mocked(upsertSongMeasurements).mockResolvedValue([] as never); }); - it("writes the historic series as songstats measurements, records spend, marks done", async () => { - vi.mocked(fetchSongstats).mockResolvedValue({ + it("writes the historic series, records the spend, marks done on 200", async () => { + vi.mocked(fetchSongstatsWithBackoff).mockResolvedValue({ status: 200, + attempts: 1, + retriesExhausted: false, data: { stats: [ { source: "spotify", - data: { - history: [ - { date: "2025-01-01", streams_total: 1008736324 }, - { date: "2026-01-01", streams_total: 1330251464 }, - ], - }, + data: { history: [{ date: "2025-01-01", streams_total: 1008736324 }] }, }, ], }, @@ -45,10 +45,11 @@ describe("backfillTrackStep", () => { const result = await backfillTrackStep(ROW); - expect(fetchSongstats).toHaveBeenCalledWith("tracks/historic_stats", { + expect(fetchSongstatsWithBackoff).toHaveBeenCalledWith("tracks/historic_stats", { isrc: "USA2P2015959", source: "spotify", }); + // exact transformation: each history point → a permanent songstats measurement expect(upsertSongMeasurements).toHaveBeenCalledWith([ { song: "USA2P2015959", @@ -59,74 +60,65 @@ describe("backfillTrackStep", () => { data_source: "songstats", raw_ref: "songstats-backfill", }, - { - song: "USA2P2015959", - platform: "spotify", - metric: "platform_displayed_play_count", - value: 1330251464, - captured_at: "2026-01-01T00:00:00.000Z", - data_source: "songstats", - raw_ref: "songstats-backfill", - }, ]); expect(insertSongstatsQuotaLedger).toHaveBeenCalledWith({ hits: 1, purpose: "backfill USA2P2015959", }); - expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith("q1", { status: "done" }); + expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith(["q1"], { status: "done" }); expect(result).toEqual({ ok: true, hitsSpent: 1 }); }); - it("marks a transient upstream error (429) as failed (reclaimable) and records the spend", async () => { - vi.mocked(fetchSongstats).mockResolvedValue({ status: 429, data: {} }); - - const result = await backfillTrackStep(ROW); - - // transient -> 'failed' so the daily reclaim sweep returns it to 'pending' - expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith("q1", { status: "failed" }); - expect(insertSongstatsQuotaLedger).toHaveBeenCalledWith({ - hits: 1, - purpose: "backfill USA2P2015959 (failed 429)", + it("DEFERS (pending, no quota hit, signals stop) when backoff is exhausted on 429", async () => { + vi.mocked(fetchSongstatsWithBackoff).mockResolvedValue({ + status: 429, + attempts: 6, + retriesExhausted: true, + data: {}, }); - expect(upsertSongMeasurements).not.toHaveBeenCalled(); - expect(result).toEqual({ ok: false, hitsSpent: 1 }); - }); - - it("marks a transient 5xx as failed (reclaimable)", async () => { - vi.mocked(fetchSongstats).mockResolvedValue({ status: 504, data: {} }); const result = await backfillTrackStep(ROW); - expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith("q1", { status: "failed" }); - expect(result).toEqual({ ok: false, hitsSpent: 1 }); + // left pending for the next drain; NO ledger hit (Songstats consumed nothing) + expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith(["q1"], { status: "pending" }); + expect(insertSongstatsQuotaLedger).not.toHaveBeenCalled(); + expect(upsertSongMeasurements).not.toHaveBeenCalled(); + expect(result).toEqual({ ok: false, hitsSpent: 0, deferred: true }); }); - it("marks a permanent client error (403) as done so reclaim never recycles it", async () => { - vi.mocked(fetchSongstats).mockResolvedValue({ status: 403, data: {} }); + it("marks a definitive 404 (no history) as done and records the spend", async () => { + vi.mocked(fetchSongstatsWithBackoff).mockResolvedValue({ + status: 404, + attempts: 1, + retriesExhausted: false, + data: {}, + }); const result = await backfillTrackStep(ROW); - // non-retryable 4xx (not 408/429) is terminal -> 'done', not 'failed' - expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith("q1", { status: "done" }); + expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith(["q1"], { status: "done" }); expect(insertSongstatsQuotaLedger).toHaveBeenCalledWith({ hits: 1, - purpose: "backfill USA2P2015959 (terminal 403)", + purpose: "backfill USA2P2015959 (no data 404)", }); expect(result).toEqual({ ok: false, hitsSpent: 1 }); }); - it("marks a definitive 404 (no history exists) as done so it is never retried", async () => { - vi.mocked(fetchSongstats).mockResolvedValue({ status: 404, data: {} }); + it("marks a permanent 4xx (403) as done (terminal) and records the spend", async () => { + vi.mocked(fetchSongstatsWithBackoff).mockResolvedValue({ + status: 403, + attempts: 1, + retriesExhausted: false, + data: {}, + }); const result = await backfillTrackStep(ROW); - // terminal no-data -> 'done', not 'failed' — the reclaim sweep must not resurrect it - expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith("q1", { status: "done" }); + expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith(["q1"], { status: "done" }); expect(insertSongstatsQuotaLedger).toHaveBeenCalledWith({ hits: 1, - purpose: "backfill USA2P2015959 (no data 404)", + purpose: "backfill USA2P2015959 (terminal 403)", }); - expect(upsertSongMeasurements).not.toHaveBeenCalled(); expect(result).toEqual({ ok: false, hitsSpent: 1 }); }); }); diff --git a/app/workflows/__tests__/songstatsBackfillWorkflow.test.ts b/app/workflows/__tests__/songstatsBackfillWorkflow.test.ts new file mode 100644 index 00000000..cc435558 --- /dev/null +++ b/app/workflows/__tests__/songstatsBackfillWorkflow.test.ts @@ -0,0 +1,61 @@ +import { describe, it, expect, vi, beforeEach } from "vitest"; +import { songstatsBackfillWorkflow } from "../songstatsBackfillWorkflow"; + +import { getBackfillBudgetStep } from "../getBackfillBudgetStep"; +import { claimBackfillRowsStep } from "../claimBackfillRowsStep"; +import { backfillTrackStep } from "../backfillTrackStep"; +import { releaseClaimedRowsStep } from "../releaseClaimedRowsStep"; + +vi.mock("../getBackfillBudgetStep", () => ({ getBackfillBudgetStep: vi.fn() })); +vi.mock("../claimBackfillRowsStep", () => ({ claimBackfillRowsStep: vi.fn() })); +vi.mock("../backfillTrackStep", () => ({ backfillTrackStep: vi.fn() })); +vi.mock("../releaseClaimedRowsStep", () => ({ releaseClaimedRowsStep: vi.fn() })); + +const row = (id: string) => ({ id, song: id }) as never; + +describe("songstatsBackfillWorkflow", () => { + beforeEach(() => { + vi.clearAllMocks(); + vi.spyOn(console, "log").mockImplementation(() => {}); + vi.mocked(releaseClaimedRowsStep).mockResolvedValue(undefined); + }); + + it("releases the rest of the claimed batch to pending when a track defers", async () => { + vi.mocked(getBackfillBudgetStep).mockResolvedValue(100); + vi.mocked(claimBackfillRowsStep).mockResolvedValue([row("r1"), row("r2"), row("r3")]); + vi.mocked(backfillTrackStep) + .mockResolvedValueOnce({ ok: true, hitsSpent: 1 }) // r1 + .mockResolvedValueOnce({ ok: false, hitsSpent: 0, deferred: true }); // r2 defers + + const result = await songstatsBackfillWorkflow(); + + // r2 is set pending by the step itself; the unprocessed remainder (r3) is released here + expect(releaseClaimedRowsStep).toHaveBeenCalledWith(["r3"]); + expect(backfillTrackStep).toHaveBeenCalledTimes(2); // stopped at the defer, never reached r3 + expect(result).toEqual({ backfilled: 1, failed: 0, deferred: true }); + }); + + it("drains until the queue is empty and never releases when nothing defers", async () => { + vi.mocked(getBackfillBudgetStep).mockResolvedValue(100); + vi.mocked(claimBackfillRowsStep) + .mockResolvedValueOnce([row("a"), row("b")]) + .mockResolvedValueOnce([]); // queue drained + vi.mocked(backfillTrackStep) + .mockResolvedValueOnce({ ok: true, hitsSpent: 1 }) + .mockResolvedValueOnce({ ok: false, hitsSpent: 1 }); // terminal (e.g. 404) + + const result = await songstatsBackfillWorkflow(); + + expect(releaseClaimedRowsStep).not.toHaveBeenCalled(); + expect(result).toEqual({ backfilled: 1, failed: 1, deferred: false }); + }); + + it("does not drain when there is no budget", async () => { + vi.mocked(getBackfillBudgetStep).mockResolvedValue(0); + + const result = await songstatsBackfillWorkflow(); + + expect(claimBackfillRowsStep).not.toHaveBeenCalled(); + expect(result).toEqual({ backfilled: 0, failed: 0, deferred: false }); + }); +}); diff --git a/app/workflows/backfillTrackStep.ts b/app/workflows/backfillTrackStep.ts index 3247ff4c..fd394743 100644 --- a/app/workflows/backfillTrackStep.ts +++ b/app/workflows/backfillTrackStep.ts @@ -1,4 +1,4 @@ -import { fetchSongstats } from "@/lib/songstats/fetchSongstats"; +import { fetchSongstatsWithBackoff } from "@/lib/songstats/fetchSongstatsWithBackoff"; import { upsertSongMeasurements } from "@/lib/supabase/song_measurements/upsertSongMeasurements"; import { insertSongstatsQuotaLedger } from "@/lib/supabase/songstats_quota_ledger/insertSongstatsQuotaLedger"; import { updateSongstatsBackfillQueue } from "@/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue"; @@ -8,40 +8,48 @@ import { Tables } from "@/types/database.types"; const METRIC = "platform_displayed_play_count"; /** - * Backfill one claimed queue row: fetch the track's Songstats historic series - * (one quota hit — recorded win or lose), write each point as a permanent - * `songstats`-labeled measurement, and close the row. Failures mark the row - * failed without failing the run — the next row may still succeed. + * Backfill one claimed queue row, with bounded exponential backoff on Songstats' + * rate limit (Songstats is the rate authority — see chat#1797): + * - **200** → write each history point as a permanent `songstats` measurement, + * record the spend, mark `done`. + * - **404 / other 4xx** → a real request with a definitive answer; terminal, so + * mark `done` (404 = no history) and record the spend. + * - **backoff exhausted** (still 429/5xx after retries) → **defer**: leave the row + * `pending` for the next drain, consume no quota, and signal the workflow to + * stop (`deferred`) — Songstats is saturated right now. * * @param row - The claimed queue row (already in_progress) - * @returns ok + hits spent (always 1; the hit is consumed even on failure) + * @returns ok + hitsSpent (0 when deferred) + `deferred` when Songstats is saturated */ export async function backfillTrackStep( row: Tables<"songstats_backfill_queue">, -): Promise<{ ok: boolean; hitsSpent: number }> { +): Promise<{ ok: boolean; hitsSpent: number; deferred?: boolean }> { "use step"; - const result = await fetchSongstats("tracks/historic_stats", { + const result = await fetchSongstatsWithBackoff("tracks/historic_stats", { isrc: row.song, source: "spotify", }); - if (result.status !== 200) { - const status = result.status; - const isNoData = status === 404; - // Only transient errors are retryable: 408 (timeout), 429 (quota), any 5xx. - const isRetryable = status === 408 || status === 429 || status >= 500; - - // `failed` is reclaimable (the daily sweep returns it to `pending`, bounded - // by the rolling-window budget). 404 no-data and other permanent 4xx are - // terminal → `done`, so reclaim never recycles a track that can't succeed. - const nextStatus = isRetryable ? "failed" : "done"; - - let outcome = `terminal ${status}`; - if (isNoData) outcome = "no data 404"; - else if (isRetryable) outcome = `failed ${status}`; + if (result.retriesExhausted) { + // Still retryable (429 throttle / 408 / gateway 5xx) past the backoff bound — + // leave it for the next run, spend nothing. + console.log( + `[backfill] ${row.song} deferred (retryable ${result.status} after ${result.attempts} tries)`, + ); + await updateSongstatsBackfillQueue([row.id], { status: "pending" }); + return { ok: false, hitsSpent: 0, deferred: true }; + } - await insertSongstatsQuotaLedger({ hits: 1, purpose: `backfill ${row.song} (${outcome})` }); - await updateSongstatsBackfillQueue(row.id, { status: nextStatus }); + if (result.status !== 200) { + const noData = result.status === 404; + console.log( + `[backfill] ${row.song} done (${noData ? "no data 404" : `terminal ${result.status}`})`, + ); + await insertSongstatsQuotaLedger({ + hits: 1, + purpose: `backfill ${row.song} (${noData ? "no data 404" : `terminal ${result.status}`})`, + }); + await updateSongstatsBackfillQueue([row.id], { status: "done" }); return { ok: false, hitsSpent: 1 }; } @@ -67,7 +75,8 @@ export async function backfillTrackStep( }); await upsertSongMeasurements(rows); + console.log(`[backfill] ${row.song} done (${rows.length} points written)`); await insertSongstatsQuotaLedger({ hits: 1, purpose: `backfill ${row.song}` }); - await updateSongstatsBackfillQueue(row.id, { status: "done" }); + await updateSongstatsBackfillQueue([row.id], { status: "done" }); return { ok: true, hitsSpent: 1 }; } diff --git a/app/workflows/releaseClaimedRowsStep.ts b/app/workflows/releaseClaimedRowsStep.ts new file mode 100644 index 00000000..788d752a --- /dev/null +++ b/app/workflows/releaseClaimedRowsStep.ts @@ -0,0 +1,15 @@ +import { updateSongstatsBackfillQueue } from "@/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue"; + +/** + * Durable step: return unprocessed claimed rows to `pending` when the drain + * stops early on a defer, so the next run retries them immediately instead of + * waiting on the stale-reclaim sweep. + * + * @param ids - Queue row ids still `in_progress` from the aborted batch. + */ +export async function releaseClaimedRowsStep(ids: string[]): Promise { + "use step"; + if (ids.length === 0) return; + await updateSongstatsBackfillQueue(ids, { status: "pending" }); + console.log(`[songstats-backfill] released ${ids.length} claimed rows back to pending`); +} diff --git a/app/workflows/songstatsBackfillWorkflow.ts b/app/workflows/songstatsBackfillWorkflow.ts index 0a1960bf..f94c0223 100644 --- a/app/workflows/songstatsBackfillWorkflow.ts +++ b/app/workflows/songstatsBackfillWorkflow.ts @@ -1,15 +1,20 @@ import { getBackfillBudgetStep } from "@/app/workflows/getBackfillBudgetStep"; import { claimBackfillRowsStep } from "@/app/workflows/claimBackfillRowsStep"; import { backfillTrackStep } from "@/app/workflows/backfillTrackStep"; +import { releaseClaimedRowsStep } from "@/app/workflows/releaseClaimedRowsStep"; const BATCH_SIZE = 25; /** - * Durable Songstats backfill drain (recoupable/chat#1791 write path): check - * the rolling-window budget, claim value-ranked rows via the SKIP LOCKED RPC, - * backfill each track's historic series into the measurement store, and stop - * when the queue or the budget is dry. Every quota hit converts into - * permanent owned data (fetch-once: captured history is never refetched). + * Durable Songstats backfill drain (recoupable/chat#1791 write path): claim + * value-ranked rows via the SKIP LOCKED RPC and backfill each track's historic + * series, with per-track exponential backoff handling Songstats' rate limit + * (chat#1797). **Stops as soon as a track defers** — Songstats still + * rate-limiting it past the backoff bound — releasing the rest of the claimed + * batch back to `pending` (so the next drain retries them immediately rather + * than waiting on stale-reclaim) instead of hammering a saturated API. Every + * successful hit converts into permanent owned data (fetch-once: captured + * history is never refetched). */ export async function songstatsBackfillWorkflow() { "use workflow"; @@ -17,13 +22,23 @@ export async function songstatsBackfillWorkflow() { let budget = await getBackfillBudgetStep(); let backfilled = 0; let failed = 0; + let deferred = false; - while (budget > 0) { + drain: while (budget > 0) { const rows = await claimBackfillRowsStep(Math.min(budget, BATCH_SIZE)); if (rows.length === 0) break; + console.log(`[songstats-backfill] claimed ${rows.length} rows`); - for (const row of rows) { - const result = await backfillTrackStep(row); + for (let i = 0; i < rows.length; i += 1) { + const result = await backfillTrackStep(rows[i]); + if (result.deferred) { + // Songstats is saturated — stop now. The deferred row is already back to + // `pending`; release the rest of this claimed batch too so they don't sit + // `in_progress` until stale-reclaim. + deferred = true; + await releaseClaimedRowsStep(rows.slice(i + 1).map(r => r.id)); + break drain; + } budget -= result.hitsSpent; if (result.ok) backfilled += 1; else failed += 1; @@ -31,6 +46,9 @@ export async function songstatsBackfillWorkflow() { } } - console.log(`[songstats-backfill] done: ${backfilled} backfilled, ${failed} failed`); - return { backfilled, failed }; + console.log( + `[songstats-backfill] done: ${backfilled} backfilled, ${failed} terminal` + + (deferred ? ", deferred (rate-limited)" : ""), + ); + return { backfilled, failed, deferred }; } diff --git a/lib/songstats/__tests__/fetchSongstatsWithBackoff.test.ts b/lib/songstats/__tests__/fetchSongstatsWithBackoff.test.ts new file mode 100644 index 00000000..21015ef1 --- /dev/null +++ b/lib/songstats/__tests__/fetchSongstatsWithBackoff.test.ts @@ -0,0 +1,91 @@ +import { describe, it, expect, vi, beforeEach } from "vitest"; +import { fetchSongstatsWithBackoff } from "../fetchSongstatsWithBackoff"; +import { fetchSongstats } from "../fetchSongstats"; + +vi.mock("../fetchSongstats", () => ({ fetchSongstats: vi.fn() })); + +const noSleep = vi.fn().mockResolvedValue(undefined); + +describe("fetchSongstatsWithBackoff", () => { + beforeEach(() => vi.clearAllMocks()); + + it("returns immediately on 200 with no retries or sleeps", async () => { + vi.mocked(fetchSongstats).mockResolvedValue({ status: 200, data: { ok: true } }); + + const r = await fetchSongstatsWithBackoff( + "tracks/historic_stats", + { isrc: "I" }, + { sleep: noSleep }, + ); + + expect(fetchSongstats).toHaveBeenCalledTimes(1); + expect(noSleep).not.toHaveBeenCalled(); + expect(r).toMatchObject({ status: 200, attempts: 1, retriesExhausted: false }); + }); + + it("does NOT retry a non-retryable status (404)", async () => { + vi.mocked(fetchSongstats).mockResolvedValue({ status: 404, data: {} }); + + const r = await fetchSongstatsWithBackoff("p", undefined, { sleep: noSleep }); + + expect(fetchSongstats).toHaveBeenCalledTimes(1); + expect(r).toMatchObject({ status: 404, retriesExhausted: false }); + }); + + it("backs off and retries on 429, succeeding on a later attempt", async () => { + vi.mocked(fetchSongstats) + .mockResolvedValueOnce({ status: 429, data: {} }) + .mockResolvedValueOnce({ status: 429, data: {} }) + .mockResolvedValueOnce({ status: 200, data: { ok: true } }); + + const r = await fetchSongstatsWithBackoff("p", undefined, { sleep: noSleep, baseMs: 100 }); + + expect(fetchSongstats).toHaveBeenCalledTimes(3); + expect(noSleep).toHaveBeenCalledTimes(2); + // exponential: 100 then 200 + expect(noSleep).toHaveBeenNthCalledWith(1, 100); + expect(noSleep).toHaveBeenNthCalledWith(2, 200); + expect(r).toMatchObject({ status: 200, attempts: 3, retriesExhausted: false }); + }); + + it("gives up after maxRetries on persistent 429 and flags retriesExhausted", async () => { + vi.mocked(fetchSongstats).mockResolvedValue({ status: 429, data: {} }); + + const r = await fetchSongstatsWithBackoff("p", undefined, { sleep: noSleep, maxRetries: 3 }); + + expect(fetchSongstats).toHaveBeenCalledTimes(4); // 1 initial + 3 retries + expect(noSleep).toHaveBeenCalledTimes(3); + expect(r).toMatchObject({ status: 429, retriesExhausted: true }); + }); + + it("treats transient gateway 5xx (503) and 408 as retryable", async () => { + vi.mocked(fetchSongstats) + .mockResolvedValueOnce({ status: 503, data: {} }) + .mockResolvedValueOnce({ status: 200, data: {} }); + const r = await fetchSongstatsWithBackoff("p", undefined, { sleep: noSleep, maxRetries: 2 }); + expect(fetchSongstats).toHaveBeenCalledTimes(2); + expect(r).toMatchObject({ status: 200, retriesExhausted: false }); + }); + + it("does NOT retry a 500 (fetchSongstats maps missing key / fetch failure to 500)", async () => { + vi.mocked(fetchSongstats).mockResolvedValue({ status: 500, data: {} }); + + const r = await fetchSongstatsWithBackoff("p", undefined, { sleep: noSleep }); + + expect(fetchSongstats).toHaveBeenCalledTimes(1); + expect(noSleep).not.toHaveBeenCalled(); + expect(r).toMatchObject({ status: 500, retriesExhausted: false }); + }); + + it("caps the backoff at maxMs", async () => { + vi.mocked(fetchSongstats).mockResolvedValue({ status: 429, data: {} }); + await fetchSongstatsWithBackoff("p", undefined, { + sleep: noSleep, + baseMs: 1000, + maxMs: 1500, + maxRetries: 3, + }); + // 1000, 2000->capped 1500, 4000->capped 1500 + expect(noSleep.mock.calls.map(c => c[0])).toEqual([1000, 1500, 1500]); + }); +}); diff --git a/lib/songstats/__tests__/isRetryableStatus.test.ts b/lib/songstats/__tests__/isRetryableStatus.test.ts new file mode 100644 index 00000000..a1b707f0 --- /dev/null +++ b/lib/songstats/__tests__/isRetryableStatus.test.ts @@ -0,0 +1,26 @@ +import { describe, it, expect } from "vitest"; +import { isRetryableStatus } from "../isRetryableStatus"; + +describe("isRetryableStatus", () => { + it("retries transient throttling/timeouts: 408, 429", () => { + expect(isRetryableStatus(408)).toBe(true); + expect(isRetryableStatus(429)).toBe(true); + }); + + it("retries transient gateway 5xx: 502, 503, 504", () => { + expect(isRetryableStatus(502)).toBe(true); + expect(isRetryableStatus(503)).toBe(true); + expect(isRetryableStatus(504)).toBe(true); + }); + + it("does NOT retry 500/501 (fetchSongstats maps missing key + fetch failures to 500)", () => { + expect(isRetryableStatus(500)).toBe(false); + expect(isRetryableStatus(501)).toBe(false); + }); + + it("does NOT retry definitive responses: 200, 404, 403", () => { + expect(isRetryableStatus(200)).toBe(false); + expect(isRetryableStatus(404)).toBe(false); + expect(isRetryableStatus(403)).toBe(false); + }); +}); diff --git a/lib/songstats/fetchSongstatsWithBackoff.ts b/lib/songstats/fetchSongstatsWithBackoff.ts new file mode 100644 index 00000000..8b3a4b09 --- /dev/null +++ b/lib/songstats/fetchSongstatsWithBackoff.ts @@ -0,0 +1,61 @@ +import { fetchSongstats } from "@/lib/songstats/fetchSongstats"; +import { isRetryableStatus } from "@/lib/songstats/isRetryableStatus"; +import { delay } from "@/lib/time/delay"; +import type { ProxyResult } from "@/lib/research/ProxyResult"; + +// Short, in-step backoff for Songstats' per-second rate limit. The default +// budget is 1+2+4+8 = 15s of waits (base 1s, doubling, capped at 8s, 4 retries), +// well within a workflow step's duration. Persistent rejection defers the row to +// the next drain run rather than sleeping for minutes inside one invocation. +const DEFAULT_MAX_RETRIES = 4; +const DEFAULT_BASE_MS = 1000; +const DEFAULT_MAX_MS = 8_000; + +export type FetchSongstatsBackoffOptions = { + maxRetries?: number; + baseMs?: number; + maxMs?: number; + /** Injectable for tests; defaults to a real timer. */ + sleep?: (ms: number) => Promise; +}; + +export type BackoffResult = ProxyResult & { + /** Total attempts made (1 + retries). */ + attempts: number; + /** True when the final result is still retryable after exhausting retries. */ + retriesExhausted: boolean; +}; + +/** + * Call Songstats with bounded exponential backoff on transient rejections + * (429 rate limit, 408, 5xx). Retries the **same** request up to `maxRetries` + * with `min(maxMs, baseMs * 2^attempt)` waits; a 200 or any non-retryable status + * (e.g. 404) returns immediately. When backoff is exhausted and the call is + * still being rejected, `retriesExhausted` is true so the caller can defer the + * work (leave it `pending`) rather than burn it — Songstats is the rate + * authority, not a local quota ledger. + * + * @param path - Songstats enterprise path (e.g. `tracks/historic_stats`). + * @param queryParams - Query params forwarded to Songstats. + * @param options - Backoff tuning + an injectable `sleep`. + */ +export async function fetchSongstatsWithBackoff( + path: string, + queryParams?: Record, + options: FetchSongstatsBackoffOptions = {}, +): Promise { + const maxRetries = options.maxRetries ?? DEFAULT_MAX_RETRIES; + const baseMs = options.baseMs ?? DEFAULT_BASE_MS; + const maxMs = options.maxMs ?? DEFAULT_MAX_MS; + const sleep = options.sleep ?? delay; + + let result = await fetchSongstats(path, queryParams); + let retries = 0; + while (isRetryableStatus(result.status) && retries < maxRetries) { + await sleep(Math.min(maxMs, baseMs * 2 ** retries)); + result = await fetchSongstats(path, queryParams); + retries += 1; + } + + return { ...result, attempts: retries + 1, retriesExhausted: isRetryableStatus(result.status) }; +} diff --git a/lib/songstats/isRetryableStatus.ts b/lib/songstats/isRetryableStatus.ts new file mode 100644 index 00000000..eb0004ee --- /dev/null +++ b/lib/songstats/isRetryableStatus.ts @@ -0,0 +1,14 @@ +/** + * Whether a Songstats response status is worth retrying with backoff. + * + * Transient: 408 (request timeout), 429 (rate limit), and the gateway 5xx + * 502/503/504 (bad gateway / unavailable / gateway timeout). Deliberately + * **excludes** 500/501 — `fetchSongstats` maps a missing API key and any + * non-HTTP fetch failure to 500, which are permanent for that request, so + * retrying them just burns the backoff budget before the row defers. + * + * @param status - HTTP status from `fetchSongstats`. + */ +export function isRetryableStatus(status: number): boolean { + return status === 408 || status === 429 || status === 502 || status === 503 || status === 504; +} diff --git a/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts b/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts index eb8d0230..73be7347 100644 --- a/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts +++ b/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts @@ -14,24 +14,40 @@ vi.mock("../../serverClient", () => { describe("updateSongstatsBackfillQueue", () => { beforeEach(() => vi.clearAllMocks()); - it("updates a queue row's status by id", async () => { - const eq = vi.fn().mockResolvedValue({ error: null }); - const update = vi.fn().mockReturnValue({ eq }); + it("updates a single row by id (one-element array)", async () => { + const inFn = vi.fn().mockResolvedValue({ error: null }); + const update = vi.fn().mockReturnValue({ in: inFn }); vi.mocked(supabase.from).mockReturnValue({ update } as never); - await updateSongstatsBackfillQueue("q1", { status: "done" }); + await updateSongstatsBackfillQueue(["q1"], { status: "done" }); expect(supabase.from).toHaveBeenCalledWith("songstats_backfill_queue"); expect(update).toHaveBeenCalledWith({ status: "done" }); - expect(eq).toHaveBeenCalledWith("id", "q1"); + expect(inFn).toHaveBeenCalledWith("id", ["q1"]); + }); + + it("bulk-updates many rows in one call (e.g. releasing a claimed batch)", async () => { + const inFn = vi.fn().mockResolvedValue({ error: null }); + const update = vi.fn().mockReturnValue({ in: inFn }); + vi.mocked(supabase.from).mockReturnValue({ update } as never); + + await updateSongstatsBackfillQueue(["q1", "q2"], { status: "pending" }); + + expect(update).toHaveBeenCalledWith({ status: "pending" }); + expect(inFn).toHaveBeenCalledWith("id", ["q1", "q2"]); + }); + + it("is a no-op on an empty id list (no DB call)", async () => { + await updateSongstatsBackfillQueue([], { status: "pending" }); + expect(supabase.from).not.toHaveBeenCalled(); }); it("throws on update error", async () => { - const eq = vi.fn().mockResolvedValue({ error: { message: "boom" } }); - const update = vi.fn().mockReturnValue({ eq }); + const inFn = vi.fn().mockResolvedValue({ error: { message: "boom" } }); + const update = vi.fn().mockReturnValue({ in: inFn }); vi.mocked(supabase.from).mockReturnValue({ update } as never); - await expect(updateSongstatsBackfillQueue("q1", { status: "failed" })).rejects.toThrow( + await expect(updateSongstatsBackfillQueue(["q1"], { status: "failed" })).rejects.toThrow( "Failed to update songstats backfill queue: boom", ); }); diff --git a/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue.ts b/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue.ts index b462381a..d2469412 100644 --- a/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue.ts +++ b/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue.ts @@ -2,17 +2,22 @@ import supabase from "../serverClient"; import { TablesUpdate } from "@/types/database.types"; /** - * Update a backfill queue row (mark done/failed after a claim). + * Update one or more backfill queue rows by id in a single round trip. Handles + * both the per-row status flip after a claim (`[row.id]`) and the bulk release + * of a claimed batch back to `pending` when the drain stops early (`.in` works + * for one id or many). No-op on an empty id list. * - * @param id - The queue row id - * @param fields - Fields to update + * @param ids - Queue row ids to update + * @param fields - Fields to set (e.g. `{ status: "done" }`) * @throws Error if the update fails */ export async function updateSongstatsBackfillQueue( - id: string, + ids: string[], fields: TablesUpdate<"songstats_backfill_queue">, ): Promise { - const { error } = await supabase.from("songstats_backfill_queue").update(fields).eq("id", id); + if (ids.length === 0) return; + + const { error } = await supabase.from("songstats_backfill_queue").update(fields).in("id", ids); if (error) { throw new Error(`Failed to update songstats backfill queue: ${error.message}`);