From 98e078d359bf6d26ec28d1c7f0fcb0626671dcb1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marc-Andr=C3=A9=20Bombeck?= Date: Sun, 17 May 2026 16:37:51 +0200 Subject: [PATCH] =?UTF-8?q?v1.4.37.1=20=E2=80=94=20event-loop=20unblock=20?= =?UTF-8?q?on=20the=20read=20path?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Hotfix on top of v1.4.37. The post-deploy verify caught /api/analytics cold-mount hits of ~62 s and parallel /api/health checks of ~58 s on the live instance, far above the v1.4.37 1.5-3 s perf claim. Root cause: the synchronous ensureUserRollupsFresh(userId) call at the top of each heavy read path folds the trailing 90-day DAY window when the rollup watermark trails the newest measurement. On a power-user account whose iOS step samples push the watermark every few minutes, each cache miss synchronously paid the full refresh cost on a Node worker that also serves the rest of the request fan-out (including /api/health, /api/version, and concurrent iOS calls), and the event loop was blocked for the duration of the recompute. Convert the three call sites (analytics route, comprehensive aggregator, summaries slice) to fire-and-forget. The downstream probeRollupCoverage gate falls back to live SQL on partial coverage so correctness is preserved; the only user-observable change is one cache window of staleness on the very first request after a new measurement landed. --- .planning/round-audit-marathon-closure.md | 5 +- .planning/round-v1437-perf-verify.md | 91 ++++++++++++++++++++ CHANGELOG.md | 38 ++++++++ package.json | 2 +- src/app/api/analytics/route.ts | 20 +++-- src/lib/analytics/summaries-slice.ts | 13 +-- src/lib/insights/comprehensive-aggregator.ts | 14 +-- 7 files changed, 161 insertions(+), 22 deletions(-) create mode 100644 .planning/round-v1437-perf-verify.md diff --git a/.planning/round-audit-marathon-closure.md b/.planning/round-audit-marathon-closure.md index 33dfb61a4..4fc6ba946 100644 --- a/.planning/round-audit-marathon-closure.md +++ b/.planning/round-audit-marathon-closure.md @@ -1,6 +1,6 @@ -# v1.4.34.4 + v1.4.34.5 + v1.4.35 + v1.4.35.1 + v1.4.36 — Audit-Marathon Closure (extended) +# v1.4.34.4 + v1.4.34.5 + v1.4.35 + v1.4.35.1 + v1.4.36 + v1.4.37 — Audit-Marathon Closure (extended) -Shipped: 2026-05-17 (five consecutive releases on the same date as v1.4.34.3). +Shipped: 2026-05-17 (six consecutive releases on the same date as v1.4.34.3). | Tag | Highlights | Release | | --- | --- | --- | @@ -9,6 +9,7 @@ Shipped: 2026-05-17 (five consecutive releases on the same date as v1.4.34.3). | v1.4.35 | Layer B landed — persistent `measurement_rollups` foundation + partial reader read-swap on the comprehensive aggregator and the slim summaries slice | [v1.4.35](https://github.com/MBombeck/HealthLog/releases/tag/v1.4.35) | | v1.4.35.1 | Auto-converging rollup backfill on worker boot — no operator action required on self-hosted instances | [v1.4.35.1](https://github.com/MBombeck/HealthLog/releases/tag/v1.4.35.1) | | v1.4.36 | Perf, charts, AI payload trim, UX punch — heavy-aggregate skip on the rollup-fresh path, daily chart fetches opt into rollup buckets, Insights `extractFeatures` swap (25.9 MB → 30,096 tokens, **−99.5 %**), page-blocking call 10.88 s → 4.57 s (**−58 %**), per-section early-skeleton paint, intake-history list restored, About → Admin Console, auto-checking update badge, cumulative-metric tiles, IP-whois fallback | [v1.4.36](https://github.com/MBombeck/HealthLog/releases/tag/v1.4.36) | +| v1.4.37 | Final web polish before iOS focus — full `/api/analytics` route on the rollup-coverage probe (cold worst-case 111 s → **~1.5–3 s** estimated), Apple Health step consolidation (`groupBy=day` + nightly drain, **~50× row compression target**), `IntakeHistoryListV2` regression fix, Coach disable cascade with invariant test, Mounjaro/Ramipril card byte-equivalent symmetry, HealthScoreCard full-height parity, `TRUST_CF_CONNECTING_IP` env flag, Arztbericht hero card, dashboard `Medikamenteneinnahme` quick-add overlay, timezone-override removal + silent auto-seed, v1.4.36 red-CI cleanup, **README + healthlog-docs + healthlog-landing refresh with five new Dracula-palette architecture diagrams**. Unit suite 4354 → 4486 passing. | [v1.4.37](https://github.com/MBombeck/HealthLog/releases/tag/v1.4.37) | ## Audit waves diff --git a/.planning/round-v1437-perf-verify.md b/.planning/round-v1437-perf-verify.md new file mode 100644 index 000000000..93974dd74 --- /dev/null +++ b/.planning/round-v1437-perf-verify.md @@ -0,0 +1,91 @@ +# v1.4.37 post-deploy perf verification + +**Release:** v1.4.37 (`88028fa0` on main, live 2026-05-17 13:42 UTC) +**Live host:** https://healthlog.bombeck.io +**Account under test:** Marc's production account (311,779+ measurements) + +## TL;DR + +- Live tag is **1.4.37**; build hash `88028fa082085f595e5ee423839c4561c21a11c9`. +- Boot clean: reminder worker up in 772 ms; no pending migrations (the v1.4.36 `0068_v1436_insights_exclude_metrics` was already applied). +- No boot errors → the W10-1 C-1 fix landed correctly: `DRAIN_CUMULATIVE_QUEUE` registration in `allQueues` succeeded; the worker boot would have aborted on the `boss.schedule(DRAIN_CUMULATIVE_QUEUE, …)` call otherwise. +- Anonymous 401 baseline 77–130 ms on `/api/insights/comprehensive` + `/api/analytics` — identical to v1.4.36 (no auth-layer regression). +- The W2 perf carry-over (full `/api/analytics` 111 s cold worst-case → ~1.5–3 s) needs a real authenticated web load to confirm — pending Marc's next dashboard / insights mount. Framework captured below; live numbers fill in as they surface in the logs. + +## Boot trace (verified) + +``` +HealthLog: Waiting for database... +HealthLog: Database is reachable. +HealthLog: Running database migrations... +[...] +No pending migrations to apply. +HealthLog: Migrations complete. +HealthLog: Starting application... +▲ Next.js 16.2.6 +✓ Ready in 0ms +{ background.task_name: "startup", reminder_worker: "started", duration_ms: 772 } +``` + +No `boss.createQueue` errors, no schedule-registration warnings. C-1 fix verified by absence of failure. + +## Anonymous latency (auth-layer baseline) + +| Surface | Cold | Notes | +|---|---|---| +| `/api/version` | 80 ms | sanity ping, public | +| `/api/insights/comprehensive` (anon) | 77–108 ms | 401 reject | +| `/api/analytics` (anon) | 84–131 ms | 401 reject | +| `/api/health` (Uptime-Kuma) | 73 ms | health check | + +Identical envelope to v1.4.36 → no auth/middleware regression. + +## Expected authenticated wins (pending Marc's web session) + +| Surface | v1.4.36 baseline | v1.4.37 expected | Mechanism | +|---|---|---|---| +| `/api/insights/comprehensive` (cold) | 4566 ms | comparable (no changes this release) | already on rollup probe | +| `/api/analytics` slim slice | 4153 ms | comparable | already on rollup probe | +| `/api/analytics` FULL slice (correlations + healthScore + bp_in_target) | **111,092 ms** worst-case cold | **1500–3000 ms** | W2 — three branches on the rollup-coverage probe with per-branch `path` annotate | +| `/api/insights/targets` | 1609 ms cold / < 50 ms cached | unchanged | LRU same | +| `GET /api/measurements?groupBy=day&type=ACTIVITY_STEPS` (new) | n/a | < 200 ms | rollup DAY buckets, no per-sample scan | +| `GET /api/measurements?aggregate=daily&source=rollup` (existing v1.4.36) | < 100 ms | unchanged | rollup-direct | + +## Headline perf bet — full `/api/analytics` cold-path + +The W2 wave lifted correlations + healthScore + bp_in_target onto the v1.4.36 `probeRollupCoverage` probe. Each branch now: + +- consults the probe once per request +- reads from `measurement_rollups` when DAY-bucket coverage is full +- falls back to live SQL chunks when partial +- emits `meta..path: "rollup"|"live"` for prod observability + +The correlations branch additionally tightened its scan from 30 to 28 days with a `CORRELATION_WINDOW_DAYS` constant + sentinel annotate. + +**Verification path** (run once Marc loads the dashboard / insights): + +```bash +# Capture the most recent FULL /api/analytics call on Marc's account +ssh apps-01 'docker logs $(docker ps --format "{{.Names}}" | grep "^app-pg8wggwogo8c4gc4ks0kk4ss") 2>&1 | jq -c "select(.http.path == \"/api/analytics\" and (.meta?.analytics?.slim_summaries | not))" | tail -3' + +# Look for: meta.correlations.path, meta.healthScore.path, meta.bp_in_target.path +# Each should be "rollup" on Marc's account (every type has DAY coverage from the v1.4.35.1 auto-converging backfill). +``` + +If the first cold hit is < 5 s and per-branch paths are all "rollup": shipped. If any branch still says "live": the probe didn't cover — check the rollup table for that type. + +## Apple Health step consolidation (W7c) + +The new `groupBy=day` + `dayKey` modes don't run automatically — they kick in only when the UI requests them. Marc's iOS app does not yet pass these params (a v1.5 iOS sprint item), so the feature lives on the web measurement-list page for now. + +The nightly drain at 03:45 Europe/Berlin (36 h grace) will run for the first time tonight. Tomorrow the table should be ~50× smaller for cumulative HK types on Marc's account. + +## Carry-over to v1.4.38 if a number lands materially worse than estimate + +If the full `/api/analytics` cold hit stays above 5 s on Marc's account after the deploy: file v1.4.37.1 hotfix issue, investigate why the probe missed (per-type coverage gap? cache miss cascade? something downstream of the W2 work). + +If the nightly drain produces no row-count compression: the singleton-key on the pg-boss schedule may be coalescing with no-op runs; investigate the W10-2 M-2 finding (per-process singleton-guard) earlier than planned. + +## Verdict (interim — pending Marc-authenticated traffic) + +Deploy is **healthy and live**. The W10-1 Critical fix (drain queue registration) is verified by clean boot. The W2 perf claim is **framework-ready, awaiting first authenticated mount on Marc's account** to confirm cold worst-case in the 1.5–3 s range. diff --git a/CHANGELOG.md b/CHANGELOG.md index 6fbc08029..9b1720bdf 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,43 @@ # Changelog +## [1.4.37.1] — 2026-05-17 — Event-loop unblock on the read path + +Hotfix on top of v1.4.37. Post-deploy verification surfaced live +`/api/analytics` cold-mount hits of ~62 s and parallel +`/api/health` checks of ~58 s on the live instance — far above the +v1.4.37 perf claim of 1.5–3 s. Root cause: the synchronous +`ensureUserRollupsFresh(userId)` call at the top of each heavy +read path (analytics route, comprehensive aggregator, summaries +slice) folds the trailing 90-day DAY window when the rollup +watermark trails the newest measurement. On an account with +high-frequency Apple Health step ingest the watermark falls behind +every few minutes, so each cache miss synchronously paid the full +refresh cost on a Node.js worker that also serves the rest of the +request fan-out — including `/api/health`, `/api/version`, and +concurrent iOS calls — and the event loop was blocked for the +duration of the recompute. + +### Fixed + +- `ensureUserRollupsFresh` is now fired-and-forgotten on all three + read-path call sites (`src/app/api/analytics/route.ts`, + `src/lib/insights/comprehensive-aggregator.ts`, + `src/lib/analytics/summaries-slice.ts`). The function already + carries its own try/catch envelope, so the `void`-call cannot + reject. Correctness is preserved by the downstream + `probeRollupCoverage` check: when a type is partial the live + fallback fires; the only user-observable change is that the very + first request after a fresh measurement landed may serve data up + to ~60 s old, and the next request returns the up-to-date value + once the background refresh completes. + +### Operator notes + +- No schema change. No env-var change. +- Coolify auto-deploys main on tag push; first webhook may pull + stale `:latest`, redeploy after the docker-publish workflow + completes. + ## [1.4.37] — 2026-05-17 — Final web polish before iOS focus The closing web release before the v1.5 iOS-app sprint. Carries the diff --git a/package.json b/package.json index 8cc9a2987..83d04f3fd 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "healthlog", - "version": "1.4.37", + "version": "1.4.37.1", "description": "Self-hosted personal-health-tracking PWA with Withings integration, AI insights, and doctor-report PDF export.", "license": "AGPL-3.0-only", "homepage": "https://healthlog.dev", diff --git a/src/app/api/analytics/route.ts b/src/app/api/analytics/route.ts index 03c740849..38c327865 100644 --- a/src/app/api/analytics/route.ts +++ b/src/app/api/analytics/route.ts @@ -112,14 +112,18 @@ type AuthedUser = Awaited>["user"]; * `buildCoachSnapshotImpl` shape. */ async function buildAnalyticsResponse(user: AuthedUser) { - // v1.5.0 — warm the persistent rollup table as a side effect of - // the analytics fan-out. No-op when rollups are already ahead of - // the newest measurement; on first cold-mount after a process - // restart it folds the trailing 90-day window so downstream - // consumers (Coach drawer, weekly report, admin analytics) see a - // warm rollup table on their next read. The route's response - // shape is untouched. - await ensureUserRollupsFresh(user.id); + // v1.4.37.1 hotfix — fire-and-forget the rollup-fresh check. + // Awaiting it on the read path can stall the Node event loop for + // 30–60 s on a power-user account whose iOS step samples keep the + // 90-day DAY window slightly stale, which starves /api/health, + // /api/version, and concurrent iOS calls. The downstream coverage + // probe falls back to live SQL when a type is uncovered, so + // correctness is preserved; the worst the user sees is data from + // up to ~60 s ago on the very first request after a fresh + // measurement lands, and the next request returns the up-to-date + // value once the background refresh completes. `ensureUserRollupsFresh` + // wraps its own try/catch, so the void call cannot reject. + void ensureUserRollupsFresh(user.id); // v1.4.37 W2 — single per-type coverage probe shared by the // bp_in_target / healthScore / correlations branches below. The diff --git a/src/lib/analytics/summaries-slice.ts b/src/lib/analytics/summaries-slice.ts index 4a53bf7c8..6ceb016d8 100644 --- a/src/lib/analytics/summaries-slice.ts +++ b/src/lib/analytics/summaries-slice.ts @@ -179,11 +179,14 @@ export interface SummariesSlice { export async function computeSummariesSlice( userId: string, ): Promise { - // Keep the persistent rollup table current before the bucket read - // fires. On a warm process this is a single watermark query; on a - // cold mount it folds the trailing 90-day window into the DAY - // rollup so the bucket read below has something to compose. - await ensureUserRollupsFresh(userId); + // v1.4.37.1 hotfix — fire-and-forget. See `src/app/api/analytics/route.ts` + // for the full rationale: awaiting this on the read path can stall + // the event loop for 30–60 s on power-user accounts whose iOS step + // samples keep the 90-day window slightly stale. The downstream + // coverage probe falls back to live SQL for uncovered types, so + // correctness is preserved; the read just doesn't block waiting + // for the background refresh. + void ensureUserRollupsFresh(userId); // v1.4.36 QA C1 — per-type coverage probe replaces the legacy global // COUNT. The previous gate returned true as soon as ANY type had at diff --git a/src/lib/insights/comprehensive-aggregator.ts b/src/lib/insights/comprehensive-aggregator.ts index 8ec4c3c47..a9e6f07ff 100644 --- a/src/lib/insights/comprehensive-aggregator.ts +++ b/src/lib/insights/comprehensive-aggregator.ts @@ -233,12 +233,14 @@ export async function buildComprehensiveAggregate( ): Promise { const ninetyDaysAgo = new Date(Date.now() - 90 * 24 * 60 * 60 * 1000); - // Keep the persistent rollup table current before any read fires. - // After this returns the DAY-granularity buckets for the trailing - // 90 days reflect every measurement that landed before this call - // (the per-write hook is synchronous on the DAY bucket, and - // `ensureUserRollupsFresh` covers cold-mount / process-restart). - await ensureUserRollupsFresh(userId); + // v1.4.37.1 hotfix — fire-and-forget. See `src/app/api/analytics/route.ts` + // for the full rationale: awaiting this on the read path can stall + // the event loop for 30–60 s on power-user accounts whose iOS step + // samples keep the 90-day window slightly stale. The downstream + // coverage probe falls back to live SQL for uncovered types, so + // correctness is preserved; the read just doesn't block waiting + // for the background refresh. + void ensureUserRollupsFresh(userId); // v1.4.36 QA C1 — per-type coverage probe. The legacy global COUNT // returned true as soon as any one type had a DAY bucket, which made