diff --git a/docs/api/openapi.yaml b/docs/api/openapi.yaml index ea03883bf..138854254 100644 --- a/docs/api/openapi.yaml +++ b/docs/api/openapi.yaml @@ -89724,6 +89724,17 @@ components: anyOf: - $ref: "#/components/schemas/AdminBackupRestoreFailure" - type: "null" + waiting: + anyOf: + - type: string + enum: + - backup + - busy + - type: "null" + description: "Why a `queued` job has not started. A restore never runs beside a backup or another large job: while one + holds the server it goes back to the queue for a minute at a time. `backup` when a backup pass holds it, + `busy` for anything else (an import, a nightly pass, the memory guard). Null while the job only waits for + the worker, and on every job that is not queued." attempts: type: integer minimum: -9007199254740991 @@ -89749,6 +89760,7 @@ components: - progress - result - failure + - waiting - attempts - createdAt - startedAt diff --git a/messages/de.json b/messages/de.json index 77d4a8f41..69916f438 100644 --- a/messages/de.json +++ b/messages/de.json @@ -8264,6 +8264,9 @@ "restoreActive": "Für dieses Konto läuft schon eine Wiederherstellung. Warte, bis sie fertig ist.", "restoreJobQueuedTitle": "Wiederherstellung von {username} wartet auf den Start", "restoreJobQueuedNote": "Sie beginnt, sobald der Hintergrunddienst sie übernimmt.", + "restoreJobWaitingBackupNote": "Wartet auf das Backup, das gerade auf dem Server läuft. Eine Wiederherstellung läuft nie neben einem Backup und startet etwa eine Minute nach dessen Ende.", + "restoreJobWaitingBusyNote": "Wartet, bis eine große Aufgabe auf dem Server fertig ist, etwa ein Import oder ein nächtlicher Durchlauf. Sie startet etwa eine Minute danach.", + "restoreJobQueuedSince": "In der Warteschlange seit {when}.", "restoreJobRunningTitle": "{username} wird wiederhergestellt", "restoreJobRunningNote": "Das Konto zeigt seine bisherigen Daten, bis die Wiederherstellung fertig ist. Du kannst die Seite verlassen; die Wiederherstellung läuft auf dem Server weiter.", "restoreJobResumed": "Nach einem Neustart des Servers erneut gestartet.", diff --git a/messages/en.json b/messages/en.json index 4353cf62c..4d70f02d0 100644 --- a/messages/en.json +++ b/messages/en.json @@ -8264,6 +8264,9 @@ "restoreActive": "A restore of this account is already running. Wait for it to finish.", "restoreJobQueuedTitle": "Restore of {username} is waiting to start", "restoreJobQueuedNote": "It starts as soon as the background worker picks it up.", + "restoreJobWaitingBackupNote": "Waiting for the backup that is running on the server. A restore never runs beside one, and it starts about a minute after the backup finishes.", + "restoreJobWaitingBusyNote": "Waiting for a large job on the server to finish, such as an import or a nightly pass. It starts about a minute after that.", + "restoreJobQueuedSince": "Queued at {when}.", "restoreJobRunningTitle": "Restoring {username}", "restoreJobRunningNote": "The account keeps showing its current data until the restore finishes. You can leave this page; the restore continues on the server.", "restoreJobResumed": "Started again after the server restarted.", diff --git a/messages/es.json b/messages/es.json index 0f92c4ca9..879ccea71 100644 --- a/messages/es.json +++ b/messages/es.json @@ -8264,6 +8264,9 @@ "restoreActive": "Ya hay una restauración en curso para esta cuenta. Espera a que termine.", "restoreJobQueuedTitle": "La restauración de {username} está esperando para empezar", "restoreJobQueuedNote": "Empieza en cuanto el proceso en segundo plano la recoja.", + "restoreJobWaitingBackupNote": "Esperando a la copia de seguridad que se está ejecutando en el servidor. Una restauración nunca se ejecuta a la vez que una copia, y empieza más o menos un minuto después de que termine.", + "restoreJobWaitingBusyNote": "Esperando a que termine un trabajo grande en el servidor, como una importación o un proceso nocturno. Empieza más o menos un minuto después.", + "restoreJobQueuedSince": "En cola desde {when}.", "restoreJobRunningTitle": "Restaurando {username}", "restoreJobRunningNote": "La cuenta sigue mostrando sus datos actuales hasta que termine la restauración. Puedes salir de esta página; la restauración continúa en el servidor.", "restoreJobResumed": "Iniciada de nuevo tras reiniciarse el servidor.", diff --git a/messages/fr.json b/messages/fr.json index e293e2c47..5105b4b79 100644 --- a/messages/fr.json +++ b/messages/fr.json @@ -8264,6 +8264,9 @@ "restoreActive": "Une restauration de ce compte est déjà en cours. Attends qu'elle se termine.", "restoreJobQueuedTitle": "La restauration de {username} attend de démarrer", "restoreJobQueuedNote": "Elle démarre dès que le processus en arrière-plan la prend en charge.", + "restoreJobWaitingBackupNote": "En attente de la sauvegarde en cours sur le serveur. Une restauration ne tourne jamais en même temps qu’une sauvegarde, et elle démarre environ une minute après la fin de celle-ci.", + "restoreJobWaitingBusyNote": "En attente de la fin d’une tâche lourde sur le serveur, comme une importation ou un traitement nocturne. Elle démarre environ une minute après.", + "restoreJobQueuedSince": "En file d’attente depuis {when}.", "restoreJobRunningTitle": "Restauration de {username} en cours", "restoreJobRunningNote": "Le compte affiche ses données actuelles jusqu'à la fin de la restauration. Tu peux quitter cette page ; la restauration continue sur le serveur.", "restoreJobResumed": "Relancée après le redémarrage du serveur.", diff --git a/messages/it.json b/messages/it.json index 57c7a2ecd..ffcbd71a8 100644 --- a/messages/it.json +++ b/messages/it.json @@ -8264,6 +8264,9 @@ "restoreActive": "Per questo account è già in corso un ripristino. Aspetta che finisca.", "restoreJobQueuedTitle": "Il ripristino di {username} è in attesa di partire", "restoreJobQueuedNote": "Parte appena il processo in background lo prende in carico.", + "restoreJobWaitingBackupNote": "In attesa del backup in corso sul server. Un ripristino non gira mai insieme a un backup e parte circa un minuto dopo la sua fine.", + "restoreJobWaitingBusyNote": "In attesa che finisca un lavoro pesante sul server, come un’importazione o un’elaborazione notturna. Parte circa un minuto dopo.", + "restoreJobQueuedSince": "In coda dalle {when}.", "restoreJobRunningTitle": "Ripristino di {username} in corso", "restoreJobRunningNote": "L'account continua a mostrare i dati attuali finché il ripristino non termina. Puoi lasciare questa pagina: il ripristino prosegue sul server.", "restoreJobResumed": "Riavviato dopo il riavvio del server.", diff --git a/messages/ko.json b/messages/ko.json index 49f7f9551..7a90ee3e6 100644 --- a/messages/ko.json +++ b/messages/ko.json @@ -8239,6 +8239,9 @@ "restoreActive": "이 계정의 복원이 이미 진행 중이에요. 끝날 때까지 기다려 주세요.", "restoreJobQueuedTitle": "{username} 복원이 시작을 기다리고 있어요", "restoreJobQueuedNote": "백그라운드 작업자가 가져가는 즉시 시작돼요.", + "restoreJobWaitingBackupNote": "서버에서 실행 중인 백업을 기다리고 있어요. 복원은 백업과 동시에 실행되지 않으며, 백업이 끝나고 1분쯤 뒤에 시작돼요.", + "restoreJobWaitingBusyNote": "가져오기나 야간 작업 같은 서버의 큰 작업이 끝나기를 기다리고 있어요. 그 후 1분쯤 뒤에 시작돼요.", + "restoreJobQueuedSince": "{when}부터 대기 중이에요.", "restoreJobRunningTitle": "{username} 복원 중", "restoreJobRunningNote": "복원이 끝날 때까지 계정에는 기존 데이터가 그대로 보여요. 이 페이지를 떠나도 복원은 서버에서 계속돼요.", "restoreJobResumed": "서버가 다시 시작된 뒤 복원을 다시 시작했어요.", diff --git a/messages/nl.json b/messages/nl.json index 92c3bc0ba..1d791cffe 100644 --- a/messages/nl.json +++ b/messages/nl.json @@ -8264,6 +8264,9 @@ "restoreActive": "Er wordt al een back-up van dit account teruggezet. Wacht tot dat klaar is.", "restoreJobQueuedTitle": "Terugzetten van {username} wacht op start", "restoreJobQueuedNote": "Het begint zodra de achtergrondworker het oppakt.", + "restoreJobWaitingBackupNote": "Wacht op de back-up die nu op de server draait. Terugzetten draait nooit naast een back-up en begint ongeveer een minuut nadat die klaar is.", + "restoreJobWaitingBusyNote": "Wacht tot een grote taak op de server klaar is, zoals een import of een nachtelijke run. Het begint ongeveer een minuut daarna.", + "restoreJobQueuedSince": "In de wachtrij sinds {when}.", "restoreJobRunningTitle": "{username} wordt teruggezet", "restoreJobRunningNote": "Het account toont de huidige gegevens tot het terugzetten klaar is. Je kunt deze pagina verlaten; het terugzetten gaat op de server verder.", "restoreJobResumed": "Opnieuw gestart nadat de server is herstart.", diff --git a/messages/pl.json b/messages/pl.json index 81ef5b1d2..85ddb378c 100644 --- a/messages/pl.json +++ b/messages/pl.json @@ -8264,6 +8264,9 @@ "restoreActive": "Dla tego konta trwa już przywracanie. Poczekaj, aż się skończy.", "restoreJobQueuedTitle": "Przywracanie {username} czeka na start", "restoreJobQueuedNote": "Zacznie się, gdy tylko proces w tle je przejmie.", + "restoreJobWaitingBackupNote": "Czeka na kopię zapasową, która właśnie działa na serwerze. Przywracanie nigdy nie działa równolegle z kopią i zaczyna się mniej więcej minutę po jej zakończeniu.", + "restoreJobWaitingBusyNote": "Czeka na zakończenie dużego zadania na serwerze, na przykład importu albo nocnego przebiegu. Zacznie się mniej więcej minutę później.", + "restoreJobQueuedSince": "W kolejce od {when}.", "restoreJobRunningTitle": "Przywracanie {username}", "restoreJobRunningNote": "Konto pokazuje dotychczasowe dane, dopóki przywracanie się nie zakończy. Możesz opuścić tę stronę; przywracanie trwa dalej na serwerze.", "restoreJobResumed": "Uruchomione ponownie po restarcie serwera.", diff --git a/messages/pt-BR.json b/messages/pt-BR.json index e20851594..191340d81 100644 --- a/messages/pt-BR.json +++ b/messages/pt-BR.json @@ -8264,6 +8264,9 @@ "restoreActive": "Uma restauração desta conta já está em execução. Aguarde a conclusão.", "restoreJobQueuedTitle": "A restauração de {username} está aguardando para iniciar", "restoreJobQueuedNote": "Ela começa assim que o worker em segundo plano a pegar.", + "restoreJobWaitingBackupNote": "Aguardando o backup que está em execução no servidor. Uma restauração nunca roda ao mesmo tempo que um backup e começa cerca de um minuto depois que ele termina.", + "restoreJobWaitingBusyNote": "Aguardando um trabalho grande no servidor terminar, como uma importação ou uma rotina noturna. Ela começa cerca de um minuto depois.", + "restoreJobQueuedSince": "Na fila desde {when}.", "restoreJobRunningTitle": "Restaurando {username}", "restoreJobRunningNote": "A conta continua exibindo seus dados atuais até a restauração terminar. Você pode sair desta página; a restauração continua no servidor.", "restoreJobResumed": "Iniciada novamente após o servidor reiniciar.", diff --git a/prisma/schema.prisma b/prisma/schema.prisma index 915db7acd..b5ecaa161 100644 --- a/prisma/schema.prisma +++ b/prisma/schema.prisma @@ -5766,7 +5766,8 @@ model BackupRestoreJob { restoreInstanceSettings Boolean @default(false) @map("restore_instance_settings") /// `pg-boss` job id of the latest delivery. Consumer: the boot sweep, which /// completes a delivery whose worker is gone so it does not later surface as - /// a timed-out job. + /// a timed-out job, and the status routes, which read from it whether the + /// heavy lane put a queued restore back (`backup-restore-wait.ts`). pgBossJobId String? @map("pg_boss_job_id") /// `queued | running | succeeded | failed`. Consumer: every reader. status String @default("queued") diff --git a/src/__tests__/baselines/source-file-lines.json b/src/__tests__/baselines/source-file-lines.json index fef8023c4..1f4e342a1 100644 --- a/src/__tests__/baselines/source-file-lines.json +++ b/src/__tests__/baselines/source-file-lines.json @@ -1,7 +1,7 @@ { "$comment": "Production files over 800 lines and their length. Maintained by src/__tests__/source-size-ratchet.test.ts.", - "count": 90, - "total": 100487, + "count": 89, + "total": 99600, "entries": { "app/medications/page-client.tsx": 839, "components/charts/mood-chart.tsx": 1166, @@ -67,7 +67,6 @@ "lib/insights/mood-aggregates.ts": 1053, "lib/insights/status-cache.ts": 812, "lib/integrations/status.ts": 1445, - "lib/jobs/backup-restore.ts": 887, "lib/jobs/coach-nudge.ts": 1084, "lib/jobs/insight-pregenerate.ts": 1259, "lib/jobs/medication-intake-import.ts": 819, diff --git a/src/__tests__/sql-now-utc-guard.test.ts b/src/__tests__/sql-now-utc-guard.test.ts index ce1f2e423..4dca58fec 100644 --- a/src/__tests__/sql-now-utc-guard.test.ts +++ b/src/__tests__/sql-now-utc-guard.test.ts @@ -39,6 +39,10 @@ const ALLOWED: Record = { hits: 1, why: "pg-boss start_after is timestamptz", }, + "src/lib/jobs/backup-restore-wait.ts": { + hits: 1, + why: "pg-boss start_after is timestamptz", + }, "src/lib/jobs/reminder/registrar-shared.ts": { hits: 1, why: "pg-boss tables are timestamptz", diff --git a/src/app/api/admin/backups/restores/[jobId]/route.ts b/src/app/api/admin/backups/restores/[jobId]/route.ts index 7270bb688..561387986 100644 --- a/src/app/api/admin/backups/restores/[jobId]/route.ts +++ b/src/app/api/admin/backups/restores/[jobId]/route.ts @@ -7,10 +7,8 @@ */ import { apiHandler, HttpError, requireAdmin } from "@/lib/api-handler"; import { apiSuccess } from "@/lib/api-response"; -import { - evictAfterRestore, - readBackupRestoreJob, -} from "@/lib/jobs/backup-restore"; +import { evictAfterRestore } from "@/lib/jobs/backup-restore"; +import { readBackupRestoreJob } from "@/lib/jobs/backup-restore-view"; import { annotate } from "@/lib/logging/context"; export const dynamic = "force-dynamic"; diff --git a/src/app/api/admin/backups/restores/route.ts b/src/app/api/admin/backups/restores/route.ts index 9e3d2ffb7..3e6382bf9 100644 --- a/src/app/api/admin/backups/restores/route.ts +++ b/src/app/api/admin/backups/restores/route.ts @@ -8,10 +8,8 @@ */ import { apiHandler, requireAdmin } from "@/lib/api-handler"; import { apiSuccess } from "@/lib/api-response"; -import { - evictAfterRestore, - listRecentBackupRestoreJobs, -} from "@/lib/jobs/backup-restore"; +import { evictAfterRestore } from "@/lib/jobs/backup-restore"; +import { listRecentBackupRestoreJobs } from "@/lib/jobs/backup-restore-view"; import { annotate } from "@/lib/logging/context"; export const dynamic = "force-dynamic"; diff --git a/src/components/admin/__tests__/backup-restore-status.test.tsx b/src/components/admin/__tests__/backup-restore-status.test.tsx index d29ae2964..caed72049 100644 --- a/src/components/admin/__tests__/backup-restore-status.test.tsx +++ b/src/components/admin/__tests__/backup-restore-status.test.tsx @@ -26,7 +26,7 @@ import { RestoreJobStatus, visibleRestoreJobs, } from "@/components/admin/backup-restore-status"; -import type { BackupRestoreJobView } from "@/lib/jobs/backup-restore"; +import type { BackupRestoreJobView } from "@/lib/jobs/backup-restore-view"; import { primeLocales } from "@/__tests__/helpers/prime-locales"; primeLocales("de"); @@ -54,6 +54,7 @@ function job(overrides: Partial): BackupRestoreJobView { }, result: null, failure: null, + waiting: null, attempts: 1, createdAt: "2026-09-25T08:00:00.000Z", startedAt: "2026-09-25T08:00:01.000Z", @@ -85,9 +86,29 @@ describe("RestoreJobStatus while it runs", () => { expect(html).not.toContain('data-slot="restore-job-progress"'); }); - it("says a queued restore is waiting", () => { + it("says a queued restore is waiting, and since when", () => { const html = render(job({ status: "queued", phase: null, progress: null })); expect(html).toContain("waiting to start"); + expect(html).toContain("background worker picks it up"); + expect(html).toContain("Queued at"); + expect(html).not.toContain("data-waiting"); + }); + + it("says it waits for the running backup, not for a stuck worker", () => { + const html = render( + job({ status: "queued", phase: null, progress: null, waiting: "backup" }), + ); + expect(html).toContain('data-waiting="backup"'); + expect(html).toContain("Waiting for the backup"); + expect(html).not.toContain("background worker picks it up"); + }); + + it("says it waits for another large job when that holds the server", () => { + const html = render( + job({ status: "queued", phase: null, progress: null, waiting: "busy" }), + ); + expect(html).toContain('data-waiting="busy"'); + expect(html).toContain("large job"); }); it("says when it was started again after a restart", () => { @@ -179,4 +200,12 @@ describe("RestoreJobStatus in another language", () => { expect(html).toContain("alex wird wiederhergestellt"); expect(html).toContain("Messwerte werden geschrieben"); }); + + it("says in German that it waits for the backup", () => { + const html = render( + job({ status: "queued", phase: null, progress: null, waiting: "backup" }), + "de", + ); + expect(html).toContain("Wartet auf das Backup"); + }); }); diff --git a/src/components/admin/backup-restore-status.tsx b/src/components/admin/backup-restore-status.tsx index 50faa8323..359c26351 100644 --- a/src/components/admin/backup-restore-status.tsx +++ b/src/components/admin/backup-restore-status.tsx @@ -28,10 +28,8 @@ import { Button } from "@/components/ui/button"; import { Progress } from "@/components/ui/progress"; import { useFormatters, useTranslations } from "@/lib/i18n/context"; import type { RestoreFailureCause } from "@/lib/export/restore-failure-cause"; -import type { - BackupRestoreFailureCode, - BackupRestoreJobView, -} from "@/lib/jobs/backup-restore"; +import type { BackupRestoreFailureCode } from "@/lib/jobs/backup-restore"; +import type { BackupRestoreJobView } from "@/lib/jobs/backup-restore-view"; /** Whether a job still holds its account's one restore slot. */ export function isActiveRestore(job: BackupRestoreJobView): boolean { @@ -147,6 +145,30 @@ function transactionFailureText( } } +/** + * What a queued job is waiting for. A restore never runs beside a backup or + * another large job (the heavy lane puts it back for a minute at a time), and + * a wait that said only "until the worker picks it up" read as a stuck + * worker for as long as a backup ran. + */ +function queuedText( + job: BackupRestoreJobView, + t: ReturnType["t"], +): string { + switch (job.waiting) { + case "backup": + return t("admin.section.backups.restoreJobWaitingBackupNote"); + case "busy": + return t("admin.section.backups.restoreJobWaitingBusyNote"); + case null: + return t("admin.section.backups.restoreJobQueuedNote"); + default: { + const unhandled: never = job.waiting; + return unhandled; + } + } +} + /** What a running job is doing, and the share of it done when that is known. */ function runningLine( job: BackupRestoreJobView, @@ -213,16 +235,14 @@ export function RestoreJobStatus({ const line = job.status === "running" ? runningLine(job, t, fmt) - : { - text: t("admin.section.backups.restoreJobQueuedNote"), - percent: null, - }; + : { text: queuedText(job, t), percent: null }; return (
@@ -248,6 +268,13 @@ export function RestoreJobStatus({ data-slot="restore-job-progress" /> ) : null} + {job.status === "queued" ? ( +

+ {t("admin.section.backups.restoreJobQueuedSince", { + when: fmt.dateTime(job.createdAt), + })} +

+ ) : null} {job.attempts > 1 ? (

{t("admin.section.backups.restoreJobResumed")} diff --git a/src/components/admin/backups/use-backup-restores.ts b/src/components/admin/backups/use-backup-restores.ts index 97531da48..7f1854ca5 100644 --- a/src/components/admin/backups/use-backup-restores.ts +++ b/src/components/admin/backups/use-backup-restores.ts @@ -10,7 +10,7 @@ import type { MissingBackupSection, RestoreSkipSummary, } from "@/lib/export/restore-skips"; -import type { BackupRestoreJobView } from "@/lib/jobs/backup-restore"; +import type { BackupRestoreJobView } from "@/lib/jobs/backup-restore-view"; import { useTranslations } from "@/lib/i18n/context"; import { queryKeys } from "@/lib/query-keys"; import { randomId } from "@/lib/random-id"; diff --git a/src/lib/jobs/backup-restore-view.ts b/src/lib/jobs/backup-restore-view.ts new file mode 100644 index 000000000..f237bf57d --- /dev/null +++ b/src/lib/jobs/backup-restore-view.ts @@ -0,0 +1,214 @@ +/** + * The read side of a restore job: its row as the status routes answer it. + * + * The row's JSON columns are parsed defensively (a row written by an older + * build reads as nothing rather than as a malformed object), and a queued job + * says what it waits for (`backup-restore-wait.ts`). The worker and the + * admission check live in `backup-restore.ts`. + */ +import { z } from "zod/v4"; + +import { prisma } from "@/lib/db"; +import type { + RestorePhase, + RestoreProgress, +} from "@/lib/export/restore-backup"; +import { RESTORE_FAILURE_CAUSES } from "@/lib/export/restore-failure-cause"; + +import type { + BackupRestoreFailure, + BackupRestoreStatus, +} from "./backup-restore"; +import { restoreWaits, type RestoreWait } from "./backup-restore-wait"; + +const failureSchema = z.object({ + code: z.string(), + message: z.string(), + sections: z.array(z.string()).optional(), + keyIds: z.array(z.string()).optional(), + cause: z.enum(RESTORE_FAILURE_CAUSES).optional(), +}); + +const progressSchema = z.object({ + measurementsChecked: z.number().int().nonnegative(), + measurementsTotal: z.number().int().nonnegative().nullable(), + measurementsWritten: z.number().int().nonnegative(), + sectionsDone: z.number().int().nonnegative(), + sectionsTotal: z.number().int().nonnegative(), +}); + +const resultSchema = z.object({ + summary: z.record(z.string(), z.unknown()), + skipped: z.object({ + links: z.number().int(), + catalogueKeys: z.array( + z.object({ + catalogue: z.string(), + key: z.string(), + links: z.number().int(), + }), + ), + }), + cleared: z.record(z.string(), z.number()), +}); + +export type BackupRestoreResult = z.infer; + +/** What the status routes answer with. Counts and codes, never content. */ +export interface BackupRestoreJobView { + id: string; + userId: string; + username: string | null; + backupId: string; + restoreInstanceSettings: boolean; + status: BackupRestoreStatus; + phase: RestorePhase | null; + progress: RestoreProgress | null; + result: BackupRestoreResult | null; + failure: BackupRestoreFailure | null; + /** + * Why a queued job has not started: the heavy lane put it back while a + * backup pass (`backup`) or another large job (`busy`) held it. Null while + * it only waits for the worker, and on every job that is not queued. + */ + waiting: RestoreWait | null; + attempts: number; + createdAt: string; + startedAt: string | null; + completedAt: string | null; +} + +const PHASES: readonly RestorePhase[] = [ + "validating", + "clearing", + "measurements", + "sections", + "rebuilding", +]; +const STATUSES: readonly BackupRestoreStatus[] = [ + "queued", + "running", + "succeeded", + "failed", +]; + +const viewSelect = { + id: true, + userId: true, + backupId: true, + restoreInstanceSettings: true, + status: true, + phase: true, + progress: true, + result: true, + failure: true, + attempts: true, + createdAt: true, + startedAt: true, + completedAt: true, + pgBossJobId: true, + user: { select: { username: true } }, +} as const; + +type ViewRow = { + id: string; + userId: string; + backupId: string; + restoreInstanceSettings: boolean; + status: string; + phase: string | null; + progress: unknown; + result: unknown; + failure: unknown; + attempts: number; + createdAt: Date; + startedAt: Date | null; + completedAt: Date | null; + pgBossJobId: string | null; + user: { username: string } | null; +}; + +function toView( + row: ViewRow, + waits: ReadonlyMap, +): BackupRestoreJobView { + const status = (STATUSES as readonly string[]).includes(row.status) + ? (row.status as BackupRestoreStatus) + : "failed"; + const phase = + row.phase && (PHASES as readonly string[]).includes(row.phase) + ? (row.phase as RestorePhase) + : null; + const progress = progressSchema.safeParse(row.progress); + const result = resultSchema.safeParse(row.result); + const failure = failureSchema.safeParse(row.failure); + return { + id: row.id, + userId: row.userId, + username: row.user?.username ?? null, + backupId: row.backupId, + restoreInstanceSettings: row.restoreInstanceSettings, + status, + phase: status === "running" ? phase : null, + progress: progress.success ? progress.data : null, + result: result.success ? result.data : null, + failure: failure.success + ? (failure.data as BackupRestoreFailure) + : status === "failed" + ? { code: "unexpected", message: "The restore failed." } + : null, + waiting: + status === "queued" && row.pgBossJobId + ? (waits.get(row.pgBossJobId) ?? null) + : null, + attempts: row.attempts, + createdAt: row.createdAt.toISOString(), + startedAt: row.startedAt?.toISOString() ?? null, + completedAt: row.completedAt?.toISOString() ?? null, + }; +} + +/** What the queued ones among `rows` wait for. */ +function waitsOf(rows: readonly ViewRow[]) { + return restoreWaits( + rows.flatMap((row) => + row.status === "queued" && row.pgBossJobId ? [row.pgBossJobId] : [], + ), + ); +} + +/** One job, for the status route. Null when the id is unknown. */ +export async function readBackupRestoreJob( + id: string, +): Promise { + const row = await prisma.backupRestoreJob.findUnique({ + where: { id }, + select: viewSelect, + }); + if (!row) return null; + return toView(row, await waitsOf([row])); +} + +/** + * The jobs the console shows: every queued or running one, and the finished + * ones of the last day, newest first. What a reload of the page needs to pick + * up a restore it was watching, and to show how the last one ended. + */ +export async function listRecentBackupRestoreJobs( + now: Date = new Date(), +): Promise { + const since = new Date(now.getTime() - 24 * 60 * 60 * 1000); + const rows = await prisma.backupRestoreJob.findMany({ + where: { + OR: [ + { status: { in: ["queued", "running"] } }, + { createdAt: { gte: since } }, + ], + }, + orderBy: { createdAt: "desc" }, + take: 20, + select: viewSelect, + }); + const waits = await waitsOf(rows); + return rows.map((row) => toView(row, waits)); +} diff --git a/src/lib/jobs/backup-restore-wait.ts b/src/lib/jobs/backup-restore-wait.ts new file mode 100644 index 000000000..dc1ce8149 --- /dev/null +++ b/src/lib/jobs/backup-restore-wait.ts @@ -0,0 +1,79 @@ +/** + * What a queued restore is waiting for, read from the queue itself. + * + * A restore runs in the heavy lane (`heavy-lane.ts`): while a backup pass or + * another large job holds it, the restore goes back to its queue for a minute + * at a time, so it never runs beside one. That is deliberate, and invisible + * from the restore's own row, which says `queued` for the whole wait. The + * console said the restore starts "as soon as the background worker picks it + * up", which read as a stuck worker while a backup ran for half an hour. + * + * The queue knows. A delivery the lane put back sits in `created` with a + * `start_after` ahead of now, and the job holding the lane is the active row + * of a heavy queue. Reading both answers the question without a column that + * would have to be kept in step with the lane. + */ +import { prisma } from "@/lib/db"; +import { HEAVY_QUEUES } from "@/lib/jobs/heavy-lane"; +import { logCaught } from "@/lib/logging/signal"; + +import { BACKUP_RESTORE_QUEUE } from "./backup-restore-queue"; + +/** + * Why a queued restore has not started: a backup pass holds the lane, or + * something else does (an import, a nightly pass, the memory guard). + */ +export type RestoreWait = "backup" | "busy"; + +/** The queues whose holder the console names as "the backup". */ +const BACKUP_PASS_QUEUES: ReadonlySet = new Set([ + "data-backup", + "data-backup-offhost", +]); + +const OTHER_HEAVY_QUEUES = Object.keys(HEAVY_QUEUES).filter( + (queue) => queue !== BACKUP_RESTORE_QUEUE, +); + +/** + * For each of `deliveries` (pg-boss job ids of queued restores) that the lane + * has put back, what holds the lane. A delivery not in the map is waiting + * for the worker to pick it up, nothing more. + * + * Never fails the read it serves: a queue that cannot be asked answers no + * waits, reported at warn, and the console says what it said before. + */ +export async function restoreWaits( + deliveries: readonly string[], +): Promise> { + const waits = new Map(); + if (deliveries.length === 0) return waits; + try { + const deferred = await prisma.$queryRaw>` + SELECT id::text AS id + FROM pgboss.job + WHERE name = ${BACKUP_RESTORE_QUEUE} + AND id = ANY(${[...deliveries]}::uuid[]) + AND state = 'created' + AND start_after > now() + `; + if (deferred.length === 0) return waits; + const holders = await prisma.$queryRaw>` + SELECT name + FROM pgboss.job + WHERE state = 'active' + AND name = ANY(${OTHER_HEAVY_QUEUES}::text[]) + ORDER BY started_on ASC + LIMIT 1 + `; + const holder = holders[0]?.name; + const wait: RestoreWait = + holder !== undefined && BACKUP_PASS_QUEUES.has(holder) + ? "backup" + : "busy"; + for (const row of deferred) waits.set(row.id, wait); + } catch (err) { + logCaught("backup.restore.wait_unread", err); + } + return waits; +} diff --git a/src/lib/jobs/backup-restore.ts b/src/lib/jobs/backup-restore.ts index ab721743e..7ad611afb 100644 --- a/src/lib/jobs/backup-restore.ts +++ b/src/lib/jobs/backup-restore.ts @@ -51,7 +51,6 @@ import { createHash } from "node:crypto"; import type { Job, PgBoss } from "pg-boss"; -import { z } from "zod/v4"; import { invalidateUserData } from "@/lib/cache/invalidate"; import { prisma, toJson } from "@/lib/db"; @@ -79,6 +78,10 @@ import { } from "@/lib/export/restore-failure-cause"; import { logCaught } from "@/lib/logging/signal"; import { BACKUP_RESTORE_QUEUE } from "./backup-restore-queue"; +import type { + BackupRestoreJobView, + BackupRestoreResult, +} from "./backup-restore-view"; /** Stable code of the 409 a second restore of the same account gets. */ export const BACKUP_RESTORE_ACTIVE_CODE = "backup.restore.active"; @@ -140,71 +143,6 @@ export interface BackupRestoreFailure { cause?: RestoreFailureCause; } -const failureSchema = z.object({ - code: z.string(), - message: z.string(), - sections: z.array(z.string()).optional(), - keyIds: z.array(z.string()).optional(), - cause: z.enum(RESTORE_FAILURE_CAUSES).optional(), -}); - -const progressSchema = z.object({ - measurementsChecked: z.number().int().nonnegative(), - measurementsTotal: z.number().int().nonnegative().nullable(), - measurementsWritten: z.number().int().nonnegative(), - sectionsDone: z.number().int().nonnegative(), - sectionsTotal: z.number().int().nonnegative(), -}); - -const resultSchema = z.object({ - summary: z.record(z.string(), z.unknown()), - skipped: z.object({ - links: z.number().int(), - catalogueKeys: z.array( - z.object({ - catalogue: z.string(), - key: z.string(), - links: z.number().int(), - }), - ), - }), - cleared: z.record(z.string(), z.number()), -}); - -export type BackupRestoreResult = z.infer; - -/** What the status routes answer with. Counts and codes, never content. */ -export interface BackupRestoreJobView { - id: string; - userId: string; - username: string | null; - backupId: string; - restoreInstanceSettings: boolean; - status: BackupRestoreStatus; - phase: RestorePhase | null; - progress: RestoreProgress | null; - result: BackupRestoreResult | null; - failure: BackupRestoreFailure | null; - attempts: number; - createdAt: string; - startedAt: string | null; - completedAt: string | null; -} - -const PHASES: readonly RestorePhase[] = [ - "validating", - "clearing", - "measurements", - "sections", - "rebuilding", -]; -const STATUSES: readonly BackupRestoreStatus[] = [ - "queued", - "running", - "succeeded", - "failed", -]; - /** * A failure code as a job fact. Job facts are lower-case words joined by * underscores (`job-outcome.ts`), and two of the restore's codes are the @@ -222,107 +160,6 @@ export function backupDigest(identity: string): string { return createHash("sha256").update(identity).digest("hex"); } -const viewSelect = { - id: true, - userId: true, - backupId: true, - restoreInstanceSettings: true, - status: true, - phase: true, - progress: true, - result: true, - failure: true, - attempts: true, - createdAt: true, - startedAt: true, - completedAt: true, - user: { select: { username: true } }, -} as const; - -type ViewRow = { - id: string; - userId: string; - backupId: string; - restoreInstanceSettings: boolean; - status: string; - phase: string | null; - progress: unknown; - result: unknown; - failure: unknown; - attempts: number; - createdAt: Date; - startedAt: Date | null; - completedAt: Date | null; - user: { username: string } | null; -}; - -function toView(row: ViewRow): BackupRestoreJobView { - const status = (STATUSES as readonly string[]).includes(row.status) - ? (row.status as BackupRestoreStatus) - : "failed"; - const phase = - row.phase && (PHASES as readonly string[]).includes(row.phase) - ? (row.phase as RestorePhase) - : null; - const progress = progressSchema.safeParse(row.progress); - const result = resultSchema.safeParse(row.result); - const failure = failureSchema.safeParse(row.failure); - return { - id: row.id, - userId: row.userId, - username: row.user?.username ?? null, - backupId: row.backupId, - restoreInstanceSettings: row.restoreInstanceSettings, - status, - phase: status === "running" ? phase : null, - progress: progress.success ? progress.data : null, - result: result.success ? result.data : null, - failure: failure.success - ? (failure.data as BackupRestoreFailure) - : status === "failed" - ? { code: "unexpected", message: "The restore failed." } - : null, - attempts: row.attempts, - createdAt: row.createdAt.toISOString(), - startedAt: row.startedAt?.toISOString() ?? null, - completedAt: row.completedAt?.toISOString() ?? null, - }; -} - -/** One job, for the status route. Null when the id is unknown. */ -export async function readBackupRestoreJob( - id: string, -): Promise { - const row = await prisma.backupRestoreJob.findUnique({ - where: { id }, - select: viewSelect, - }); - return row ? toView(row) : null; -} - -/** - * The jobs the console shows: every queued or running one, and the finished - * ones of the last day, newest first. What a reload of the page needs to pick - * up a restore it was watching, and to show how the last one ended. - */ -export async function listRecentBackupRestoreJobs( - now: Date = new Date(), -): Promise { - const since = new Date(now.getTime() - 24 * 60 * 60 * 1000); - const rows = await prisma.backupRestoreJob.findMany({ - where: { - OR: [ - { status: { in: ["queued", "running"] } }, - { createdAt: { gte: since } }, - ], - }, - orderBy: { createdAt: "desc" }, - take: 20, - select: viewSelect, - }); - return rows.map(toView); -} - function failureJson(failure: BackupRestoreFailure) { return toJson({ code: failure.code, diff --git a/src/lib/openapi/routes/admin-backups.ts b/src/lib/openapi/routes/admin-backups.ts index 686c2adf5..a9dd6727c 100644 --- a/src/lib/openapi/routes/admin-backups.ts +++ b/src/lib/openapi/routes/admin-backups.ts @@ -132,6 +132,12 @@ const restoreJob = z }) .nullable(), failure: restoreFailure.nullable(), + waiting: z + .enum(["backup", "busy"]) + .nullable() + .describe( + "Why a `queued` job has not started. A restore never runs beside a backup or another large job: while one holds the server it goes back to the queue for a minute at a time. `backup` when a backup pass holds it, `busy` for anything else (an import, a nightly pass, the memory guard). Null while the job only waits for the worker, and on every job that is not queued.", + ), attempts: z.number().int(), createdAt: z.string(), startedAt: z.string().nullable(), diff --git a/tests/integration/backup-chunked-storage.test.ts b/tests/integration/backup-chunked-storage.test.ts index 36ee1fb34..b53e9ae51 100644 --- a/tests/integration/backup-chunked-storage.test.ts +++ b/tests/integration/backup-chunked-storage.test.ts @@ -461,8 +461,9 @@ describe("a restore queued against a copy that is then replaced", () => { await import("@/app/api/admin/backups/[id]/restore/route"); const { getGlobalBoss, setGlobalBoss } = await import("@/lib/jobs/boss-instance"); - const { readBackupRestoreJob, runBackupRestoreJob } = - await import("@/lib/jobs/backup-restore"); + const { runBackupRestoreJob } = await import("@/lib/jobs/backup-restore"); + const { readBackupRestoreJob } = + await import("@/lib/jobs/backup-restore-view"); const previous = getGlobalBoss(); setGlobalBoss(acceptingBoss); diff --git a/tests/integration/backup-restore-job.test.ts b/tests/integration/backup-restore-job.test.ts index 1902b918a..29c0be93d 100644 --- a/tests/integration/backup-restore-job.test.ts +++ b/tests/integration/backup-restore-job.test.ts @@ -45,10 +45,10 @@ import { runJob } from "@/lib/jobs/run-job"; import { BACKUP_RESTORE_MAX_ATTEMPTS, handleBackupRestore, - readBackupRestoreJob, runBackupRestoreJob, sweepInterruptedRestores, } from "@/lib/jobs/backup-restore"; +import { readBackupRestoreJob } from "@/lib/jobs/backup-restore-view"; import { BACKUP_RESTORE_QUEUE } from "@/lib/jobs/backup-restore-queue"; import { backupPayloadSchema } from "@/lib/validations/backup"; diff --git a/tests/integration/backup-restore-statement-timeout.test.ts b/tests/integration/backup-restore-statement-timeout.test.ts index e5ac4eb3b..0fd6d182a 100644 --- a/tests/integration/backup-restore-statement-timeout.test.ts +++ b/tests/integration/backup-restore-statement-timeout.test.ts @@ -49,7 +49,7 @@ import { getPrismaClient, truncateAllTables } from "./setup"; import { streamFullBackupJson } from "@/lib/export/full-backup-stream"; import { storeBackupBlob } from "@/lib/export/store-backup-blob"; import { RESTORE_FAILURE_CAUSE_MESSAGES } from "@/lib/export/restore-failure-cause"; -import { readBackupRestoreJob } from "@/lib/jobs/backup-restore"; +import { readBackupRestoreJob } from "@/lib/jobs/backup-restore-view"; vi.mock("next/headers", async () => { const { cookieJar, headerJar } = await import("./mock-next-headers"); diff --git a/tests/integration/backup-restore-wait.test.ts b/tests/integration/backup-restore-wait.test.ts new file mode 100644 index 000000000..f1b14b11e --- /dev/null +++ b/tests/integration/backup-restore-wait.test.ts @@ -0,0 +1,114 @@ +/** + * What a queued restore says it waits for, read from a real pg-boss. + * + * A restore never runs beside a backup pass or another large job: the heavy + * lane puts its delivery back in the queue for a minute at a time + * (`deferLaneJobs`). Its own row says `queued` throughout, and the console + * used to say only that it starts "as soon as the background worker picks it + * up", which read as a stuck worker while a backup ran. The status read now + * asks the queue: a delivery that went back, and the heavy job that holds + * the lane. + */ +import { afterAll, beforeAll, describe, expect, it } from "vitest"; +import { PgBoss } from "pg-boss"; + +import { prisma } from "@/lib/db"; +import { readBackupRestoreJob } from "@/lib/jobs/backup-restore-view"; +import { BACKUP_RESTORE_QUEUE } from "@/lib/jobs/backup-restore-queue"; +import { restoreWaits } from "@/lib/jobs/backup-restore-wait"; +import { deferLaneJobs } from "@/lib/jobs/heavy-lane"; + +import { makeUser } from "../kit/factories"; +import { truncateAllTables } from "./setup"; + +let boss: PgBoss; + +const QUEUES = [BACKUP_RESTORE_QUEUE, "data-backup", "rollup-full-backfill"]; + +beforeAll(async () => { + await truncateAllTables(prisma); + boss = new PgBoss({ connectionString: process.env.DATABASE_URL }); + await boss.start(); + for (const queue of QUEUES) await boss.createQueue(queue); +}, 120_000); + +afterAll(async () => { + for (const queue of QUEUES) await boss.deleteAllJobs(queue); + await boss?.stop({ graceful: false }); + await truncateAllTables(prisma); +}); + +/** A restore delivery the lane has put back, as `heavyLane` leaves it. */ +async function deferredRestore(): Promise { + const id = await boss.send(BACKUP_RESTORE_QUEUE, { restoreJobId: "r" }); + const [fetched] = await boss.fetch(BACKUP_RESTORE_QUEUE); + expect(fetched?.id).toBe(id); + expect((await deferLaneJobs(BACKUP_RESTORE_QUEUE, [fetched!])).deferred).toBe( + 1, + ); + return id!; +} + +/** A job of `queue` running, so it holds the lane. */ +async function running(queue: string): Promise { + const id = await boss.send(queue, {}); + const [fetched] = await boss.fetch(queue); + expect(fetched?.id).toBe(id); + return id!; +} + +describe("restoreWaits", () => { + it("names the backup when a backup pass holds the lane", async () => { + const restore = await deferredRestore(); + const backup = await running("data-backup"); + expect(await restoreWaits([restore])).toEqual( + new Map([[restore, "backup"]]), + ); + await boss.complete("data-backup", backup); + + // Another large job holding it is named as one. + const fold = await running("rollup-full-backfill"); + expect((await restoreWaits([restore])).get(restore)).toBe("busy"); + await boss.complete("rollup-full-backfill", fold); + + // Put back with nothing running (the memory guard, or a holder that has + // just finished): still a wait for room, not for the worker. + expect((await restoreWaits([restore])).get(restore)).toBe("busy"); + await boss.deleteJob(BACKUP_RESTORE_QUEUE, restore); + }); + + it("says nothing about a delivery that only waits for the worker", async () => { + const queued = await boss.send(BACKUP_RESTORE_QUEUE, { restoreJobId: "q" }); + const backup = await running("data-backup"); + expect(await restoreWaits([queued!])).toEqual(new Map()); + await boss.complete("data-backup", backup); + await boss.deleteJob(BACKUP_RESTORE_QUEUE, queued!); + }); + + it("reaches the status read of the job behind the delivery", async () => { + const owner = await makeUser({}); + const restore = await deferredRestore(); + const job = await prisma.backupRestoreJob.create({ + data: { + userId: owner.id, + actorUserId: owner.id, + backupId: "backup-1", + backupDigest: "digest", + status: "queued", + pgBossJobId: restore, + }, + }); + const backup = await running("data-backup"); + expect((await readBackupRestoreJob(job.id))?.waiting).toBe("backup"); + await boss.complete("data-backup", backup); + + // A job that is no longer queued waits for nothing, whatever its last + // delivery says. + await prisma.backupRestoreJob.update({ + where: { id: job.id }, + data: { status: "running" }, + }); + expect((await readBackupRestoreJob(job.id))?.waiting).toBeNull(); + await boss.deleteJob(BACKUP_RESTORE_QUEUE, restore); + }); +}); diff --git a/tests/integration/restore-consolidation-deadlock.test.ts b/tests/integration/restore-consolidation-deadlock.test.ts index 8f9df2686..82b6b991b 100644 --- a/tests/integration/restore-consolidation-deadlock.test.ts +++ b/tests/integration/restore-consolidation-deadlock.test.ts @@ -191,7 +191,8 @@ describe("restore against a running consolidation (#1031)", () => { const restore = await startRestore(backupId); const [folded] = await Promise.all([consolidation, restore.done]); - const { readBackupRestoreJob } = await import("@/lib/jobs/backup-restore"); + const { readBackupRestoreJob } = + await import("@/lib/jobs/backup-restore-view"); const job = await readBackupRestoreJob(restore.jobId); expect( diff --git a/tests/integration/restore-job-driver.ts b/tests/integration/restore-job-driver.ts index 2986bcb77..94dddd6b0 100644 --- a/tests/integration/restore-job-driver.ts +++ b/tests/integration/restore-job-driver.ts @@ -17,10 +17,8 @@ import type { PgBoss } from "pg-boss"; import { POST as queueRestore } from "@/app/api/admin/backups/[id]/restore/route"; import { getGlobalBoss, setGlobalBoss } from "@/lib/jobs/boss-instance"; -import { - readBackupRestoreJob, - runBackupRestoreJob, -} from "@/lib/jobs/backup-restore"; +import { runBackupRestoreJob } from "@/lib/jobs/backup-restore"; +import { readBackupRestoreJob } from "@/lib/jobs/backup-restore-view"; /** The status the synchronous route answered each refusal with. */ const LEGACY_STATUS: Record = {