fix(documents): keep document reads inside their job's expiry

Since the lab staging reads a long report in parts, one auto-index could
make the transcription plus up to twenty reads of two calls each at the
person's response timeout, hours past pg-boss's fifteen-minute default,
which failed the job and retried it beside the reads still running. The
staging now takes the run's deadline as a schedule and plans only the
reads that fit before it. The index job is long, with an expiry above the
calls that run before the plan can say no, a stop on jobDeadline and a
lock per document; the document run hands the same staging its own
deadline, which moves the run's expiry as the reads are planned. The
document summary, one call and its reasoning repeat, gets an expiry above
that worst case.

ocrReadCallMs in the read core is the one per-call timeout both deadlines
divide by. The expiry guard now names every importer of the document and
lab read entry points with the queues that reach it.

The runtime guard's planted cases stripped every file's comments again on
each rescan, which took over a second alone and timed out under a full
parallel run; the stripped text is now memoised.

Refs #1274

src/__tests__/ai-job-expiry-guard.test.ts

@@ -11,13 +11,17 @@
  * workout line and the Coach memory pass could each do the same once a status
  * run waited for its reasoning repeat.
  *
- * Two entry points carry every background model run at the person's
- * timeout: `runStatusCompletion` (a status run, `STATUS_MODEL_CALLS` calls)
- * and `generateComprehensiveInsight` (`COMPREHENSIVE_MODEL_CALLS` calls). The
- * guard holds:
+ * The entry points that carry a background model run at the person's
+ * timeout: `runStatusCompletion` (a status run, `STATUS_MODEL_CALLS` calls),
+ * `generateComprehensiveInsight` (`COMPREHENSIVE_MODEL_CALLS` calls), and the
+ * document and lab reads: `runOcrReads` (a report's reads, as many as the
+ * run's deadline allows, or up to `OCR_MAX_PAGES` without one),
+ * `transcribeDocument`, `runDocumentSummary`, `runDocumentAssist` and
+ * `executeSupplementLabelExtraction`. The guard holds:
  *
  *   1. every file that imports one of them is named below with the queues
- *      whose jobs reach it, so a new caller has to be attributed;
+ *      whose jobs reach it, or as a request surface with its reason, so a new
+ *      caller has to be attributed;
  *   2. each of those queues is `bounded` in `queue-runtime.ts`, with model
  *      time at least the runs it makes at the largest setting and an expiry
  *      above that, or `long`, where the run's lock makes the retry after an
@@ -26,13 +30,16 @@
  *
  * Its limit: the run counts per queue are declared here, not derived; the
  * Coach memory refresh's three runs, for instance, are three calls in
- * `runCoachMemoryRefresh` that a reader has to count. Model calls outside the
- * two entry points (the document and lab runs, the reaction line, the nudge)
- * keep their own deadlines and are not covered here.
+ * `runCoachMemoryRefresh` that a reader has to count. A `long` queue is held
+ * to its lock, not to arithmetic: its reads are planned against the job's
+ * deadline (`jobDeadline`), which `document-index.test.ts` and the document
+ * run's own tests prove. Model calls outside these entry points (the
+ * reaction line and the nudge, both under a fixed surface ceiling) are not
+ * covered here.
  *
- * Mutation check: declare `morning-digest-refresh` short again, drop a run
- * from a queue's model time, or import `runStatusCompletion` into a new file,
- * and this goes red. The "plants" case runs the check over the table as it
+ * Mutation check: declare `morning-digest-refresh` or `document-index` short
+ * again, drop a run from a queue's model time, or import `runStatusCompletion`
+ * or `runOcrReads` into a new file, and this goes red. The "plants" case runs the check over the table as it
  * stood before #1274.
  */
 import { join } from "node:path";
@@ -46,6 +53,7 @@ import {
 } from "./helpers/source-files";
 import { QUEUE_RUNTIME, type QueueRuntime } from "@/lib/jobs/queue-runtime";
 import {
+  COMPLETION_CEILING_MS,
   COMPREHENSIVE_WARM_CEILING_MS,
   STATUS_RUN_CEILING_MS,
 } from "@/lib/jobs/model-time";
@@ -56,7 +64,15 @@ import {
 import { AI_RESPONSE_TIMEOUT_MAX_SECONDS } from "@/lib/ai/effective-timeout";
 
 const SRC = join(process.cwd(), "src");
-const ENTRY_POINTS = ["runStatusCompletion", "generateComprehensiveInsight"];
+const ENTRY_POINTS = [
+  "runStatusCompletion",
+  "generateComprehensiveInsight",
+  "runOcrReads",
+  "transcribeDocument",
+  "runDocumentSummary",
+  "runDocumentAssist",
+  "executeSupplementLabelExtraction",
+];
 
 /** Each importer of an entry point, and the queues whose jobs reach it. */
 const MODEL_RUN_SITES: Readonly<Record<string, readonly string[]>> = {
@@ -79,11 +95,39 @@ const MODEL_RUN_SITES: Readonly<Record<string, readonly string[]>> = {
   "lib/jobs/workout-insight-generate.ts": ["workout-insight-generate"],
   "lib/jobs/insight-pregenerate.ts": ["insight-pregenerate"],
   "lib/jobs/morning-digest-refresh.ts": ["morning-digest-refresh"],
+  "lib/documents/extract.ts": ["document-ai-run", "document-index"],
+  "lib/documents/index-document.ts": ["document-index", "document-ai-run"],
+  "lib/documents/ai-runs/index-run.ts": ["document-ai-run"],
+  "lib/documents/ai-runs/summary-run.ts": ["document-ai-run"],
+  "lib/documents/ai-runs/suggest-run.ts": ["document-ai-run"],
+  "lib/labs/ocr-extract.ts": ["document-ai-run"],
+  "lib/jobs/document-ai-run.ts": ["document-ai-run"],
+  "lib/jobs/document-content-index-backfill.ts": [
+    "document-content-index-backfill",
+  ],
+  "lib/jobs/document-summary.ts": ["document-summary"],
+};
+
+/**
+ * Importers no queue reaches: a request waits on them, and the browser's
+ * abort follows the published setting (`clientAbortMs`).
+ */
+const REQUEST_SITES: Readonly<Record<string, string>> = {
+  "app/api/documents/inbound/[id]/summary/route.ts":
+    "The on-demand transcription a person asked for; the background path runs through document-ai-run.",
 };
 
 /** What one job of a bounded queue runs, at most, one after another. */
 const RUNS: Readonly<
-  Record<string, { status?: number; comprehensive?: number; why: string }>
+  Record<
+    string,
+    {
+      status?: number;
+      comprehensive?: number;
+      completions?: number;
+      why: string;
+    }
+  >
 > = {
   "insight-status-generate": {
     status: 1,
@@ -101,6 +145,10 @@ const RUNS: Readonly<
     comprehensive: 1,
     why: "One forced comprehensive generation.",
   },
+  "document-summary": {
+    completions: 1,
+    why: "One summary call (DOCUMENT_SUMMARY_MODEL_CALLS) and its reasoning repeat.",
+  },
 };
 
 /** Value specifiers of every `import { … } from` in `text`. */
@@ -126,10 +174,15 @@ function importers(): string[] {
 }
 
 /** Seconds of model work `runs` makes at the largest setting. */
-function modelSecondsOf(runs: { status?: number; comprehensive?: number }) {
+function modelSecondsOf(runs: {
+  status?: number;
+  comprehensive?: number;
+  completions?: number;
+}) {
   return (
     ((runs.status ?? 0) * STATUS_RUN_CEILING_MS +
-      (runs.comprehensive ?? 0) * COMPREHENSIVE_WARM_CEILING_MS) /
+      (runs.comprehensive ?? 0) * COMPREHENSIVE_WARM_CEILING_MS +
+      (runs.completions ?? 0) * COMPLETION_CEILING_MS) /
     1000
   );
 }
@@ -177,8 +230,10 @@ function findings(table: Readonly<Record<string, QueueRuntime>>): string[] {
 describe("jobs that wait on the response timeout outlast it", () => {
   it("names every importer of a model run (an empty set is a failure)", () => {
     const found = importers();
-    expect(found.length).toBeGreaterThanOrEqual(10);
-    expect(found).toEqual(Object.keys(MODEL_RUN_SITES).sort());
+    expect(found.length).toBeGreaterThanOrEqual(20);
+    expect(found).toEqual(
+      [...Object.keys(MODEL_RUN_SITES), ...Object.keys(REQUEST_SITES)].sort(),
+    );
   });
 
   it("sizes the run ceilings from the largest setting and the call counts", () => {
@@ -200,6 +255,13 @@ describe("jobs that wait on the response timeout outlast it", () => {
     ).toEqual([]);
   });
 
+  it("names every request surface with a reason, and none twice", () => {
+    for (const [rel, why] of Object.entries(REQUEST_SITES)) {
+      expect(why.length, rel).toBeGreaterThan(30);
+      expect(rel in MODEL_RUN_SITES, rel).toBe(false);
+    }
+  });
+
   it("plants: the table before #1274 is caught", () => {
     const before: Record<string, QueueRuntime> = {
       ...QUEUE_RUNTIME,

src/__tests__/baselines/test-as-never.json

@@ -1,7 +1,7 @@
 {
   "$comment": "as never casts in tests, per test file under src/. Maintained by src/__tests__/test-realism-ratchet.test.ts.",
   "count": 524,
-  "total": 5490,
+  "total": 5489,
   "entries": {
     "__tests__/api/auth/login/mfa-branch.test.ts": 10,
     "__tests__/api/auth/mfa/verify.test.ts": 9,
@@ -433,7 +433,7 @@
     "lib/jobs/__tests__/data-arrival-worker.test.ts": 18,
     "lib/jobs/__tests__/document-ai-run.test.ts": 1,
     "lib/jobs/__tests__/document-content-index-backfill.test.ts": 29,
-    "lib/jobs/__tests__/document-index.test.ts": 6,
+    "lib/jobs/__tests__/document-index.test.ts": 5,
     "lib/jobs/__tests__/document-summary-reaper.test.ts": 1,
     "lib/jobs/__tests__/document-summary.test.ts": 19,
     "lib/jobs/__tests__/geo-backfill.test.ts": 1,

src/__tests__/job-queue-runtime-guard.test.ts

@@ -60,9 +60,20 @@ const source = new Map(
   files.map((f) => [f, readFileSync(join(SRC, f), "utf8")]),
 );
 
-/** Strip comments so documentation that quotes code never matches. */
+/**
+ * Strip comments so documentation that quotes code never matches. Memoised
+ * per text: the planted cases rescan the whole tree once per finding, and
+ * stripping every file again each time made that one case take seconds,
+ * past the default timeout under a full parallel run.
+ */
+const stripped = new Map<string, string>();
 function code(text: string): string {
-  return stripComments(text);
+  let out = stripped.get(text);
+  if (out === undefined) {
+    out = stripComments(text);
+    stripped.set(text, out);
+  }
+  return out;
 }
 
 /** Index just past the bracket that closes the one at `open`. */
@@ -326,9 +337,7 @@ describe("every queue declares its runtime", () => {
         { definitions: [planted({})], ...scan(texts(budgeted)) },
       ),
     ).toEqual(["planted-long: expiry 900s out of range"]);
-    // Each finding rescans every send in the tree; under a full parallel run
-    // that took six to nine seconds against the five-second default.
-  }, 30_000);
+  });
 });
 
 /**

src/__tests__/transcription-read-core-guard.test.ts

@@ -70,12 +70,18 @@ describe("transcription read core", () => {
     expect(setters).toEqual(["documents/ocr-read.ts"]);
   });
 
-  it("reads the per-read timeout in the core and in the deadline that plans the reads, nowhere else", () => {
+  it("reads the per-read timeout in the core only, and every deadline that plans reads asks it", () => {
     const readers = filesMatching(/\bAI_BUDGETS\.ocrExtract\.timeoutMs\b/);
-    requireFloor("files reading the transcription timeout", readers, 2);
-    expect(readers).toEqual([
-      "documents/ocr-read.ts",
+    requireFloor("files reading the transcription timeout", readers, 1);
+    expect(readers).toEqual(["documents/ocr-read.ts"]);
+    // The document run and the auto-index job divide their deadlines by the
+    // same per-call timeout the reads send (`ocrReadCallMs`).
+    const planners = filesMatching(/\bocrReadCallMs\s*\(/).filter(
+      (rel) => rel !== "documents/ocr-read.ts",
+    );
+    expect(planners).toEqual([
       "jobs/document-ai-run.ts",
+      "jobs/document-index.ts",
     ]);
   });