diff --git a/package-lock.json b/package-lock.json index 421f4b7..4aed683 100644 --- a/package-lock.json +++ b/package-lock.json @@ -9007,7 +9007,7 @@ }, "packages/plugin": { "name": "@harperfast/prerender", - "version": "0.24.0", + "version": "0.26.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 cff5f9d..0e1d94b 100644 --- a/packages/plugin/README.md +++ b/packages/plugin/README.md @@ -133,7 +133,9 @@ rest: true # required for the @export-ed table REST endpoints excludePathPatterns: ['/search/'] # paths containing these are never auto-scheduled analytics: - enabled: true # record bot_request analytics at all + 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) recordUnmatched: true # also record UAs that matched no configured bot (as 'other') bots: # registry: which crawlers are tracked by name. { name, match } — match is a - { name: Googlebot, match: googlebot } # case-insensitive UA substring; longer matches win. diff --git a/packages/plugin/package.json b/packages/plugin/package.json index 527cde2..4057351 100644 --- a/packages/plugin/package.json +++ b/packages/plugin/package.json @@ -1,6 +1,6 @@ { "name": "@harperfast/prerender", - "version": "0.24.0", + "version": "0.26.0", "type": "module", "description": "Configurable Harper plugin for prerendering pages for bots and crawlers", "license": "Apache-2.0", diff --git a/packages/plugin/src/admin/views/overview.js b/packages/plugin/src/admin/views/overview.js index e38eb46..816e5b9 100644 --- a/packages/plugin/src/admin/views/overview.js +++ b/packages/plugin/src/admin/views/overview.js @@ -71,16 +71,18 @@ function counts(ctx, data) { /** * Bot traffic is the one number that says whether any of this is working, and it is the panel - * this console most obviously wants. The serving path already records a `bot_request` metric, - * but without a cache-status label there is no way to split hit from stale from miss — which is - * the entire point of the chart. Left declared and empty until that is decided. + * this console most obviously wants. The serving path now records everything it needs — the + * `bot_serve` metric (source / cacheStatus / botName, see http_handlers/bot_request.js) splits + * hit from stale from miss with the crawler breakdown, and `page_age` carries freshness. Left + * declared and empty until the remaining decision is made: reading node-local hdb_analytics + * vs aggregating across the cluster. */ const traffic = () => card('Bot traffic served, last 24h', { body: [ unwired( 'Requests served to bots, split by cache hit / stale / miss, with the crawler breakdown.', - 'a cache-status label on the bot_request analytics metric, and a decision on reading node-local hdb_analytics vs aggregating across the cluster' + 'a decision on reading node-local hdb_analytics vs aggregating across the cluster (the bot_serve and page_age metrics are recorded as of v0.26.0)' ), ], }); diff --git a/packages/plugin/src/http_handlers/bot_request.js b/packages/plugin/src/http_handlers/bot_request.js index 22661e1..a35e4d5 100644 --- a/packages/plugin/src/http_handlers/bot_request.js +++ b/packages/plugin/src/http_handlers/bot_request.js @@ -26,7 +26,8 @@ export async function handleBotRequest(request) { const { url, cacheUrl, deviceType, routeClass, route } = target; request.botName = getBotName(request.headers); - if (config.analytics.enabled && (request.botName !== 'other' || config.analytics.recordUnmatched)) { + const recordBots = config.analytics.enabled && (request.botName !== 'other' || config.analytics.recordUnmatched); + if (recordBots) { server.recordAnalytics(true, 'bot_request', url.hostname, request.botName, deviceType); } @@ -37,6 +38,9 @@ export async function handleBotRequest(request) { const resource = await resolveResource({ request, url, cacheUrl, deviceType, routeClass, info }); maybeSchedule(resource, routeClass); + if (recordBots) { + recordServeOutcome(resource, request, info, deviceType); + } return deliverResource(resource, request, info); } catch (e) { @@ -48,6 +52,36 @@ export async function handleBotRequest(request) { } } +// Serve-outcome analytics, recorded once the request has resolved to a resource. `bot_request` +// (above, at ingress) is raw bot volume; this is what actually answered the request — the +// 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) +// 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 +// (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) { + server.recordAnalytics(true, 'bot_serve', info.source, info.cacheStatus, request.botName); + 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 + // would record age ≈ Date.now() and poison the metric. Past the guard, a Date, number, + // or serialized string all compare correctly; a malformed value yields NaN, and a + // negative age (cross-node clock skew on a page another node just wrote) would poison + // the mean — both fail the >= 0 check and record nothing. + const age = Date.now() - new Date(resource.lastCached).getTime(); + if (age >= 0) { + server.recordAnalytics(age, 'page_age', request.botName, deviceType); + } + } +} + // Resolve the request into { url, cacheUrl, deviceType, routeClass, route }, dispatching on // ingress mode. In 'forwarded' mode isBotRequest already resolved + stashed the target; the // fallback resolve guards against direct calls. Returns null when a forwarded request @@ -86,6 +120,7 @@ function resolveBotTarget(request) { async function resolveResource({ request, url, cacheUrl, deviceType, routeClass, info }) { if (request.method !== 'GET' && request.method !== 'HEAD') { logger.warn(`Unexpected Request ${request.method} ${url}`); + info.cacheStatus = 'bypass'; info.source = 'origin'; return fetchOriginResource({ url, diff --git a/packages/plugin/test/botServe.test.js b/packages/plugin/test/botServe.test.js new file mode 100644 index 0000000..5b10a2b --- /dev/null +++ b/packages/plugin/test/botServe.test.js @@ -0,0 +1,89 @@ +import { test, before, beforeEach } from 'node:test'; +import assert from 'node:assert/strict'; + +/** + * recordServeOutcome — the serve-outcome analytics behind the rollout success metrics. + * + * The properties pinned here: + * - `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. + * - 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. + */ + +let analytics = []; +let recordServeOutcome; + +before(async () => { + // bot_request.js transitively imports the Harper resource classes; stub the runtime + // bindings, then dynamic-import so the stubs are in place before module evaluation. + globalThis.Resource = class {}; + globalThis.server = { + hostname: 'test-node', + nodes: [], + config: { http: { port: 9926 } }, + recordAnalytics: (...args) => analytics.push(args), + }; + globalThis.logger = { info() {}, warn() {}, error() {} }; + globalThis.databases = { + coordination: { + SharedBuffer: { + primaryStore: { + getUserSharedBuffer: (_key, buf) => buf, + tryLock: () => true, + unlock() {}, + }, + }, + }, + render_service: { Target: class {}, QueueControl: class {} }, + render_schedule: { RenderSchedule: class {} }, + page_cache: { PrerenderedPage: class {} }, + }; + ({ recordServeOutcome } = await import('../src/http_handlers/bot_request.js')); +}); + +beforeEach(() => { + analytics = []; +}); + +const request = { botName: 'Googlebot' }; + +test('bot_serve records (source, cacheStatus, botName) in that order', () => { + recordServeOutcome({}, request, { source: 'origin', cacheStatus: 'miss' }, 'desktop'); + assert.deepEqual(analytics, [[true, 'bot_serve', 'origin', 'miss', 'Googlebot']]); +}); + +test('a cache hit also records page_age with (botName, 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]; + assert.equal(metric, 'page_age'); + assert.equal(bot, 'Googlebot'); + assert.equal(device, 'mobile'); + assert.ok(age >= 4000 && age <= 7000, `expected age ~5000ms, got ${age}`); + } +}); + +test('page_age is 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'); +}); + +test('page_age is 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')); +});