From ea5140d98c17ec04361905c9cb6e2550fb050d3e Mon Sep 17 00:00:00 2001 From: vreshch Date: Mon, 10 Aug 2026 03:05:49 +0200 Subject: [PATCH] chore(release): 0.9.0 - health timings, instance id, bounded facts Adds the four fields that let a probe interpret a health response instead of just reading its status word, and closes a latent restart-loop in the facts path. - `timings` (per check, plus `facts`) and `durationMs`: a check near 0ms is a memoized value, not a measurement. `"db": "ok"` cannot distinguish a live round trip from a cached one that keeps reporting ok after the dependency dies. `durationMs` also lets a probe subtract the server from its own round trip: the admin console reports 197ms for catalog-backend where curl sees 55ms including TLS, and nothing in the payload could attribute the gap. - `checkedAt`: the cache detector. Frozen across two probes means something in front of the service is serving a copy. Nothing in the estate is cached today - `no-store` verified on all 21 - but it is undetectable if that changes. - `instance`: random per process, so a value that changes between probes means a different replica answered. catalog-web runs at least two (distinct startedAt, interleaved across 8 samples), so its uptime bounces in a way otherwise indistinguishable from a crash loop. Not the hostname: /health is public and must not leak internal topology. Stashed on globalThis because Next can load one module into several bundle contexts per process. - `reasons`: a timeout and an instant ECONNREFUSED both read `down` alone. Flattened and bounded to 200 chars - a driver message is not a stack trace to paste onto a public endpoint. Fixes: the facts producer had no timeout while every check had one, so a fact off a wedged DB could outlive the container HEALTHCHECK and have Swarm kill a healthy task. Same shape as the store-mount rollback. catalog-backend, the one service returning a DB-backed fact, had to hand-roll its own guard. Also: `startedAt` now derives from `process.uptime()` rather than module load, so a lazily-imported Next route handler stops reporting a fresh uptime for a container that has been up for hours. Additive only. `checks` stays a flat string map, so admin's derive, the e2e smokes and the deploy gates keep working untouched; services pick the fields up on their next kit bump. `runChecks` keeps its signature, with the detail available via the new `runCheckOutcomes`. --- README.md | 38 +++++++- package-lock.json | 4 +- package.json | 2 +- src/health.ts | 227 ++++++++++++++++++++++++++++++++++++++------ test/health.test.ts | 202 +++++++++++++++++++++++++++++++++++++++ 5 files changed, 439 insertions(+), 34 deletions(-) diff --git a/README.md b/README.md index 69cc507..a67ffc1 100644 --- a/README.md +++ b/README.md @@ -84,12 +84,17 @@ One envelope, every service. Contract: vault `specs/health-endpoints`. "data": { "status": "ok", // ok | degraded | unavailable "service": "memory-mcp", // defaults to OTEL_SERVICE_NAME + "instance": "b82fc8d3", // random per process "version": "21150d69...", "commit": "21150d6", "buildTime": "2026-08-09T10:08:07Z", // ISO or null, never "" "startedAt": "...", "uptimeSeconds": 590, + "checkedAt": "2026-08-10T01:04:40.586Z", // when THIS payload was computed + "durationMs": 22.7, // total server-side cost "checks": { "store": "ok" }, // ok | degraded | down | skipped + "timings": { "store": 21.5, "facts": 1.1 }, // per check, plus facts + "reasons": { "search": "timed out after 60ms" }, // only when not ok "facts": { "memories": 412 }, // counts only, never state }, } @@ -100,6 +105,32 @@ One envelope, every service. Contract: vault `specs/health-endpoints`. without must report `degraded`, not `down`. `data` is always present, including on a 503, so a probe reads the outage instead of an empty body. +### Reading the timing fields + +They exist to answer three questions a status word cannot: + +- **Is this response cached?** `checkedAt` advances on every request. Frozen + across two probes means something in front of the service is serving a copy - + a CDN, a proxy, or a Next route that lost `force-dynamic`. +- **Is this check real, or memoized?** A `timings` entry near `0` is a value the + service already had; a real round trip costs milliseconds. `"db": "ok"` alone + cannot tell you which, and a memoized check keeps reporting `ok` long after + the dependency dies. +- **Was it the service or the network?** `durationMs` is the server-side cost, + so a probe subtracts it from its own round trip and attributes the rest to + TLS, the edge and the wire. + +`instance` is the fourth question, and the one that keeps the other three +honest: a value that changes between probes means a **different replica +answered**, not a cache and not a restart. Behind a load balancer, `uptimeSeconds` +bouncing around is otherwise indistinguishable from a crash loop. It is a random +per-process id, never the hostname - `/health` is public and must not leak +internal topology. + +The same numbers go out as a `Server-Timing` header +(`health;dur=22.7, store;dur=21.5`), so the split shows in browser devtools and +proxy logs without parsing the body. + **Express** - mount on `/health`, and on `/api/health` where the edge routes only `/api`: @@ -115,8 +146,11 @@ app.get('/health', health); A check may return a `CheckState` or a boolean, and may throw, reject or hang: it is timed out (1s default) and read as `down`, or `degraded` when -`optional: true`. Facts are decoration - a throwing producer is dropped, never -reddening the service. +`optional: true`, with the reason recorded under `reasons`. Facts are +decoration - a throwing producer is dropped, never reddening the service - and +are bounded by the same 1s budget (`factsTimeoutMs`). Do not let a facts +producer run unbounded: `/health` outliving the container `HEALTHCHECK +--timeout` is how Swarm kills a task that was only ever slow to count rows. **Next App Router** - `src/app/health/route.ts`: diff --git a/package-lock.json b/package-lock.json index 9d388e6..622dd94 100644 --- a/package-lock.json +++ b/package-lock.json @@ -1,12 +1,12 @@ { "name": "@agentage/observability", - "version": "0.6.0", + "version": "0.9.0", "lockfileVersion": 3, "requires": true, "packages": { "": { "name": "@agentage/observability", - "version": "0.6.0", + "version": "0.9.0", "license": "MIT", "dependencies": { "@opentelemetry/api": "1.9.1", diff --git a/package.json b/package.json index 357347f..0f38527 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "@agentage/observability", - "version": "0.8.1", + "version": "0.9.0", "description": "Shared observability kit for agentage services: OTLP trace bootstrap (node --import), pino logger preset with trace correlation, one-call error capture, and the estate /health envelope.", "type": "module", "license": "MIT", diff --git a/src/health.ts b/src/health.ts index e3e5784..b041abd 100644 --- a/src/health.ts +++ b/src/health.ts @@ -10,8 +10,8 @@ * * Build provenance (`version`/`commit`/`buildTime`) is baked per image via the * Dockerfile `ARG COMMIT_SHA` / `ARG BUILD_TIME` -> ENV. Pure logic plus the - * global `process`: no imports, safe in an isomorphic barrel, only ever called - * server-side. + * globals `process`/`performance`/`crypto`: no imports, safe in an isomorphic + * barrel, only ever called server-side. */ export type CheckState = 'ok' | 'degraded' | 'down' | 'skipped'; @@ -20,27 +20,72 @@ export type HealthStatus = 'ok' | 'degraded' | 'unavailable'; export interface HealthData { status: HealthStatus; service: string; + /** Random per process. Distinguishes "a cached response" from "a different replica". */ + instance: string; version: string; // full COMMIT_SHA, or '0.0.0-dev' when unset (local) commit: string; // 7-char short SHA, or 'dev' buildTime: string | null; // ISO from BUILD_TIME, null when unset OR blank startedAt: string; // ISO process start == last deploy (a deploy restarts the container) uptimeSeconds: number; + /** When THIS payload was computed. Frozen across two probes means something cached it. */ + checkedAt: string; + /** Total server-side cost of producing the payload, so a probe can subtract the network. */ + durationMs: number; checks?: Record; + /** Per-check wall time, plus `facts`. A check at ~0 is memoized, not measured. */ + timings?: Record; + /** Only for checks that are not ok: why. A timeout and a refusal both read `down` without it. */ + reasons?: Record; facts?: Record; } -/** No process behind it (nginx, a static bundle), so there is no uptime to report. */ -export type StaticHealthData = Omit; +/** No process behind it (nginx, a static bundle), so there is nothing to time or identify. */ +export type StaticHealthData = Omit< + HealthData, + 'instance' | 'startedAt' | 'uptimeSeconds' | 'checkedAt' | 'durationMs' | 'timings' | 'reasons' +>; export interface HealthEnvelope { success: boolean; data: T; } -const STARTED_AT = new Date(); - const clean = (value: string | undefined): string => (value ?? '').trim(); +// performance.now() is monotonic; Date.now() jumps when NTP steps the clock, which +// is how a 2ms check gets reported as -400ms. +const now = (): number => (typeof performance !== 'undefined' ? performance.now() : Date.now()); + +/** One decimal: 0.3ms (memoized) and 0ms (not run) must not round to the same number. */ +const since = (start: number): number => Math.round((now() - start) * 10) / 10; + +// process.uptime() is the real process start. A module-level `new Date()` is only +// module-LOAD time, and a lazily-imported Next route handler can load minutes after +// boot - reporting a fresh uptime for a container that has been up for hours. +function processStart(): Date { + const uptime = typeof process?.uptime === 'function' ? process.uptime() : 0; + return new Date(Date.now() - Math.round(uptime * 1000)); +} + +const STARTED_AT = processStart(); + +// Stashed on globalThis, not just module scope: Next can load one module into several +// bundle contexts in a single process, and a per-context id would look like a replica +// changing between requests - the exact signal `instance` exists to make trustworthy. +const INSTANCE_KEY = Symbol.for('agentage.observability.instance'); + +function resolveInstance(): string { + const host = globalThis as Record; + const existing = host[INSTANCE_KEY]; + if (typeof existing === 'string') return existing; + const uuid = globalThis.crypto?.randomUUID?.(); + const id = (uuid ?? `${Date.now().toString(36)}${Math.random().toString(36).slice(2)}`) + .replace(/-/g, '') + .slice(0, 8); + host[INSTANCE_KEY] = id; + return id; +} + /** 'unknown' is deliberately loud: the estate contract gate fails on it. */ export function resolveServiceName( explicit?: string, @@ -80,26 +125,40 @@ export interface HealthOptions { /** Defaults to `status !== 'unavailable'`. */ success?: boolean; checks?: Record; + timings?: Record; + reasons?: Record; /** Counts and sizes only, never state, so a probe never has to type-sniff. */ facts?: Record; env?: NodeJS.ProcessEnv; startedAt?: Date; + /** Injected by `resolveHealth`; defaults to now. */ + checkedAt?: Date; + durationMs?: number; } +const present = (key: string, value: T | undefined) => + value && Object.keys(value).length ? { [key]: value } : {}; + export function healthEnvelope(service?: string, options: HealthOptions = {}): HealthEnvelope { const env = options.env ?? process.env; const startedAt = options.startedAt ?? STARTED_AT; + const checkedAt = options.checkedAt ?? new Date(); const status = options.status ?? statusFromChecks(options.checks); return { success: options.success ?? status !== 'unavailable', data: { status, service: resolveServiceName(service, env), + instance: resolveInstance(), ...provenance(env), startedAt: startedAt.toISOString(), - uptimeSeconds: Math.round((Date.now() - startedAt.getTime()) / 1000), - ...(options.checks ? { checks: options.checks } : {}), - ...(options.facts ? { facts: options.facts } : {}), + uptimeSeconds: Math.round((checkedAt.getTime() - startedAt.getTime()) / 1000), + checkedAt: checkedAt.toISOString(), + durationMs: options.durationMs ?? 0, + ...present('checks', options.checks), + ...present('timings', options.timings), + ...present('reasons', options.reasons), + ...present('facts', options.facts), }, }; } @@ -113,36 +172,78 @@ export interface HealthCheck { optional?: boolean; } +/** What one check actually cost, and why it failed if it did. */ +export interface CheckOutcome { + state: CheckState; + durationMs: number; + reason?: string; +} + // Kept well under the container HEALTHCHECK --timeout so a hung dependency // reports as down rather than hanging the probe itself. const DEFAULT_CHECK_TIMEOUT_MS = 1000; +// A stack trace is not an operator-facing reason, and an unbounded message from a +// driver can be kilobytes on a public endpoint. +const MAX_REASON_CHARS = 200; + +const describeError = (err: unknown): string => { + const message = err instanceof Error ? err.message : String(err); + const flat = message.replace(/\s+/g, ' ').trim() || 'threw a non-error'; + return flat.length > MAX_REASON_CHARS ? `${flat.slice(0, MAX_REASON_CHARS)}...` : flat; +}; + const asState = (value: CheckState | boolean): CheckState => typeof value === 'boolean' ? (value ? 'ok' : 'down') : value; const failState = (check: HealthCheck): CheckState => (check.optional ? 'degraded' : 'down'); -async function runCheck(check: HealthCheck, defaultTimeoutMs: number): Promise { +async function runCheck(check: HealthCheck, defaultTimeoutMs: number): Promise { + const timeoutMs = check.timeoutMs ?? defaultTimeoutMs; + const started = now(); let timer: ReturnType | undefined; - const expiry = new Promise((resolve) => { - timer = setTimeout(() => resolve(failState(check)), check.timeoutMs ?? defaultTimeoutMs); + const expiry = new Promise((resolve) => { + timer = setTimeout( + () => + resolve({ + state: failState(check), + durationMs: since(started), + reason: `timed out after ${timeoutMs}ms`, + }), + timeoutMs + ); timer.unref?.(); }); try { - return await Promise.race([Promise.resolve(check.run()).then(asState), expiry]); - } catch { - return failState(check); + return await Promise.race([ + Promise.resolve(check.run()).then((value) => ({ + state: asState(value), + durationMs: since(started), + })), + expiry, + ]); + } catch (err) { + return { state: failState(check), durationMs: since(started), reason: describeError(err) }; } finally { clearTimeout(timer); } } +/** Detailed form: states, per-check timings and failure reasons. */ +export async function runCheckOutcomes( + checks: HealthCheck[] = [], + defaultTimeoutMs: number = DEFAULT_CHECK_TIMEOUT_MS +): Promise> { + const outcomes = await Promise.all(checks.map((check) => runCheck(check, defaultTimeoutMs))); + return Object.fromEntries(checks.map((check, i) => [check.name, outcomes[i]])); +} + export async function runChecks( checks: HealthCheck[] = [], defaultTimeoutMs: number = DEFAULT_CHECK_TIMEOUT_MS ): Promise> { - const states = await Promise.all(checks.map((check) => runCheck(check, defaultTimeoutMs))); - return Object.fromEntries(checks.map((check, i) => [check.name, states[i]])); + const outcomes = await runCheckOutcomes(checks, defaultTimeoutMs); + return Object.fromEntries(Object.entries(outcomes).map(([name, o]) => [name, o.state])); } export interface HealthSourceOptions { @@ -150,31 +251,94 @@ export interface HealthSourceOptions { checks?: HealthCheck[]; facts?: () => Promise> | Record; checkTimeoutMs?: number; + /** Facts get the same budget as a check: a fact off a wedged DB must not hang /health. */ + factsTimeoutMs?: number; env?: NodeJS.ProcessEnv; } +interface FactsOutcome { + facts?: Record; + durationMs: number; + reason?: string; +} + // Facts are decoration; a throwing producer must never turn a healthy service red. +// Bounded like a check, because unbounded is how /health outlives the container +// HEALTHCHECK timeout and Swarm kills a task that was only ever slow to count rows. async function safeFacts( - produce: NonNullable -): Promise | undefined> { + produce: NonNullable, + timeoutMs: number +): Promise { + const started = now(); + let timer: ReturnType | undefined; + const expiry = new Promise((resolve) => { + timer = setTimeout( + () => resolve({ durationMs: since(started), reason: `timed out after ${timeoutMs}ms` }), + timeoutMs + ); + timer.unref?.(); + }); try { - return await produce(); - } catch { - return undefined; + return await Promise.race([ + Promise.resolve(produce()).then((facts) => ({ facts, durationMs: since(started) })), + expiry, + ]); + } catch (err) { + return { durationMs: since(started), reason: describeError(err) }; + } finally { + clearTimeout(timer); } } export async function resolveHealth( options: HealthSourceOptions = {} ): Promise<{ envelope: HealthEnvelope; httpStatus: number }> { - const [checks, facts] = await Promise.all([ - options.checks?.length ? runChecks(options.checks, options.checkTimeoutMs) : undefined, - options.facts ? safeFacts(options.facts) : undefined, + const started = now(); + const [outcomes, factsOutcome] = await Promise.all([ + options.checks?.length + ? runCheckOutcomes(options.checks, options.checkTimeoutMs) + : Promise.resolve(undefined), + options.facts + ? safeFacts(options.facts, options.factsTimeoutMs ?? DEFAULT_CHECK_TIMEOUT_MS) + : Promise.resolve(undefined), ]); - const envelope = healthEnvelope(options.service, { checks, facts, env: options.env }); + + const checks: Record = {}; + const timings: Record = {}; + const reasons: Record = {}; + for (const [name, outcome] of Object.entries(outcomes ?? {})) { + checks[name] = outcome.state; + timings[name] = outcome.durationMs; + if (outcome.reason) reasons[name] = outcome.reason; + } + if (factsOutcome) { + timings.facts = factsOutcome.durationMs; + if (factsOutcome.reason) reasons.facts = factsOutcome.reason; + } + + const envelope = healthEnvelope(options.service, { + checks: outcomes ? checks : undefined, + timings, + reasons, + facts: factsOutcome?.facts, + env: options.env, + durationMs: since(started), + }); return { envelope, httpStatus: httpStatusFor(envelope.data.status) }; } +// Same numbers as `timings`, in the standard header, so the split shows up in browser +// devtools and in any proxy log without parsing the body. +const TOKEN = /[^A-Za-z0-9_-]/g; + +export function serverTimingHeader(data: HealthData): string { + const parts = [`health;dur=${data.durationMs}`]; + for (const [name, ms] of Object.entries(data.timings ?? {})) { + parts.push(`${name.replace(TOKEN, '_')};dur=${ms}`); + } + return parts.join(', '); +} + /** Structural: keeps express out of this package's dependencies. */ export interface HealthResponseLike { status(code: number): unknown; @@ -187,6 +351,7 @@ export function createHealthHandler(options: HealthSourceOptions = {}) { return async (_req: unknown, res: HealthResponseLike): Promise => { const { envelope, httpStatus } = await resolveHealth(options); res.setHeader('Cache-Control', 'no-store'); + res.setHeader('Server-Timing', serverTimingHeader(envelope.data)); res.status(httpStatus); res.json(envelope); }; @@ -197,7 +362,11 @@ export async function healthResponse(options: HealthSourceOptions = {}): Promise const { envelope, httpStatus } = await resolveHealth(options); return new Response(JSON.stringify(envelope), { status: httpStatus, - headers: { 'content-type': 'application/json; charset=utf-8', 'cache-control': 'no-store' }, + headers: { + 'content-type': 'application/json; charset=utf-8', + 'cache-control': 'no-store', + 'server-timing': serverTimingHeader(envelope.data), + }, }); } @@ -216,8 +385,8 @@ export function staticHealthJson(options: StaticHealthOptions = {}): string { status, service: resolveServiceName(options.service, env), ...provenance(env), - ...(options.checks ? { checks: options.checks } : {}), - ...(options.facts ? { facts: options.facts } : {}), + ...present('checks', options.checks), + ...present('facts', options.facts), }; return JSON.stringify({ success: status !== 'unavailable', diff --git a/test/health.test.ts b/test/health.test.ts index 7955eb8..9c32927 100644 --- a/test/health.test.ts +++ b/test/health.test.ts @@ -6,7 +6,9 @@ import { httpStatusFor, resolveHealth, resolveServiceName, + runCheckOutcomes, runChecks, + serverTimingHeader, staticHealthJson, statusFromChecks, type CheckState, @@ -288,3 +290,203 @@ describe('staticHealthJson', () => { expect(staticHealthJson({ service: 'agentage-ds', env: built })).not.toContain('\n'); }); }); + +describe('instance', () => { + it('is stable within a process, so a changing value means a different replica', () => { + const a = healthEnvelope('sync', { env: built }).data.instance; + const b = healthEnvelope('sync', { env: built }).data.instance; + expect(a).toBe(b); + expect(a).toMatch(/^[0-9a-z]{8}$/); + }); + + it('is not the hostname - /health is public and must not leak internal topology', () => { + const { instance } = healthEnvelope('sync', { env: built }).data; + expect(instance).not.toContain('.'); + expect(instance).not.toBe(process.env.HOSTNAME); + }); +}); + +describe('checkedAt', () => { + it('advances between calls - a frozen value is how a probe detects a cache', async () => { + const first = healthEnvelope('sync', { env: built }).data.checkedAt; + await new Promise((r) => setTimeout(r, 5)); + const second = healthEnvelope('sync', { env: built }).data.checkedAt; + expect(Date.parse(second)).toBeGreaterThan(Date.parse(first)); + }); + + it('is the instant uptime is measured against, so the two can never disagree', () => { + const startedAt = new Date(Date.now() - 90_000); + const checkedAt = new Date(startedAt.getTime() + 120_000); + const { data } = healthEnvelope('sync', { env: built, startedAt, checkedAt }); + expect(data.checkedAt).toBe(checkedAt.toISOString()); + expect(data.uptimeSeconds).toBe(120); + }); +}); + +describe('startedAt', () => { + it('is process start, not module load - a lazy Next route must not reset uptime', () => { + const { data } = healthEnvelope('sync', { env: built }); + const drift = Math.abs(Date.now() - process.uptime() * 1000 - Date.parse(data.startedAt)); + expect(drift).toBeLessThan(1000); + expect(data.uptimeSeconds).toBeGreaterThanOrEqual(Math.floor(process.uptime()) - 1); + }); +}); + +describe('timings', () => { + it('reports what each check cost, so a memoized one is visibly not a real query', async () => { + const { envelope } = await resolveHealth({ + env: built, + checks: [ + { name: 'cached', run: () => true }, + { name: 'real', run: () => new Promise((r) => setTimeout(() => r(true), 40)) }, + ], + }); + const timings = envelope.data.timings!; + expect(timings.cached).toBeLessThan(10); + expect(timings.real).toBeGreaterThanOrEqual(35); + }); + + it('times the facts producer under its own key', async () => { + const { envelope } = await resolveHealth({ + env: built, + facts: () => new Promise((r) => setTimeout(() => r({ servers: 1 }), 30)), + }); + expect(envelope.data.timings!.facts).toBeGreaterThanOrEqual(25); + }); + + it('reports a total that covers the slowest check, since checks run in parallel', async () => { + const slow = (ms: number) => () => new Promise((r) => setTimeout(() => r(true), ms)); + const { envelope } = await resolveHealth({ + env: built, + checks: [ + { name: 'a', run: slow(40) }, + { name: 'b', run: slow(40) }, + ], + }); + expect(envelope.data.durationMs).toBeGreaterThanOrEqual(35); + expect(envelope.data.durationMs).toBeLessThan(120); + }); + + it('omits both maps on a service with no checks and no facts', async () => { + const { envelope } = await resolveHealth({ service: 'landing', env: built }); + expect(envelope.data).not.toHaveProperty('timings'); + expect(envelope.data).not.toHaveProperty('reasons'); + }); +}); + +describe('reasons', () => { + it('separates a timeout from an instant refusal - both read "down" alone', async () => { + const { envelope } = await resolveHealth({ + env: built, + checks: [ + { name: 'slow', run: () => new Promise(() => {}), timeoutMs: 20 }, + { name: 'refused', run: () => Promise.reject(new Error('ECONNREFUSED 10.0.0.4:5432')) }, + ], + }); + expect(envelope.data.reasons).toEqual({ + slow: 'timed out after 20ms', + refused: 'ECONNREFUSED 10.0.0.4:5432', + }); + }); + + it('says nothing about a check that simply reported false', async () => { + const { envelope } = await resolveHealth({ + env: built, + checks: [{ name: 'db', run: () => false }], + }); + expect(envelope.data.checks).toEqual({ db: 'down' }); + expect(envelope.data).not.toHaveProperty('reasons'); + }); + + it('flattens and bounds a driver message rather than pasting a stack onto a public page', async () => { + const { envelope } = await resolveHealth({ + env: built, + checks: [{ name: 'db', run: () => Promise.reject(new Error(`a\nb${'x'.repeat(500)}`)) }], + }); + const reason = envelope.data.reasons!.db; + expect(reason).not.toContain('\n'); + expect(reason.length).toBeLessThanOrEqual(203); + expect(reason.endsWith('...')).toBe(true); + }); +}); + +describe('facts timeout', () => { + it('bounds a hanging producer instead of outliving the container HEALTHCHECK', async () => { + const started = Date.now(); + const { envelope, httpStatus } = await resolveHealth({ + env: built, + facts: () => new Promise>(() => {}), + factsTimeoutMs: 30, + }); + expect(Date.now() - started).toBeLessThan(500); + expect(httpStatus).toBe(200); + expect(envelope.data).not.toHaveProperty('facts'); + expect(envelope.data.reasons!.facts).toBe('timed out after 30ms'); + }); + + it('keeps a hung fact from downing a service whose checks all passed', async () => { + const { envelope } = await resolveHealth({ + env: built, + checks: [{ name: 'db', run: () => true }], + facts: () => new Promise>(() => {}), + factsTimeoutMs: 20, + }); + expect(envelope.data.status).toBe('ok'); + expect(envelope.success).toBe(true); + }); +}); + +describe('runCheckOutcomes', () => { + it('carries state, cost and reason per check', async () => { + const outcomes = await runCheckOutcomes([ + { name: 'db', run: () => true }, + { name: 'cache', optional: true, run: () => new Promise(() => {}), timeoutMs: 15 }, + ]); + expect(outcomes.db.state).toBe('ok'); + expect(outcomes.db.reason).toBeUndefined(); + expect(outcomes.cache).toMatchObject({ state: 'degraded', reason: 'timed out after 15ms' }); + expect(outcomes.cache.durationMs).toBeGreaterThanOrEqual(10); + }); +}); + +describe('serverTimingHeader', () => { + it('mirrors the body timings into the standard header', async () => { + const { envelope } = await resolveHealth({ + env: built, + checks: [{ name: 'db', run: () => true }], + facts: () => ({ servers: 3 }), + }); + const header = serverTimingHeader(envelope.data); + expect(header).toMatch(/^health;dur=[\d.]+/); + expect(header).toContain('db;dur='); + expect(header).toContain('facts;dur='); + }); + + it('sanitises a check name that is not a valid header token', () => { + const header = serverTimingHeader({ + ...healthEnvelope('sync', { env: built }).data, + timings: { 'redis cache': 4 }, + }); + expect(header).toContain('redis_cache;dur=4'); + }); + + it('is set on both transports', async () => { + const res = await healthResponse({ + service: 'dashboard', + env: built, + checks: [{ name: 'store', run: () => true }], + }); + expect(res.headers.get('server-timing')).toContain('store;dur='); + }); +}); + +describe('staticHealthJson timing fields', () => { + it('omits every field a build-time payload cannot honestly report', () => { + const { data } = JSON.parse(staticHealthJson({ service: 'web', env: built })) as { + data: Record; + }; + for (const field of ['instance', 'checkedAt', 'durationMs', 'timings', 'reasons']) { + expect(data).not.toHaveProperty(field); + } + }); +});