feat(plugin,console): served_wrong -- every cached copy found to differ from the origin while it was being served, by detector and field, with an upper bound on how long it was out; v0.102.0

One emit per detection, from data the detector already holds: no per-serve work and no extra reads.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

Author: trial

packages/console/src/admin/views/traffic.js

@@ -187,6 +187,7 @@ export function render(ctx) {
 		negativeCache(ctx, data, filter),
 		entityServe(ctx, data, filter),
 		entityRegistry(ctx, data),
+		servedWrong(data),
 		breadth(ctx, filter),
 		el('div', { cls: 'scan-foot' }, [scanFooter(data)]),
 		knobs,
@@ -2524,6 +2525,62 @@ function entityRegistry(ctx, data) {
 	});
 }
 
+// Who found a served copy wrong (plugin `served_wrong` detail), in the order they usually run.
+const SERVED_WRONG_DETECTORS = [
+	['check', 'serve-time checks'],
+	['check-raw', 'checks of raw documents'],
+	['render-check', 'render checks'],
+	['sweep', 'the nightly pass'],
+	['negative-recheck', 'stored-404 re-checks'],
+	['negative-fetch', 'stored 404s a crawler’s miss found live'],
+];
+
+/**
+ * Served while wrong (plugin v0.102.0, prerender_ops `served_wrong`): every cached copy — a page, a raw document, a
+ * stored 404 — found to differ from the origin while it was being served, by the detector that found it. The value
+ * is an UPPER BOUND on how long it was out there (since it was last known right), so the percentiles say how long
+ * wrong copies lived, and the count by field says what was wrong. Serves per wrong copy are not counted.
+ */
+function servedWrong(data) {
+	const found = pick(data, 'prerender_ops', (s) => s.path === 'served_wrong');
+	const help = [
+		'Cached copies found to differ from the origin while they were being served, at the moment a check, the ',
+		'nightly pass, a render check or a stored-404 re-check found them. Each one’s age is how long it had been ',
+		'served since it was last known right — an upper bound. How many times each was served is not counted.',
+	];
+	if (!found.length) {
+		return card('Served while wrong', {
+			head: [spacer()],
+			help,
+			body: [el('div', { cls: 'empty', text: 'Nothing found wrong in this range.' })],
+		});
+	}
+	const of = (detector) => found.filter((s) => s.method === detector);
+	const byField = new Map();
+	for (const s of found) byField.set(s.type ?? 'unknown', (byField.get(s.type ?? 'unknown') ?? 0) + s.count);
+	const fields = [...byField].sort((a, b) => b[1] - a[1]).slice(0, 4);
+	return card(`Served while wrong — ${scopeLabel(data)}`, {
+		head: [spacer()],
+		help,
+		body: [
+			stats(
+				SERVED_WRONG_DETECTORS.filter(([key]) => of(key).length > 0).map(([key, label]) => {
+					const rows = of(key);
+					return stat(
+						`Found by ${label}`,
+						fmtCount(sumCount(rows)),
+						`out for ≤ ${fmtMs(weighted(rows, 'median'))} median · ≈${fmtMs(weighted(rows, 'p95'))} p95`
+					);
+				})
+			),
+			el('div', { cls: 'note' }, [
+				'Most often wrong: ',
+				fields.map(([field, n]) => `${field} (${num(n)})`).join(' · '),
+			]),
+		],
+	});
+}
+
 /** Days of crawl sketch one breadth read covers — the Crawl breadth panel's trend and the miss recurrence. */
 const BREADTH_DAYS = 7;
 

packages/console/test/trafficView.test.js

@@ -1445,3 +1445,33 @@ test('the registry panel is a quiet “off” when the registry is off and silen
 	const text = everything(ctx);
 	assert.match(text, /Entity registry/);
 });
+
+// ---- served while wrong (plugin served_wrong) -------------------------------------------
+
+test('the served-while-wrong card: wrong copies by the detector that found them, how long they were out, and what was wrong', async () => {
+	const analytics = {
+		...ANALYTICS,
+		series: [
+			...ANALYTICS.series,
+			combo('prerender_ops', 'served_wrong', 'check', '2:product.offers', 40, 3 * 3_600_000, 9 * 3_600_000),
+			combo('prerender_ops', 'served_wrong', 'check', '6:canonical', 5, 2 * 3_600_000, 4 * 3_600_000),
+			combo('prerender_ops', 'served_wrong', 'sweep', '2:product.offers', 300, 8 * 3_600_000, 20 * 3_600_000),
+			combo('prerender_ops', 'served_wrong', 'negative-recheck', '404', 7, 90_000, 600_000),
+		],
+	};
+	const ctx = makeCtx({ analytics });
+	await load(ctx);
+	const text = everything(ctx);
+	assert.match(text, /Served while wrong/);
+	assert.match(text, /Found by serve-time checks/);
+	assert.match(text, /Found by the nightly pass/);
+	assert.match(text, /Found by stored-404 re-checks/);
+	assert.match(text, /out for ≤ 8\.0h median · ≈20\.0h p95/);
+	assert.match(text, /Most often wrong: 2:product\.offers \(340\) · 404 \(7\) · 6:canonical \(5\)/);
+});
+
+test('the served-while-wrong card says so when nothing was found wrong', async () => {
+	const ctx = makeCtx({ analytics: ANALYTICS });
+	await load(ctx);
+	assert.match(everything(ctx), /Nothing found wrong in this range/);
+});

packages/plugin/METRICS.md

@@ -202,6 +202,18 @@ Notes that bite:
   entity, because the observation that moved the registry also filed the new canonical; under the
   adoption dry run, or past `maxPerHour`, it lasts until the new canonical renders by another path. `entity_serve_ms` (v0.102.0) is each evaluation's duration, every outcome: a
   duration, so read its percentiles.
+- **What was served wrong is `prerender_ops` / `served_wrong`** (v0.102.0): one emit per cached copy found
+  to differ from the origin while it was being served (a rendered page, a raw document, a stored 404), at the
+  moment a detector found it. Never per serve, so it costs the request path nothing. The value is an **upper
+  bound** on how long that copy was served wrong: ms since it was last known right (its render, or the last
+  check that agreed with that very copy; for a 404, its last confirmation). Detail = the detector: `check` /
+  `check-raw` (a serve-time check of a page or a raw document), `sweep` (the nightly pass; the canary is
+  left out, its cohort repeats every half hour), `render-check` (a render that landed disagreeing with the
+  origin), `negative-recheck` / `negative-fetch` (a stored 404 the origin answers 200 for, found by the
+  re-check or by a proxied request). Context = what disagreed: the `pageCheck` field label (`2:product.offers`,
+  `6:canonical`, …), `claim` (the price/availability pair) or `404`. **Read the count per field** (how many
+  wrong copies, of what) **and the percentiles per detector** (how long they were out). The number of serves
+  each made is not here: that would need a per-key serve counter, which the plugin deliberately does not keep.
 - **The entity registry is `prerender_ops` / `entity_canonical` and `canonical_adopt`** (v0.101.0,
   `entities.enabled`, on by default for routes with an `entityPrefix`). `entity_canonical`: one emit per observation of an entity's canonical, detail =
   what it did to the registry (`new`, `moved`, `same`, `older`, `foreign` — another entity's prefix, or a

packages/plugin/src/metrics.js

@@ -725,6 +725,16 @@ export const METRICS = Object.freeze({
 			'this in; a route stuck here has no rule that maps `canonical`), moved (the entity registry heard the ' +
 			'origin name another canonical after the page was last confirmed: a re-slug it predates), ' +
 			'not-self-canonical, unreadable, no-prefix, error. ' +
+			'served_wrong = one emit per cached copy found to differ from the origin while it was being served ' +
+			'(a 200 page, a raw document or a stored 404), at the moment a detector found it — never per serve, so ' +
+			'it costs nothing on the request path. The value is an UPPER BOUND on how long that copy was served ' +
+			'wrong: ms since it was last known right (its render, or the last check that agreed with this very ' +
+			'copy; for a 404 its last confirmation). detail = the detector: check / check-raw (a serve-time check), ' +
+			'sweep (the nightly pass; not the canary), render-check (a render that landed wrong), negative-recheck / ' +
+			'negative-fetch (a stored 404 the origin answers 200 for); context = what disagreed: the pageCheck field ' +
+			'label, claim (the price/availability pair), or 404. The count is how many wrong copies were found; the ' +
+			'percentiles are how long they were out there. How many serves each one made is not counted: that needs ' +
+			'a per-key serve counter, which the plugin deliberately does not keep. ' +
 			'entity_serve_ms = milliseconds one entity-serve evaluation took, every outcome: what an opted-in ' +
 			'route adds to a miss before the miss path runs. ' +
 			'entity_canonical = one emit per observation of an entity\u2019s canonical (entities.enabled, ' +
@@ -814,7 +824,7 @@ export const METRICS = Object.freeze({
 			'(promoted/demoted/held/skipped_cold/single_rung/promoted_fast/fast/graded) are per-interval/per-run counts whose `total` is the meaningful ' +
 			'sum (`count` is flushes/runs); serve_error, page_age_negative, invalidation_error, ' +
 			'invalidation_reenqueue, probe_canary_trip, probe_invalidated, discovery_gated, entity_gate, raw_cache, negative_cache, ' +
-			'gone_reopen, suppression_lifted, suppression_held, due_now_forward and serve_check are counters; negative_gap, probe_detection_lag and entity_serve_ms are durations (ms — read their percentiles, not their total); ' +
+			'gone_reopen, suppression_lifted, suppression_held, due_now_forward and serve_check are counters; negative_gap, probe_detection_lag, entity_serve_ms and served_wrong are durations (ms — read their percentiles, not their total; served_wrong\u2019s count is the number of wrong copies found); ' +
 			'config_warnings is a slow gauge (latest value); ' +
 			'demand_fill is a per-node gauge (one worker refreshes the node\u2019s union) — never sum it, and READ ITS PEAK, NOT ITS MEAN. It is the ' +
 			'set-bit fraction of the newest visit-filter slot, which resets to ~0 at every slice rollover ' +
@@ -880,6 +890,7 @@ export const METRICS = Object.freeze({
 					'entity_serve_ms',
 					'entity_canonical',
 					'canonical_adopt',
+					'served_wrong',
 					'raw_cache',
 					'negative_cache',
 					'negative_gap',
@@ -1242,6 +1253,15 @@ export const metrics = Object.freeze({
 	pageVerification: (outcome) => server.recordAnalytics(true, 'prerender_ops', 'page_verification', outcome, null),
 	serveCheck: (outcome, source) =>
 		server.recordAnalytics(true, 'prerender_ops', 'serve_check', outcome, source ?? null),
+	/**
+	 * A cached copy that was being SERVED, found to differ from the origin — one emit per detection, never per
+	 * serve. The value is an UPPER BOUND on how long it was served that way: ms since it was last known right
+	 * (its render, or the last check that agreed with this very copy; a 404's last confirmation). `detector`:
+	 * check | check-raw | sweep | render-check | negative-recheck | negative-fetch. `what`: the field that
+	 * disagreed (a pageCheck field label, `claim` for the price/availability pair), or `404`.
+	 */
+	servedWrong: (ms, detector, what) =>
+		server.recordAnalytics(Math.max(0, ms), 'prerender_ops', 'served_wrong', detector, what ?? null),
 	invalidationReenqueue: (outcome, scope) =>
 		server.recordAnalytics(true, 'prerender_ops', 'invalidation_reenqueue', outcome, scope ?? null),
 

packages/plugin/src/util/changeProbe.js

@@ -1108,6 +1108,7 @@ const confirmStaleRender = async (url, target, claimAtMs = NaN) => {
 		});
 	}
 	countProbe('render_mismatch', 'confirmed');
+	if (Number.isFinite(claimAtMs)) metrics.servedWrong(Date.now() - claimAtMs, 'render-check', 'claim');
 	logger.info?.(
 		`[prerender] change-probe: the render of ${url} disagrees with the origin, asked again — expired and re-filed`
 	);
@@ -1394,6 +1395,10 @@ export const runProbePass = async ({
 	// Called with (rule, row) for every origin CHANGE the pass detects (the rows counted `changed`) —
 	// what the detection-lag metric is emitted from.
 	onChange = () => {},
+	// Called with `{ what, knownRightAt }` for every cached page found disagreeing with the origin (the rows
+	// counted `pageMismatch`): the field, and when the page was last known right. The sweep wires the
+	// `served_wrong` metric; the canary, whose cohort repeats every half hour, wires none.
+	onServedWrong = null,
 	// What an active invalidation already does for a URL the pass would act on (`coverageOf`): 'covered',
 	// 'healed' or null. Null = no such check (the canary, and every pass that does not wire it).
 	coverageOf = null,
@@ -1600,6 +1605,7 @@ export const runProbePass = async ({
 		let verdicts = null;
 		let facts = null;
 		let mappedDisagrees = false;
+		let firstWrong = null;
 		let mappedAgreed = 0;
 		const armed = (field) => !guard || guard.isArmed(rule, field);
 		if (mappedFields.length && stored?.pageFacts && valuesOf()) {
@@ -1621,14 +1627,25 @@ export const runProbePass = async ({
 					if (witnessed) guard?.witness(rule, field, verdict === false);
 					if (verdict === false) {
 						bump(stats.fieldMismatch, rule.label, field.label);
-						if (armed(field)) mappedDisagrees = true;
+						if (armed(field)) {
+							mappedDisagrees = true;
+							firstWrong ??= field.label;
+						}
 					} else if (armed(field)) {
 						mappedAgreed++;
 					}
 				}
 			}
 		}
-		if (pageDisagrees || mappedDisagrees) stats.pageMismatch++;
+		if (pageDisagrees || mappedDisagrees) {
+			stats.pageMismatch++;
+			// Wrong since its render; or, when the origin changed since the last pass, since that pass at most.
+			if (onServedWrong) {
+				const renderedAt = epochOf(stored?.pageClaimAt);
+				const knownRightAt = signatureChanged ? Math.max(renderedAt, Number(stored.probedAt)) : renderedAt;
+				if (Number.isFinite(knownRightAt)) onServedWrong({ what: firstWrong ?? 'claim', knownRightAt });
+			}
+		}
 
 		// WHICH SLOTS CHANGED, and whether the change needs a render at all. Two ways it may not:
 		//
@@ -2586,6 +2603,7 @@ export const runProbeSweepOnce = async ({
 			onStart: (running) => (live = running),
 			onBatch: () => emit(counts()),
 			onChange: detectionLag,
+			onServedWrong: ({ what, knownRightAt }) => metrics.servedWrong(Date.now() - knownRightAt, 'sweep', what),
 			coverageOf: (url, evidence) => coverageOf(url, evidence, epochFor),
 			onPace: (rate, originThrottle, loadThrottle) =>
 				publishSweepHeadroom(

packages/plugin/src/util/negativeCache.js

@@ -312,7 +312,15 @@ export const negativeRechecksInFlight = () => inFlightChecks.size;
  * `onLive` hears about a 200 so a gone-suppressed target for the URL can be reopened (util/goneReopen.js):
  * the entry going away fixes what this node SERVES, and only a render fixes what the rotation HOLDS.
  */
-export const settleNegativeRecheck = async ({ key, cacheUrl, statusCode, policy, onLive, nowMs = Date.now() }) => {
+export const settleNegativeRecheck = async ({
+	key,
+	cacheUrl,
+	statusCode,
+	policy,
+	onLive,
+	confirmedAtMs = NaN,
+	nowMs = Date.now(),
+}) => {
 	if (policy.statuses.includes(statusCode)) {
 		await confirmNegativePage(key, policy, nowMs);
 		metrics.negativeCache('recheck-gone');
@@ -321,6 +329,8 @@ export const settleNegativeRecheck = async ({ key, cacheUrl, statusCode, policy,
 	if (statusCode >= 200 && statusCode < 300) {
 		await dropNegativePage(key);
 		metrics.negativeCache('recheck-live');
+		// Served as a 404 since its last confirmation, at most: the request that asked for this re-check got it.
+		if (Number.isFinite(confirmedAtMs)) metrics.servedWrong(nowMs - confirmedAtMs, 'negative-recheck', '404');
 		if (statusCode === 200 && onLive) {
 			try {
 				await onLive(cacheUrl);
@@ -386,6 +396,7 @@ export const startNegativeRecheck = ({
 	policy,
 	onLive,
 	refreshBody = false,
+	confirmedAtMs = NaN,
 	fetchOrigin = fetchOriginResource,
 }) => {
 	if (inFlightChecks.has(key)) {
@@ -419,7 +430,7 @@ export const startNegativeRecheck = ({
 		// has to be closed to release the socket — by destroying the source, not cancelling the web stream
 		// (see `releaseOriginBody`), and not awaited, so nothing can pin the re-check slot.
 		releaseOriginBody(resource);
-		await settleNegativeRecheck({ key, cacheUrl, statusCode: resource.statusCode, policy, onLive });
+		await settleNegativeRecheck({ key, cacheUrl, statusCode: resource.statusCode, policy, onLive, confirmedAtMs });
 	})()
 		.catch((e) => logger.warn?.(`[prerender] negative-cache re-check failed for ${key}: ${e?.message ?? String(e)}`))
 		.finally(() => inFlightChecks.delete(key));
@@ -514,6 +525,7 @@ export const answerFromNegativeCache = async ({
 					policy,
 					onLive,
 					refreshBody: negativeBodyExpired(row, policy, nowMs),
+					confirmedAtMs: checkedAtMs,
 				})
 			: false;
 	return {
@@ -576,7 +588,14 @@ export const afterNegativeProxy = (
 		if (policy.dryRun && !excluded && status === 200 && (verdict === 'fresh' || verdict === 'revalidate')) {
 			metrics.negativeCache('would-serve-live');
 		}
-		if (status >= 200 && status < 400) void dropNegativePage(key);
+		if (status >= 200 && status < 400) {
+			// An ARMED cache was answering other crawlers with this 404 until now (a dry run answered nobody).
+			if (!policy.dryRun && status === 200) {
+				const confirmedAtMs = dateColumnMs(row.checkedAt);
+				if (Number.isFinite(confirmedAtMs)) metrics.servedWrong(nowMs - confirmedAtMs, 'negative-fetch', '404');
+			}
+			void dropNegativePage(key);
+		}
 	}
 	return resource;
 };

packages/plugin/src/util/serveCheck.js

@@ -481,6 +481,12 @@ const settleMismatch = async (item, verdict, prior) => {
 	}
 	const acted = await act(item);
 	if (acted === null) return;
+	// SERVED WRONG, since the copy was last known right: its render, or a check that agreed with this very copy.
+	const agreedAt = prior?.outcome === 'agree' && prior.basisAtMs === item.lastCachedMs ? prior.checkedAtMs : -Infinity;
+	const knownRightAt = Math.max(item.lastCachedMs, agreedAt);
+	if (Number.isFinite(knownRightAt)) {
+		metrics.servedWrong(Date.now() - knownRightAt, item.kind === 'raw' ? 'check-raw' : 'check', verdict.field);
+	}
 	await deps.writeCheck(item.url, item.lastCachedMs, {
 		outcome: 'mismatch',
 		field: verdict.field,

packages/plugin/test/changeProbe.test.js

@@ -4088,3 +4088,48 @@ test('a baseline under another rule fingerprint is never spared by a check', asy
 	});
 	assert.deepEqual(probed, [URL_A]);
 });
+
+test('the sweep reports a page SERVED WRONG: since its render, or — when the origin moved — since the last pass at most', async () => {
+	const told = [];
+	const onServedWrong = (sample) => told.push(sample);
+	const unmoved = await apiSig();
+	await runMappedPass({
+		rows: [row(URL_A)],
+		answers: { [URL_A]: unmoved },
+		stored: { [URL_A]: { signature: unmoved, pageFacts: await RECORD({ title: 'Red Shoe (Old Name)' }) } },
+		onServedWrong,
+	});
+	assert.deepEqual(told, [{ what: '0:title', knownRightAt: RENDERED_AT.getTime() }], 'wrong since it was rendered');
+
+	// The origin changed since the baseline, rendered BEFORE that pass: right until then, at most.
+	told.length = 0;
+	const before = await apiSig({ title: 'Red Shoe (Old Name)' });
+	await runMappedPass({
+		rows: [row(URL_A)],
+		answers: { [URL_A]: unmoved },
+		stored: {
+			[URL_A]: {
+				signature: before,
+				probedAt: 5000,
+				pageClaimAt: RENDERED_AT,
+				pageFacts: await RECORD({ title: 'Red Shoe (Old Name)' }),
+			},
+		},
+		onServedWrong,
+	});
+	assert.deepEqual(told, [{ what: '0:title', knownRightAt: 5000 }]);
+
+	// A page that agrees is nothing to report; and no hook, no report (the canary wires none).
+	told.length = 0;
+	await runMappedPass({
+		rows: [row(URL_A)],
+		answers: { [URL_A]: unmoved },
+		stored: { [URL_A]: { signature: unmoved, pageFacts: await RECORD() } },
+		onServedWrong,
+	});
+	assert.deepEqual(told, []);
+	const SRC = await import('node:fs').then((fs) =>
+		fs.readFileSync(new URL('../src/util/changeProbe.js', import.meta.url), 'utf8')
+	);
+	assert.equal(SRC.match(/onServedWrong: \(/g)?.length, 1, 'wired once: the sweep');
+});