diff --git a/package-lock.json b/package-lock.json index 1716299..9473882 100644 --- a/package-lock.json +++ b/package-lock.json @@ -9007,7 +9007,7 @@ }, "packages/plugin": { "name": "@harperfast/prerender", - "version": "0.32.0", + "version": "0.33.0", "license": "Apache-2.0", "dependencies": { "fast-xml-parser": "^5.0.9", diff --git a/packages/plugin/README.md b/packages/plugin/README.md index 36623d2..e112b8c 100644 --- a/packages/plugin/README.md +++ b/packages/plugin/README.md @@ -129,8 +129,13 @@ rest: true # required for the @export-ed table REST endpoints analytics: enabled: true # record bot analytics at all: bot_request (ingress volume by host/bot/device), - # bot_serve (outcome by source/cache-status/bot — origin offload + cache hit rate), and - # page_age (ms since the served page rendered — freshness at serve, cache hits only) + # bot_serve (outcome by source/cache-status/bot — origin offload + cache hit rate), + # page_age (ms since the served page rendered — freshness at serve, cache-served only), + # route_serve (outcome by route/cache-status/device — per-route delivery, for tuning each + # route's renderInterval), and route_page_age (served age by route/cache-status/device). + # cache-status distinguishes 'hit' (within the page's renderInterval) from 'swr' (served + # from the stale-while-revalidate window because the re-render is late/in flight) — both + # are cache serves; 'hit' alone is the "is the TTL being met" signal. crawlStats: # crawl breadth: distinct URLs crawled per bot per UTC day (HyperLogLog, ~0.8% error) enabled: true # also gated by analytics.enabled above; read via GET /prerender_admin/crawl-breadth?days=7 diff --git a/packages/plugin/package.json b/packages/plugin/package.json index a069af1..53f44b7 100644 --- a/packages/plugin/package.json +++ b/packages/plugin/package.json @@ -1,6 +1,6 @@ { "name": "@harperfast/prerender", - "version": "0.32.0", + "version": "0.33.0", "type": "module", "description": "Configurable Harper plugin for prerendering pages for bots and crawlers", "license": "Apache-2.0", diff --git a/packages/plugin/src/http_handlers/bot_request.js b/packages/plugin/src/http_handlers/bot_request.js index 1fa81c3..f0e5f14 100644 --- a/packages/plugin/src/http_handlers/bot_request.js +++ b/packages/plugin/src/http_handlers/bot_request.js @@ -12,6 +12,7 @@ import { QueueState } from '../resources/QueueState.js'; import { fetchOriginResource } from '../util/upstream.js'; import { PrerenderedPage } from '../resources/PrerenderedPage.js'; import { resolveServingPolicy, pollForFreshRender } from '../util/renderNow.js'; +import { cacheServeStatus } from '../util/pageFreshness.js'; import { currentMinuteMs } from '../util/time.js'; import { recordCrawl } from '../util/crawlStats.js'; import { deliverResource } from './response.js'; @@ -61,17 +62,36 @@ export async function handleBotRequest(request) { // rollout success metrics: // // origin offload = bot_serve where source !== 'origin' (requests the origin never saw) -// cache hit rate = bot_serve by cacheStatus (hit / stale / miss / skip / bypass) +// cache hit rate = bot_serve by cacheStatus (hit / swr / stale / miss / skip / bypass). +// 'hit' is within the page's renderInterval; 'swr' is served from the +// stale-while-revalidate window. Cache-served = hit + swr; treat hit +// alone as the freshness signal ("is the configured TTL being met"). // freshness = page_age, ms since the served page rendered (cache-served only, so a // render-now response doesn't drag the distribution toward zero) // -// Cost: one in-memory counter bump per request plus one numeric sample on a cache hit +// Per-route variants of the same two signals, for tuning each route's renderInterval up or +// down independently (recordAnalytics has exactly three dimension slots — path/method/type — +// and bot_serve's are all taken, hence separate metrics rather than a fourth dimension): +// +// route_serve = (route, cacheStatus, deviceType) counter. swr/stale share per route +// says whether that route's cadence is being DELIVERED; miss share says +// whether its corpus is even covered. +// route_page_age = (route, cacheStatus, deviceType), ms since render, cache-served only. +// Served age per route against that route's own renderInterval is the +// "should this TTL move" number. +// +// The route label is the matched route's path ('/', '/catalog/', '/product/prd-' — tiny, +// stable cardinality), else the route class for passthrough, else 'unrouted'. +// +// Cost: two counter bumps per request plus two numeric samples on a cache hit // (recordAnalytics buffers in a Map and flushes on Harper's analytics timer) — no storage // touch, no await, nothing added to response latency. // // Exported for tests: the dimension ORDER is the contract dashboards key on. export function recordServeOutcome(resource, request, info, deviceType) { + const route = info.route?.path ?? info.routeClass ?? 'unrouted'; server.recordAnalytics(true, 'bot_serve', info.source, info.cacheStatus, request.botName); + server.recordAnalytics(true, 'route_serve', route, info.cacheStatus, deviceType); if (info.source === 'cache' && resource.lastCached) { // lastCached is a schema Date — guard truthiness FIRST, then coerce, exactly like the // expiresAt read above: `new Date(null)` is epoch 0 (not NaN), so an unguarded null @@ -82,6 +102,7 @@ export function recordServeOutcome(resource, request, info, deviceType) { const age = Date.now() - new Date(resource.lastCached).getTime(); if (age >= 0) { server.recordAnalytics(age, 'page_age', request.botName, deviceType); + server.recordAnalytics(age, 'route_page_age', route, info.cacheStatus, deviceType); } } } @@ -150,12 +171,12 @@ async function resolveResource({ request, url, cacheUrl, deviceType, routeClass, const page = skipCache ? null : await PrerenderedPage.get(cacheKey); // expiresAt is a schema `Date` (stored from Date.now()); read it robustly so a Date, // number, or serialized string all compare correctly — cf. the Number() coercion in - // util/renderNow.js. A bad/missing value yields NaN => not fresh. + // util/renderNow.js. A bad/missing value yields NaN => not servable from cache. const expiresAtMs = page && page.expiresAt ? new Date(page.expiresAt).getTime() : NaN; - const fresh = !isNaN(expiresAtMs) && expiresAtMs + config.page.swrTtl > Date.now(); + const serveStatus = cacheServeStatus(expiresAtMs, config.page.swrTtl, Date.now()); - if (fresh) { - info.cacheStatus = 'hit'; + if (serveStatus) { + info.cacheStatus = serveStatus; info.source = 'cache'; return page; } diff --git a/packages/plugin/src/resources/PrerenderAdmin.js b/packages/plugin/src/resources/PrerenderAdmin.js index fefe550..6d725a8 100644 --- a/packages/plugin/src/resources/PrerenderAdmin.js +++ b/packages/plugin/src/resources/PrerenderAdmin.js @@ -60,6 +60,7 @@ import { describeConfigSchema } from '../configSchema.js'; import { redactConfig } from '../util/redact.js'; import { explainCacheKey } from '../util/explain.js'; import { CacheKey } from '../util/cacheKey.js'; +import { cacheServeStatus } from '../util/pageFreshness.js'; import { CLUSTER_SCOPE } from '../util/queueControl.js'; import { getResidencyByUrl } from '../util/residency.js'; import { fetchScheduleFromPeer } from '../util/peer.js'; @@ -710,9 +711,9 @@ export class PrerenderAdmin extends Resource { const now = Date.now(); const expiresAtMs = page?.expiresAt ? new Date(page.expiresAt).getTime() : NaN; - // Same freshness rule the serving path applies, so this cannot disagree with what a - // bot would actually get. - const fresh = !isNaN(expiresAtMs) && expiresAtMs + config.page.swrTtl > now; + // THE freshness rule the serving path applies (same function, not a copy), so this + // cannot disagree with what a bot would actually get. + const fresh = cacheServeStatus(expiresAtMs, config.page.swrTtl, now) !== null; // The local schedule read was node-local. If another node owns this row, ask it — a // bounded HTTPS call we control, rather than the unbounded replication fetch a plain @@ -1022,7 +1023,7 @@ export class PrerenderAdmin extends Resource { if (page) { const expiresAtMs = page.expiresAt ? new Date(page.expiresAt).getTime() : NaN; - const fresh = !isNaN(expiresAtMs) && expiresAtMs + config.page.swrTtl > Date.now(); + const fresh = cacheServeStatus(expiresAtMs, config.page.swrTtl, Date.now()) !== null; return { ...base, cacheKey, state: fresh ? 'cached' : 'stale' }; } @@ -1146,8 +1147,8 @@ export class PrerenderAdmin extends Resource { lastCached: row.lastCached ? new Date(row.lastCached).getTime() : null, expiresAt: Number.isFinite(expiresAtMs) ? expiresAtMs : null, isIndexable: row.isIndexable ?? null, - // Same freshness rule the serving path applies. - fresh: !isNaN(expiresAtMs) && expiresAtMs + config.page.swrTtl > now, + // THE freshness rule the serving path applies (same function, not a copy). + fresh: cacheServeStatus(expiresAtMs, config.page.swrTtl, now) !== null, url: urlHalf || null, deviceType: deviceType ?? null, }; diff --git a/packages/plugin/src/util/pageFreshness.js b/packages/plugin/src/util/pageFreshness.js new file mode 100644 index 0000000..53ba5cb --- /dev/null +++ b/packages/plugin/src/util/pageFreshness.js @@ -0,0 +1,21 @@ +/** + * The ONE definition of whether a cached page is servable, and under which status. Every + * consumer — the bot serve path, the admin explain/pages views — must call this rather than + * re-deriving the comparison, so the admin can never disagree with what a bot actually gets, + * and a future change (per-route swrTtl) lands everywhere at once. + */ + +/** + * Can this cached page be served, and under which status? 'hit' = within the page's own + * renderInterval (expiresAt is still ahead); 'swr' = past expiresAt but inside the + * stale-while-revalidate window (the re-render is late or still in flight); null = not + * servable from cache (stale/miss — fall through to the miss mode). The serve is identical + * either way; the split exists because folding both into 'hit' made the headline hit rate + * unreadable as a freshness signal: at one measured point 71.9% "hit" quietly included ~13% + * of the corpus being served past expiry. A NaN expiresAtMs fails both comparisons => null. + */ +export function cacheServeStatus(expiresAtMs, swrTtl, now) { + if (expiresAtMs > now) return 'hit'; + if (expiresAtMs + swrTtl > now) return 'swr'; + return null; +} diff --git a/packages/plugin/test/botServe.test.js b/packages/plugin/test/botServe.test.js index 5b10a2b..7bb53b6 100644 --- a/packages/plugin/test/botServe.test.js +++ b/packages/plugin/test/botServe.test.js @@ -8,8 +8,12 @@ import assert from 'node:assert/strict'; * - `bot_serve` dimension ORDER is (source, cacheStatus, botName). Dashboards key on the * positional path/method/type triple Harper builds from these, so reordering is a silent * breaking change. - * - `page_age` is recorded ONLY for a cache-served resource (source === 'cache'), so - * render-now responses never drag the freshness distribution toward zero. + * - `route_serve` is (route, cacheStatus, deviceType) and `route_page_age` mirrors it — + * the per-route TTL-tuning signals. Same positional contract. + * - The route label resolves route.path, then routeClass, then 'unrouted' — in that order. + * - `page_age`/`route_page_age` are recorded ONLY for a cache-served resource + * (source === 'cache'), so render-now responses never drag the freshness distribution + * toward zero. * - lastCached may arrive as a Date, a number, or a serialized string — all must yield the * same age. A missing value (NaN) or a negative age (cross-node clock skew) records * nothing rather than poisoning the mean. @@ -17,6 +21,7 @@ import assert from 'node:assert/strict'; let analytics = []; let recordServeOutcome; +let cacheServeStatus; before(async () => { // bot_request.js transitively imports the Harper resource classes; stub the runtime @@ -44,6 +49,7 @@ before(async () => { page_cache: { PrerenderedPage: class {} }, }; ({ recordServeOutcome } = await import('../src/http_handlers/bot_request.js')); + ({ cacheServeStatus } = await import('../src/util/pageFreshness.js')); }); beforeEach(() => { @@ -52,38 +58,87 @@ beforeEach(() => { const request = { botName: 'Googlebot' }; -test('bot_serve records (source, cacheStatus, botName) in that order', () => { +test('bot_serve records (source, cacheStatus, botName) and route_serve records (route, cacheStatus, deviceType)', () => { + recordServeOutcome({}, request, { source: 'origin', cacheStatus: 'miss', route: { path: '/catalog/' } }, 'desktop'); + assert.deepEqual(analytics, [ + [true, 'bot_serve', 'origin', 'miss', 'Googlebot'], + [true, 'route_serve', '/catalog/', 'miss', 'desktop'], + ]); +}); + +test('route label falls back route.path -> routeClass -> unrouted', () => { + recordServeOutcome({}, request, { source: 'origin', cacheStatus: 'miss', routeClass: 'passthrough' }, 'desktop'); recordServeOutcome({}, request, { source: 'origin', cacheStatus: 'miss' }, 'desktop'); - assert.deepEqual(analytics, [[true, 'bot_serve', 'origin', 'miss', 'Googlebot']]); + assert.equal(analytics[1][2], 'passthrough'); + assert.equal(analytics[3][2], 'unrouted'); }); -test('a cache hit also records page_age with (botName, deviceType)', () => { +test('a cache serve also records page_age (botName, deviceType) and route_page_age (route, cacheStatus, deviceType)', () => { const lastCached = Date.now() - 5000; // The three shapes a schema Date reaches this code in. for (const value of [new Date(lastCached), lastCached, new Date(lastCached).toISOString()]) { analytics = []; - recordServeOutcome({ lastCached: value }, request, { source: 'cache', cacheStatus: 'hit' }, 'mobile'); - assert.equal(analytics.length, 2); - const [age, metric, bot, device] = analytics[1]; + recordServeOutcome( + { lastCached: value }, + request, + { source: 'cache', cacheStatus: 'hit', route: { path: '/product/prd-' } }, + 'mobile' + ); + assert.equal(analytics.length, 4); + const [age, metric, bot, device] = analytics[2]; assert.equal(metric, 'page_age'); assert.equal(bot, 'Googlebot'); assert.equal(device, 'mobile'); assert.ok(age >= 4000 && age <= 7000, `expected age ~5000ms, got ${age}`); + const [rAge, rMetric, rRoute, rStatus, rDevice] = analytics[3]; + assert.equal(rMetric, 'route_page_age'); + assert.equal(rRoute, '/product/prd-'); + assert.equal(rStatus, 'hit'); + assert.equal(rDevice, 'mobile'); + assert.equal(rAge, age); } }); -test('page_age is skipped for a non-cache source, even with lastCached present', () => { +test('an swr serve carries cacheStatus swr through both route metrics', () => { + recordServeOutcome( + { lastCached: Date.now() - 5000 }, + request, + { source: 'cache', cacheStatus: 'swr', route: { path: '/catalog/' } }, + 'desktop' + ); + const statuses = analytics.map(([, metric, ...dims]) => [metric, dims]); + assert.deepEqual(statuses[0], ['bot_serve', ['cache', 'swr', 'Googlebot']]); + assert.deepEqual(statuses[1], ['route_serve', ['/catalog/', 'swr', 'desktop']]); + assert.equal(statuses[3][0], 'route_page_age'); + assert.equal(statuses[3][1][1], 'swr'); +}); + +test('age metrics are skipped for a non-cache source, even with lastCached present', () => { recordServeOutcome({ lastCached: Date.now() }, request, { source: 'rendered', cacheStatus: 'miss' }, 'desktop'); - assert.equal(analytics.length, 1); - assert.equal(analytics[0][1], 'bot_serve'); + assert.equal(analytics.length, 2); + assert.deepEqual( + analytics.map(([, metric]) => metric), + ['bot_serve', 'route_serve'] + ); }); -test('page_age is skipped when lastCached is missing, null, or in the future', () => { +test('age metrics are skipped when lastCached is missing, null, or in the future', () => { recordServeOutcome({}, request, { source: 'cache', cacheStatus: 'hit' }, 'desktop'); // null is the trap case: new Date(null) is epoch 0, not NaN — unguarded, this would // record age ≈ Date.now() instead of nothing. recordServeOutcome({ lastCached: null }, request, { source: 'cache', cacheStatus: 'hit' }, 'desktop'); recordServeOutcome({ lastCached: Date.now() + 60_000 }, request, { source: 'cache', cacheStatus: 'hit' }, 'desktop'); - assert.equal(analytics.length, 3); - assert.ok(analytics.every(([, metric]) => metric === 'bot_serve')); + assert.equal(analytics.length, 6); + assert.ok(analytics.every(([, metric]) => metric === 'bot_serve' || metric === 'route_serve')); +}); + +test('cacheServeStatus: hit before expiresAt, swr inside the window, null past it, null on NaN', () => { + const now = 1_000_000; + const swr = 100; + assert.equal(cacheServeStatus(now + 1, swr, now), 'hit'); + assert.equal(cacheServeStatus(now, swr, now), 'swr'); // expiry instant itself is already swr + assert.equal(cacheServeStatus(now - 99, swr, now), 'swr'); + assert.equal(cacheServeStatus(now - 100, swr, now), null); // window edge is exclusive + assert.equal(cacheServeStatus(NaN, swr, now), null); // missing/garbage expiresAt never serves + assert.equal(cacheServeStatus(now - 1, 0, now), null); // swrTtl 0 disables the window outright });