mirror of
https://github.com/MBombeck/HealthLog.git
synced 2026-11-11 22:02:16 +00:00
fix(backup): notice a backup run the process died under, and take its account last
A weekly or nightly backup job whose process died (a restart, a container out of memory) stayed active until its two- or four-hour expiry, and its retry walked the accounts in the same order: the account that killed it has the oldest copy, so it led again, and every account after it went without a copy for as long as that record stayed too large. Both passes now send with a five-minute pg-boss heartbeat, so a dead run fails within minutes and its retry picks it up. Each pass records when it started and finished every account (backup_pass_attempts, migration 0373); an account whose last attempt never finished goes behind all the others. The backups page shows when the run in progress started and names an account a run died under, for the weekly and the off-host card, and a heartbeat timeout reads as what it means.
This commit is contained in:
1 parent
d55e329c48
commit
f18e6ed34b
31 files changed
+734
-19
No files matched your search
@@ -19,16 +19,24 @@ vi.mock("@/lib/api-handler", () => ({
|
||||
|
||||
vi.mock("@/lib/logging/context", () => ({ annotate: vi.fn() }));
|
||||
|
||||
const runningSinceMock = vi.fn(
|
||||
async (_queue: string): Promise<string | null> => null,
|
||||
);
|
||||
vi.mock("@/lib/jobs/job-failures", () => ({
|
||||
readLastQueueRun: vi.fn(async () => null),
|
||||
readQueueRunningSince: (queue: string) => runningSinceMock(queue),
|
||||
}));
|
||||
|
||||
const queryRawMock = vi.fn();
|
||||
const findManyMock = vi.fn();
|
||||
const attemptsMock = vi.fn();
|
||||
vi.mock("@/lib/db", () => ({
|
||||
prisma: {
|
||||
$queryRaw: (...a: unknown[]) => queryRawMock(...a),
|
||||
user: { findMany: (...a: unknown[]) => findManyMock(...a) },
|
||||
backupPassAttempt: {
|
||||
findMany: (...a: unknown[]) => attemptsMock(...a),
|
||||
},
|
||||
offhostPurgeRequest: {
|
||||
count: async () => 2,
|
||||
findFirst: async () => ({
|
||||
@@ -41,6 +49,7 @@ vi.mock("@/lib/db", () => ({
|
||||
|
||||
const configuredMock = vi.fn(() => true);
|
||||
vi.mock("@/lib/jobs/offhost-backup", () => ({
|
||||
OFFHOST_BACKUP_QUEUE: "data-backup-offhost",
|
||||
offhostBackupConfigured: () => configuredMock(),
|
||||
probeOffhostLifecycle: async () => ({
|
||||
state: "missing",
|
||||
@@ -64,6 +73,8 @@ beforeEach(() => {
|
||||
configuredMock.mockReturnValue(true);
|
||||
queryRawMock.mockResolvedValue([]);
|
||||
findManyMock.mockResolvedValue([]);
|
||||
attemptsMock.mockResolvedValue([]);
|
||||
runningSinceMock.mockResolvedValue(null);
|
||||
});
|
||||
|
||||
describe("GET /api/admin/backups — off-host freshness", () => {
|
||||
@@ -226,3 +237,51 @@ describe("GET /api/admin/backups — off-host freshness", () => {
|
||||
});
|
||||
});
|
||||
});
|
||||
|
||||
describe("GET /api/admin/backups — a run in progress and one a process died under", () => {
|
||||
it("names the account an earlier run never came back from, and says since when one runs", async () => {
|
||||
const runningSince = "2026-10-04T02:00:00.000Z";
|
||||
runningSinceMock.mockImplementation(async (queue: string) =>
|
||||
queue === "data-backup" ? runningSince : null,
|
||||
);
|
||||
findManyMock.mockResolvedValue([
|
||||
{ id: "u1", username: "account-one", offhostBackupState: null },
|
||||
{ id: "u2", username: "account-two", offhostBackupState: null },
|
||||
]);
|
||||
attemptsMock.mockImplementation(
|
||||
async ({ where }: { where: { pass: string } }) =>
|
||||
where.pass === "data-backup"
|
||||
? [
|
||||
// Died under an earlier run.
|
||||
{
|
||||
userId: "u1",
|
||||
startedAt: new Date("2026-09-27T02:10:00.000Z"),
|
||||
finishedAt: new Date("2026-09-20T02:30:00.000Z"),
|
||||
},
|
||||
// The account the run in progress is on now.
|
||||
{
|
||||
userId: "u2",
|
||||
startedAt: new Date("2026-10-04T02:05:00.000Z"),
|
||||
finishedAt: null,
|
||||
},
|
||||
]
|
||||
: [],
|
||||
);
|
||||
|
||||
const body = await read();
|
||||
expect(body.scheduleActivity).toEqual({
|
||||
runningSince,
|
||||
interrupted: [
|
||||
{
|
||||
userId: "u1",
|
||||
username: "account-one",
|
||||
startedAt: "2026-09-27T02:10:00.000Z",
|
||||
},
|
||||
],
|
||||
});
|
||||
expect(body.offhost.activity).toEqual({
|
||||
runningSince: null,
|
||||
interrupted: [],
|
||||
});
|
||||
});
|
||||
});
|
||||
@@ -25,9 +25,14 @@ import { apiHandler, requireAdmin } from "@/lib/api-handler";
|
||||
import { apiSuccess } from "@/lib/api-response";
|
||||
import { annotate } from "@/lib/logging/context";
|
||||
import { DATA_BACKUP_QUEUE } from "@/lib/jobs/data-backup-policy";
|
||||
import { readLastQueueRun } from "@/lib/jobs/job-failures";
|
||||
import {
|
||||
readLastQueueRun,
|
||||
readQueueRunningSince,
|
||||
} from "@/lib/jobs/job-failures";
|
||||
import { readBackupPassActivity } from "@/lib/jobs/backup-pass-attempts";
|
||||
import { summariseBackupSchedule } from "@/lib/jobs/backup-schedule-status";
|
||||
import {
|
||||
OFFHOST_BACKUP_QUEUE,
|
||||
offhostBackupConfigured,
|
||||
probeOffhostLifecycle,
|
||||
} from "@/lib/jobs/offhost-backup";
|
||||
@@ -177,6 +182,14 @@ export const GET = apiHandler(async () => {
|
||||
lastAttemptAt: { not: null },
|
||||
},
|
||||
};
|
||||
const [weeklyRunningSince, offhostRunningSince] = await Promise.all([
|
||||
readQueueRunningSince(DATA_BACKUP_QUEUE),
|
||||
readQueueRunningSince(OFFHOST_BACKUP_QUEUE),
|
||||
]);
|
||||
const [scheduleActivity, offhostActivity] = await Promise.all([
|
||||
readBackupPassActivity(prisma, DATA_BACKUP_QUEUE, weeklyRunningSince),
|
||||
readBackupPassActivity(prisma, OFFHOST_BACKUP_QUEUE, offhostRunningSince),
|
||||
]);
|
||||
const [purgeCount, oldestPurge, lifecycle] = await Promise.all([
|
||||
prisma.offhostPurgeRequest.count({ where: stillInBucket }),
|
||||
prisma.offhostPurgeRequest.findFirst({
|
||||
@@ -201,8 +214,10 @@ export const GET = apiHandler(async () => {
|
||||
lastRun: await readLastQueueRun(DATA_BACKUP_QUEUE),
|
||||
now,
|
||||
}),
|
||||
scheduleActivity,
|
||||
offhost: {
|
||||
configured,
|
||||
activity: offhostActivity,
|
||||
periodHours: OFFHOST_BACKUP_PERIOD_HOURS,
|
||||
// An unconfigured host has nothing to list, and the card says so rather
|
||||
// than painting an empty table that reads as "no problems".
|
||||
|
||||
@@ -24,6 +24,7 @@ import { I18nProvider } from "@/lib/i18n/context";
|
||||
import { OffhostBackupsSection } from "../offhost-backups-section";
|
||||
|
||||
const QUIET = {
|
||||
activity: { runningSince: null, interrupted: [] },
|
||||
pendingDeletions: { count: 0, oldestRequestedAt: null, lastFailure: null },
|
||||
lifecycle: { state: "configured" as const, expirationDays: 30 },
|
||||
};
|
||||
@@ -126,6 +127,7 @@ describe("<OffhostBackupsSection>", () => {
|
||||
configured: true,
|
||||
periodHours: 24,
|
||||
rows: [],
|
||||
activity: { runningSince: null, interrupted: [] },
|
||||
pendingDeletions: {
|
||||
count: 2,
|
||||
oldestRequestedAt: "2026-09-20T10:00:00.000Z",
|
||||
@@ -149,4 +151,26 @@ describe("<OffhostBackupsSection>", () => {
|
||||
expect(html).toContain("after 30 days");
|
||||
expect(html).not.toContain('data-slot="offhost-pending-deletions"');
|
||||
});
|
||||
|
||||
it("names an account a run died under, and says since when one runs", () => {
|
||||
const html = render({
|
||||
configured: true,
|
||||
periodHours: 24,
|
||||
rows: [],
|
||||
...QUIET,
|
||||
activity: {
|
||||
runningSince: "2026-10-04T02:30:00.000Z",
|
||||
interrupted: [
|
||||
{
|
||||
userId: "u1",
|
||||
username: "account-one",
|
||||
startedAt: "2026-10-03T02:31:00.000Z",
|
||||
},
|
||||
],
|
||||
},
|
||||
});
|
||||
expect(html).toContain('data-slot="backup-pass-running"');
|
||||
expect(html).toContain('data-interrupted-username="account-one"');
|
||||
expect(html).toContain("never finished");
|
||||
});
|
||||
});
|
||||
@@ -0,0 +1,78 @@
|
||||
"use client";
|
||||
|
||||
/**
|
||||
* What a backup pass is doing now, and which accounts a run died under.
|
||||
*
|
||||
* A pass whose process died (a restart, or a container out of memory) used
|
||||
* to leave nothing on this page: the job sat `active` until its expiry and
|
||||
* the last finished run still read fine. The run in progress and the
|
||||
* accounts whose last attempt started and never finished are both recorded
|
||||
* now (`backup-pass-attempts.ts`), so the page says so while it matters.
|
||||
*/
|
||||
import { AlertTriangle } from "lucide-react";
|
||||
|
||||
import { useFormatters, useTranslations } from "@/lib/i18n/context";
|
||||
import type { BackupPassActivity } from "@/lib/jobs/backup-pass-attempts";
|
||||
|
||||
export function BackupPassActivityNotice({
|
||||
activity,
|
||||
}: {
|
||||
activity: BackupPassActivity;
|
||||
}) {
|
||||
const { t } = useTranslations();
|
||||
const fmt = useFormatters();
|
||||
if (activity.runningSince === null && activity.interrupted.length === 0) {
|
||||
return null;
|
||||
}
|
||||
|
||||
return (
|
||||
<div className="space-y-2" data-slot="backup-pass-activity">
|
||||
{activity.runningSince !== null ? (
|
||||
<p
|
||||
role="status"
|
||||
className="text-muted-foreground text-xs"
|
||||
data-slot="backup-pass-running"
|
||||
>
|
||||
{t("admin.section.backups.activity.running", {
|
||||
when: fmt.dateTime(activity.runningSince),
|
||||
})}
|
||||
</p>
|
||||
) : null}
|
||||
{activity.interrupted.length > 0 ? (
|
||||
<div
|
||||
role="alert"
|
||||
data-slot="backup-pass-interrupted"
|
||||
className="border-destructive/40 bg-destructive/10 rounded-md border px-3 py-2 text-sm"
|
||||
>
|
||||
<div className="flex items-start gap-2">
|
||||
<AlertTriangle
|
||||
className="mt-0.5 h-4 w-4 shrink-0"
|
||||
aria-hidden="true"
|
||||
/>
|
||||
<div>
|
||||
<p className="font-medium">
|
||||
{t("admin.section.backups.activity.interruptedTitle")}
|
||||
</p>
|
||||
<ul className="text-xs">
|
||||
{activity.interrupted.map((attempt) => (
|
||||
<li
|
||||
key={attempt.userId}
|
||||
data-interrupted-username={attempt.username}
|
||||
>
|
||||
{t("admin.section.backups.activity.interruptedAccount", {
|
||||
username: attempt.username,
|
||||
when: fmt.dateTime(attempt.startedAt),
|
||||
})}
|
||||
</li>
|
||||
))}
|
||||
</ul>
|
||||
<p className="text-muted-foreground mt-2 text-xs">
|
||||
{t("admin.section.backups.activity.interruptedRemedy")}
|
||||
</p>
|
||||
</div>
|
||||
</div>
|
||||
</div>
|
||||
) : null}
|
||||
</div>
|
||||
);
|
||||
}
|
||||
@@ -35,6 +35,7 @@ import {
|
||||
AlertDialogTitle,
|
||||
AlertDialogTrigger,
|
||||
} from "@/components/ui/alert-dialog";
|
||||
import { BackupPassActivityNotice } from "@/components/admin/backup-pass-activity";
|
||||
import { Badge } from "@/components/ui/badge";
|
||||
import { QueryErrorRow } from "@/components/ui/query-error-row";
|
||||
import { SettingsCardActions } from "@/components/settings/_card-actions";
|
||||
@@ -1149,6 +1150,9 @@ export function BackupsSection() {
|
||||
{data?.schedule ? (
|
||||
<ScheduleHealthNotice schedule={data.schedule} />
|
||||
) : null}
|
||||
{data?.scheduleActivity ? (
|
||||
<BackupPassActivityNotice activity={data.scheduleActivity} />
|
||||
) : null}
|
||||
|
||||
{/* Upload card — separate from the table so admins can ingest a
|
||||
backup file independently of any existing rows. The visible
|
||||
|
||||
@@ -21,6 +21,7 @@
|
||||
|
||||
import { useQuery } from "@tanstack/react-query";
|
||||
import { CloudUpload } from "lucide-react";
|
||||
import { BackupPassActivityNotice } from "@/components/admin/backup-pass-activity";
|
||||
import { SettingsCard } from "@/components/settings/settings-card";
|
||||
import { SettingsCardHeader } from "@/components/settings/_card-header";
|
||||
import { Badge } from "@/components/ui/badge";
|
||||
@@ -182,6 +183,7 @@ export function OffhostBackupsSection() {
|
||||
/>
|
||||
) : offhost ? (
|
||||
<div className="space-y-2">
|
||||
<BackupPassActivityNotice activity={offhost.activity} />
|
||||
<ul className="space-y-2" data-slot="offhost-backup-rows">
|
||||
{offhost.rows.map((row) => (
|
||||
<AccountRow key={row.userId} row={row} />
|
||||
|
||||
@@ -242,6 +242,9 @@ export const WIPE_MODELS = [
|
||||
// (`requestOffhostPurge`); this row, saying when they were written, is about
|
||||
// this account and goes with it.
|
||||
"OffhostBackupState",
|
||||
// Where this account stands in the two backup passes. About this account,
|
||||
// and meaningless without it.
|
||||
"BackupPassAttempt",
|
||||
"AuditLog",
|
||||
"ConsentReceipt",
|
||||
"UserKnownDevice",
|
||||
|
||||
@@ -706,6 +706,8 @@ export const NOT_IN_BACKUP_MODELS: Readonly<Record<string, string>> = {
|
||||
"The record of a restore this host ran from one of its own stored copies. It names a backup row that exists only in this database, so carrying it would describe a restore the receiving host never performed.",
|
||||
OffhostBackupState:
|
||||
"When this host last put this account's copy in this operator's bucket, and how big it was. It describes one deployment's relationship with one bucket, so restoring it elsewhere would assert an off-host copy that host has never written.",
|
||||
BackupPassAttempt:
|
||||
"When this host's backup passes last started and finished this account, kept so a pass the process died under is taken last next time and named on the backups page. It describes this deployment's own runs, so restoring it elsewhere would report an interrupted run that host never had, or hide one it did.",
|
||||
DocumentImportKey:
|
||||
"The source keys of imported documents the person deleted and the purge then removed, kept so a re-run of the importer does not store them again. The backup carries only live documents, so the tombstones that hold the same memory before the purge do not travel either; carrying the ledger alone would restore half of one decision. After a restore, a deliberate re-import can bring such a document back, and the person deletes it again.",
|
||||
DocumentAiRun:
|
||||
|
||||
@@ -22,9 +22,14 @@ import { join } from "node:path";
|
||||
import { describe, expect, it } from "vitest";
|
||||
|
||||
import {
|
||||
BACKUP_HEARTBEAT_SECONDS,
|
||||
DATA_BACKUP_QUEUE,
|
||||
DATA_BACKUP_SEND_OPTIONS,
|
||||
} from "../data-backup-policy";
|
||||
import {
|
||||
OFFHOST_BACKUP_QUEUE,
|
||||
OFFHOST_BACKUP_SEND_OPTIONS,
|
||||
} from "../offhost-backup";
|
||||
|
||||
const read = (file: string) => readFileSync(join(process.cwd(), file), "utf8");
|
||||
|
||||
@@ -39,11 +44,28 @@ describe("data-backup — pg-boss send policy", () => {
|
||||
);
|
||||
});
|
||||
|
||||
it("the weekly schedule carries the policy", () => {
|
||||
it("notices a process that died under either pass within minutes, not hours", () => {
|
||||
// pg-boss refuses less than ten seconds; more than a few minutes and a
|
||||
// dead pass sits `active` for as long as an operator would look.
|
||||
expect(BACKUP_HEARTBEAT_SECONDS).toBeGreaterThanOrEqual(10);
|
||||
expect(BACKUP_HEARTBEAT_SECONDS).toBeLessThanOrEqual(10 * 60);
|
||||
expect(DATA_BACKUP_SEND_OPTIONS.heartbeatSeconds).toBe(
|
||||
BACKUP_HEARTBEAT_SECONDS,
|
||||
);
|
||||
expect(OFFHOST_BACKUP_QUEUE).toBe("data-backup-offhost");
|
||||
expect(OFFHOST_BACKUP_SEND_OPTIONS.heartbeatSeconds).toBe(
|
||||
BACKUP_HEARTBEAT_SECONDS,
|
||||
);
|
||||
});
|
||||
|
||||
it("the weekly and nightly schedules carry the policy", () => {
|
||||
const source = read("src/lib/jobs/reminder/register-maintenance.ts");
|
||||
expect(source).toMatch(
|
||||
/\[\s*DATA_BACKUP_QUEUE,\s*DATA_BACKUP_CRON,\s*DATA_BACKUP_SEND_OPTIONS,?\s*\]/,
|
||||
);
|
||||
expect(source).toMatch(
|
||||
/\[\s*OFFHOST_BACKUP_QUEUE,\s*OFFHOST_BACKUP_CRON,\s*OFFHOST_BACKUP_SEND_OPTIONS,?\s*\]/,
|
||||
);
|
||||
});
|
||||
|
||||
it("the admin run-now route sends with the same policy", () => {
|
||||
|
||||
@@ -0,0 +1,45 @@
|
||||
/**
|
||||
* A backup job whose process died is failed by pg-boss's heartbeat monitor
|
||||
* with three bare words. The backups page shows the run's error, so the words
|
||||
* have to say what happened and where to look.
|
||||
*/
|
||||
import { beforeEach, describe, expect, it, vi } from "vitest";
|
||||
|
||||
const queryRaw = vi.hoisted(() => vi.fn());
|
||||
vi.mock("@/lib/db", () => ({
|
||||
prisma: { $queryRaw: (...a: unknown[]) => queryRaw(...a) },
|
||||
}));
|
||||
|
||||
import { readLastQueueRun, readQueueRunningSince } from "../job-failures";
|
||||
|
||||
beforeEach(() => queryRaw.mockReset());
|
||||
|
||||
describe("a backup run the process died under", () => {
|
||||
it("explains a heartbeat timeout instead of repeating it", async () => {
|
||||
queryRaw.mockResolvedValue([
|
||||
{
|
||||
state: "failed",
|
||||
completed_on: new Date("2026-10-04T02:40:00Z"),
|
||||
output: "job heartbeat timeout",
|
||||
expire_seconds: 7200,
|
||||
},
|
||||
]);
|
||||
const run = await readLastQueueRun("data-backup");
|
||||
expect(run?.state).toBe("failed");
|
||||
expect(run?.error).toMatch(/^job heartbeat timeout: /);
|
||||
expect(run?.error).toMatch(/restarted or ran out of memory/);
|
||||
});
|
||||
|
||||
it("says since when a run is in progress, and nothing when none is", async () => {
|
||||
queryRaw.mockResolvedValueOnce([
|
||||
{ started_on: new Date("2026-10-04T02:30:00Z") },
|
||||
]);
|
||||
expect(await readQueueRunningSince("data-backup")).toBe(
|
||||
"2026-10-04T02:30:00.000Z",
|
||||
);
|
||||
queryRaw.mockResolvedValueOnce([]);
|
||||
expect(await readQueueRunningSince("data-backup")).toBeNull();
|
||||
queryRaw.mockRejectedValueOnce(new Error('schema "pgboss" does not exist'));
|
||||
expect(await readQueueRunningSince("data-backup")).toBeNull();
|
||||
});
|
||||
});
|
||||
@@ -262,6 +262,49 @@ describe("runOffhostBackup", () => {
|
||||
expect(first.create.lastSuccessAt).toBeInstanceOf(Date);
|
||||
});
|
||||
|
||||
it("takes an account whose last attempt never came back last", async () => {
|
||||
const s3 = makeS3Mock();
|
||||
const attempts = {
|
||||
findMany: vi.fn().mockResolvedValue([
|
||||
// u1's last walk started and never finished: the process died
|
||||
// under it, and walking by id would put it first again.
|
||||
{
|
||||
userId: "u1",
|
||||
startedAt: new Date("2026-05-07T03:00:00Z"),
|
||||
finishedAt: null,
|
||||
},
|
||||
]),
|
||||
upsert: vi.fn().mockResolvedValue({}),
|
||||
updateMany: vi.fn().mockResolvedValue({ count: 1 }),
|
||||
};
|
||||
const prisma = {
|
||||
...purgeLedgerMocks(),
|
||||
offhostBackupState: { upsert: vi.fn() },
|
||||
backupPassAttempt: attempts,
|
||||
user: {
|
||||
count: vi.fn().mockResolvedValue(1),
|
||||
findMany: vi.fn().mockResolvedValue([{ id: "u1" }, { id: "u2" }]),
|
||||
},
|
||||
};
|
||||
|
||||
const report = await runOffhostBackup(
|
||||
// eslint-disable-next-line @typescript-eslint/no-explicit-any
|
||||
prisma as any,
|
||||
s3,
|
||||
new Date("2026-05-08T03:00:00Z"),
|
||||
);
|
||||
expect(report.uploaded).toBe(2);
|
||||
expect(s3.putStream.mock.calls.map(([key]) => key)).toEqual([
|
||||
"2026-05-08/user-u2.json.enc",
|
||||
"2026-05-08/user-u1.json.enc",
|
||||
]);
|
||||
expect(attempts.findMany).toHaveBeenCalledWith(
|
||||
expect.objectContaining({ where: { pass: "data-backup-offhost" } }),
|
||||
);
|
||||
expect(attempts.upsert).toHaveBeenCalledTimes(2);
|
||||
expect(attempts.updateMany).toHaveBeenCalledTimes(2);
|
||||
});
|
||||
|
||||
it("takes back the copy of an account deleted while it was written", async () => {
|
||||
const s3 = makeS3Mock();
|
||||
const ledger = purgeLedgerMocks();
|
||||
|
||||
@@ -0,0 +1,145 @@
|
||||
/**
|
||||
* Where each account stands in a backup pass that walks every account, so a
|
||||
* pass the process died under is noticed and does not die the same way again.
|
||||
*
|
||||
* Why. Both backup passes walk the accounts one after another in one job.
|
||||
* When an account's record kills the process (the container runs out of
|
||||
* memory), the job is left `active`, and its retry walks the accounts in the
|
||||
* same order: the weekly pass takes the oldest copy first, which is the very
|
||||
* account that never got a new one, and the off-host pass walks by id. The
|
||||
* same account kills the retry, and every account after it goes without a
|
||||
* copy for as long as that account stays too large.
|
||||
*
|
||||
* What this does. The pass writes `startedAt` before it starts an account and
|
||||
* `finishedAt` once it is past it, whatever the outcome it caught. A start
|
||||
* newer than the finish is an attempt that never came back: the next pass
|
||||
* takes that account last, after everybody else has their copy, and the admin
|
||||
* backups page names it. Every write and read here is best effort: the marker
|
||||
* is bookkeeping about a backup, and must never be the reason one fails.
|
||||
*/
|
||||
import type { PrismaClient } from "@/generated/prisma/client";
|
||||
|
||||
/** The pass's queue name, which is also the marker's key. */
|
||||
export type BackupPass = "data-backup" | "data-backup-offhost";
|
||||
|
||||
type Db = Pick<PrismaClient, "backupPassAttempt">;
|
||||
|
||||
export async function markBackupAttemptStarted(
|
||||
prisma: Db,
|
||||
pass: BackupPass,
|
||||
userId: string,
|
||||
at: Date = new Date(),
|
||||
): Promise<void> {
|
||||
try {
|
||||
await prisma.backupPassAttempt.upsert({
|
||||
where: { userId_pass: { userId, pass } },
|
||||
update: { startedAt: at },
|
||||
create: { userId, pass, startedAt: at },
|
||||
});
|
||||
} catch {
|
||||
// Bookkeeping only; an account deleted meanwhile has no row to write.
|
||||
}
|
||||
}
|
||||
|
||||
export async function markBackupAttemptFinished(
|
||||
prisma: Db,
|
||||
pass: BackupPass,
|
||||
userId: string,
|
||||
at: Date = new Date(),
|
||||
): Promise<void> {
|
||||
try {
|
||||
await prisma.backupPassAttempt.updateMany({
|
||||
where: { userId, pass },
|
||||
data: { finishedAt: at },
|
||||
});
|
||||
} catch {
|
||||
// Bookkeeping only.
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* The accounts whose last attempt in `pass` started and never finished, with
|
||||
* when it started. Empty when the table cannot be read.
|
||||
*/
|
||||
export async function readInterruptedBackupAttempts(
|
||||
prisma: Db,
|
||||
pass: BackupPass,
|
||||
): Promise<Map<string, Date>> {
|
||||
try {
|
||||
const rows = await prisma.backupPassAttempt.findMany({
|
||||
where: { pass },
|
||||
select: { userId: true, startedAt: true, finishedAt: true },
|
||||
});
|
||||
return new Map(
|
||||
rows
|
||||
.filter(
|
||||
(row) => row.finishedAt === null || row.finishedAt < row.startedAt,
|
||||
)
|
||||
.map((row) => [row.userId, row.startedAt]),
|
||||
);
|
||||
} catch {
|
||||
return new Map();
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* `accounts` in their order, with every interrupted one moved behind the
|
||||
* rest; among those, the one interrupted longest ago first.
|
||||
*/
|
||||
export function orderInterruptedLast<T extends { id: string }>(
|
||||
accounts: readonly T[],
|
||||
interrupted: ReadonlyMap<string, Date>,
|
||||
): T[] {
|
||||
const clean = accounts.filter((account) => !interrupted.has(account.id));
|
||||
const last = accounts
|
||||
.filter((account) => interrupted.has(account.id))
|
||||
.sort(
|
||||
(a, b) =>
|
||||
interrupted.get(a.id)!.getTime() - interrupted.get(b.id)!.getTime(),
|
||||
);
|
||||
return [...clean, ...last];
|
||||
}
|
||||
|
||||
/** What the admin backups page shows about one pass while it runs or after. */
|
||||
export interface BackupPassActivity {
|
||||
/** When the run in progress started; null when none is running. */
|
||||
runningSince: string | null;
|
||||
/**
|
||||
* Accounts whose last attempt started and never finished, oldest first.
|
||||
* The account the run in progress is on right now is not among them.
|
||||
*/
|
||||
interrupted: Array<{ userId: string; username: string; startedAt: string }>;
|
||||
}
|
||||
|
||||
export async function readBackupPassActivity(
|
||||
prisma: Db & Pick<PrismaClient, "user">,
|
||||
pass: BackupPass,
|
||||
runningSince: string | null,
|
||||
): Promise<BackupPassActivity> {
|
||||
const attempts = await readInterruptedBackupAttempts(prisma, pass);
|
||||
const since = runningSince === null ? null : new Date(runningSince);
|
||||
// An attempt the run in progress started is the account it is on now.
|
||||
const stuck = [...attempts].filter(
|
||||
([, startedAt]) => since === null || startedAt < since,
|
||||
);
|
||||
if (stuck.length === 0) return { runningSince, interrupted: [] };
|
||||
const names = new Map(
|
||||
(
|
||||
await prisma.user.findMany({
|
||||
where: { id: { in: stuck.map(([userId]) => userId) } },
|
||||
select: { id: true, username: true },
|
||||
})
|
||||
).map((user) => [user.id, user.username]),
|
||||
);
|
||||
return {
|
||||
runningSince,
|
||||
interrupted: stuck
|
||||
.filter(([userId]) => names.has(userId))
|
||||
.sort(([, a], [, b]) => a.getTime() - b.getTime())
|
||||
.map(([userId, startedAt]) => ({
|
||||
userId,
|
||||
username: names.get(userId)!,
|
||||
startedAt: startedAt.toISOString(),
|
||||
})),
|
||||
};
|
||||
}
|
||||
@@ -34,6 +34,22 @@
|
||||
|
||||
export const DATA_BACKUP_QUEUE = "data-backup";
|
||||
|
||||
/**
|
||||
* How long a backup job may go without a sign of life before pg-boss fails it
|
||||
* (and retries it, within `retryLimit`). The worker refreshes the heartbeat
|
||||
* every half of this while the handler runs, so only a process that died under
|
||||
* the job stops it: a restart, or a container killed for memory. Without it
|
||||
* such a job sat `active` until its expiry, two hours for this pass and four
|
||||
* for the off-host one, and the admin page showed nothing wrong in between.
|
||||
*
|
||||
* Five minutes rather than pg-boss's floor of ten seconds: the refresh is a
|
||||
* timer on the event loop, and serialising one large section of a record can
|
||||
* hold the loop for a while. A refresh every two and a half minutes survives
|
||||
* that; a crash is still noticed at the next supervision tick after five.
|
||||
*/
|
||||
export const BACKUP_HEARTBEAT_SECONDS = 5 * 60;
|
||||
|
||||
export const DATA_BACKUP_SEND_OPTIONS = {
|
||||
expireInSeconds: 2 * 60 * 60,
|
||||
heartbeatSeconds: BACKUP_HEARTBEAT_SECONDS,
|
||||
} as const;
|
||||
@@ -76,6 +76,9 @@ interface FailingQueueRow {
|
||||
*/
|
||||
const TIMEOUT_MESSAGE = /^(job timed out|handler execution exceeded \d+s)$/;
|
||||
|
||||
/** What pg-boss writes when a job with a heartbeat stopped sending one. */
|
||||
const HEARTBEAT_MESSAGE = /^job heartbeat timeout$/;
|
||||
|
||||
/**
|
||||
* Say what a bare timeout means. "job timed out" alone sent an operator
|
||||
* nowhere: pg-boss writes the same words for a pass that was too slow for its
|
||||
@@ -111,6 +114,13 @@ function presentError(
|
||||
if (trimmed.length === 0) return "";
|
||||
if (TIMEOUT_MESSAGE.test(trimmed))
|
||||
return explainTimeout(trimmed, expireSeconds);
|
||||
if (HEARTBEAT_MESSAGE.test(trimmed)) {
|
||||
return (
|
||||
`${trimmed}: the process running it stopped answering, most often ` +
|
||||
`because the app restarted or ran out of memory while it ran; a restart ` +
|
||||
`shows in the container's restart count and log.`
|
||||
);
|
||||
}
|
||||
const redacted = redactSecrets(trimmed);
|
||||
return redacted.length > MAX_ERROR_CHARS
|
||||
? `${redacted.slice(0, MAX_ERROR_CHARS)}…`
|
||||
@@ -339,3 +349,27 @@ export async function readActiveJobsStartedBefore(
|
||||
return null;
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* When the run of `queue` that is in progress now started, or null when none
|
||||
* is (or the queue schema cannot be read). The oldest active job, so a retry
|
||||
* of a run reads as the run it continues only once it has been picked up.
|
||||
*/
|
||||
export async function readQueueRunningSince(
|
||||
queue: string,
|
||||
): Promise<string | null> {
|
||||
try {
|
||||
const rows = await prisma.$queryRaw<Array<{ started_on: Date | null }>>`
|
||||
SELECT started_on
|
||||
FROM pgboss.job
|
||||
WHERE name = ${queue}
|
||||
AND state = 'active'
|
||||
AND started_on IS NOT NULL
|
||||
ORDER BY started_on ASC
|
||||
LIMIT 1
|
||||
`;
|
||||
return rows[0]?.started_on?.toISOString() ?? null;
|
||||
} catch {
|
||||
return null;
|
||||
}
|
||||
}
|
||||
@@ -35,6 +35,13 @@ import type { PrismaClient } from "@/generated/prisma/client";
|
||||
import { createRawStreamEncryptor, decryptRawStream } from "@/lib/crypto";
|
||||
import { createBackupKeyIdTextScanner } from "@/lib/export/backup-key-ids";
|
||||
import { streamFullBackupJson } from "@/lib/export/full-backup-stream";
|
||||
import {
|
||||
markBackupAttemptFinished,
|
||||
markBackupAttemptStarted,
|
||||
orderInterruptedLast,
|
||||
readInterruptedBackupAttempts,
|
||||
} from "@/lib/jobs/backup-pass-attempts";
|
||||
import { BACKUP_HEARTBEAT_SECONDS } from "@/lib/jobs/data-backup-policy";
|
||||
import { annotate, getEvent } from "@/lib/logging/context";
|
||||
import { envValue } from "@/lib/env";
|
||||
|
||||
@@ -51,6 +58,18 @@ const TAG_LENGTH = 16;
|
||||
*/
|
||||
export const OFFHOST_BACKUP_EXPIRE_SECONDS = 4 * 60 * 60;
|
||||
|
||||
export const OFFHOST_BACKUP_QUEUE = "data-backup-offhost";
|
||||
|
||||
/**
|
||||
* What the nightly schedule sends with: the four hours above, and the
|
||||
* heartbeat that notices a process that died under the pass within minutes
|
||||
* rather than at the end of them (`BACKUP_HEARTBEAT_SECONDS`).
|
||||
*/
|
||||
export const OFFHOST_BACKUP_SEND_OPTIONS = {
|
||||
expireInSeconds: OFFHOST_BACKUP_EXPIRE_SECONDS,
|
||||
heartbeatSeconds: BACKUP_HEARTBEAT_SECONDS,
|
||||
} as const;
|
||||
|
||||
export interface OffhostBackupConfig {
|
||||
endpoint: string;
|
||||
bucket: string;
|
||||
@@ -909,10 +928,17 @@ export async function runOffhostBackup(
|
||||
// eslint-disable-next-line healthlog/no-utc-day-key -- UTC by design: off-host object key date, the name the restore drill and the purge look up
|
||||
const dateKey = (runStartedAt ?? now).toISOString().slice(0, 10);
|
||||
|
||||
const users = await prisma.user.findMany({
|
||||
select: { id: true },
|
||||
orderBy: { id: "asc" },
|
||||
});
|
||||
// By id, with an account whose last walk never came back behind the rest:
|
||||
// a record that killed the process once would otherwise lead every retry
|
||||
// and keep every account after it out of the bucket
|
||||
// (`backup-pass-attempts.ts`).
|
||||
const users = orderInterruptedLast(
|
||||
await prisma.user.findMany({
|
||||
select: { id: true },
|
||||
orderBy: { id: "asc" },
|
||||
}),
|
||||
await readInterruptedBackupAttempts(prisma, OFFHOST_BACKUP_QUEUE),
|
||||
);
|
||||
const doneThisRun = new Set<string>();
|
||||
if (runStartedAt) {
|
||||
const done = await prisma.offhostBackupState.findMany({
|
||||
@@ -946,6 +972,12 @@ export async function runOffhostBackup(
|
||||
// admin encryption view uses them to say how long a retired key is still
|
||||
// needed for what is in the bucket.
|
||||
const keyScanner = createBackupKeyIdTextScanner();
|
||||
await markBackupAttemptStarted(
|
||||
prisma,
|
||||
OFFHOST_BACKUP_QUEUE,
|
||||
user.id,
|
||||
accountStartedAt,
|
||||
);
|
||||
try {
|
||||
objectBytes = await uploadEncryptedBackup(
|
||||
s3,
|
||||
@@ -998,6 +1030,10 @@ export async function runOffhostBackup(
|
||||
evt?.addWarning(
|
||||
`offhost-backup user ${user.id} failed: ${message.slice(0, 200)}`,
|
||||
);
|
||||
} finally {
|
||||
// Past this account, whatever the outcome: only a process that died
|
||||
// under it leaves the start without a finish.
|
||||
await markBackupAttemptFinished(prisma, OFFHOST_BACKUP_QUEUE, user.id);
|
||||
}
|
||||
|
||||
// The per-account ledger, and deliberately NOT inside the upload's `try`.
|
||||
|
||||
@@ -259,7 +259,7 @@ export const QUEUE_RUNTIME: Readonly<Record<string, QueueRuntime>> = {
|
||||
"data-backup-offhost": {
|
||||
runtime: "long",
|
||||
expireInSeconds: OFFHOST_BACKUP_EXPIRE_SECONDS,
|
||||
expiryVia: ["OFFHOST_BACKUP_EXPIRE_SECONDS"],
|
||||
expiryVia: ["OFFHOST_BACKUP_SEND_OPTIONS"],
|
||||
stop: {
|
||||
file: "lib/jobs/reminder/backup-handlers.ts",
|
||||
fn: "handleOffhostBackup",
|
||||
|
||||
@@ -71,6 +71,11 @@ function buildPrismaMock(
|
||||
return {
|
||||
user: { findMany: vi.fn().mockResolvedValue(users) },
|
||||
dataBackup: { findMany: vi.fn().mockResolvedValue([]) },
|
||||
backupPassAttempt: {
|
||||
findMany: vi.fn().mockResolvedValue([]),
|
||||
upsert: vi.fn().mockResolvedValue({}),
|
||||
updateMany: vi.fn().mockResolvedValue({ count: 1 }),
|
||||
},
|
||||
};
|
||||
}
|
||||
|
||||
@@ -278,4 +283,44 @@ describe("handleDataBackup on a large instance", () => {
|
||||
did: { backed: 2, stopped_early: true },
|
||||
});
|
||||
});
|
||||
|
||||
it("takes an account whose last attempt never came back last, and marks every attempt", async () => {
|
||||
const prisma = buildPrismaMock([
|
||||
{ id: "big", username: "big" },
|
||||
{ id: "small", username: "small" },
|
||||
{ id: "other", username: "other" },
|
||||
]);
|
||||
// `big` has the oldest copy, so it would lead; its last attempt started
|
||||
// and never finished: the process died under it.
|
||||
prisma.dataBackup.findMany.mockResolvedValue([
|
||||
{ userId: "big", createdAt: new Date("2026-08-01T00:00:00Z") },
|
||||
{ userId: "small", createdAt: new Date("2026-09-01T00:00:00Z") },
|
||||
{ userId: "other", createdAt: new Date("2026-09-02T00:00:00Z") },
|
||||
]);
|
||||
prisma.backupPassAttempt.findMany.mockResolvedValue([
|
||||
{
|
||||
userId: "big",
|
||||
startedAt: new Date("2026-09-28T02:00:00Z"),
|
||||
finishedAt: new Date("2026-09-21T02:30:00Z"),
|
||||
},
|
||||
{
|
||||
userId: "small",
|
||||
startedAt: new Date("2026-09-21T02:31:00Z"),
|
||||
finishedAt: new Date("2026-09-21T02:32:00Z"),
|
||||
},
|
||||
]);
|
||||
mocks.getWorkerPrisma.mockReturnValue(prisma);
|
||||
|
||||
await handleDataBackup([]);
|
||||
|
||||
const order = mocks.store.mock.calls.map(
|
||||
([input]) => (input as { userId: string }).userId,
|
||||
);
|
||||
expect(order).toEqual(["small", "other", "big"]);
|
||||
expect(prisma.backupPassAttempt.findMany).toHaveBeenCalledWith(
|
||||
expect.objectContaining({ where: { pass: "data-backup" } }),
|
||||
);
|
||||
expect(prisma.backupPassAttempt.upsert).toHaveBeenCalledTimes(3);
|
||||
expect(prisma.backupPassAttempt.updateMany).toHaveBeenCalledTimes(3);
|
||||
});
|
||||
});
|
||||
@@ -23,6 +23,13 @@ import {
|
||||
} from "@/lib/jobs/offhost-backup";
|
||||
import { getWorkerPrisma } from "./shared";
|
||||
import { reportJobProgress } from "@/lib/jobs/job-observer";
|
||||
import {
|
||||
markBackupAttemptFinished,
|
||||
markBackupAttemptStarted,
|
||||
orderInterruptedLast,
|
||||
readInterruptedBackupAttempts,
|
||||
} from "@/lib/jobs/backup-pass-attempts";
|
||||
import { DATA_BACKUP_QUEUE } from "@/lib/jobs/data-backup-policy";
|
||||
|
||||
export interface DataBackupPayload {
|
||||
triggeredAt: string;
|
||||
@@ -141,20 +148,31 @@ export async function handleDataBackup(
|
||||
return withBackgroundEvent("job.data_backup", async (evt) => {
|
||||
const prisma = getWorkerPrisma();
|
||||
try {
|
||||
const [accounts, copies] = await Promise.all([
|
||||
const [accounts, copies, interrupted] = await Promise.all([
|
||||
prisma.user.findMany({ select: { id: true, username: true } }),
|
||||
prisma.dataBackup.findMany({
|
||||
where: { type: "WEEKLY_AUTO" },
|
||||
select: { userId: true, createdAt: true },
|
||||
}),
|
||||
readInterruptedBackupAttempts(prisma, DATA_BACKUP_QUEUE),
|
||||
]);
|
||||
const copiedAt = new Map(
|
||||
copies.map((copy) => [copy.userId, copy.createdAt.getTime()]),
|
||||
);
|
||||
// No copy yet sorts first, then the oldest copy.
|
||||
const users = [...accounts].sort(
|
||||
(a, b) => (copiedAt.get(a.id) ?? -1) - (copiedAt.get(b.id) ?? -1),
|
||||
// No copy yet sorts first, then the oldest copy. An account whose last
|
||||
// attempt never came back goes behind all of them: it is the one with
|
||||
// the oldest copy, so it would lead every retry, and a record that
|
||||
// killed the process once would keep every account after it from a
|
||||
// copy (`backup-pass-attempts.ts`).
|
||||
const users = orderInterruptedLast(
|
||||
[...accounts].sort(
|
||||
(a, b) => (copiedAt.get(a.id) ?? -1) - (copiedAt.get(b.id) ?? -1),
|
||||
),
|
||||
interrupted,
|
||||
);
|
||||
if (interrupted.size > 0) {
|
||||
evt.addMeta("data_backup_interrupted_accounts", interrupted.size);
|
||||
}
|
||||
let stoppedEarly = false;
|
||||
|
||||
let backed = 0;
|
||||
@@ -176,6 +194,7 @@ export async function handleDataBackup(
|
||||
backup_users_done: backed + usersFailed + skippedRestoring,
|
||||
backup_users_total: users.length,
|
||||
});
|
||||
await markBackupAttemptStarted(prisma, DATA_BACKUP_QUEUE, user.id);
|
||||
try {
|
||||
// Streamed, compressed, then encrypted (the record contains
|
||||
// sensitive health information), and stored a piece at a time.
|
||||
@@ -226,6 +245,10 @@ export async function handleDataBackup(
|
||||
lastError = err;
|
||||
if (err instanceof BackupBlobTooLargeError) oversized++;
|
||||
evt.addWarning(`Failed for user ${user.id}: ${err}`);
|
||||
} finally {
|
||||
// Past this account, whatever the outcome: only a process that died
|
||||
// under it leaves the start without a finish.
|
||||
await markBackupAttemptFinished(prisma, DATA_BACKUP_QUEUE, user.id);
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@@ -36,7 +36,10 @@ import {
|
||||
} from "@/lib/jobs/pr-detection";
|
||||
import { jobBudget } from "@/lib/jobs/job-budget";
|
||||
import { lockedPass, WHOLE_PASS } from "@/lib/jobs/long-pass";
|
||||
import { OFFHOST_BACKUP_EXPIRE_SECONDS } from "@/lib/jobs/offhost-backup";
|
||||
import {
|
||||
OFFHOST_BACKUP_QUEUE,
|
||||
OFFHOST_BACKUP_SEND_OPTIONS,
|
||||
} from "@/lib/jobs/offhost-backup";
|
||||
import {
|
||||
MEDICATION_INVENTORY_EXPIRE_QUEUE,
|
||||
MEDICATION_INVENTORY_EXPIRE_CRON,
|
||||
@@ -291,7 +294,6 @@ const AUDIT_LOG_CLEANUP_CRON = "15 3 * * *"; // daily at 03:15 (Europe/Berlin)
|
||||
|
||||
const INTAKE_SLOT_DEDUP_CRON = "28 3 * * *";
|
||||
|
||||
const OFFHOST_BACKUP_QUEUE = "data-backup-offhost";
|
||||
// 02:30 Europe/Berlin — runs after audit-log/idempotency cleanups so old
|
||||
// rows are gone before they're snapshotted, but before the existing
|
||||
// in-DB DATA_BACKUP at 03:00 (Sundays only) so the off-host copy is
|
||||
@@ -568,11 +570,7 @@ const schedules: ScheduleEntry[] = [
|
||||
STEP_UP_ELEVATION_CLEANUP_CRON,
|
||||
cronIsTheRetry,
|
||||
],
|
||||
[
|
||||
OFFHOST_BACKUP_QUEUE,
|
||||
OFFHOST_BACKUP_CRON,
|
||||
{ expireInSeconds: OFFHOST_BACKUP_EXPIRE_SECONDS },
|
||||
],
|
||||
[OFFHOST_BACKUP_QUEUE, OFFHOST_BACKUP_CRON, OFFHOST_BACKUP_SEND_OPTIONS],
|
||||
[RESTORE_DRILL_QUEUE, RESTORE_DRILL_CRON],
|
||||
// Nightly backstop for the purge the deletion kicks straight away: a
|
||||
// request the bucket refused, or one written while the queue was down.
|
||||
|
||||
@@ -9,6 +9,7 @@
|
||||
* both sides a route-handler-independent shared type home; the route
|
||||
* keeps owning the HTTP contract, the component keeps owning the UI.
|
||||
*/
|
||||
import type { BackupPassActivity } from "@/lib/jobs/backup-pass-attempts";
|
||||
import type { BackupScheduleStatus } from "@/lib/jobs/backup-schedule-status";
|
||||
import type { OffhostBackupFreshness } from "@/lib/jobs/offhost-backup-freshness";
|
||||
|
||||
@@ -54,6 +55,8 @@ export interface OffhostAccountRow {
|
||||
export interface OffhostBackupOverview {
|
||||
/** Whether this host has the variables the nightly job needs. */
|
||||
configured: boolean;
|
||||
/** The run in progress, and accounts a run died under. */
|
||||
activity: BackupPassActivity;
|
||||
/** Hours between two scheduled runs — the number behind the verdicts. */
|
||||
periodHours: number;
|
||||
/** One row per account. Empty when off-host backup is not configured. */
|
||||
@@ -87,6 +90,11 @@ export interface BackupsList {
|
||||
* made six weeks ago and one made on Sunday look identical in a table.
|
||||
*/
|
||||
schedule: BackupScheduleStatus;
|
||||
/**
|
||||
* The weekly run in progress, and accounts a run died under: a start
|
||||
* without a finish, which a crash leaves and a caught failure does not.
|
||||
*/
|
||||
scheduleActivity: BackupPassActivity;
|
||||
/**
|
||||
* The off-host leg. A weekly row in this table says the copy that lives in
|
||||
* this database is current; it says nothing about whether anything reached
|
||||
|
||||
Reference in new issue
Block a user