From c250b340e62c4468b600d9ca2d0350ef795b6f45 Mon Sep 17 00:00:00 2001 From: Sweets Sweetman Date: Tue, 16 Jun 2026 14:09:07 -0500 Subject: [PATCH 1/4] fix(songstats-backfill): exponential backoff on 429 + defer instead of churn (chat#1797 #1, #3) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The full-catalog drain hammered Songstats past its per-second rate limit (~79% 429s) and counted every 429 as a quota hit, prematurely capping the drain. Fix the rate-limit handling and add observability: - new fetchSongstatsWithBackoff: bounded exponential backoff on 429/408/5xx (retries the same request, ~15s cap, well within a step's duration), flags retriesExhausted when still rejected. - backfillTrackStep: 200 -> write/done/hit; 404/4xx -> done/hit (terminal); backoff exhausted -> DEFER (leave `pending`, record NO quota hit) so the next drain retries — Songstats is the rate authority, no phantom 429 spend. - songstatsBackfillWorkflow: stop the run on the first deferral (Songstats saturated; rest stay pending) instead of churning failed->reclaim->429. - per-step + per-batch logging (chat#1797 #3) so a drain is traceable in Vercel. 11 new/updated unit tests; workflows+songstats+research suite 317 green; tsc/lint clean. --- .../__tests__/backfillTrackStep.test.ts | 97 ++++++++----------- app/workflows/backfillTrackStep.ts | 56 ++++++----- app/workflows/songstatsBackfillWorkflow.ts | 28 ++++-- .../fetchSongstatsWithBackoff.test.ts | 81 ++++++++++++++++ lib/songstats/fetchSongstatsWithBackoff.ts | 63 ++++++++++++ 5 files changed, 235 insertions(+), 90 deletions(-) create mode 100644 lib/songstats/__tests__/fetchSongstatsWithBackoff.test.ts create mode 100644 lib/songstats/fetchSongstatsWithBackoff.ts diff --git a/app/workflows/__tests__/backfillTrackStep.test.ts b/app/workflows/__tests__/backfillTrackStep.test.ts index ebe77370..a26fc6e8 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,30 +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", }); - expect(upsertSongMeasurements).toHaveBeenCalledWith([ - { - song: "USA2P2015959", - platform: "spotify", - metric: "platform_displayed_play_count", - value: 1008736324, - captured_at: "2025-01-01T00:00:00.000Z", - 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(upsertSongMeasurements).toHaveBeenCalled(); expect(insertSongstatsQuotaLedger).toHaveBeenCalledWith({ hits: 1, purpose: "backfill USA2P2015959", @@ -77,56 +58,56 @@ describe("backfillTrackStep", () => { 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(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(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/backfillTrackStep.ts b/app/workflows/backfillTrackStep.ts index 3247ff4c..1e4c1c48 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,47 @@ 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) { + // Rate-limited past the backoff bound — leave it for the next run, spend nothing. + console.log( + `[backfill] ${row.song} deferred (rate-limited ${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,6 +74,7 @@ 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" }); return { ok: true, hitsSpent: 1 }; diff --git a/app/workflows/songstatsBackfillWorkflow.ts b/app/workflows/songstatsBackfillWorkflow.ts index 0a1960bf..67c1a6e4 100644 --- a/app/workflows/songstatsBackfillWorkflow.ts +++ b/app/workflows/songstatsBackfillWorkflow.ts @@ -5,11 +5,13 @@ import { backfillTrackStep } from "@/app/workflows/backfillTrackStep"; 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 — leaving the rest `pending` for the + * next drain 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 +19,20 @@ 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); + if (result.deferred) { + // Songstats is saturated — stop now; remaining claimed rows stay pending. + deferred = true; + break drain; + } budget -= result.hitsSpent; if (result.ok) backfilled += 1; else failed += 1; @@ -31,6 +40,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..1dda52b4 --- /dev/null +++ b/lib/songstats/__tests__/fetchSongstatsWithBackoff.test.ts @@ -0,0 +1,81 @@ +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 5xx and 408 as retryable too", 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("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/fetchSongstatsWithBackoff.ts b/lib/songstats/fetchSongstatsWithBackoff.ts new file mode 100644 index 00000000..0110469d --- /dev/null +++ b/lib/songstats/fetchSongstatsWithBackoff.ts @@ -0,0 +1,63 @@ +import { fetchSongstats } from "@/lib/songstats/fetchSongstats"; +import type { ProxyResult } from "@/lib/research/ProxyResult"; + +// Short, in-step backoff for Songstats' per-second rate limit (total ~15s, 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 = 5; +const DEFAULT_BASE_MS = 1000; +const DEFAULT_MAX_MS = 8_000; + +/** Transient statuses worth retrying: 408 timeout, 429 rate limit, any 5xx. */ +const isRetryable = (status: number) => status === 408 || status === 429 || status >= 500; + +const realSleep = (ms: number) => new Promise(resolve => setTimeout(resolve, ms)); + +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 ?? realSleep; + + let result = await fetchSongstats(path, queryParams); + let retries = 0; + while (isRetryable(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: isRetryable(result.status) }; +} From f6eed906e39f74b53b9d7f7859382bcb3695b4f5 Mon Sep 17 00:00:00 2001 From: Sweets Sweetman Date: Tue, 16 Jun 2026 16:21:02 -0500 Subject: [PATCH 2/4] =?UTF-8?q?refactor(songstats):=20address=20PR=20#673?= =?UTF-8?q?=20review=20=E2=80=94=20SRP,=20retry=20scope,=20strand=20fix?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - SRP (sweetman): extract isRetryable → lib/songstats/isRetryableStatus.ts; reuse the existing lib/time/delay.ts instead of an inline realSleep. - Narrow retryable 5xx to transient gateway codes 502/503/504 (fetchSongstats maps a missing key / fetch failure to 500 → permanent, don't retry). - Fix deferred-break stranding the rest of the claimed batch in `in_progress`: releaseClaimedRowsStep returns the unprocessed remainder to `pending` so the next drain retries them instead of waiting on the 1h stale-reclaim. - Tighten the default backoff budget to the documented ~15s (4 retries: 1+2+4+8). - Deferred log says "retryable" not "rate-limited" (covers 408/5xx defers). - Restore the exact upsert-payload assertion in the 200 test; add tests for isRetryableStatus, releaseSongstatsBackfillRows, and the workflow strand-release. Co-Authored-By: Claude Opus 4.8 (1M context) --- .../__tests__/backfillTrackStep.test.ts | 13 +++- .../songstatsBackfillWorkflow.test.ts | 61 +++++++++++++++++++ app/workflows/backfillTrackStep.ts | 5 +- app/workflows/releaseClaimedRowsStep.ts | 15 +++++ app/workflows/songstatsBackfillWorkflow.ts | 18 ++++-- .../fetchSongstatsWithBackoff.test.ts | 12 +++- .../__tests__/isRetryableStatus.test.ts | 26 ++++++++ lib/songstats/fetchSongstatsWithBackoff.ts | 22 +++---- lib/songstats/isRetryableStatus.ts | 14 +++++ .../releaseSongstatsBackfillRows.test.ts | 39 ++++++++++++ .../releaseSongstatsBackfillRows.ts | 26 ++++++++ 11 files changed, 229 insertions(+), 22 deletions(-) create mode 100644 app/workflows/__tests__/songstatsBackfillWorkflow.test.ts create mode 100644 app/workflows/releaseClaimedRowsStep.ts create mode 100644 lib/songstats/__tests__/isRetryableStatus.test.ts create mode 100644 lib/songstats/isRetryableStatus.ts create mode 100644 lib/supabase/songstats_backfill_queue/__tests__/releaseSongstatsBackfillRows.test.ts create mode 100644 lib/supabase/songstats_backfill_queue/releaseSongstatsBackfillRows.ts diff --git a/app/workflows/__tests__/backfillTrackStep.test.ts b/app/workflows/__tests__/backfillTrackStep.test.ts index a26fc6e8..12931350 100644 --- a/app/workflows/__tests__/backfillTrackStep.test.ts +++ b/app/workflows/__tests__/backfillTrackStep.test.ts @@ -49,7 +49,18 @@ describe("backfillTrackStep", () => { isrc: "USA2P2015959", source: "spotify", }); - expect(upsertSongMeasurements).toHaveBeenCalled(); + // exact transformation: each history point → a permanent songstats measurement + expect(upsertSongMeasurements).toHaveBeenCalledWith([ + { + song: "USA2P2015959", + platform: "spotify", + metric: "platform_displayed_play_count", + value: 1008736324, + captured_at: "2025-01-01T00:00:00.000Z", + data_source: "songstats", + raw_ref: "songstats-backfill", + }, + ]); expect(insertSongstatsQuotaLedger).toHaveBeenCalledWith({ hits: 1, purpose: "backfill USA2P2015959", 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 1e4c1c48..b5b8c272 100644 --- a/app/workflows/backfillTrackStep.ts +++ b/app/workflows/backfillTrackStep.ts @@ -31,9 +31,10 @@ export async function backfillTrackStep( }); if (result.retriesExhausted) { - // Rate-limited past the backoff bound — leave it for the next run, spend nothing. + // 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 (rate-limited ${result.status} after ${result.attempts} tries)`, + `[backfill] ${row.song} deferred (retryable ${result.status} after ${result.attempts} tries)`, ); await updateSongstatsBackfillQueue(row.id, { status: "pending" }); return { ok: false, hitsSpent: 0, deferred: true }; diff --git a/app/workflows/releaseClaimedRowsStep.ts b/app/workflows/releaseClaimedRowsStep.ts new file mode 100644 index 00000000..39c6a55f --- /dev/null +++ b/app/workflows/releaseClaimedRowsStep.ts @@ -0,0 +1,15 @@ +import { releaseSongstatsBackfillRows } from "@/lib/supabase/songstats_backfill_queue/releaseSongstatsBackfillRows"; + +/** + * 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 releaseSongstatsBackfillRows(ids); + 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 67c1a6e4..f94c0223 100644 --- a/app/workflows/songstatsBackfillWorkflow.ts +++ b/app/workflows/songstatsBackfillWorkflow.ts @@ -1,6 +1,7 @@ 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; @@ -9,9 +10,11 @@ const BATCH_SIZE = 25; * 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 — leaving the rest `pending` for the - * next drain instead of hammering a saturated API. Every successful hit converts - * into permanent owned data (fetch-once: captured history is never refetched). + * 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"; @@ -26,11 +29,14 @@ export async function songstatsBackfillWorkflow() { 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; remaining claimed rows stay pending. + // 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; diff --git a/lib/songstats/__tests__/fetchSongstatsWithBackoff.test.ts b/lib/songstats/__tests__/fetchSongstatsWithBackoff.test.ts index 1dda52b4..21015ef1 100644 --- a/lib/songstats/__tests__/fetchSongstatsWithBackoff.test.ts +++ b/lib/songstats/__tests__/fetchSongstatsWithBackoff.test.ts @@ -58,7 +58,7 @@ describe("fetchSongstatsWithBackoff", () => { expect(r).toMatchObject({ status: 429, retriesExhausted: true }); }); - it("treats 5xx and 408 as retryable too", async () => { + it("treats transient gateway 5xx (503) and 408 as retryable", async () => { vi.mocked(fetchSongstats) .mockResolvedValueOnce({ status: 503, data: {} }) .mockResolvedValueOnce({ status: 200, data: {} }); @@ -67,6 +67,16 @@ describe("fetchSongstatsWithBackoff", () => { 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, { 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 index 0110469d..8b3a4b09 100644 --- a/lib/songstats/fetchSongstatsWithBackoff.ts +++ b/lib/songstats/fetchSongstatsWithBackoff.ts @@ -1,18 +1,16 @@ 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 (total ~15s, 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 = 5; +// 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; -/** Transient statuses worth retrying: 408 timeout, 429 rate limit, any 5xx. */ -const isRetryable = (status: number) => status === 408 || status === 429 || status >= 500; - -const realSleep = (ms: number) => new Promise(resolve => setTimeout(resolve, ms)); - export type FetchSongstatsBackoffOptions = { maxRetries?: number; baseMs?: number; @@ -49,15 +47,15 @@ export async function fetchSongstatsWithBackoff( 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 ?? realSleep; + const sleep = options.sleep ?? delay; let result = await fetchSongstats(path, queryParams); let retries = 0; - while (isRetryable(result.status) && retries < maxRetries) { + 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: isRetryable(result.status) }; + 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__/releaseSongstatsBackfillRows.test.ts b/lib/supabase/songstats_backfill_queue/__tests__/releaseSongstatsBackfillRows.test.ts new file mode 100644 index 00000000..f03f7cf4 --- /dev/null +++ b/lib/supabase/songstats_backfill_queue/__tests__/releaseSongstatsBackfillRows.test.ts @@ -0,0 +1,39 @@ +import { describe, it, expect, vi, beforeEach } from "vitest"; +import { releaseSongstatsBackfillRows } from "../releaseSongstatsBackfillRows"; +import supabase from "../../serverClient"; + +vi.mock("../../serverClient", () => { + const mockFrom = vi.fn(); + return { default: { from: mockFrom } }; +}); + +describe("releaseSongstatsBackfillRows", () => { + beforeEach(() => vi.clearAllMocks()); + + it("resets the given ids to pending in one update", async () => { + const inFn = vi.fn().mockResolvedValue({ error: null }); + const update = vi.fn().mockReturnValue({ in: inFn }); + vi.mocked(supabase.from).mockReturnValue({ update } as never); + + await releaseSongstatsBackfillRows(["q1", "q2"]); + + expect(supabase.from).toHaveBeenCalledWith("songstats_backfill_queue"); + expect(update).toHaveBeenCalledWith({ status: "pending" }); + expect(inFn).toHaveBeenCalledWith("id", ["q1", "q2"]); + }); + + it("is a no-op on an empty list (no DB call)", async () => { + await releaseSongstatsBackfillRows([]); + expect(supabase.from).not.toHaveBeenCalled(); + }); + + it("throws on update error", async () => { + 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(releaseSongstatsBackfillRows(["q1"])).rejects.toThrow( + "Failed to release songstats backfill rows: boom", + ); + }); +}); diff --git a/lib/supabase/songstats_backfill_queue/releaseSongstatsBackfillRows.ts b/lib/supabase/songstats_backfill_queue/releaseSongstatsBackfillRows.ts new file mode 100644 index 00000000..0bb5a4b4 --- /dev/null +++ b/lib/supabase/songstats_backfill_queue/releaseSongstatsBackfillRows.ts @@ -0,0 +1,26 @@ +import supabase from "../serverClient"; + +/** + * Return a set of claimed (`in_progress`) backfill rows to `pending` in one + * round trip. Used when the drain stops early (a track deferred under sustained + * rate-limiting): the rest of the already-claimed batch must go back to + * `pending` so the next drain retries them immediately, instead of sitting + * `in_progress` until the 1-hour stale-reclaim sweep picks them up. + * + * No-op on an empty list. Throws on a DB error so the caller fails loudly. + * + * @param ids - Queue row ids to release back to `pending`. + * @throws Error if the update fails + */ +export async function releaseSongstatsBackfillRows(ids: string[]): Promise { + if (ids.length === 0) return; + + const { error } = await supabase + .from("songstats_backfill_queue") + .update({ status: "pending" }) + .in("id", ids); + + if (error) { + throw new Error(`Failed to release songstats backfill rows: ${error.message}`); + } +} From 805bef49068335744603b4cbdf1b2b071488e134 Mon Sep 17 00:00:00 2001 From: Sweets Sweetman Date: Tue, 16 Jun 2026 16:25:05 -0500 Subject: [PATCH 3/4] refactor(songstats): co-locate releaseSongstatsBackfillRows in updateSongstatsBackfillQueue (PR #673 review) Per review: queue status-mutation helpers live together in updateSongstatsBackfillQueue.ts (alongside updateSongstatsBackfillQueue + reclaimStaleSongstatsBackfillRows), not in a standalone file. Moves the function + its tests there and drops the separate files. Co-Authored-By: Claude Opus 4.8 (1M context) --- app/workflows/releaseClaimedRowsStep.ts | 2 +- .../releaseSongstatsBackfillRows.test.ts | 39 ------------------- .../updateSongstatsBackfillQueue.test.ts | 32 +++++++++++++++ .../releaseSongstatsBackfillRows.ts | 26 ------------- .../updateSongstatsBackfillQueue.ts | 23 +++++++++++ 5 files changed, 56 insertions(+), 66 deletions(-) delete mode 100644 lib/supabase/songstats_backfill_queue/__tests__/releaseSongstatsBackfillRows.test.ts delete mode 100644 lib/supabase/songstats_backfill_queue/releaseSongstatsBackfillRows.ts diff --git a/app/workflows/releaseClaimedRowsStep.ts b/app/workflows/releaseClaimedRowsStep.ts index 39c6a55f..b22f581e 100644 --- a/app/workflows/releaseClaimedRowsStep.ts +++ b/app/workflows/releaseClaimedRowsStep.ts @@ -1,4 +1,4 @@ -import { releaseSongstatsBackfillRows } from "@/lib/supabase/songstats_backfill_queue/releaseSongstatsBackfillRows"; +import { releaseSongstatsBackfillRows } from "@/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue"; /** * Durable step: return unprocessed claimed rows to `pending` when the drain diff --git a/lib/supabase/songstats_backfill_queue/__tests__/releaseSongstatsBackfillRows.test.ts b/lib/supabase/songstats_backfill_queue/__tests__/releaseSongstatsBackfillRows.test.ts deleted file mode 100644 index f03f7cf4..00000000 --- a/lib/supabase/songstats_backfill_queue/__tests__/releaseSongstatsBackfillRows.test.ts +++ /dev/null @@ -1,39 +0,0 @@ -import { describe, it, expect, vi, beforeEach } from "vitest"; -import { releaseSongstatsBackfillRows } from "../releaseSongstatsBackfillRows"; -import supabase from "../../serverClient"; - -vi.mock("../../serverClient", () => { - const mockFrom = vi.fn(); - return { default: { from: mockFrom } }; -}); - -describe("releaseSongstatsBackfillRows", () => { - beforeEach(() => vi.clearAllMocks()); - - it("resets the given ids to pending in one update", async () => { - const inFn = vi.fn().mockResolvedValue({ error: null }); - const update = vi.fn().mockReturnValue({ in: inFn }); - vi.mocked(supabase.from).mockReturnValue({ update } as never); - - await releaseSongstatsBackfillRows(["q1", "q2"]); - - expect(supabase.from).toHaveBeenCalledWith("songstats_backfill_queue"); - expect(update).toHaveBeenCalledWith({ status: "pending" }); - expect(inFn).toHaveBeenCalledWith("id", ["q1", "q2"]); - }); - - it("is a no-op on an empty list (no DB call)", async () => { - await releaseSongstatsBackfillRows([]); - expect(supabase.from).not.toHaveBeenCalled(); - }); - - it("throws on update error", async () => { - 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(releaseSongstatsBackfillRows(["q1"])).rejects.toThrow( - "Failed to release songstats backfill rows: boom", - ); - }); -}); diff --git a/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts b/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts index eb8d0230..667d0e11 100644 --- a/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts +++ b/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts @@ -2,6 +2,7 @@ import { describe, it, expect, vi, beforeEach } from "vitest"; import { updateSongstatsBackfillQueue, reclaimStaleSongstatsBackfillRows, + releaseSongstatsBackfillRows, } from "../updateSongstatsBackfillQueue"; import supabase from "../../serverClient"; @@ -67,3 +68,34 @@ describe("reclaimStaleSongstatsBackfillRows", () => { ); }); }); + +describe("releaseSongstatsBackfillRows", () => { + beforeEach(() => vi.clearAllMocks()); + + it("resets the given ids to pending in one update", async () => { + const inFn = vi.fn().mockResolvedValue({ error: null }); + const update = vi.fn().mockReturnValue({ in: inFn }); + vi.mocked(supabase.from).mockReturnValue({ update } as never); + + await releaseSongstatsBackfillRows(["q1", "q2"]); + + expect(supabase.from).toHaveBeenCalledWith("songstats_backfill_queue"); + expect(update).toHaveBeenCalledWith({ status: "pending" }); + expect(inFn).toHaveBeenCalledWith("id", ["q1", "q2"]); + }); + + it("is a no-op on an empty list (no DB call)", async () => { + await releaseSongstatsBackfillRows([]); + expect(supabase.from).not.toHaveBeenCalled(); + }); + + it("throws on update error", async () => { + 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(releaseSongstatsBackfillRows(["q1"])).rejects.toThrow( + "Failed to release songstats backfill rows: boom", + ); + }); +}); diff --git a/lib/supabase/songstats_backfill_queue/releaseSongstatsBackfillRows.ts b/lib/supabase/songstats_backfill_queue/releaseSongstatsBackfillRows.ts deleted file mode 100644 index 0bb5a4b4..00000000 --- a/lib/supabase/songstats_backfill_queue/releaseSongstatsBackfillRows.ts +++ /dev/null @@ -1,26 +0,0 @@ -import supabase from "../serverClient"; - -/** - * Return a set of claimed (`in_progress`) backfill rows to `pending` in one - * round trip. Used when the drain stops early (a track deferred under sustained - * rate-limiting): the rest of the already-claimed batch must go back to - * `pending` so the next drain retries them immediately, instead of sitting - * `in_progress` until the 1-hour stale-reclaim sweep picks them up. - * - * No-op on an empty list. Throws on a DB error so the caller fails loudly. - * - * @param ids - Queue row ids to release back to `pending`. - * @throws Error if the update fails - */ -export async function releaseSongstatsBackfillRows(ids: string[]): Promise { - if (ids.length === 0) return; - - const { error } = await supabase - .from("songstats_backfill_queue") - .update({ status: "pending" }) - .in("id", ids); - - if (error) { - throw new Error(`Failed to release songstats backfill rows: ${error.message}`); - } -} diff --git a/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue.ts b/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue.ts index b462381a..f5154045 100644 --- a/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue.ts +++ b/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue.ts @@ -48,3 +48,26 @@ export async function reclaimStaleSongstatsBackfillRows(): Promise { return data?.length ?? 0; } + +/** + * Return a set of claimed (`in_progress`) rows to `pending` in one round trip. + * Used when the drain stops early (a track deferred under sustained + * rate-limiting): the rest of the already-claimed batch goes back to `pending` + * so the next drain retries them immediately, instead of sitting `in_progress` + * until the 1-hour stale-reclaim sweep. No-op on an empty list. + * + * @param ids - Queue row ids to release back to `pending`. + * @throws Error if the update fails + */ +export async function releaseSongstatsBackfillRows(ids: string[]): Promise { + if (ids.length === 0) return; + + const { error } = await supabase + .from("songstats_backfill_queue") + .update({ status: "pending" }) + .in("id", ids); + + if (error) { + throw new Error(`Failed to release songstats backfill rows: ${error.message}`); + } +} From e9a1b05a167e2df2b2283a1fce3c4db5b6f13510 Mon Sep 17 00:00:00 2001 From: Sweets Sweetman Date: Tue, 16 Jun 2026 16:34:28 -0500 Subject: [PATCH 4/4] =?UTF-8?q?refactor(songstats):=20KISS=20=E2=80=94=20o?= =?UTF-8?q?ne=20updateSongstatsBackfillQueue(ids[],=20fields)=20for=20sing?= =?UTF-8?q?le=20+=20bulk=20(PR=20#673=20review)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Per review: collapse the separate bulk helper into updateSongstatsBackfillQueue by taking an id array and using .in("id", ids) (works for one id or many). The deferred-batch release now calls updateSongstatsBackfillQueue(ids, {status: "pending"}); per-row callers pass [row.id]. No-op on an empty list. Co-Authored-By: Claude Opus 4.8 (1M context) --- .../__tests__/backfillTrackStep.test.ts | 8 +-- app/workflows/backfillTrackStep.ts | 6 +- app/workflows/releaseClaimedRowsStep.ts | 4 +- .../updateSongstatsBackfillQueue.test.ts | 64 +++++++------------ .../updateSongstatsBackfillQueue.ts | 38 +++-------- 5 files changed, 43 insertions(+), 77 deletions(-) diff --git a/app/workflows/__tests__/backfillTrackStep.test.ts b/app/workflows/__tests__/backfillTrackStep.test.ts index 12931350..6c211ed6 100644 --- a/app/workflows/__tests__/backfillTrackStep.test.ts +++ b/app/workflows/__tests__/backfillTrackStep.test.ts @@ -65,7 +65,7 @@ describe("backfillTrackStep", () => { hits: 1, purpose: "backfill USA2P2015959", }); - expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith("q1", { status: "done" }); + expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith(["q1"], { status: "done" }); expect(result).toEqual({ ok: true, hitsSpent: 1 }); }); @@ -80,7 +80,7 @@ describe("backfillTrackStep", () => { const result = await backfillTrackStep(ROW); // left pending for the next drain; NO ledger hit (Songstats consumed nothing) - expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith("q1", { status: "pending" }); + expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith(["q1"], { status: "pending" }); expect(insertSongstatsQuotaLedger).not.toHaveBeenCalled(); expect(upsertSongMeasurements).not.toHaveBeenCalled(); expect(result).toEqual({ ok: false, hitsSpent: 0, deferred: true }); @@ -96,7 +96,7 @@ describe("backfillTrackStep", () => { const result = await backfillTrackStep(ROW); - expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith("q1", { status: "done" }); + expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith(["q1"], { status: "done" }); expect(insertSongstatsQuotaLedger).toHaveBeenCalledWith({ hits: 1, purpose: "backfill USA2P2015959 (no data 404)", @@ -114,7 +114,7 @@ describe("backfillTrackStep", () => { const result = await backfillTrackStep(ROW); - expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith("q1", { status: "done" }); + expect(updateSongstatsBackfillQueue).toHaveBeenCalledWith(["q1"], { status: "done" }); expect(insertSongstatsQuotaLedger).toHaveBeenCalledWith({ hits: 1, purpose: "backfill USA2P2015959 (terminal 403)", diff --git a/app/workflows/backfillTrackStep.ts b/app/workflows/backfillTrackStep.ts index b5b8c272..fd394743 100644 --- a/app/workflows/backfillTrackStep.ts +++ b/app/workflows/backfillTrackStep.ts @@ -36,7 +36,7 @@ export async function backfillTrackStep( console.log( `[backfill] ${row.song} deferred (retryable ${result.status} after ${result.attempts} tries)`, ); - await updateSongstatsBackfillQueue(row.id, { status: "pending" }); + await updateSongstatsBackfillQueue([row.id], { status: "pending" }); return { ok: false, hitsSpent: 0, deferred: true }; } @@ -49,7 +49,7 @@ export async function backfillTrackStep( hits: 1, purpose: `backfill ${row.song} (${noData ? "no data 404" : `terminal ${result.status}`})`, }); - await updateSongstatsBackfillQueue(row.id, { status: "done" }); + await updateSongstatsBackfillQueue([row.id], { status: "done" }); return { ok: false, hitsSpent: 1 }; } @@ -77,6 +77,6 @@ export async function backfillTrackStep( 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 index b22f581e..788d752a 100644 --- a/app/workflows/releaseClaimedRowsStep.ts +++ b/app/workflows/releaseClaimedRowsStep.ts @@ -1,4 +1,4 @@ -import { releaseSongstatsBackfillRows } from "@/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue"; +import { updateSongstatsBackfillQueue } from "@/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue"; /** * Durable step: return unprocessed claimed rows to `pending` when the drain @@ -10,6 +10,6 @@ import { releaseSongstatsBackfillRows } from "@/lib/supabase/songstats_backfill_ export async function releaseClaimedRowsStep(ids: string[]): Promise { "use step"; if (ids.length === 0) return; - await releaseSongstatsBackfillRows(ids); + await updateSongstatsBackfillQueue(ids, { status: "pending" }); console.log(`[songstats-backfill] released ${ids.length} claimed rows back to pending`); } diff --git a/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts b/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts index 667d0e11..73be7347 100644 --- a/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts +++ b/lib/supabase/songstats_backfill_queue/__tests__/updateSongstatsBackfillQueue.test.ts @@ -2,7 +2,6 @@ import { describe, it, expect, vi, beforeEach } from "vitest"; import { updateSongstatsBackfillQueue, reclaimStaleSongstatsBackfillRows, - releaseSongstatsBackfillRows, } from "../updateSongstatsBackfillQueue"; import supabase from "../../serverClient"; @@ -15,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", ); }); @@ -68,34 +83,3 @@ describe("reclaimStaleSongstatsBackfillRows", () => { ); }); }); - -describe("releaseSongstatsBackfillRows", () => { - beforeEach(() => vi.clearAllMocks()); - - it("resets the given ids to pending in one update", async () => { - const inFn = vi.fn().mockResolvedValue({ error: null }); - const update = vi.fn().mockReturnValue({ in: inFn }); - vi.mocked(supabase.from).mockReturnValue({ update } as never); - - await releaseSongstatsBackfillRows(["q1", "q2"]); - - expect(supabase.from).toHaveBeenCalledWith("songstats_backfill_queue"); - expect(update).toHaveBeenCalledWith({ status: "pending" }); - expect(inFn).toHaveBeenCalledWith("id", ["q1", "q2"]); - }); - - it("is a no-op on an empty list (no DB call)", async () => { - await releaseSongstatsBackfillRows([]); - expect(supabase.from).not.toHaveBeenCalled(); - }); - - it("throws on update error", async () => { - 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(releaseSongstatsBackfillRows(["q1"])).rejects.toThrow( - "Failed to release songstats backfill rows: boom", - ); - }); -}); diff --git a/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue.ts b/lib/supabase/songstats_backfill_queue/updateSongstatsBackfillQueue.ts index f5154045..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}`); @@ -48,26 +53,3 @@ export async function reclaimStaleSongstatsBackfillRows(): Promise { return data?.length ?? 0; } - -/** - * Return a set of claimed (`in_progress`) rows to `pending` in one round trip. - * Used when the drain stops early (a track deferred under sustained - * rate-limiting): the rest of the already-claimed batch goes back to `pending` - * so the next drain retries them immediately, instead of sitting `in_progress` - * until the 1-hour stale-reclaim sweep. No-op on an empty list. - * - * @param ids - Queue row ids to release back to `pending`. - * @throws Error if the update fails - */ -export async function releaseSongstatsBackfillRows(ids: string[]): Promise { - if (ids.length === 0) return; - - const { error } = await supabase - .from("songstats_backfill_queue") - .update({ status: "pending" }) - .in("id", ids); - - if (error) { - throw new Error(`Failed to release songstats backfill rows: ${error.message}`); - } -}