feat(resilience): warn on slow /healthz event-loop lag (#10827)

Merged — validated together with a batch of related RaviTharuma PRs in one combined worktree (typecheck:core clean, complexity/file-size/changelog gates green, focused tests passing). Thanks for the contribution!

changelog.d/features/10303-healthz-event-loop-lag.md

@@ -0,0 +1 @@
+- **feat(resilience):** warn when `/healthz` is served under event-loop lag ≥200ms so a slow 200 is visible as sick, not healthy ([#10303](https://github.com/diegosouzapw/OmniRoute/issues/10303))

docs/ops/MONITORING_GUIDE.md

@@ -162,7 +162,7 @@ OmniRoute is a **single Node process** (one event loop). Stock Docker `HEALTHCHE
 | Probe | Recommended target | Notes |
 | --- | --- | --- |
 | **Startup** | HTTP `GET /healthz` with a long `failureThreshold` (or large `startPeriod`) | Cold start + SQLite migration can exceed a few seconds |
-| **Readiness** | HTTP `GET /healthz` | Remove endpoints while starting/stopping; still flaps if the loop is CPU-blocked |
+| **Readiness** | HTTP `GET /healthz` | Remove endpoints while starting/stopping; still flaps if the loop is CPU-blocked. A **200 in multiple seconds is not healthy** (#10303) — it means the event loop was starved before the 3-byte handler ran |
 | **Liveness** | **TCP** on the main service port (`PORT`, default `20128`), **or** HTTP `/healthz` with soft thresholds | Do **not** kill the pod on short event-loop stalls; busy ≠ dead |
 | **Deep health** | `GET /api/monitoring/health` from an external checker | Not for kubelet `livenessProbe` / tight `readinessProbe` |
 

src/app/healthz/route.ts

@@ -1,4 +1,5 @@
 import { getServerLifecyclePhase } from "@/lib/serverLifecycle";
+import { observeHealthzEventLoopLag } from "@/lib/healthzLag";
 
 export const dynamic = "force-dynamic";
 
@@ -23,6 +24,7 @@ function createHealthResponse(method: "GET" | "HEAD"): Response {
 }
 
 export function GET(): Response {
+  observeHealthzEventLoopLag();
   return createHealthResponse("GET");
 }
 

src/lib/healthzLag.ts

@@ -0,0 +1,40 @@
+import { monitorEventLoopDelay } from "node:perf_hooks";
+
+/** `/healthz` returning 200 after this much event-loop lag is already sick (#10303). */
+export const HEALTHZ_SLOW_LAG_MS = 200;
+const WARN_EVERY_MS = 10_000;
+
+let lastWarnAt = 0;
+let histogram: ReturnType<typeof monitorEventLoopDelay> | null = null;
+
+export function resetHealthzLagWarnStateForTests(): void {
+  lastWarnAt = 0;
+}
+
+export function shouldWarnHealthzLag(lagMs: number, now = Date.now()): boolean {
+  if (!Number.isFinite(lagMs) || lagMs < HEALTHZ_SLOW_LAG_MS) return false;
+  if (now - lastWarnAt < WARN_EVERY_MS) return false;
+  lastWarnAt = now;
+  return true;
+}
+
+export function formatHealthzLagWarning(lagMs: number): string {
+  return `GET /healthz event-loop lag ${Math.round(lagMs)}ms (HTTP 200 is not healthy; busy != ready)`;
+}
+
+export function getEventLoopLagMs(): number {
+  if (!histogram) {
+    histogram = monitorEventLoopDelay({ resolution: 20 });
+    histogram.enable();
+  }
+  return histogram.mean / 1e6;
+}
+
+export function observeHealthzEventLoopLag(
+  log: (msg: string) => void = console.warn,
+  lagMs = getEventLoopLagMs()
+): boolean {
+  if (!shouldWarnHealthzLag(lagMs)) return false;
+  log(`[HEALTHZ] ${formatHealthzLagWarning(lagMs)}`);
+  return true;
+}

tests/unit/10303-healthz-lag.test.ts

@@ -0,0 +1,35 @@
+import test from "node:test";
+import assert from "node:assert/strict";
+
+import {
+  HEALTHZ_SLOW_LAG_MS,
+  formatHealthzLagWarning,
+  observeHealthzEventLoopLag,
+  resetHealthzLagWarnStateForTests,
+  shouldWarnHealthzLag,
+} from "../../src/lib/healthzLag.ts";
+
+test("shouldWarnHealthzLag ignores sub-threshold lag", () => {
+  resetHealthzLagWarnStateForTests();
+  assert.equal(shouldWarnHealthzLag(0), false);
+  assert.equal(shouldWarnHealthzLag(HEALTHZ_SLOW_LAG_MS - 1), false);
+});
+
+test("shouldWarnHealthzLag fires once then debounce", () => {
+  resetHealthzLagWarnStateForTests();
+  const t0 = 1_700_000_000_000;
+  assert.equal(shouldWarnHealthzLag(3748, t0), true);
+  assert.equal(shouldWarnHealthzLag(3748, t0 + 1000), false);
+  assert.equal(shouldWarnHealthzLag(3748, t0 + 10_000), true);
+});
+
+test("observeHealthzEventLoopLag logs when injected lag is high", () => {
+  resetHealthzLagWarnStateForTests();
+  const messages: string[] = [];
+  assert.equal(observeHealthzEventLoopLag((m) => messages.push(m), 12), false);
+  assert.equal(messages.length, 0);
+  assert.equal(observeHealthzEventLoopLag((m) => messages.push(m), 3748), true);
+  assert.equal(messages[0], `[HEALTHZ] ${formatHealthzLagWarning(3748)}`);
+  assert.match(messages[0], /3748ms/);
+  assert.match(messages[0], /not healthy/);
+});