From b34d73dbb9ab175b085c85c3a3a56c7883ff8493 Mon Sep 17 00:00:00 2001 From: ScreenTinker Date: Tue, 28 Jul 2026 14:11:32 -0500 Subject: [PATCH] Report zero event-loop lag when a window recorded no samples A sampling window that recorded nothing leaves the histogram empty, and an empty IntervalHistogram reports its mean as NaN. Its percentiles return a floor instead, which is why only the mean was affected and why this went unnoticed. NaN then survives every arithmetic step in the sampler without complaint and becomes visible only at the edge, where JSON.stringify renders it as null. So /api/status served "mean_ms": null while nothing raised an error anywhere, and any consumer of that gauge read null instead of a number. Non-finite readings now report 0, which is the honest value: no samples means no measured delay. Applied to every field so a later change to the histogram source cannot reintroduce this one field at a time. Found by CI rather than locally, because an idle window is far likelier on a loaded runner with several test servers in flight. The failure was real; the new tests establish the NaN premise and the null serialisation directly rather than relying on that timing to reproduce. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01Uaeo9MvzKoyXuN6ZsbhtkL --- server/services/loop-lag.js | 19 ++++++-- server/test/loop-lag-empty-window.test.js | 58 +++++++++++++++++++++++ 2 files changed, 73 insertions(+), 4 deletions(-) create mode 100644 server/test/loop-lag-empty-window.test.js diff --git a/server/services/loop-lag.js b/server/services/loop-lag.js index 258dfc1..d422aaf 100644 --- a/server/services/loop-lag.js +++ b/server/services/loop-lag.js @@ -54,15 +54,23 @@ function nextBand(cur, p99, calm) { return [cur, 0]; } +// A sampling window that recorded NOTHING leaves the histogram empty, and an empty +// IntervalHistogram reports `mean` as NaN (its percentiles return a floor instead, which is +// why only the mean was ever affected). NaN survives every arithmetic step here and only +// becomes visible at the edge, where JSON.stringify turns it into `null` — so /api/status +// served `mean_ms: null` to anything reading it, and no error was raised anywhere. Zero is the +// honest value: no samples means no measured delay. Applied to every field so a future change +// to the histogram source cannot reintroduce this one field at a time. const round2 = (x) => Math.round(x * 100) / 100; +const metric = (x) => (Number.isFinite(x) ? round2(x) : 0); function sample() { const p99 = histogram.percentile(99) / NS_PER_MS; const snap = { - mean_ms: round2(histogram.mean / NS_PER_MS), - p50_ms: round2(histogram.percentile(50) / NS_PER_MS), - p99_ms: round2(p99), - max_ms: round2(histogram.max / NS_PER_MS), + mean_ms: metric(histogram.mean / NS_PER_MS), + p50_ms: metric(histogram.percentile(50) / NS_PER_MS), + p99_ms: metric(p99), + max_ms: metric(histogram.max / NS_PER_MS), }; histogram.reset(); @@ -135,3 +143,6 @@ function getBand() { return band; } function getLag() { return { ...current }; } module.exports = { startLoopLagMonitor, getBand, getLag, nextBand }; +// Exported for tests: the NaN-from-an-empty-window case is invisible in normal operation +// (it only surfaces after JSON serialisation) so it needs to be assertable directly. +module.exports._metric = metric; diff --git a/server/test/loop-lag-empty-window.test.js b/server/test/loop-lag-empty-window.test.js new file mode 100644 index 0000000..5419e65 --- /dev/null +++ b/server/test/loop-lag-empty-window.test.js @@ -0,0 +1,58 @@ +'use strict'; + +// An event-loop-lag sampling window that recorded nothing leaves the histogram empty, and an +// empty IntervalHistogram reports `mean` as NaN. NaN survives every arithmetic step in the +// sampler without complaint and only becomes visible at the very edge, where JSON.stringify +// silently renders it as `null` — so /api/status served `"mean_ms": null` and nothing anywhere +// raised an error. Anything consuming that gauge (a dashboard, an alerting rule) saw null +// instead of a number. +// +// It surfaced as a CI-only test failure — `typeof mean_ms` came back 'object' — because an +// idle window is far more likely on a loaded runner with several test servers in flight than +// on a developer machine. The failure was real, not flaky infrastructure. +// +// The rule pinned here: a metric with no samples reports 0, never NaN and never null. Zero is +// the honest answer — no samples means no measured delay. + +const { test } = require('node:test'); +const assert = require('node:assert/strict'); +const { monitorEventLoopDelay } = require('node:perf_hooks'); +const { _metric } = require('../services/loop-lag'); + +test('THE BUG: an empty histogram really does report NaN for mean', () => { + // Establishes the premise rather than assuming it — if Node ever changes this, the reason + // for the guard below disappears and this test says so. + const h = monitorEventLoopDelay({ resolution: 10 }); + h.enable(); h.disable(); h.reset(); + assert.ok(Number.isNaN(h.mean), 'empty histogram mean is NaN'); + assert.ok(Number.isFinite(h.percentile(99)), 'percentiles return a floor, which is why only mean broke'); +}); + +test('NaN would serialise to null, which is how it escaped notice', () => { + const round2 = (x) => Math.round(x * 100) / 100; + const unguarded = round2(NaN / 1e6); + assert.ok(Number.isNaN(unguarded), 'NaN propagates silently through the arithmetic'); + assert.equal(JSON.parse(JSON.stringify({ mean_ms: unguarded })).mean_ms, null, + 'and JSON.stringify turns it into null at the API boundary'); +}); + +test('the guard converts a non-finite reading to 0', () => { + assert.equal(_metric(NaN), 0); + assert.equal(_metric(Infinity), 0); + assert.equal(_metric(-Infinity), 0); +}); + +test('normal readings are untouched, still rounded to 2dp', () => { + assert.equal(_metric(1.234), 1.23); + assert.equal(_metric(0), 0); + assert.equal(_metric(15.005), 15.01); + assert.equal(_metric(1234.5678), 1234.57); +}); + +test('every guarded value survives a JSON round-trip as a number', () => { + const snap = { mean_ms: _metric(NaN), p50_ms: _metric(0), p99_ms: _metric(2.5), max_ms: _metric(NaN) }; + const back = JSON.parse(JSON.stringify(snap)); + for (const k of Object.keys(snap)) { + assert.equal(typeof back[k], 'number', `${k} stays numeric across the API boundary`); + } +});