observability: Add prerender server heap reporting - #5852
Conversation
The prerender server is long-lived and holds memory from renders it has already finished, but nothing it emits describes its own heap. The only place that memory has been visible is the crash trace V8 prints on the way out, which means the state leading up to a crash has to be reconstructed afterwards from how long each task survived. Emit heap used, total, limit, rss and external on a fixed interval, and serve the same numbers from the health endpoint. The limit is worth carrying explicitly: V8 sizes its default old-space ceiling from visible memory rather than from the task's allocation, so what a running process actually took cannot be derived from the ECS memory setting. The line goes out before the queue snapshot's quiet-path return, and separately from it. The heap keeps growing while the pool sits idle, so gating it on current load would hide the growth that has no queue behind it to explain it, and keeping it off the snapshot line leaves existing greps of that line alone. The dashboard charts the highest instance rather than a breakdown: these logs carry no per-task label, and the instance nearest the limit is the one worth watching. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Grafana previewPreview deployed for 1 dashboard in the staging Grafana.
Dashboards: Preview is torn down automatically when this PR is closed or merged. (Run: https://github.com/cardstack/boxel/actions/runs/32523845813) |
Observability diff (vs staging)Show diffdiff --git a/tmp/remote-canon.V3cdTp/dashboards/boxel-status/service-prerender-server.json b/tmp/committed-canon.QWZ4JE/dashboards/boxel-status/service-prerender-server.json
index 448f534..b9034c5 100644
--- a/tmp/remote-canon.V3cdTp/dashboards/boxel-status/service-prerender-server.json
+++ b/tmp/committed-canon.QWZ4JE/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,
@@ -198,6 +198,130 @@
"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 — rather than sawtoothing under load and settling when idle — 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"
+ }
+ ]
+ },
+ "unit": "decmbytes"
+ },
+ "overrides": []
+ },
+ "gridPos": {
+ "h": 8,
+ "w": 24,
+ "x": 0,
+ "y": 8
+ },
+ "id": 3,
+ "interval": "1m",
+ "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<heapUsedMB>[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<heapLimitMB>[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<rssMB>[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<externalMB>[0-9]+)\" | unwrap externalMB [$__interval])",
+ "legendFormat": "external",
+ "queryType": "range",
+ "refId": "D"
+ }
+ ],
+ "title": "Node heap (highest instance)",
+ "type": "timeseries"
+ },
{
"datasource": {
"type": "loki",
@@ -208,7 +332,7 @@
"h": 16,
"w": 24,
"x": 0,
- "y": 8
+ "y": 16
},
"id": 1,
"options": {
(Run: https://github.com/cardstack/boxel/actions/runs/32523845849) |
![chatgpt-codex-connector[bot]](https://avatars.githubusercontent.com/in/1144995?s=60&v=4){kind=small}
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 279a77f512
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| // `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() }); |
There was a problem hiding this comment.
Every successful GET / now includes memory, but packages/realm-server/tests/prerender-server-test.ts:133 still asserts that the response body is exactly { ready: true }. This makes the realm-server prerender test suite fail deterministically; update the existing assertion and cover the new telemetry fields.
AGENTS.md reference: AGENTS.md:L266-L271
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
[Claude Code 🤖] Confirmed, and fixed in 26de2ef. assert.deepEqual(res.body, { ready: true }) compared the whole body, so the added memory block failed it deterministically — you're right that it was a guaranteed failure rather than a risk.
The test now asserts ready on its own and checks the heap block beside it. The field names are pinned on purpose: the heap dashboard panel extracts each one by name out of the log line, so a rename would leave those panels silently empty without failing anywhere. The values vary per run, so beyond the shape it only claims the heap in use is positive and within the limit.
I checked the surrounding surface for the same problem and this was the only place: no other test asserts that payload, and nothing reads it at runtime — the Docker HEALTHCHECK discards the body and reads only the status code, and the manager tracks servers through heartbeat POSTs to /prerender-servers rather than this endpoint. So the blast radius was test-only.
One note in case it helps future suggestions on this suite: qunit/no-assert-logical-expression rejects combining the two numeric claims into one assert.true(a && b), so they're asserted separately.
The liveness test compared the whole response body against `{ ready:
true }`, so reporting heap alongside it fails that assertion outright.
Assert `ready` on its own and check the heap block beside it. The field
names are pinned deliberately: they are read by name from outside this
codebase, so a rename would leave the heap dashboard's panels empty
without failing anywhere. Values vary per run, so beyond the shape the
only claim worth making is that the heap in use is positive and within
the limit.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Each instance reports its heap every 30 seconds and the instances are not aligned with one another, so over a half-hour window Grafana picks a step of a few seconds and most windows contain no sample at all. The series draws as isolated spikes separated by gaps, and the legend's mean is pulled towards whichever instances happened to land inside a window rather than describing the fleet. Pin the panel's min step to a minute, which is comfortably clear of the reporting interval even with the instances unaligned, and span nulls so a missed window bridges rather than breaking the line. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
35482cb to
2cb3fc3
Compare
1 participant
Looking at a recent publish check failure in production, there may be a memory leak in the prerender server. This adds a
POST /heap-snapshotendpoint…Claude explanation
The prerender server is long-lived and holds memory from renders it has already finished, but nothing it emits describes its own heap. The only place that memory has been visible is the crash trace V8 prints on the way out, which means the state leading up to a crash has to be reconstructed afterwards from how long each task survived.Emit heap used, total, limit, rss and external on a fixed interval, and serve the same numbers from the health endpoint. The limit is worth carrying explicitly: V8 sizes its default old-space ceiling from visible memory rather than from the task's allocation, so what a running process actually took cannot be derived from the ECS memory setting.
The line goes out before the queue snapshot's quiet-path return, and separately from it. The heap keeps growing while the pool sits idle, so gating it on current load would hide the growth that has no queue behind it to explain it, and keeping it off the snapshot line leaves existing greps of that line alone.
The dashboard charts the highest instance rather than a breakdown: these logs carry no per-task label, and the instance nearest the limit is the one worth watching.