diff --git a/.planning/phase-W-INSIGHTS-HOT-report.md b/.planning/phase-W-INSIGHTS-HOT-report.md new file mode 100644 index 000000000..9f3984893 --- /dev/null +++ b/.planning/phase-W-INSIGHTS-HOT-report.md @@ -0,0 +1,105 @@ +# Phase report — W-INSIGHTS-HOT (v1.4.41) + +## Mission + +Eliminate the recurring ~14 s warm response on the two iOS-facing insight +endpoints: + +- `GET /api/insights/blood-pressure-status` +- `GET /api/insights/weight-status` + +iOS v0.5.4 hits both on every dashboard open. Marc feels them daily. + +## Root cause + +The sibling `bmi-status` route shipped a **timeout-stub persist** in +v1.4.37: when the AI provider stalls past the 20 s budget, the route +writes a `model: "timeout-stub", timeout: true` sentinel row keyed to +today's Berlin day. The next mount hits the cache-lookup branch and +short-circuits — no further provider race that day. + +`blood-pressure-status` and `weight-status` carried only the bare-fallback +return (no persist), so every reload re-raced the same 20 s provider +call. That is the ~14 s warm response Marc sees (the provider call +itself averages ~14 s on cold paths before the 20 s timeout cuts it). + +## Fix + +Mirror the bmi-status stub-persist pattern verbatim into both routes. + +- `src/lib/insights/blood-pressure-status.ts` — lines 544-551 + (pre-existing return) replaced with the 40-line stub-persist block + (best-effort `prisma.auditLog.create` then return the stub envelope). +- `src/lib/insights/weight-status.ts` — same shape, same block. + +Response shape unchanged. iOS v0.5.4 contract preserved: +`{ hasProvider, text, cached, updatedAt }`. + +## Files touched + +- `src/lib/insights/blood-pressure-status.ts` (+43 / −4) +- `src/lib/insights/weight-status.ts` (+43 / −4) +- `src/lib/insights/__tests__/blood-pressure-status.test.ts` (+98) +- `src/lib/insights/__tests__/weight-status.test.ts` (+86) + +## Tests added + +Two new test suites per route, copied from the bmi-status template: + +1. **Timeout-stub persistence** — provider hangs past timeout, asserts + one `auditLog.create` call with `timeout: true`, `model: + "timeout-stub"`, `dateKey` matching `YYYY-MM-DD`. +2. **Cache short-circuit** — second mount with a stub row in + `findFirst` returns the cached text, never calls the provider, never + writes a new row. + +Both use `vi.useFakeTimers()` + `advanceTimersByTimeAsync(25_000)` so +the suite does not actually wait 20 s. + +## Verification + +- `pnpm test src/lib/insights` — 148/148 pass (up from 144). +- `pnpm typecheck` — clean (after `pnpm db:generate` to materialise the + Prisma client in the worktree). +- `pnpm lint` — clean (only pre-existing warnings in `insights/page.tsx` + and `summaries-slice.ts`, unrelated). + +## Perf delta (estimated) + +| State | Before | After | +|---|---|---| +| Cache hit (fresh insight or stub) | ~50 ms | ~50 ms (unchanged) | +| Provider available, no cache | ~3-5 s (real AI call) | ~3-5 s (unchanged) | +| Provider stall, no cache, **first** mount of the day | ~20 s timeout | ~20 s timeout (unchanged) | +| Provider stall, no cache, **subsequent** mounts | **~14-20 s every time** | **~50 ms (cache hit on stub)** | + +Marc's reported ~14 s recurring warm response is the **subsequent-mount** +case — that is the row the fix eliminates. The first daily stall still +takes the 20 s budget, same as bmi-status. + +## Risk callouts for reconcile + +1. **Stub-persist comment carries forward bmi-status' optimistic note** + about the pre-warm worker overwriting the stub. In reality the + pre-warm worker uses `force: false`, so it also short-circuits on + the stub. This is consistent with bmi-status' shipped behaviour and + matches the day-key invalidation cycle (the stub naturally clears at + midnight Berlin time when the dateKey rolls). No code change needed; + noting it so the reconcile reviewer does not re-open the question. +2. **No shape change** — the response envelope, the `auditLog` row + shape, and the cache-lookup branch are unchanged. No iOS or + web-frontend touch required. +3. **No new dependencies, no provider-side changes, no DB migration.** +4. **The two test suites use fake timers**, mirroring the bmi-status + pattern that has been stable since v1.4.37 — should be safe under + the existing vitest config. + +## Commits + +Single atomic commit on `worktree-agent-a9d3a2cf26b93d03d`: + +``` +perf(insights): persist timeout stub for blood-pressure and weight status +``` + +Pushed to origin at end of session. diff --git a/src/lib/insights/__tests__/blood-pressure-status.test.ts b/src/lib/insights/__tests__/blood-pressure-status.test.ts index 7b089aaec..aa7f9bfa9 100644 --- a/src/lib/insights/__tests__/blood-pressure-status.test.ts +++ b/src/lib/insights/__tests__/blood-pressure-status.test.ts @@ -109,6 +109,104 @@ describe("generateBloodPressureStatusForUser — v1.4.6 bucketed payload", () => }); }); +describe("generateBloodPressureStatusForUser — v1.4.41 timeout-stub persistence", () => { + it("persists a sentinel row keyed to today when the provider times out", async () => { + vi.mocked(prisma.user.findUnique).mockResolvedValue({ + dateOfBirth: null, + } as never); + vi.mocked(prisma.auditLog.findFirst).mockResolvedValue(null); + vi.mocked(prisma.measurement.findMany).mockResolvedValue([ + { type: "BLOOD_PRESSURE_SYS", value: 132, measuredAt: new Date() }, + { type: "BLOOD_PRESSURE_DIA", value: 84, measuredAt: new Date() }, + ] as never); + vi.mocked(prisma.medication.findMany).mockResolvedValue([] as never); + vi.mocked(prisma.medicationIntakeEvent.findMany).mockResolvedValue( + [] as never, + ); + vi.mocked(prisma.moodEntry.findMany).mockResolvedValue([] as never); + vi.mocked(prisma.auditLog.create).mockResolvedValue({ + createdAt: new Date(), + } as never); + + // Provider hangs past the 20 s timeout — withTimeout cuts the race. + vi.mocked(resolveProvider).mockResolvedValue({ + type: "anthropic", + generateCompletion: vi.fn( + () => + new Promise(() => { + /* never resolves */ + }), + ), + } as never); + + vi.useFakeTimers(); + const promise = generateBloodPressureStatusForUser("user-1", { + locale: "en", + }); + await vi.advanceTimersByTimeAsync(25_000); + const result = await promise; + vi.useRealTimers(); + + expect(result.text).toBeTruthy(); + expect(result.cached).toBe(true); + expect(result.updatedAt).toBeTruthy(); + + const createCalls = vi.mocked(prisma.auditLog.create).mock.calls; + expect(createCalls.length).toBe(1); + const details = (createCalls[0][0] as { data: { details: string } }).data + .details; + const parsed = JSON.parse(details) as { + dateKey?: string; + text?: string; + timeout?: boolean; + model?: string; + }; + expect(parsed.text).toBeTruthy(); + expect(parsed.timeout).toBe(true); + expect(parsed.model).toBe("timeout-stub"); + expect(parsed.dateKey).toMatch(/^\d{4}-\d{2}-\d{2}$/); + }); + + it("subsequent mounts short-circuit at the cache lookup and skip the race", async () => { + const parts = new Intl.DateTimeFormat("en-US", { + timeZone: "Europe/Berlin", + year: "numeric", + month: "2-digit", + day: "2-digit", + }).formatToParts(new Date()); + const y = parts.find((p) => p.type === "year")!.value; + const m = parts.find((p) => p.type === "month")!.value; + const d = parts.find((p) => p.type === "day")!.value; + const todayKey = `${y}-${m}-${d}`; + const stubRow = { + createdAt: new Date(), + details: JSON.stringify({ + dateKey: todayKey, + locale: "en", + text: "Blood-pressure assessment temporarily unavailable.", + timeout: true, + }), + }; + + vi.mocked(prisma.auditLog.findFirst).mockResolvedValue(stubRow as never); + const providerCall = vi.fn(); + vi.mocked(resolveProvider).mockResolvedValue({ + type: "anthropic", + generateCompletion: providerCall, + } as never); + + const result = await generateBloodPressureStatusForUser("user-1", { + locale: "en", + }); + + expect(providerCall).not.toHaveBeenCalled(); + expect(result.text).toBe("Blood-pressure assessment temporarily unavailable."); + expect(result.cached).toBe(true); + expect(result.updatedAt).toBe(stubRow.createdAt.toISOString()); + expect(prisma.auditLog.create).not.toHaveBeenCalled(); + }); +}); + describe("generateBloodPressureStatusForUser — token-leak hardening (v1.4.27 F16)", () => { it("strips metric: tokens out of the cached text before persisting", async () => { vi.mocked(prisma.user.findUnique).mockResolvedValue({ diff --git a/src/lib/insights/__tests__/weight-status.test.ts b/src/lib/insights/__tests__/weight-status.test.ts index 82409970f..858aee7f7 100644 --- a/src/lib/insights/__tests__/weight-status.test.ts +++ b/src/lib/insights/__tests__/weight-status.test.ts @@ -82,6 +82,92 @@ describe("generateWeightStatusForUser — v1.4.6 bucketed payload", () => { }); }); +describe("generateWeightStatusForUser — v1.4.41 timeout-stub persistence", () => { + it("persists a sentinel row keyed to today when the provider times out", async () => { + vi.mocked(prisma.auditLog.findFirst).mockResolvedValue(null); + vi.mocked(prisma.measurement.findMany).mockResolvedValue([ + { type: "WEIGHT", value: 82, measuredAt: new Date() }, + ] as never); + vi.mocked(prisma.moodEntry.findMany).mockResolvedValue([] as never); + vi.mocked(prisma.auditLog.create).mockResolvedValue({ + createdAt: new Date(), + } as never); + + // Provider hangs past the 20 s timeout — withTimeout cuts the race. + vi.mocked(resolveProvider).mockResolvedValue({ + type: "anthropic", + generateCompletion: vi.fn( + () => + new Promise(() => { + /* never resolves */ + }), + ), + } as never); + + vi.useFakeTimers(); + const promise = generateWeightStatusForUser("user-1", { locale: "en" }); + await vi.advanceTimersByTimeAsync(25_000); + const result = await promise; + vi.useRealTimers(); + + expect(result.text).toBeTruthy(); + expect(result.cached).toBe(true); + expect(result.updatedAt).toBeTruthy(); + + const createCalls = vi.mocked(prisma.auditLog.create).mock.calls; + expect(createCalls.length).toBe(1); + const details = (createCalls[0][0] as { data: { details: string } }).data + .details; + const parsed = JSON.parse(details) as { + dateKey?: string; + text?: string; + timeout?: boolean; + model?: string; + }; + expect(parsed.text).toBeTruthy(); + expect(parsed.timeout).toBe(true); + expect(parsed.model).toBe("timeout-stub"); + expect(parsed.dateKey).toMatch(/^\d{4}-\d{2}-\d{2}$/); + }); + + it("subsequent mounts short-circuit at the cache lookup and skip the race", async () => { + const parts = new Intl.DateTimeFormat("en-US", { + timeZone: "Europe/Berlin", + year: "numeric", + month: "2-digit", + day: "2-digit", + }).formatToParts(new Date()); + const y = parts.find((p) => p.type === "year")!.value; + const m = parts.find((p) => p.type === "month")!.value; + const d = parts.find((p) => p.type === "day")!.value; + const todayKey = `${y}-${m}-${d}`; + const stubRow = { + createdAt: new Date(), + details: JSON.stringify({ + dateKey: todayKey, + locale: "en", + text: "Weight assessment temporarily unavailable.", + timeout: true, + }), + }; + + vi.mocked(prisma.auditLog.findFirst).mockResolvedValue(stubRow as never); + const providerCall = vi.fn(); + vi.mocked(resolveProvider).mockResolvedValue({ + type: "anthropic", + generateCompletion: providerCall, + } as never); + + const result = await generateWeightStatusForUser("user-1", { locale: "en" }); + + expect(providerCall).not.toHaveBeenCalled(); + expect(result.text).toBe("Weight assessment temporarily unavailable."); + expect(result.cached).toBe(true); + expect(result.updatedAt).toBe(stubRow.createdAt.toISOString()); + expect(prisma.auditLog.create).not.toHaveBeenCalled(); + }); +}); + describe("generateWeightStatusForUser — token-leak hardening (v1.4.27 F16)", () => { it("strips metric: tokens out of the cached text before persisting", async () => { vi.mocked(prisma.auditLog.findFirst).mockResolvedValue(null); diff --git a/src/lib/insights/blood-pressure-status.ts b/src/lib/insights/blood-pressure-status.ts index c7f03e84c..009927bfa 100644 --- a/src/lib/insights/blood-pressure-status.ts +++ b/src/lib/insights/blood-pressure-status.ts @@ -542,11 +542,50 @@ export async function generateBloodPressureStatusForUser( ); if (raced.timedOut || raced.value === null) { + // v1.4.41 — parity with bmi-status: persist a sentinel row keyed + // to today so the next mount short-circuits at the cache lookup + // above instead of re-racing the same 20 s provider call on every + // cold visit. Without this, a single stall (provider hiccup, + // network blip, model warm-up) left iOS users staring at the + // loading state on every dashboard open for the rest of the day. + // The body is the same no-key fallback the caller returned + // before, so the user-facing UI is identical; only the re-fire + // frequency drops to zero until the daily pre-warm job overwrites + // the stub. `meta.timeout` is set so the pre-warm worker can + // recognise and replace it rather than respect it as a real + // assessment. + const stubText = getNoKeyBloodPressureStatusText(locale); + let stubUpdatedAt: string | null = null; + try { + const stub = await prisma.auditLog.create({ + data: { + userId, + action: cacheAction, + details: JSON.stringify({ + dateKey: todayKey, + locale, + text: stubText, + providerType: provider.type, + model: "timeout-stub", + tokensUsed: null, + timeout: true, + }), + }, + select: { createdAt: true }, + }); + stubUpdatedAt = stub.createdAt.toISOString(); + } catch { + // Best-effort persist — if the row write fails the caller still + // sees the deterministic fallback text and the next mount falls + // back to the (still expensive) race. Do not surface the error: + // the user does not care that the cache write missed, only that + // the page rendered. + } return { hasProvider: true, - text: getNoKeyBloodPressureStatusText(locale), + text: stubText, cached: true, - updatedAt: null, + updatedAt: stubUpdatedAt, }; } diff --git a/src/lib/insights/weight-status.ts b/src/lib/insights/weight-status.ts index 4f0a72adf..77f7a0351 100644 --- a/src/lib/insights/weight-status.ts +++ b/src/lib/insights/weight-status.ts @@ -440,11 +440,50 @@ export async function generateWeightStatusForUser( ); if (raced.timedOut || raced.value === null) { + // v1.4.41 — parity with bmi-status: persist a sentinel row keyed + // to today so the next mount short-circuits at the cache lookup + // above instead of re-racing the same 20 s provider call on every + // cold visit. Without this, a single stall (provider hiccup, + // network blip, model warm-up) left iOS users staring at the + // loading state on every dashboard open for the rest of the day. + // The body is the same no-key fallback the caller returned + // before, so the user-facing UI is identical; only the re-fire + // frequency drops to zero until the daily pre-warm job overwrites + // the stub. `meta.timeout` is set so the pre-warm worker can + // recognise and replace it rather than respect it as a real + // assessment. + const stubText = getNoKeyWeightStatusText(locale); + let stubUpdatedAt: string | null = null; + try { + const stub = await prisma.auditLog.create({ + data: { + userId, + action: cacheAction, + details: JSON.stringify({ + dateKey: todayKey, + locale, + text: stubText, + providerType: provider.type, + model: "timeout-stub", + tokensUsed: null, + timeout: true, + }), + }, + select: { createdAt: true }, + }); + stubUpdatedAt = stub.createdAt.toISOString(); + } catch { + // Best-effort persist — if the row write fails the caller still + // sees the deterministic fallback text and the next mount falls + // back to the (still expensive) race. Do not surface the error: + // the user does not care that the cache write missed, only that + // the page rendered. + } return { hasProvider: true, - text: getNoKeyWeightStatusText(locale), + text: stubText, cached: true, - updatedAt: null, + updatedAt: stubUpdatedAt, }; }