diff --git a/prisma/migrations/0479_retry_failed_local_pdf_index/migration.sql b/prisma/migrations/0479_retry_failed_local_pdf_index/migration.sql new file mode 100644 index 000000000..1ef661170 --- /dev/null +++ b/prisma/migrations/0479_retry_failed_local_pdf_index/migration.sql @@ -0,0 +1,32 @@ +-- Queue one more content-index attempt for every PDF whose last one failed in +-- a way a pdf.js clash produces. +-- +-- Until this release the server could load two pdf.js versions. Once a page +-- render had claimed the in-process pdf.js worker, every later local text read +-- failed until a restart, which the index records as `decrypt-error`; the +-- other way round, a scanned PDF the picked provider could only read as images +-- failed to rasterize and was recorded as `raster-failed`. Neither document has +-- a content index, so neither is found by search, and on an instance without a +-- configured AI provider nothing offers to index it again. +-- +-- The marker is the state no index attempt ever leaves behind: a failure +-- reason with no attempt time (the recorder always writes both). The boot +-- discovery `document-index-retry` enqueues the auto-index job for exactly +-- those rows, through the same provider-first, local-fallback decision and the +-- same consent rules as an upload. The attempt writes its time back, so the +-- row drops out whatever the outcome: a document that really cannot be read +-- records its reason again and stays settled. +-- +-- Only PDFs without an index and with a recorded attempt are touched; running +-- this again queues those that failed once more for one more attempt. +UPDATE "inbound_documents" AS d + SET "last_index_attempt_at" = NULL + WHERE d."deleted_at" IS NULL + AND d."mime_type" = 'application/pdf' + AND d."last_index_outcome" IN ('decrypt-error', 'raster-failed') + AND d."last_index_attempt_at" IS NOT NULL + AND NOT EXISTS ( + SELECT 1 + FROM "document_content_index" AS c + WHERE c."document_id" = d."id" + ); diff --git a/src/lib/jobs/document-index-retry.ts b/src/lib/jobs/document-index-retry.ts new file mode 100644 index 000000000..4df8c08e0 --- /dev/null +++ b/src/lib/jobs/document-index-retry.ts @@ -0,0 +1,62 @@ +/** + * Boot discovery: one more content-index attempt for the documents a + * migration marked for it. + * + * Migration 0479 marks a PDF whose last index attempt failed the way a pdf.js + * clash made it fail by clearing its attempt time and keeping its failure + * reason. No index attempt leaves that state behind (`recordIndexAttempt` + * always writes both), so the mark selects exactly those documents and + * nothing a person or a job produced. + * + * Each marked document gets the auto-index job an upload enqueues, so it runs + * the same provider-first, local-fallback decision under the same consent + * rules: a deferred import stays local because the document row says so, and + * an external provider reads it only when the owner opted into automatic + * reads. The attempt writes its time back, so the document drops out whatever + * the outcome, and a document that really cannot be read records its reason + * again and is not picked up at the next boot. An account whose documents + * module is off keeps its marks until the module is on again; a boot with + * nothing marked costs one query. + */ +import { prisma } from "@/lib/db"; +import { enqueueDocumentIndex } from "@/lib/jobs/document-index"; +import { annotate } from "@/lib/logging/context"; +import { isModuleEnabled } from "@/lib/modules/gate"; + +/** Documents enqueued per boot; the rest wait for the next one. */ +const MAX_ENQUEUES_PER_BOOT = 1000; + +export async function enqueueBootTimeIndexRetry(): Promise<{ + enqueued: number; +}> { + const rows = await prisma.inboundDocument.findMany({ + where: { + deletedAt: null, + lastIndexAttemptAt: null, + lastIndexOutcome: { not: null }, + contentIndex: { is: null }, + }, + select: { id: true, userId: true }, + orderBy: { id: "asc" }, + take: MAX_ENQUEUES_PER_BOOT, + }); + + const moduleOn = new Map(); + let enqueued = 0; + for (const { id, userId } of rows) { + let on = moduleOn.get(userId); + if (on === undefined) { + on = await isModuleEnabled(userId, "inboundDocuments"); + moduleOn.set(userId, on); + } + if (!on) continue; + const { enqueued: ok } = await enqueueDocumentIndex(userId, id); + if (ok) enqueued += 1; + } + + annotate({ + action: { name: "documents.contentIndex.retry.boot" }, + meta: { marked: rows.length, enqueued }, + }); + return { enqueued }; +} diff --git a/src/lib/jobs/registry/maintenance-discovery.ts b/src/lib/jobs/registry/maintenance-discovery.ts index aa137ea13..c0f2c41e2 100644 --- a/src/lib/jobs/registry/maintenance-discovery.ts +++ b/src/lib/jobs/registry/maintenance-discovery.ts @@ -1,9 +1,10 @@ /** * The boot discovery of the maintenance group: the duplicate dose-slot - * cleanup, the encryption backfills, the thumbnail backfill, the air-quality - * history, the fold repair and the purge that waits for it, the GeoLite2 - * fetch, and the detached climb backfill. Each pass is idempotent across - * boots; the heavy ones start past the boot storm. + * cleanup, the encryption backfills, the thumbnail backfill, the marked + * document index retry, the air-quality history, the fold repair and the + * purge that waits for it, the GeoLite2 fetch, and the detached climb + * backfill. Each pass is idempotent across boots; the heavy ones start past + * the boot storm. */ import { BOOT_BACKFILL_STAGGER_SECONDS } from "@/lib/jobs/reminder/shared"; @@ -53,6 +54,14 @@ export const MAINTENANCE_DISCOVERY: readonly BootDiscovery[] = [ return { enqueued }; }, }, + // Only the documents a migration marked; a boot with none costs one query. + { + name: "document-index-retry", + run: async () => + ( + await import("@/lib/jobs/document-index-retry") + ).enqueueBootTimeIndexRetry(), + }, { name: "environment-aq-history", run: async () => diff --git a/tests/integration/pdfjs-clash-recovery.test.ts b/tests/integration/pdfjs-clash-recovery.test.ts new file mode 100644 index 000000000..dd9da8f93 --- /dev/null +++ b/tests/integration/pdfjs-clash-recovery.test.ts @@ -0,0 +1,292 @@ +/** + * Migrations 0478 and 0479: what a pdf.js clash left behind gets one more try + * after the update, through the paths that run on their own. + * + * While the server loaded two pdf.js versions, whichever ran first broke the + * other until a restart. Previews failed as `raster-failed`, which the + * thumbnail backfill treats as final, and local text reads failed as + * `decrypt-error`, which nothing on an instance without an AI provider ever + * retries. The rows are seeded the way such an instance holds them, the data + * step is read out of each migration file and executed, and then only what a + * boot runs on its own is called: the boot discovery and the jobs it enqueues. + * The renderer, the text reader and the database are real; the queue records + * what was sent, and the test runs each job it holds. + */ +import { readFileSync } from "node:fs"; +import path from "node:path"; + +import { jsPDF } from "jspdf"; +import { beforeEach, describe, expect, it, vi } from "vitest"; + +const sends = vi.hoisted(() => [] as Array<{ queue: string; data: unknown }>); + +vi.mock("@/lib/documents/native-canvas-support", () => ({ + nativeCanvasSupported: () => true, +})); +vi.mock("@/lib/jobs/boss-instance", () => ({ + getGlobalBoss: () => ({ + send: async (queue: string, data: unknown) => { + sends.push({ queue, data }); + return `job-${sends.length}`; + }, + }), +})); + +import { encryptDocumentContent } from "@/lib/documents/store"; +import { + runDocumentIndex, + type DocumentIndexPayload, +} from "@/lib/jobs/document-index"; +import { enqueueBootTimeIndexRetry } from "@/lib/jobs/document-index-retry"; +import { runDocumentThumbnail } from "@/lib/jobs/document-thumbnail"; +import { + enqueueBootTimeThumbnailBackfill, + runThumbnailBackfillForUser, + type ThumbnailBackfillPayload, +} from "@/lib/jobs/document-thumbnail-backfill"; +import { MAINTENANCE_DISCOVERY } from "@/lib/jobs/registry/maintenance-discovery"; +import { getPrismaClient, truncateAllTables } from "./setup"; + +const prisma = getPrismaClient(); +const USER_ID = "pdfjs-clash-owner"; + +/** The one data statement of a migration file, comments removed. */ +function migrationStep(name: string): string { + const sql = readFileSync( + path.join(process.cwd(), "prisma", "migrations", name, "migration.sql"), + "utf8", + ) + .split("\n") + .filter((line) => !line.trimStart().startsWith("--")) + .join("\n") + .trim(); + const statements = sql.split(";").filter((s) => s.trim().length > 0); + expect(statements, name).toHaveLength(1); + return statements[0]!; +} + +/** Run one pass of the worker's boot discovery, found by its name. */ +async function boot(name: string): Promise { + const pass = MAINTENANCE_DISCOVERY.find((d) => d.name === name); + expect(pass, `boot discovery ${name}`).toBeDefined(); + const result = await pass!.run(); + return Number(result?.enqueued ?? 0); +} + +const LETTER = readFileSync( + path.join(process.cwd(), "tests", "fixtures", "pdf", "fallback-fonts.pdf"), +); + +function textPdf(): Buffer { + const doc = new jsPDF(); + doc.text("Discharge letter creatinine 0.9 mg/dL haemoglobin 14.2", 10, 10); + return Buffer.from(doc.output("arraybuffer")); +} + +async function seedPdf( + id: string, + bytes: Buffer, + extra: { lastIndexOutcome?: string; lastIndexAttemptAt?: Date } = {}, + corrupt = false, +) { + const { content, codec } = encryptDocumentContent(bytes); + if (corrupt) content[Math.floor(content.length / 2)] ^= 0xff; + await prisma.inboundDocument.create({ + data: { + id, + userId: USER_ID, + mimeType: "application/pdf", + byteSize: bytes.length, + contentEncrypted: content, + contentCodec: codec, + title: id, + ...extra, + }, + }); +} + +function takeSends(queue: string): unknown[] { + const taken = sends.filter((s) => s.queue === queue).map((s) => s.data); + sends.length = 0; + return taken; +} + +beforeEach(async () => { + await truncateAllTables(prisma); + sends.length = 0; + await prisma.user.create({ + data: { id: USER_ID, username: "pdfjs-clash-owner" }, + }); +}); + +describe("0478: previews that failed to rasterize", () => { + it("are rendered again by the boot backfill, once", async () => { + await seedPdf("doc-letter", LETTER); + await prisma.documentThumbnailFailure.create({ + data: { + documentId: "doc-letter", + userId: USER_ID, + reason: "raster-failed", + attempts: 1, + failedAt: new Date(), + }, + }); + // Final as stored: no boot finds it. + expect((await enqueueBootTimeThumbnailBackfill()).enqueued).toBe(0); + + await prisma.$executeRawUnsafe( + migrationStep("0478_retry_raster_failed_thumbnails"), + ); + + expect(await boot("document-thumbnail-backfill")).toBe(1); + const [backfill] = takeSends("document-thumbnail-backfill") as [ + ThumbnailBackfillPayload, + ]; + await runThumbnailBackfillForUser(backfill.userId); + const jobs = takeSends("document-thumbnail") as Array<{ + userId: string; + documentId: string; + }>; + expect(jobs.map((j) => j.documentId)).toEqual(["doc-letter"]); + await runDocumentThumbnail(jobs[0]!); + + expect( + await prisma.documentThumbnail.count({ + where: { documentId: "doc-letter" }, + }), + ).toBe(1); + expect(await prisma.documentThumbnailFailure.count()).toBe(0); + expect((await enqueueBootTimeThumbnailBackfill()).enqueued).toBe(0); + }); + + it("leaves a page that really renders blank settled after its one retry", async () => { + const blank = readFileSync( + path.join( + process.cwd(), + "tests", + "fixtures", + "pdf", + "invisible-text-only.pdf", + ), + ); + await seedPdf("doc-blank", blank); + await prisma.documentThumbnailFailure.create({ + data: { + documentId: "doc-blank", + userId: USER_ID, + reason: "raster-failed", + attempts: 1, + failedAt: new Date(), + }, + }); + await prisma.$executeRawUnsafe( + migrationStep("0478_retry_raster_failed_thumbnails"), + ); + expect((await enqueueBootTimeThumbnailBackfill()).enqueued).toBe(1); + takeSends("document-thumbnail-backfill"); + await runThumbnailBackfillForUser(USER_ID); + const jobs = takeSends("document-thumbnail") as Array<{ + userId: string; + documentId: string; + }>; + await runDocumentThumbnail(jobs[0]!); + + const failure = await prisma.documentThumbnailFailure.findUnique({ + where: { documentId: "doc-blank" }, + }); + expect(failure).toMatchObject({ reason: "raster-failed", attempts: 1 }); + expect((await enqueueBootTimeThumbnailBackfill()).enqueued).toBe(0); + }); +}); + +describe("0479: PDFs whose local text read failed", () => { + it("indexes a readable one and settles an unreadable one after one retry", async () => { + const failedAt = new Date("2026-10-20T10:00:00.000Z"); + const failed = { + lastIndexOutcome: "decrypt-error", + lastIndexAttemptAt: failedAt, + }; + await seedPdf("doc-text", textPdf(), failed); + await seedPdf("doc-cipher-broken", textPdf(), failed, true); + await seedPdf("doc-not-a-pdf", Buffer.from("not a pdf at all"), failed); + // Never attempted, and a failure no clash produces: both left alone. + await seedPdf("doc-never", textPdf()); + await seedPdf("doc-scan", textPdf(), { + lastIndexOutcome: "local-empty", + lastIndexAttemptAt: failedAt, + }); + + expect((await enqueueBootTimeIndexRetry()).enqueued).toBe(0); + + await prisma.$executeRawUnsafe( + migrationStep("0479_retry_failed_local_pdf_index"), + ); + + expect(await boot("document-index-retry")).toBe(3); + const jobs = takeSends("document-index") as DocumentIndexPayload[]; + expect(jobs.map((j) => j.documentId).sort()).toEqual([ + "doc-cipher-broken", + "doc-not-a-pdf", + "doc-text", + ]); + // The upload's job, not a narrower one: no local-only flag. + expect(jobs.every((j) => j.localOnly === undefined)).toBe(true); + for (const job of jobs) await runDocumentIndex(job); + + const rows = await prisma.inboundDocument.findMany({ + select: { + id: true, + lastIndexOutcome: true, + lastIndexAttemptAt: true, + contentIndex: { select: { source: true } }, + }, + orderBy: { id: "asc" }, + }); + const byId = Object.fromEntries(rows.map((r) => [r.id, r])); + expect(byId["doc-text"]).toMatchObject({ + lastIndexOutcome: null, + contentIndex: { source: "local-pdf" }, + }); + for (const id of ["doc-cipher-broken", "doc-not-a-pdf"]) { + expect(byId[id]!.contentIndex, id).toBeNull(); + expect(byId[id]!.lastIndexOutcome, id).toBe("decrypt-error"); + expect(byId[id]!.lastIndexAttemptAt!.getTime(), id).toBeGreaterThan( + failedAt.getTime(), + ); + } + expect(byId["doc-never"]).toMatchObject({ + lastIndexAttemptAt: null, + lastIndexOutcome: null, + contentIndex: null, + }); + expect(byId["doc-scan"]).toMatchObject({ + lastIndexOutcome: "local-empty", + lastIndexAttemptAt: failedAt, + }); + + // Every later boot finds nothing. + expect((await enqueueBootTimeIndexRetry()).enqueued).toBe(0); + expect(takeSends("document-index")).toEqual([]); + }); + + it("keeps the mark while the documents module is off", async () => { + await seedPdf("doc-text", textPdf(), { + lastIndexOutcome: "decrypt-error", + lastIndexAttemptAt: new Date(), + }); + await prisma.$executeRawUnsafe( + migrationStep("0479_retry_failed_local_pdf_index"), + ); + await prisma.user.update({ + where: { id: USER_ID }, + data: { modulePreferencesJson: { inboundDocuments: false } }, + }); + expect((await enqueueBootTimeIndexRetry()).enqueued).toBe(0); + expect( + await prisma.inboundDocument.findUnique({ + where: { id: "doc-text" }, + select: { lastIndexAttemptAt: true }, + }), + ).toEqual({ lastIndexAttemptAt: null }); + }); +});