Merge branch 'fix/v1437-r2-jobs' into release/v1.43.7

tests/integration/heavy-lane-defer.test.ts

@@ -0,0 +1,147 @@
+/**
+ * The heavy lane against a real pg-boss on a real Postgres: a heavy job that
+ * finds the lane taken goes back to its queue, keeps its id and its attempt,
+ * is not settled by pg-boss's completion of the handler that sent it back,
+ * and does not spend its expiry while it waits.
+ *
+ * The case it replaces: a job that waited in the handler ran its expiry down
+ * while it stood in line, because pg-boss counts the expiry from the fetch.
+ * Here the holder runs for six seconds against a two-second expiry on the
+ * waiting job; the waiting job still runs once, after the holder, without a
+ * single failed attempt.
+ */
+import { afterAll, beforeAll, describe, expect, it } from "vitest";
+import { PgBoss, type Job } from "pg-boss";
+
+import { prisma } from "@/lib/db";
+import { deferLaneJobs, heavyLane } from "@/lib/jobs/heavy-lane";
+import { jobDone } from "@/lib/jobs/job-outcome";
+
+let boss: PgBoss;
+
+const HOLDER_QUEUE = "data-backup-offhost";
+const WAITER_QUEUE = "data-backup";
+const WORK = { localConcurrency: 1, pollingIntervalSeconds: 0.5 } as const;
+
+const sleep = (ms: number) => new Promise((r) => setTimeout(r, ms));
+
+beforeAll(async () => {
+  boss = new PgBoss({ connectionString: process.env.DATABASE_URL });
+  await boss.start();
+  await boss.createQueue(HOLDER_QUEUE);
+  await boss.createQueue(WAITER_QUEUE);
+}, 120_000);
+
+afterAll(async () => {
+  await boss?.stop({ graceful: false });
+});
+
+async function row(id: string) {
+  const rows = await prisma.$queryRaw<
+    Array<{
+      state: string;
+      retry_count: number;
+      started_on: Date | null;
+      future: boolean;
+    }>
+  >`
+    SELECT state::text AS state, retry_count, started_on,
+           start_after > now() AS future
+    FROM pgboss.job WHERE id = ${id}::uuid
+  `;
+  return rows[0];
+}
+
+describe("deferLaneJobs", () => {
+  it("returns an active job to created, later, at the same attempt", async () => {
+    const id = await boss.send(WAITER_QUEUE, { probe: 1 });
+    const [fetched] = await boss.fetch(WAITER_QUEUE);
+    expect(fetched?.id).toBe(id);
+    expect((await row(id!))?.state).toBe("active");
+
+    expect(await deferLaneJobs(WAITER_QUEUE, [fetched!], 30)).toBe(1);
+    expect(await row(id!)).toMatchObject({
+      state: "created",
+      retry_count: 0,
+      started_on: null,
+      future: true,
+    });
+    // Not claimable before its time.
+    expect(await boss.fetch(WAITER_QUEUE)).toEqual([]);
+    // pg-boss's completion of the handler finds no active row to settle.
+    await boss.complete(WAITER_QUEUE, id!);
+    expect((await row(id!))?.state).toBe("created");
+    await boss.deleteJob(WAITER_QUEUE, id!);
+  });
+
+  it("leaves a job alone that is no longer active", async () => {
+    const id = await boss.send(WAITER_QUEUE, { probe: 2 });
+    const job = { id, name: WAITER_QUEUE, data: {} } as unknown as Job<object>;
+    expect(await deferLaneJobs(WAITER_QUEUE, [job], 30)).toBe(0);
+    expect((await row(id!))?.future).toBe(false);
+    await boss.deleteJob(WAITER_QUEUE, id!);
+  });
+});
+
+describe("a heavy job behind a long one", () => {
+  it("waits in the queue, not in the handler, and runs once after it", async () => {
+    const log: string[] = [];
+    const deliveries: string[] = [];
+    const shortDefer = (queue: string, jobs: readonly Job<unknown>[]) =>
+      deferLaneJobs(queue, jobs, 1);
+
+    await boss.work(
+      HOLDER_QUEUE,
+      WORK,
+      heavyLane(
+        HOLDER_QUEUE,
+        async () => {
+          log.push("start:holder");
+          await sleep(6_000);
+          log.push("end:holder");
+          return jobDone({ jobs: 1 });
+        },
+        undefined,
+        shortDefer,
+      ),
+    );
+    await boss.work(
+      WAITER_QUEUE,
+      WORK,
+      heavyLane(
+        WAITER_QUEUE,
+        async () => {
+          log.push("run:waiter");
+          return jobDone({ jobs: 1 });
+        },
+        undefined,
+        async (queue, jobs) => {
+          deliveries.push(jobs[0]!.id);
+          return shortDefer(queue, jobs);
+        },
+      ),
+    );
+
+    await boss.send(HOLDER_QUEUE, {}, { expireInSeconds: 60 });
+    await sleep(1_000);
+    const waiter = await boss.send(
+      WAITER_QUEUE,
+      {},
+      { expireInSeconds: 2, retryLimit: 0 },
+    );
+
+    await sleep(9_000);
+    await boss.offWork(WAITER_QUEUE);
+    await boss.offWork(HOLDER_QUEUE);
+
+    // Three times its expiry in line, and not a single failed attempt.
+    expect(await row(waiter!)).toMatchObject({
+      state: "completed",
+      retry_count: 0,
+    });
+    // Sent back several times while the holder ran, then run once after it.
+    expect(deliveries.length).toBeGreaterThanOrEqual(2);
+    expect(new Set(deliveries)).toEqual(new Set([waiter]));
+    expect(log).toEqual(["start:holder", "end:holder", "run:waiter"]);
+  }, 60_000);
+});

tests/integration/integration-status.test.ts

@@ -3,13 +3,9 @@
  *
  * The unit suite (`src/lib/integrations/__tests__/status.test.ts`)
  * mocks Prisma. This file lights up the real driver so we lock in the
- * upsert + concurrent-write story AND prove that every sync failure
- * writes one `AuditLog` row with the documented schema:
- *
- *   action  : "integrations.sync.failed"
- *   userId  : <subject>
- *   details : { integration, kind, errorCode, message,
- *               attemptNumber, state }
+ * upsert + concurrent-write story, and that a sync failure leaves the audit
+ * log alone: it emits an `integrations.sync.failed` signal instead, and the
+ * provider's message stays sealed on the status row.
  *
  * The dispatcher is mocked at module level so we don't actually hit
  * Telegram while testing — the assertion is on the alerting side
@@ -34,6 +30,11 @@ vi.mock("@/lib/db-compat", () => ({
 // configs and call sendViaTelegram. We're not testing that path —
 // B3 owns it. Stub returns void so the helper's await chain
 // resolves cleanly.
+vi.mock("@/lib/logging/signal", async (importOriginal) => {
+  const actual = await importOriginal<typeof import("@/lib/logging/signal")>();
+  return { ...actual, emitSignal: vi.fn(actual.emitSignal) };
+});
+
 vi.mock("@/lib/notifications/dispatcher", () => ({
   dispatchNotification: vi.fn().mockResolvedValue({
     dispatched: true,
@@ -53,6 +54,7 @@ import {
   resumeIntegrationFromPark,
 } from "@/lib/integrations/status";
 import { dispatchNotification } from "@/lib/notifications/dispatcher";
+import { emitSignal } from "@/lib/logging/signal";
 
 const TEST_USER_ID = "user-integration-status-e2e";
 
@@ -66,6 +68,7 @@ beforeEach(async () => {
     },
   });
   vi.mocked(dispatchNotification).mockClear();
+  vi.mocked(emitSignal).mockClear();
 });
 
 describe("IntegrationStatus end-to-end", () => {
@@ -103,16 +106,19 @@ describe("IntegrationStatus end-to-end", () => {
     const audits = await getPrismaClient().auditLog.findMany({
       where: { action: "integrations.sync.failed", userId: TEST_USER_ID },
     });
-    expect(audits).toHaveLength(1);
-    const detailsParsed = JSON.parse(audits[0].details ?? "{}");
-    expect(detailsParsed).toMatchObject({
-      integration: "withings",
-      kind: "transient",
-      errorCode: "503",
-      message: "Withings refresh error: 503 - upstream",
-      attemptNumber: 1,
-      state: "error_transient",
-    });
+    expect(audits).toHaveLength(0);
+    expect(emitSignal).toHaveBeenCalledWith(
+      expect.objectContaining({
+        action: "integrations.sync.failed",
+        meta: expect.objectContaining({
+          integration: "withings",
+          kind: "transient",
+          error_code: "503",
+          attempt_number: 1,
+          state: "error_transient",
+        }),
+      }),
+    );
   });
 
   it("getIntegrationStatus returns plaintext error after roundtrip (decryption succeeds)", async () => {

tests/integration/integration-sync-escalation.test.ts

@@ -30,6 +30,11 @@ vi.mock("@/lib/db-compat", () => ({
   ensureDbCompatibility: vi.fn().mockResolvedValue(undefined),
 }));
 
+vi.mock("@/lib/logging/signal", async (importOriginal) => {
+  const actual = await importOriginal<typeof import("@/lib/logging/signal")>();
+  return { ...actual, emitSignal: vi.fn(actual.emitSignal) };
+});
+
 vi.mock("@/lib/notifications/dispatcher", () => ({
   dispatchNotification: vi.fn().mockResolvedValue(undefined),
 }));
@@ -40,6 +45,7 @@ import {
   recordSyncFailure,
   recordSyncSuccess,
 } from "@/lib/integrations/status";
+import { emitSignal } from "@/lib/logging/signal";
 
 const TEST_USER_ID = "user-sync-escalation";
 const HOUR_MS = 60 * 60 * 1000;
@@ -85,6 +91,7 @@ async function failTransient(integration: string, leg?: string) {
 }
 
 beforeEach(async () => {
+  vi.mocked(emitSignal).mockClear();
   await truncateAllTables(getPrismaClient());
   await getPrismaClient().user.create({
     data: {
@@ -124,15 +131,15 @@ describe("failure escalation", () => {
     });
     expect(current!.persistentFailureStartedAt).toBeInstanceOf(Date);
 
-    const audits = await getPrismaClient().auditLog.findMany({
-      where: { action: "integrations.sync.failed", userId: TEST_USER_ID },
-      orderBy: { createdAt: "asc" },
-    });
-    const last = JSON.parse(audits[audits.length - 1]!.details ?? "{}");
+    const signals = vi
+      .mocked(emitSignal)
+      .mock.calls.map(([signal]) => signal)
+      .filter((signal) => signal.action === "integrations.sync.failed");
+    const last = signals[signals.length - 1]!.meta!;
     expect(last.kind).toBe("persistent");
-    // The trail keeps the classifier's own verdict, so an operator can tell
+    // The signal keeps the classifier's own verdict, so an operator can tell
     // "the upstream said this was permanent" from "we concluded it was".
-    expect(last.escalatedFrom).toBe("transient");
+    expect(last.escalated_from).toBe("transient");
   });
 
   it("parks the escalated streak a further window later and stops attempting", async () => {

tests/integration/measurement-hot-update.test.ts

@@ -7,9 +7,12 @@
  * grew the table by a full row version and an entry in every index. Proven
  * here against Postgres: the no-op update keeps `updated_at` and
  * `sync_version` and is counted as HOT in the transaction's own statistics,
- * a real change still moves both, and the nightly check reads the table's
- * statistics and vacuums only when dead rows pass its threshold.
+ * a real change still moves both, the nightly check reads the table's
+ * statistics and leaves the vacuuming to autovacuum, and the migration gives
+ * up on a lock it cannot get instead of queueing every writer behind it.
  */
+import { readFileSync } from "node:fs";
+import { join } from "node:path";
 import { Client } from "pg";
 import { beforeEach, describe, expect, it } from "vitest";
 
@@ -100,7 +103,7 @@ describe("an update that changes nothing", () => {
 });
 
 describe("the nightly check", () => {
-  it("reads the statistics and does nothing while no vacuum is due", async () => {
+  it("reads the statistics and leaves the vacuuming to autovacuum", async () => {
     await seedReading();
     const db = new Client({ connectionString: process.env.DATABASE_URL });
     await db.connect();
@@ -108,7 +111,7 @@ describe("the nightly check", () => {
       await db.query("ANALYZE measurements");
       const health = await tableHealth(db);
       expect(health.heapBytes).toBeGreaterThan(0);
-      const steps = resolveSteps({}, health);
+      const steps = resolveSteps({});
       expect(steps).toEqual({ vacuum: false, reindex: false });
       const summary = await runMeasurementMaintenance(db, steps);
       expect(summary.outcome).toBe("nothing_due");
@@ -118,3 +121,46 @@ describe("the nightly check", () => {
     }
   });
 });
+
+describe("the migration's lock wait", () => {
+  it("fails within its lock timeout while another session holds the table", async () => {
+    // The migration's own text under fresh names, run the way `migrate
+    // deploy` runs a file: one multi-statement query, one transaction.
+    const sql = readFileSync(
+      join(
+        process.cwd(),
+        "prisma/migrations/0412_measurement_hot_updates/migration.sql",
+      ),
+      "utf8",
+    )
+      .replaceAll("measurements_keep_stamps_on_noop", "lock_probe_fn")
+      .replaceAll("measurements_noop_update_keeps_stamps", "lock_probe_trg");
+    const holder = new Client({ connectionString: process.env.DATABASE_URL });
+    const migrator = new Client({ connectionString: process.env.DATABASE_URL });
+    await holder.connect();
+    await migrator.connect();
+    try {
+      // What an anti-wraparound autovacuum holds, and does not give up.
+      await holder.query("BEGIN");
+      await holder.query(
+        "LOCK TABLE measurements IN SHARE UPDATE EXCLUSIVE MODE",
+      );
+      const startedAt = Date.now();
+      const error = await migrator.query(sql).then(
+        () => null,
+        (err: { code?: string }) => err,
+      );
+      expect(error?.code).toBe("55P03");
+      expect(Date.now() - startedAt).toBeLessThan(30_000);
+      // Rolled back whole: nothing of the probe is left behind.
+      const { rows } = await migrator.query(
+        "SELECT to_regproc('lock_probe_fn') AS fn",
+      );
+      expect(rows[0].fn).toBeNull();
+    } finally {
+      await holder.query("ROLLBACK").catch(() => {});
+      await holder.end();
+      await migrator.end();
+    }
+  }, 60_000);
+});

tests/integration/measurements-batch.test.ts

@@ -1266,7 +1266,7 @@ describe("POST /api/measurements/batch (real Postgres)", () => {
       });
     });
 
-    it("re-imports an XML estimate onto one row with monotonic syncVersion", async () => {
+    it("re-imports an XML estimate onto one row without moving its syncVersion", async () => {
       const prisma = getPrismaClient();
       const xmlPath = writeCumulativeXml();
       await streamParseExportXml({
@@ -1288,11 +1288,15 @@ describe("POST /api/measurements/batch (real Postgres)", () => {
           externalId: "stats:HKQuantityTypeIdentifierStepCount:2026-07-20",
         },
       });
+      // The second import writes the same value, provenance and every other
+      // column, so the update changes nothing and migration 0412 keeps the
+      // row's stamps: the phone is not sent a row that did not change. The
+      // version never goes backwards; it stays where the first import left it.
       expect(rows).toHaveLength(1);
       expect(rows[0]).toMatchObject({
         value: 8_526,
         aggregationProvenance: "EXPORT_XML_SOURCE_MAX",
-        syncVersion: 2,
+        syncVersion: 1,
       });
     });