diff --git a/src/__tests__/background-task-settle-guard.test.ts b/src/__tests__/background-task-settle-guard.test.ts index 9ce3fa914..322c7dd6f 100644 --- a/src/__tests__/background-task-settle-guard.test.ts +++ b/src/__tests__/background-task-settle-guard.test.ts @@ -19,6 +19,18 @@ * `.catch()` / `.then()` whose handler writes to the console — the shape that * actually produced the failure. A background path that logs some other way, * or that logs from a callee rather than from the handler, is invisible to it. + * + * It was narrower than that until the window below was widened. An + * eight-line handler window and a five-line registration preamble were both + * measured against the sites that existed when the guard was written, and + * both cut through real code: the console write in `mood-rollups.ts` sits + * nine lines into its handler, so the sweep never saw the one detached + * `Promise.all` in the tree that was genuinely unregistered, and the + * registration in `fire-and-forget.ts` sits BELOW its handler rather than + * above it, so a site that is correct read as a violation. The window now + * spans a plausible handler body and registration counts wherever it wraps + * the statement — above the handle or on the line that files the settled + * result. */ import { describe, it, expect } from "vitest"; import { readFileSync } from "node:fs"; @@ -57,6 +69,37 @@ function sourceFiles(): string[] { .filter((rel) => !rel.endsWith(".test.ts") && !rel.endsWith(".test.tsx")); } +/** + * How far past the `.catch(` / `.then(` line a handler's console write still + * counts as this handler's. Twenty lines covers every handler body in the + * tree with room to spare; eight did not. + */ +const HANDLER_WINDOW = 20; + +const registers = (text: string) => /trackBackgroundTask\(/.test(text); + +/** + * The source lines that open a call still unclosed at the start of `line` — + * the chain of enclosing calls the handler sits inside, innermost last. + * + * Paren counting is a coarse reading of TypeScript: a `(` inside a string or a + * comment counts like any other. That costs nothing here, because the question + * asked of the result is only whether one of those lines names + * `trackBackgroundTask`, and a stray paren can at worst widen the chain by a + * line that does not. + */ +function enclosingOpenCallLines(source: string, line: number): string[] { + const lines = source.split("\n"); + const open: number[] = []; + for (let i = 0; i < line - 1; i += 1) { + for (const ch of lines[i]) { + if (ch === "(") open.push(i); + else if (ch === ")") open.pop(); + } + } + return open.map((i) => lines[i]); +} + /** Lines starting a `.catch()` / `.then()` whose handler writes to the console. */ function consoleWritingHandlers(): { file: string; line: number }[] { const found: { file: string; line: number }[] = []; @@ -64,7 +107,7 @@ function consoleWritingHandlers(): { file: string; line: number }[] { const lines = readFileSync(join(SRC, rel), "utf8").split("\n"); lines.forEach((line, index) => { if (!/\.(catch|then)\(/.test(line)) return; - const handler = lines.slice(index, index + 8).join("\n"); + const handler = lines.slice(index, index + HANDLER_WINDOW).join("\n"); if (!/console\.(log|warn|error|info|debug|trace)\(/.test(handler)) return; found.push({ file: rel, line: index + 1 }); }); @@ -149,11 +192,18 @@ describe("background-task settle contract", () => { const unregistered = sites.filter(({ file, line }) => { if (UNREGISTERED_BY_DESIGN.has(file)) return false; - const lines = readFileSync(join(SRC, file), "utf8").split("\n"); - // The registration wraps the handle, so it opens on one of the few lines - // above the `.catch(` / `.then(` the sweep matched. - const preamble = lines.slice(Math.max(0, line - 5), line).join("\n"); - return !/trackBackgroundTask\(/.test(preamble); + const source = readFileSync(join(SRC, file), "utf8"); + // Registered either by wrapping the handle — `trackBackgroundTask(` is + // then one of the calls still open where the handler starts, however + // many lines above that is — or by filing the settled handle just after + // the handler closes. Both shapes are in the tree; a fixed window above + // the match saw neither reliably. + if (enclosingOpenCallLines(source, line).some(registers)) return false; + const lines = source.split("\n"); + const trailer = lines + .slice(line, line + HANDLER_WINDOW + 5) + .filter((l) => registers(l)); + return trailer.length === 0; }); expect( diff --git a/src/lib/insights/__tests__/recovery-score.test.ts b/src/lib/insights/__tests__/recovery-score.test.ts index 375edd22d..12237c9aa 100644 --- a/src/lib/insights/__tests__/recovery-score.test.ts +++ b/src/lib/insights/__tests__/recovery-score.test.ts @@ -12,6 +12,18 @@ import { describe, it, expect, vi, beforeEach } from "vitest"; import type { Derived } from "@/lib/insights/derived/types"; import type { ReadinessValue } from "@/lib/insights/derived/readiness"; +/** + * The post-mutation tail reads the real `@/lib/db` client, not the fake this + * file injects, so a stored score opened a socket to a Postgres the unit job + * does not run. The attempt failed a few hundred milliseconds later and logged + * on the way out — after the test that started it had ended — which is how a + * green file tore its worker's RPC channel down mid-write. Stubbed here; + * `score-row.test.ts` asserts the wiring this stands for. + */ +vi.mock("@/lib/rollups/after-measurement-mutation", () => ({ + afterMeasurementMutation: vi.fn(async () => {}), +})); + const computeReadinessMock = vi.fn<(...args: unknown[]) => Promise>>(); diff --git a/src/lib/insights/__tests__/score-row.test.ts b/src/lib/insights/__tests__/score-row.test.ts index 63c4fb4f6..b21f2b2c9 100644 --- a/src/lib/insights/__tests__/score-row.test.ts +++ b/src/lib/insights/__tests__/score-row.test.ts @@ -14,6 +14,27 @@ vi.mock("@/lib/logging/context", () => ({ annotate: (...args: unknown[]) => annotateMock(...args), })); +/** + * The post-mutation tail talks to the real database, and this file does not. + * + * `upsertScoreRow` routes every stored score through + * `afterMeasurementMutation`, which reads the `@/lib/db` singleton rather than + * the client the caller injected. A unit test that hands in a fake Prisma + * therefore still opened a socket to a Postgres the unit job does not run: the + * attempt failed with ECONNREFUSED a few hundred milliseconds later and both + * legs logged on the way out, after the test that started them had ended. A + * console write that lands while the worker is closing its RPC channel fails + * the whole run with `EnvironmentTeardownError: Closing rpc while + * "onUserConsoleLog" was pending` — four of nine unit-suite failures in thirty + * days, every one of them with all tests green. Stubbing the tail removes the + * doomed I/O rather than the log line, and the call it made by accident is + * asserted below instead. + */ +vi.mock("@/lib/rollups/after-measurement-mutation", () => ({ + afterMeasurementMutation: vi.fn(async () => {}), +})); + +import { afterMeasurementMutation } from "@/lib/rollups/after-measurement-mutation"; import { scoreDayKey, scoreMeasuredAt, @@ -92,6 +113,31 @@ describe("upsertScoreRow", () => { measuredAt: arg.create.measuredAt, }); }); + + it("routes the written row through the shared post-mutation tail", async () => { + // v1.37.19 wiring: a score row is a Measurement like any other, so the + // (type, day) rollup bucket and the cached status assessment converge on + // the tick that wrote it. Pinned here rather than left to a live database + // call that no unit job can serve. + const prisma = { + measurement: { upsert: vi.fn().mockResolvedValue({}) }, + } as unknown as Parameters[0]; + + await upsertScoreRow(prisma, { + userId: "u1", + type: "STRAIN_SCORE", + externalIdPrefix: "strain:", + score: 42, + now: new Date("2026-06-02T03:00:00Z"), + }); + + expect(afterMeasurementMutation).toHaveBeenCalledWith("u1", [ + { + type: "STRAIN_SCORE", + measuredAt: new Date("2026-06-01T12:00:00.000Z"), + }, + ]); + }); }); describe("runScoreBatch", () => { diff --git a/src/lib/insights/__tests__/strain-score.test.ts b/src/lib/insights/__tests__/strain-score.test.ts index 1e47ca9f2..6ac225af0 100644 --- a/src/lib/insights/__tests__/strain-score.test.ts +++ b/src/lib/insights/__tests__/strain-score.test.ts @@ -10,6 +10,18 @@ */ import { describe, it, expect, vi, beforeEach } from "vitest"; +/** + * The post-mutation tail reads the real `@/lib/db` client, not the fake this + * file injects, so a stored score opened a socket to a Postgres the unit job + * does not run. The attempt failed a few hundred milliseconds later and logged + * on the way out — after the test that started it had ended — which is how a + * green file tore its worker's RPC channel down mid-write. Stubbed here; + * `score-row.test.ts` asserts the wiring this stands for. + */ +vi.mock("@/lib/rollups/after-measurement-mutation", () => ({ + afterMeasurementMutation: vi.fn(async () => {}), +})); + import { strainDayKey, strainExternalId, diff --git a/src/lib/insights/__tests__/stress-score.test.ts b/src/lib/insights/__tests__/stress-score.test.ts index 1427c4723..b5f5f5391 100644 --- a/src/lib/insights/__tests__/stress-score.test.ts +++ b/src/lib/insights/__tests__/stress-score.test.ts @@ -10,6 +10,18 @@ */ import { describe, it, expect, vi, beforeEach } from "vitest"; +/** + * The post-mutation tail reads the real `@/lib/db` client, not the fake this + * file injects, so a stored score opened a socket to a Postgres the unit job + * does not run. The attempt failed a few hundred milliseconds later and logged + * on the way out — after the test that started it had ended — which is how a + * green file tore its worker's RPC channel down mid-write. Stubbed here; + * `score-row.test.ts` asserts the wiring this stands for. + */ +vi.mock("@/lib/rollups/after-measurement-mutation", () => ({ + afterMeasurementMutation: vi.fn(async () => {}), +})); + const computeVitalsBaselineMock = vi.fn(); vi.mock("@/lib/insights/derived/baseline", () => ({ computeVitalsBaseline: (...args: unknown[]) => diff --git a/src/lib/rollups/mood-rollups.ts b/src/lib/rollups/mood-rollups.ts index 78596eea9..9f9986bd0 100644 --- a/src/lib/rollups/mood-rollups.ts +++ b/src/lib/rollups/mood-rollups.ts @@ -48,6 +48,7 @@ import { prisma } from "@/lib/db"; import { getGlobalBoss } from "@/lib/jobs/boss-instance"; import { annotate } from "@/lib/logging/context"; +import { trackBackgroundTask } from "@/lib/logging/background-tasks"; import { startOfUtcDay } from "@/lib/tz/start-of-utc-day"; import type { Prisma, @@ -307,25 +308,30 @@ export async function recomputeMoodBucketsForEntry( // off the pg-boss critical path. Errors stay caught inside // `enqueueMoodRollupRecompute` so the unhandled-rejection logger // captures any pg-boss failure. - void Promise.all( - ASYNC_GRANULARITIES.map((granularity) => { - const { from, to } = bucketSpan(dateLabel, granularity); - return enqueueMoodRollupRecompute({ - userId, - granularity, - from, - to, - }).catch((err: unknown) => { - const message = err instanceof Error ? err.message : String(err); - annotate({ - meta: { - mood_rollup_enqueue_failed: true, - mood_rollup_enqueue_error: message, - }, + // Registered so the test suite can await it: the error below is a console + // write on a detached handle, and one that lands while a vitest worker is + // closing its RPC channel fails the whole run. No-op outside test. + trackBackgroundTask( + Promise.all( + ASYNC_GRANULARITIES.map((granularity) => { + const { from, to } = bucketSpan(dateLabel, granularity); + return enqueueMoodRollupRecompute({ + userId, + granularity, + from, + to, + }).catch((err: unknown) => { + const message = err instanceof Error ? err.message : String(err); + annotate({ + meta: { + mood_rollup_enqueue_failed: true, + mood_rollup_enqueue_error: message, + }, + }); + console.error("[mood-rollups] async enqueue failed:", message); }); - console.error("[mood-rollups] async enqueue failed:", message); - }); - }), + }), + ), ); }