diff --git a/packages/observability/grafanactl/resources/dashboards/boxel-status/service-prerender-server.json b/packages/observability/grafanactl/resources/dashboards/boxel-status/service-prerender-server.json index 693c125713a..c1738659d47 100644 --- a/packages/observability/grafanactl/resources/dashboards/boxel-status/service-prerender-server.json +++ b/packages/observability/grafanactl/resources/dashboards/boxel-status/service-prerender-server.json @@ -24,7 +24,7 @@ } ] }, - "description": "Per-service deep-dive for the Prerender Server ECS service. Currently stub-only — shows filtered logs from Loki. CloudWatch CPU / memory / running-task-count panels are TBD and will land when ECS cluster naming is standardized in observability config.", + "description": "Per-service deep-dive for the Prerender Server ECS service. Request rate and Node heap come from the service's own log lines via Loki, alongside filtered logs. CloudWatch CPU and running-task-count panels are TBD and will land when ECS cluster naming is standardized in observability config.", "editable": true, "fiscalYearStartMonth": 0, "graphTooltip": 0, @@ -199,6 +199,131 @@ "title": "Request rate (total / 4xx / 5xx)", "type": "timeseries" }, + { + "datasource": { + "type": "loki", + "uid": "loki" + }, + "description": "The prerender server's own Node heap, from the `prerender-heap` log line each instance emits on a fixed interval. Charted as the highest value across instances in each window, because Loki carries no per-task label here and the instance closest to the limit is the one that matters.\n\n`limit` is the effective `--max-old-space-size`. V8 derives its default from visible memory rather than from the ECS memory setting, so this is the only place the value a running task actually took is readable. Reaching it is fatal: the process dies with `Reached heap limit`, ECS replaces the task, and the surviving instances inherit its realm affinities and serve renders from cold tabs.\n\n`used` climbing steadily between task restarts \u2014 rather than sawtoothing under load and settling when idle \u2014 means memory is being retained, not merely in use. `external` covers strings and buffers held outside the JS heap, where response serialisation holds memory that `used` does not account for.\n\nMin step is pinned to 1m because each instance reports every 30s: a finer step would leave most windows with no sample in them, which draws as isolated spikes and drags the mean down towards the instances that happened to land in a window.", + "fieldConfig": { + "defaults": { + "color": { + "mode": "palette-classic" + }, + "custom": { + "axisLabel": "MB", + "axisPlacement": "auto", + "barAlignment": 0, + "drawStyle": "line", + "fillOpacity": 10, + "gradientMode": "none", + "hideFrom": { + "legend": false, + "tooltip": false, + "viz": false + }, + "lineInterpolation": "linear", + "lineWidth": 1, + "pointSize": 5, + "scaleDistribution": { + "type": "linear" + }, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "group": "A", + "mode": "none" + }, + "thresholdsStyle": { + "mode": "off" + } + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green", + "value": null + } + ] + }, + "unit": "decmbytes" + }, + "overrides": [] + }, + "gridPos": { + "h": 8, + "w": 24, + "x": 0, + "y": 8 + }, + "id": 3, + "options": { + "legend": { + "calcs": [ + "mean", + "max" + ], + "displayMode": "table", + "placement": "right", + "showLegend": true + }, + "tooltip": { + "mode": "multi", + "sort": "none" + } + }, + "targets": [ + { + "datasource": { + "type": "loki", + "uid": "loki" + }, + "editorMode": "code", + "expr": "max_over_time({service=\"prerender\"} |~ \"prerender-heap\" | regexp \"heapUsedMB=(?P[0-9]+)\" | unwrap heapUsedMB [$__interval])", + "legendFormat": "used", + "queryType": "range", + "refId": "A" + }, + { + "datasource": { + "type": "loki", + "uid": "loki" + }, + "editorMode": "code", + "expr": "max_over_time({service=\"prerender\"} |~ \"prerender-heap\" | regexp \"heapLimitMB=(?P[0-9]+)\" | unwrap heapLimitMB [$__interval])", + "legendFormat": "limit", + "queryType": "range", + "refId": "B" + }, + { + "datasource": { + "type": "loki", + "uid": "loki" + }, + "editorMode": "code", + "expr": "max_over_time({service=\"prerender\"} |~ \"prerender-heap\" | regexp \"rssMB=(?P[0-9]+)\" | unwrap rssMB [$__interval])", + "legendFormat": "rss", + "queryType": "range", + "refId": "C" + }, + { + "datasource": { + "type": "loki", + "uid": "loki" + }, + "editorMode": "code", + "expr": "max_over_time({service=\"prerender\"} |~ \"prerender-heap\" | regexp \"externalMB=(?P[0-9]+)\" | unwrap externalMB [$__interval])", + "legendFormat": "external", + "queryType": "range", + "refId": "D" + } + ], + "title": "Node heap (highest instance)", + "type": "timeseries", + "interval": "1m" + }, { "datasource": { "type": "loki", @@ -209,7 +334,7 @@ "h": 16, "w": 24, "x": 0, - "y": 8 + "y": 16 }, "id": 1, "options": { diff --git a/packages/realm-server/prerender/heap-telemetry.ts b/packages/realm-server/prerender/heap-telemetry.ts new file mode 100644 index 00000000000..889e2965950 --- /dev/null +++ b/packages/realm-server/prerender/heap-telemetry.ts @@ -0,0 +1,54 @@ +import { getHeapStatistics } from 'node:v8'; + +// The prerender server's own Node heap, as distinct from the browser-side +// JS heap the render paths already report (`jsHeapUsedMB` on a paused +// stack capture). A prerender server is long-lived and holds memory from +// work it has already finished, so these are the numbers that say whether +// a task is heading for `FATAL ERROR: Reached heap limit` — a crash that +// takes the task's warm tabs with it and leaves the surviving instances +// serving cold ones. +export interface HeapTelemetry { + heapUsedMB: number; + heapTotalMB: number; + heapLimitMB: number; + rssMB: number; + externalMB: number; +} + +function mb(bytes: number): number { + return Math.round(bytes / 1024 / 1024); +} + +export function heapTelemetry(): HeapTelemetry { + let heap = getHeapStatistics(); + let mem = process.memoryUsage(); + return { + heapUsedMB: mb(heap.used_heap_size), + heapTotalMB: mb(heap.total_heap_size), + // V8 sizes its default old-space limit from visible memory rather + // than from the task's allocation, so this is not derivable from the + // ECS memory setting — reporting it makes the effective + // `--max-old-space-size` readable from a running task instead of + // inferred from a task definition plus a Node version. + heapLimitMB: mb(heap.heap_size_limit), + rssMB: mb(mem.rss), + // Strings and buffers held outside the JS heap. Worth its own field + // rather than folding into rss: heap exhaustion here has surfaced + // during response serialisation, and memory retained that way shows + // up here rather than in `heapUsedMB`. + externalMB: mb(mem.external), + }; +} + +// Rendered as `key=value` pairs to match the surrounding prerender log +// lines, so the same greps work and a Loki query can pull any single +// field out with one `regexp` stage. +export function formatHeapTelemetry(telemetry: HeapTelemetry): string { + return ( + `heapUsedMB=${telemetry.heapUsedMB} ` + + `heapTotalMB=${telemetry.heapTotalMB} ` + + `heapLimitMB=${telemetry.heapLimitMB} ` + + `rssMB=${telemetry.rssMB} ` + + `externalMB=${telemetry.externalMB}` + ); +} diff --git a/packages/realm-server/prerender/prerender-app.ts b/packages/realm-server/prerender/prerender-app.ts index 263c99dc205..99e7a1cfdce 100644 --- a/packages/realm-server/prerender/prerender-app.ts +++ b/packages/realm-server/prerender/prerender-app.ts @@ -22,6 +22,7 @@ import { import { Prerenderer } from './index.ts'; import type { Timings } from './render-runner.ts'; import { resolvePrerenderManagerURL } from './config.ts'; +import { heapTelemetry } from './heap-telemetry.ts'; import { PRERENDER_HOST_SHELL_HASH_HEADER, PRERENDER_JOB_ID_HEADER, @@ -122,11 +123,19 @@ export function buildPrerenderApp(options: { PRERENDER_SERVER_STATUS_DRAINING, ); ctxt.set('Content-Type', 'application/json'); - ctxt.body = JSON.stringify({ ready: false, draining: true }); + ctxt.body = JSON.stringify({ + ready: false, + draining: true, + memory: heapTelemetry(), + }); return; } ctxt.set('Content-Type', 'application/json'); - ctxt.body = JSON.stringify({ ready: true }); + // `memory` makes a single task's heap readable on demand — including + // `heapLimitMB`, which is the only way to confirm from outside what + // `--max-old-space-size` a running process actually took. The Docker + // HEALTHCHECK discards this body, so the extra fields cost it nothing. + ctxt.body = JSON.stringify({ ready: true, memory: heapTelemetry() }); ctxt.status = 200; }); diff --git a/packages/realm-server/prerender/prerenderer.ts b/packages/realm-server/prerender/prerenderer.ts index 6227c9ece53..55bac83349d 100644 --- a/packages/realm-server/prerender/prerenderer.ts +++ b/packages/realm-server/prerender/prerenderer.ts @@ -21,6 +21,7 @@ import { toAffinityKey } from './affinity.ts'; import { PrerenderCancelledError, throwIfAborted } from './prerender-cancel.ts'; import { AffinityActivityTracker } from './affinity-activity.ts'; import { AsyncSemaphore } from './async-semaphore.ts'; +import { formatHeapTelemetry, heapTelemetry } from './heap-telemetry.ts'; import { type BatchOwner, computeBatchClearCacheGate, @@ -989,6 +990,17 @@ export class Prerenderer { return; } this.#queueSnapshotInterval = setInterval(() => { + // Emitted before the quiet-path return below, and on its own line + // rather than appended to the snapshot. The heap holds memory from + // work already finished and keeps growing with the pool idle, so + // gating this on current load would hide exactly the growth that + // has no queue behind it to explain it. Kept separate from the + // snapshot line so existing greps of that line are unaffected. + try { + log.info('prerender-heap %s', formatHeapTelemetry(heapTelemetry())); + } catch (e) { + log.warn('heap telemetry log failed:', e); + } try { let snap = this.#pagePool.getQueueDepthSnapshot(); if (snap.affinities.length === 0 && snap.totalPending === 0) { diff --git a/packages/realm-server/tests/prerender-server-test.ts b/packages/realm-server/tests/prerender-server-test.ts index b6de336b071..8da7b28295c 100644 --- a/packages/realm-server/tests/prerender-server-test.ts +++ b/packages/realm-server/tests/prerender-server-test.ts @@ -130,7 +130,28 @@ module(basename(import.meta.filename), function () { test('liveness', async function (assert) { let res = await request.get('/').set('Accept', 'application/json'); assert.strictEqual(res.status, 200, 'HTTP 200'); - assert.deepEqual(res.body, { ready: true }, 'ready payload'); + assert.true(res.body.ready, 'ready payload'); + + // The field names are pinned because they are read by name outside + // this codebase: the heap dashboard extracts each one out of the + // `prerender-heap` log line with a regex, and a rename here would + // leave those panels silently empty rather than failing anywhere. + // The values themselves vary per run, so assert only the shape and + // the one relationship that always has to hold. + let memory = res.body.memory; + assert.deepEqual( + Object.keys(memory).sort(), + ['externalMB', 'heapLimitMB', 'heapTotalMB', 'heapUsedMB', 'rssMB'], + 'memory reports the expected fields', + ); + for (let [field, value] of Object.entries(memory)) { + assert.strictEqual(typeof value, 'number', `${field} is a number`); + } + assert.true(memory.heapUsedMB > 0, 'heap in use is positive'); + assert.true( + memory.heapUsedMB <= memory.heapLimitMB, + 'heap in use is within the limit', + ); }); test('it handles prerender request', async function (assert) {