| name | indexing-diagnostics |
| description | Investigate slow or failing indexing using the per-row diagnostics persisted split by visit — the index visit's breakdown on `boxel_index.diagnostics`, the prerender-html visit's render breakdown (launch/wait/render timings, per-format render timings) on `prerendered_html.diagnostics`, each mirrored onto its table's `error_doc.diagnostics` for error rows, joinable per row via url + the two request ids — plus the matching prerender-server / manager logs. Covers (1) a render inside indexing timed out — classify which part of the prerender pipeline stalled, (2) an incremental or full reindex was slow but didn't fail — attribute time across the invalidation fan-out and find the rows that cost the most, (3) enumerating cards with broken `linksTo` / `linksToMany` targets via `diagnostics.brokenLinks` (those cards index cleanly, so this is the only indexed signal), (4) verifying the module pre-warm phase populates the definition cache under a key the indexer / on-demand prerender reads actually hit — i.e. it isn't a silent no-op — via the `definition-cache-key` hit/miss log channel, and (5) attributing a slow in-render `_search` round-trip to the realm-server's own request→response stages (parse / SQL / loadLinks / serialize / queue) via the `realm:search-timing`, `realm:requests` (`dur=`), and `realm:health` log channels keyed by the `x-boxel-logging-correlation-id` correlation id, and (6) capturing full CPU profiles / CDP traces / heap-allocation profiles to the prerender S3 artifact bucket (`boxel-prerender-artifacts-<env>`) when the summary signals name a hot function but you need the whole call tree, a JS-vs-GC-vs-layout breakdown, or a heap-growth story — the streaming trace is the only capture that survives a fully-wedged renderer; gated behind `PRERENDER_PROFILE_AFFINITY` + per-mode SSM flags and pulled with the `boxel-claude-readonly` S3 read grant, and (7) attributing a slow search-doc build to specific fields and link loads — the settle loop's per-target load timings (`searchDocSettleMs` / `searchDocLinkLoads`) vs the field walk's per-dotted-path evaluation timings (`searchDocMs` / `searchDocFieldsMs`), both on `boxel_index.diagnostics`, and (8) decomposing the between-visit / non-render slice of an index job's wall — the once-per-job phases (invalidation discovery, dependency ordering, module pre-warm, aggregate row writes, the final swap) on `jobs.result.phaseTimings` plus the per-row client overhead (file read / render round-trip transport / post-render bookkeeping) on `boxel_index.diagnostics.indexVisitClientMs` — the wall that runs serially between the server renders and is invisible in the per-row `totalElapsedMs`, and (9) decomposing a trivial card's fixed per-visit floor — the route machinery (the meta / icon / file-extract route transitions, instantiation, and per-visit request plumbing) around the search-doc work — into per-route wall-clock buckets on `boxel_index.diagnostics.indexRoutesMs` (the index-half sibling of the render channel's `renderFormatsMs`), so a floor that isn't the search doc reads as measured route steps rather than an inference from `renderElapsedMs`, and (10) recognizing a batch-level setup-phase failure of an incremental job — N error docs sharing one `error_doc.message` and `job_id`, carrying no visit diagnostics, from a rejected job whose whole batch failed before its visit loop — vs per-row render failures, and the re-push recovery those error docs enable. Use when indexing fails with "Render timeout", when a user sees a 504, when a reindex took much longer than expected, when an `.gts` edit triggers a surprising amount of re-render work, when investigating prerender-saturation incidents, when a render stalls in `waiting-stability` on a `_search` whose SQL is fast but whose response is slow to come back, when a row's index visit is slow and you need to know which field or link load inside the search doc ate the time, when a trivial-search-doc card still costs far more per visit than its doc justifies and you need to attribute the per-visit floor to a route step, or when asked to list / count cards with broken links in a realm. For staging/prod investigations this skill layers on top of `aws-access`, which provides the AWS session and the SSM port-forward path into the in-VPC database (authenticated as `claude_readonly_user`) — read that skill first when the question is about a deployed environment. |
| allowed-tools | Read, Grep, Glob, Bash |
Indexing diagnostics
Every indexer write (IndexWriter.updateEntry) persists a diagnostic blob on the row it wrote — the diagnostics JSONB column. Most of the blob is about what the prerender pipeline spent its time on and what category of stall (if any) the render was stuck in, but it also records non-timing render findings, notably brokenLinks. A row is produced by two visits on two channels, and each visit's diagnostics follow its writes: the index visit's breakdown lands on boxel_index.diagnostics, the prerender-html visit's render breakdown lands on prerendered_html.diagnostics (see Two visits, two tables). It's the primary tool for investigating:
- A render that timed out during indexing — classify the stall, fix the right layer. (Also applies to user-facing 504s since the UI path goes through the same prerender.)
- A reindex that was slow but succeeded — attribute wall-clock across the cards that got re-rendered, find the real culprit in the fan-out.
- Which cards have broken links — enumerate cards with a broken
linksTo / linksToMany target straight from the column; those cards index cleanly, so diagnostics.brokenLinks is the only indexed signal. See Mode E.
- Whether module pre-warm is effective — confirm the pre-warm phase populates the definition cache under a key the indexer / on-demand reads actually hit (not a silent no-op), using the
definition-cache-key hit/miss log channel. This one isn't about the diagnostics column — it reads the logs. See Mode F.
- Why an in-render
_search was slow to come back — when a render stalls in waiting-stability waiting on a query-backed linksTo / linksToMany search (the boxel_index.diagnostics shows it client-side as queryLoadsInFlight aging) but the SQL is fast, attribute the realm-server's request→response time across its stages (parse / SQL / loadLinks / serialize) and tell handler-time from queued-before-handler / event-loop saturation. Log-based, keyed by the correlation id. See Mode G.
- A search doc that was slow to build — attribute a slow index visit inside the search-doc build itself: the settle loop's link loads (
searchDocSettleMs, per target in searchDocLinkLoads) vs the field walk (searchDocMs, per dotted field path in searchDocFieldsMs). See Mode J.
- The index job's wall didn't add up to its visits — decompose the between-visit / non-render slice of an index job's wall (invalidation discovery, dependency ordering, module pre-warm, the serial per-visit client overhead, aggregate row writes, the final swap) into measured buckets: the once-per-job phases on
jobs.result.phaseTimings, and the per-row client overhead on boxel_index.diagnostics.indexVisitClientMs. This is the wall that runs between the server renders, so it's invisible in the per-row totalElapsedMs the other modes read. See Mode K.
- A trivial card still costs a fixed per-visit floor — a card whose search doc is near-free (
searchDocMs/searchDocSettleMs ~0) still pays a per-visit amount for the route machinery around the work (route transitions, instantiation, per-visit request plumbing). indexRoutesMs decomposes that floor into the wall-clock of each index-visit route step — meta / icon for a card, fileExtract / icon for a file — so the floor reads as measured buckets rather than being inferred from renderElapsedMs. See Mode L.
The first three read from the same diagnostics column; the difference is the query you start with. Modes F and G are log-based.
Where the diagnostics live
Seven places, all correlated:
boxel_index.diagnostics (and boxel_index_working.diagnostics) — JSONB column, populated for every row the indexer writes, regardless of has_error. Source of truth for the index visit of a card/file: the RenderTimeoutDiagnostics server timings of that visit plus the host-side PrerenderMetaDiagnostics block (serializeMs, searchDocMs, searchDocSettleMs/searchDocSettlePasses, searchDocFieldsMs, searchDocLinkLoads, computedCalls/computedCacheHits), the per-route indexRoutesMs breakdown (the index-half sibling of the render channel's renderFormatsMs — the wall-clock of each index-visit route step, so the per-visit floor decomposes into meta / icon / fileExtract buckets; see Mode L), and three write-side stamps: invalidationId, indexedAt, requestId. It also carries an indexVisitClientMs block (read / renderRpc / bookkeeping) — the indexer's per-row client-side overhead outside the server render, i.e. this row's slice of the between-visit wall (see Mode K) — and a brokenLinks array on any card row whose render found a broken linksTo / linksToMany target — see Mode E. Note brokenLinks is the one block that isn't about timing: a card with broken links still indexes as a clean type='instance' (the broken slot renders a placeholder), so it's the only indexed signal that the row has a broken reference. Rows written by a fused single-visit pass (the SQLite in-browser path) carry one combined blob covering both visits here instead.
prerendered_html.diagnostics (and prerendered_html_working.diagnostics) — JSONB column, populated for every row the prerender_html job writes, success and render-error alike. Source of truth for the prerender-html visit: launch/wait timings, renderElapsedMs/totalElapsedMs, the per-format renderFormatsMs breakdown, and the visit's HTTP correlation id under prerenderHtmlRequestId (never requestId — that name always means an index visit). See Two visits, two tables.
modules.diagnostics — JSONB column, populated for every row persistModuleCacheEntry writes (success and error paths). Source of truth for module renders (prerenderModule → definition extraction). Same RenderTimeoutDiagnostics shape with requestId flattened in; no invalidationId (modules don't go through Batch.invalidate). The row's existing created_at column is the wall-clock stamp for cross-table joins. See Mode D below.
error_doc.diagnostics — derived copy of the same table's diagnostics, written only for error rows: an index error's copy rides boxel_index.error_doc, a render error's rides prerendered_html.error_doc (an instance's effective error is the union of the two). Exists so the existing UI read path (error_doc → CardErrorJSONAPI.meta.diagnostics via formattedError) keeps working without a schema rename. Non-error rows have error_doc = null; go to diagnostics directly.
- Logs —
prerender-server, manager, and remote-prerenderer lines all carry requestId=…. grep requestId=<uuid> collates one call across all three processes. The same id lands on boxel_index.diagnostics->>'requestId' and modules.diagnostics->>'requestId' — and, for the render channel, on prerendered_html.diagnostics->>'prerenderHtmlRequestId' — so a hung card render and the module renders it triggered (via getDefinition) can be joined back to one investigation. For saturation incidents there's also the periodic prerender-queue-snapshot line on each prerender server.
- Realm-server search-timing logs — separate from the prerender
requestId chain above. The realm-server emits, per instrumented _federated-search, a realm:search-timing line (request→response stage breakdown) and a realm:requests --> line with dur= (total) — both keyed by corr=<id>, the x-boxel-logging-correlation-id the prerendered host stamps. A periodic realm:health line reports event-loop lag + in-flight _search count during saturation windows. These are the server's view of the search the card is blocked on; the card's boxel_index.diagnostics only has the client's view (queryLoadsInFlight). See Mode G.
jobs.result.phaseTimings — JSONB, one object per completed index job (on the from-scratch-index / incremental-index row's result column). The job-level phase decomposition: the once-per-job phases that surround and interleave the serial visit loop (setupMs, discoverMs, orderMs, preWarmMs, swapMs, and the from-scratch-only mtimesMs), plus visitLoopMs (the whole serial loop), writeMs (the aggregate row-write time — tracked here, not per row, because a row can't time its own INSERT), and totalMs. This is the only place the between-visit wall is attributed; the per-row server render lives on boxel_index.diagnostics.totalElapsedMs and the per-row client overhead on boxel_index.diagnostics.indexVisitClientMs. See Mode K.
For UI triage you'll typically read the JSON error response (which surfaces error_doc.diagnostics as meta.diagnostics). For operator / SQL triage — especially slow non-failing reindexes — query the diagnostics column directly.
How to actually run these queries
The SQL examples below are environment-agnostic — they work the same against local dev, staging, or prod. What changes is how you reach the database:
- Local dev:
psql "$DATABASE_URL" (or whatever your local boxel server uses) directly.
- Staging / prod: the RDS instances are private to the cardstack VPC. Use the
aws-access skill — it covers (a) provisioning a Claude-usable AWS session via mise run claude-aws <env> <token>, (b) the SSM port-forward tunnel through the realm-server ECS task to RDS, and (c) connecting via psql as the read-only claude_readonly_user (member of readonly_role). This skill assumes you've already got that connection working; it doesn't re-document the AWS plumbing.
When wrapping a query below into the staging/prod form, run it through the psql -h localhost -p <local-port> -A -t invocation that the aws-access skill sets up — same SQL, different transport.
Two visits, two tables — which timings live where
A URL is produced by two prerender visits on two channels, and each visit's diagnostics follow its writes:
| where | visit | what's in it |
|---|
boxel_index.diagnostics | index visit | that visit's server timings (launchMs, waits, renderElapsedMs, totalElapsedMs), the per-route floor split (indexRoutesMs — one number per index-visit route step, split into a card block meta / icon and a file block fileExtract / icon; see Mode L), the search-doc build (serializeMs, searchDocMs, searchDocSettleMs/searchDocSettlePasses, the per-field searchDocFieldsMs and per-link-load searchDocLinkLoads detail, computedCalls/computedCacheHits), the indexer's own per-row client overhead outside the render (indexVisitClientMs: read / renderRpc / bookkeeping — see Mode K), brokenLinks, and the write-side stamps (invalidationId, indexedAt). HTTP id: requestId. |
prerendered_html.diagnostics | prerender-html visit | that visit's server timings (launchMs, waits, renderElapsedMs, totalElapsedMs) plus renderFormatsMs — per-format wall-clock, split into a card and a file block with one number per html-route step (isolated, head, atom, markdown, fitted, embedded; the ancestor-driven fitted/embedded numbers each cover the whole ancestor chain). HTTP id: prerenderHtmlRequestId. |
So "why was indexing this card slow?" and "why was rendering this card slow?" are separately answerable per row: the index cost is boxel_index.diagnostics, the render cost is prerendered_html.diagnostics. Each side names the sub-step that dominated its channel: on the index side indexRoutesMs names the route (a slow meta build vs an icon render vs fileExtract), on the render side renderFormatsMs names the format (a slow isolated template vs a fitted render fanning out across many ancestors).
The field-name → visit mapping is constant across both tables: requestId always names an index visit's HTTP request, prerenderHtmlRequestId always names a prerender-html visit's. Join a row's two halves on url (each table keys on (url, realm_url, type)), then carry each side's id into the log search:
SELECT b.url,
b.diagnostics->>'requestId' AS index_visit_request,
(b.diagnostics->>'totalElapsedMs')::int AS index_visit_ms,
(b.diagnostics->>'searchDocMs')::int AS search_doc_ms,
p.diagnostics->>'prerenderHtmlRequestId' AS render_visit_request,
(p.diagnostics->>'totalElapsedMs')::int AS render_visit_ms,
p.diagnostics->'renderFormatsMs' AS render_formats_ms
FROM boxel_index b
LEFT JOIN prerendered_html p
ON p.url = b.url AND p.realm_url = b.realm_url AND p.type = b.type
WHERE b.url = '<card-url>'
AND b.type = 'instance';
Caveats:
- Rows written by a fused single-visit pass (the SQLite in-browser path) carry one combined blob on
boxel_index.diagnostics — summed timings across both visits, with the render visit's id under prerenderHtmlRequestId alongside requestId — and the inline prerendered_html write lands that same combined blob on the prerendered_html row.
- One prerender-html visit produces both of a URL's rows (
type='instance' and type='file'), so both carry the same blob; the card block of renderFormatsMs describes the instance rendering and the file block the FileDef rendering.
- The two tables' generations advance independently:
p.rendered_at / p.generation tell you which index generation the persisted render diagnostics belong to (fresh when it equals b.generation).
- A
prerender_html job that never ran (queued, crashed pre-write) leaves no diagnostics — check jobs / job_reservations for the realm's prerender_html lane instead.
The four stall categories
Every slow or timed-out render falls into one of:
- Launch stall: the request waited in the render-semaphore or tab queue and never got a real render attempt. Fix is capacity, not host code.
- Loader stall: the render started but was still pulling
.gts modules when the timer fired. Fix is module graph / network.
- Data stall: the render got past module load but is still fetching cards, file-meta, or query-field results. Fix is the host data layer or the backend search. When it's a query-field
_search (queryLoadsInFlight aging), Mode G attributes the backend search to the realm-server's own request→response stages.
- Render stall: the render is in DOM rendering / stability-wait but nothing is in flight. Fix is Glimmer / template side.
If you pick the wrong category you waste a day. The diagnostic fields in the Classify in one pass table below pick it for you.
Prerender priorities
A prerender request a worker job spawns carries a numeric priority — threaded from that job through the per-tab queue, the per-affinity file-admission semaphore, and the per-server render semaphore (a request with no originating job priority omits the field). The value is the worker-job priority of the job that produced the render, so it splits by both initiator (user vs. system) and job family (indexing vs. prerender-html):
10 — userInitiatedPriority. A user-initiated index visit: the _reindex endpoint, ad-hoc card publishes, manual UI-driven reindex actions.
9 — userInitiatedPrerenderHtmlPriority. The HTML render a user-initiated index pass spawns — one tier below the index visit so it stays off the indexing hot path. Exception: a render a publish is awaiting (published-realm readiness gates on it) is lifted to 10, co-equal with indexing, so the prerender server admits it ahead of ordinary user renders.
1 — systemInitiatedPriority. A system-initiated index visit: scheduled full-reindex sweeps, _full-reindex runs, the worker's continuous reindex queue. The default worker-job priority for any code path that doesn't explicitly opt in.
0 — systemInitiatedPrerenderHtmlPriority. The HTML render a system-initiated index pass spawns — the background floor only the all-priority worker pool takes.
The two job families land on different diagnostics tables: an index-visit row on boxel_index.diagnostics carries 10 or 1; the prerender-html render it spawns, on prerendered_html.diagnostics, carries 9 or 0 — one notch below its initiator — except a publish-awaited render, which carries 10. So priority=10 can show up on either table: an index visit, or a publish's HTML render.
Higher priority dequeues first; FIFO is preserved within a priority bucket. There is no preemption — an in-flight lower-priority render runs to completion. The next free slot goes to the highest-priority queued waiter.
Why this matters for triage:
-
Reading a stuck render: a user-initiated render (10 on an index visit or a publish-awaited render, 9 on an ordinary user render) is a UX-facing request. If it's stuck on waits.tabQueueMs or waits.semaphoreMs, that's the saturation event priority routing was designed to mitigate. A system-initiated render (1 or 0) stuck on the same wait is background work — operationally less urgent and often expected during a deliberate reindex burst.
-
Distinguishing capacity issues from priority misrouting: a user-priority row that waited >1s in tabQueueMs while the affinity's prerender-queue-snapshot shows it queued behind same-or-higher-priority work is a capacity problem — the user-priority workload exceeded the fleet. The same row queued behind strictly lower-priority (background) work, with manager-side priority routing live in the build, is a routing failure — the manager picked the wrong server, or the file render the row was queued behind isn't releasing. These need different fixes.
-
Confirming priority routing actually fired: if a known-user _reindex shows up in diagnostics with a system-tier priority (1 or 0), the producer-side threading (job → IndexRunner → prerenderVisit) regressed somewhere. Most-likely place is a new task type that didn't pick up jobInfo.priority.
-
Sharpening the deadlock fingerprint: affinitySnapshot.sameAffinityActivity[*].priority lets you tell a self-referential prerender deadlock apart from priority-driven queuing. Same-priority queued module sub-render on a stuck same-priority file render → deadlock. Higher-priority queued sibling → priority routing working as intended.
The priority value lives on the diagnostics.priority field and on every sameAffinityActivity entry. The periodic prerender-queue-snapshot log line carries per-affinity priority breakdowns. See Classify in one pass and the field-by-field section below for the exact triage rules.
Mode A — a render timed out
Pull the diagnostic JSON for the erroring row — from the channel the failure happened on. An index-visit failure (search-doc build, serialization) errors the boxel_index row; an html-render failure in the prerender_html job errors the prerendered_html row. When you don't know which, check both — an instance's effective error is the union:
SELECT 'index' AS channel, diagnostics, error_doc IS NOT NULL AS errored
FROM boxel_index
WHERE url = '<errored-card-url>' AND type = 'instance'
UNION ALL
SELECT 'render' AS channel, diagnostics, error_doc IS NOT NULL AS errored
FROM prerendered_html
WHERE url = '<errored-card-url>' AND type = 'instance';
(Or read error_doc.diagnostics from the JSON:API error response — same shape.)
Walk the fields per Classify in one pass. The first positive signal wins; stop there. On the render channel, renderFormatsMs additionally names which format's render ate the time.
Mode B — an incremental reindex was slow
Every Batch.invalidate(urls) call mints a UUID stashed into diagnostics.invalidationId for every row written during that fan-out. If a .gts edit invalidates 8 rows (one file + seven card instances), all eight carry the same invalidationId — so you can look at the whole reindex as a group.
Step 1 — find the invalidation you care about. If you don't already have the ID, discover recent big ones:
SELECT
diagnostics->>'invalidationId' AS id,
count(*) AS rows_touched,
to_timestamp(
max((diagnostics->>'indexedAt')::bigint) / 1000
) AS last_indexed_at,
sum((diagnostics->>'renderElapsedMs')::int)
AS total_render_ms,
max((diagnostics->>'renderElapsedMs')::int)
AS slowest_ms
FROM boxel_index
WHERE realm_url = 'https://localhost:4201/user/your-realm/'
AND diagnostics->>'invalidationId' IS NOT NULL
GROUP BY 1
ORDER BY last_indexed_at DESC
LIMIT 20;
Step 2 — walk the fan-out. Given an invalidationId, pull every row it touched, ordered by render cost:
SELECT
url,
type,
has_error,
diagnostics->>'renderStage' AS stage,
(diagnostics->>'renderElapsedMs')::int AS render_ms,
(diagnostics->>'launchMs')::int AS launch_ms,
diagnostics->'waits' AS waits,
jsonb_array_length(
COALESCE(diagnostics->'queryLoadsInFlight', '[]'::jsonb)
) AS queries_stuck,
jsonb_array_length(
COALESCE(diagnostics->'inFlightModuleImports', '[]'::jsonb)
) AS modules_stuck,
to_timestamp((diagnostics->>'indexedAt')::bigint / 1000)
AS indexed_at
FROM boxel_index
WHERE realm_url = 'https://localhost:4201/user/your-realm/'
AND diagnostics->>'invalidationId' = '<uuid>'
ORDER BY render_ms DESC NULLS LAST;
Step 3 — classify each slow row. For the top offenders, pull the full diagnostics and apply the Classify in one pass table to each. Common patterns:
- One row dominates (e.g. a dashboard card) and the rest are cheap. The big row is the real target — investigate its
queryLoadsInFlight / recentModuleEvaluations / cardDocLoadsInFlight.
- All rows share a large
launchMs. Capacity contention during the reindex, not the cards' fault.
- The first row in the batch (min
indexedAt) has a large renderElapsedMs but the rest are cheap — this is the cold-loader tax paid by whichever card was rendered first after clearCache: true fired. Expected on any executable invalidation; only worth chasing if the cold cost is disproportionate to the dep closure.
- The
deps / types columns on the same rows tell you why each row was invalidated — useful for discovering unintentionally-heavy transitive deps (e.g. a dashboard re-renders because one of its metrics modules has a runtime reference to the changed module).
Other useful queries:
SELECT
url,
to_timestamp((diagnostics->>'indexedAt')::bigint / 1000) AS indexed_at,
(diagnostics->>'renderElapsedMs')::int AS render_ms,
diagnostics->>'renderStage' AS stage,
diagnostics->>'invalidationId' AS group,
has_error
FROM boxel_index
WHERE realm_url = 'https://localhost:4201/user/your-realm/'
ORDER BY render_ms DESC NULLS LAST
LIMIT 20;
SELECT
realm_url,
avg((diagnostics->>'renderElapsedMs')::int) AS avg_ms,
percentile_cont(0.95) WITHIN GROUP (
ORDER BY (diagnostics->>'renderElapsedMs')::int
) AS p95_ms,
count(*) AS rows
FROM boxel_index
WHERE diagnostics->>'renderElapsedMs' IS NOT NULL
GROUP BY 1
ORDER BY p95_ms DESC NULLS LAST
LIMIT 20;
SELECT
url,
to_timestamp((diagnostics->>'indexedAt')::bigint / 1000) AS indexed_at,
(diagnostics->>'computedCalls')::int AS calls,
(diagnostics->>'computedCacheHits')::int AS cache_hits,
(diagnostics->>'serializeMs')::numeric AS serialize_ms,
(diagnostics->>'searchDocMs')::numeric AS search_doc_ms,
(diagnostics->>'searchDocSettleMs')::numeric AS settle_ms,
(diagnostics->>'renderElapsedMs')::int AS render_ms
FROM boxel_index
WHERE realm_url = 'https://localhost:4201/user/your-realm/'
AND diagnostics->>'computedCalls' IS NOT NULL
ORDER BY (diagnostics->>'computedCalls')::int DESC NULLS LAST
LIMIT 20;
For any row this surfaces, Mode J drills inside its search-doc cost — which field, which link load.
Mode C — a worker job is stuck or got rejected
Mode A and Mode B both assume boxel_index has up-to-date diagnostics for the rows you're investigating. That assumption breaks when an indexing job is in progress or got rejected mid-flight: with one exception (next paragraph), nothing has been committed to boxel_index yet (the indexer writes to a staging table and only swaps on success — see Reading partial progress from boxel_index_working below), so the diagnostics column there is stale or null for the affected rows.
The exception — a batch-level setup-phase failure. An incremental-index job that throws during its setup phase (the invalidation fan-out, dependency ordering, or file-meta prefetch — everything before the per-URL visit loop) still rejects, but a recovery pass first commits a has_error = TRUE error row for every URL the job was handed with an update operation (delete operations are left untouched so a failed delete is never half-applied; see IndexRunner.#recordSetupPhaseError in packages/runtime-common/index-runner.ts). The signature that distinguishes this from per-row render failures:
- N error rows sharing one identical
error_doc.message and one job_id, at one generation — matching the rejected job's result error and its args.changes URL set.
- The error docs carry no visit diagnostics (no render or index visit ever ran for these URLs) — a render failure's error doc carries the visit's timing blocks.
realm_meta at that generation is a carry-forward of the prior generation's summary, not a recompute, so type counts do not move.
- An incremental invalidation event is broadcast for the attempted URLs even though the job rejected, so subscribers re-fetch and see the error state.
Recovery for the errored URLs is any later write touching them (error rows are excluded from job resume and invalidate like any other row — a re-push replaces them with clean content) or the next full reindex.
For everything else in this mode the diagnostic stance flips from "what timed out" (Mode A) or "what was slow" (Mode B) to "what hasn't happened yet". You're reconstructing the work the job would have done from three sources together:
boxel_index_working — the staging table the indexer writes to as it makes progress. On success its rows for the touched URLs are copied into boxel_index (Batch.applyBatchUpdates in packages/runtime-common/index-writer.ts). On failure (worker crash, job timeout, manual cancel) the working rows are left behind, which is exactly the bisection signal you want: any row in boxel_index_working that is not yet in boxel_index (or has a higher realm_version) was already processed by the stuck job.
- EFS file mtimes — reachable via the
aws-access skill's "Browsing the EFS filesystem" path (the boxel-claude-fs-readonly-<env> Fargate task). Combined with boxel_index.last_modified (the indexer's view of when each file was last processed) this lets you reconstruct what would have been invalidated by a from-scratch run, before any boxel_index_working rows existed.
- Worker logs in CloudWatch (
ecs-boxel-worker-<env>) — confirms the job's start, the file it was on at the freeze point, and any partial completion lines.
1. Recognising the situation
You're in Mode C territory if any of these hold:
- The worker log shows a
starting from-scratch indexing or starting from incremental indexing line for the realm but no matching completed from scratch indexing / completed incremental indexing line in the same [job: <id>.<rid>] group (the job-identity prefix is [job: <jobId>.<reservationId>]; see jobIdentity in packages/runtime-common/utils.ts).
boxel_index rows for the realm look stale (last_modified predates the file's EFS mtime, or diagnostics->>'indexedAt' is older than you'd expect for the last reindex you triggered).
- The job-id appears as
unfulfilled in jobs and has at least one row in job_reservations whose completed_at IS NULL (in-flight). A rejected row in jobs with no completed_at on its newest reservation means the worker bailed but the worker-finalize transaction may not have run cleanly.
- A subsequent reindex was enqueued and re-reserved the same concurrency group (
indexing:<realm-url>) — check job_reservations.created_at for the same job_id.
Job/reservation health (read-only):
SELECT
j.id AS job_id,
j.job_type,
j.status,
j.created_at,
j.finished_at,
j.args->>'realmURL' AS realm_url,
j.timeout AS timeout_sec,
j.concurrency_group
FROM jobs j
WHERE j.args->>'realmURL' = '<realm-url>'
AND j.job_type IN ('from-scratch-index', 'incremental-index', 'copy-index')
ORDER BY j.created_at DESC
LIMIT 20;
SELECT
id, job_id, worker_id, created_at, locked_until, completed_at,
locked_until < NOW() AS expired
FROM job_reservations
WHERE job_id = <job-id>
ORDER BY created_at DESC;
(See packages/runtime-common/realm-index-updater.ts::publishFullIndex and update, packages/runtime-common/jobs/reindex-realm.ts, and packages/postgres/pg-queue.ts for how these tables are populated and what unfulfilled / resolved / rejected mean. The full-reindex path (enqueueReindexRealmJob with clearLastModified: true) intentionally nulls boxel_index.last_modified before enqueuing — relevant to step 3 below.)
2. Distinguishing from-scratch vs incremental
Look at the worker log's start line for the job. Both come from index-runner.ts at debug level on the index-runner logger:
- From-scratch:
[job: <jobId>.<rid>] starting from scratch indexing (line 156). The wrapping task layer (tasks/indexer.ts line 252) also logs [job: …] starting from-scratch indexing for job: <stringified-args> on the worker logger; this is the line that contains the full args payload (realmURL, realmUsername).
- Incremental:
[job: <jobId>.<rid>] starting from incremental indexing for <comma-separated-urls> (line 273). The matching worker-logger line is [job: …] starting incremental indexing for job: <stringified-args> — its changes array is the seed set you'll need in step 4.
Both lines are at debug. If the worker's LOG_LEVELS is *=info (the default — see packages/realm-server/setup-logger.ts), neither will be in CloudWatch. Check which loggers are on before you try to grep — see step 7.
The next steps differ by mode:
- From-scratch: the seed isn't in the job args; you have to reconstruct it from EFS mtimes vs
boxel_index.last_modified (step 3).
- Incremental: the seed is the
changes array in the job's args (step 4).
3. Reconstructing the invalidation graph for a from-scratch job
The from-scratch path lives in IndexRunner.fromScratch (packages/runtime-common/index-runner.ts). It:
-
Reads every existing row's (url, type, last_modified, has_error) from boxel_index — this is Batch.getModifiedTimes in index-writer.ts (line 212):
SELECT i.url, i.type, i.last_modified, i.has_error
FROM boxel_index AS i
WHERE i.realm_url = '<realm-url>';
-
Walks the realm's filesystem via the _mtimes endpoint (Realm.realmMtimes in realm.ts line 4307) — for the deployed environments you reproduce this walk by browsing EFS via the fs-explorer task in aws-access. The endpoint walks realmsRootPath recursively, calls lastModified() per file, and returns { <fileURL>: <epoch-seconds> }. Skips anything matched by .gitignore or the realm's hard-coded ignore list (.git, .template-lintrc.js).
-
Builds the seed set in discoverInvalidations (packages/runtime-common/index-runner/discover-invalidations.ts). A file is in the seed if any of:
- it's not in the index (
!indexEntry),
- the index row has
has_error = TRUE (re-try error rows on every from-scratch),
last_modified IS NULL in the index (full-reindex with clearLastModified zeroed it — that's why _full-reindex is destined to invalidate everything),
- the filesystem mtime differs from the index's
last_modified (file was edited since last successful index).
Plus: any URL in boxel_index that is not present on disk is added as a deletion ("tombstone") seed. From the code (lines 64-90):
for (let [mtimeUrl, lastModified] of Object.entries(filesystemMtimes)) {
let indexEntry = indexMtimes.get(mtimeUrl);
if (
!indexEntry ||
indexEntry.hasError ||
indexEntry.lastModified == null ||
lastModified !== indexEntry.lastModified
) {
invalidationList.push(mtimeUrl);
}
}
let deletedUrls = [...indexMtimes.keys()].filter(
(indexedUrl) => !filesystemMtimes[indexedUrl],
);
invalidationList.push(...deletedUrls);
Reproduce that comparison by hand. To find rows in the index that would have been seeded:
SELECT
i.url,
i.type,
i.has_error,
i.last_modified,
to_timestamp(i.last_modified::bigint) AS index_seen_at
FROM boxel_index AS i
WHERE i.realm_url = '<realm-url>'
AND (
i.has_error = TRUE
OR i.last_modified IS NULL
)
ORDER BY i.has_error DESC, i.last_modified ASC NULLS FIRST;
Then take the EFS listing for the same realm (recursively via the fs-explorer Caddy autoindex — packages/runtime-common/realm.ts walks every file under the realm root, skipping .git / ignored paths) and join it against boxel_index.last_modified. The set of files where filesystem mtime differs from last_modified (or the file isn't in boxel_index at all) is the from-scratch seed.
-
Once the seed is known, the runner immediately calls Batch.invalidate(seed) to grow the seed by consumer fan-out (step 5). The visit loop then iterates over the resulting invalidation list.
If the worker froze before any seed-driven visit ran (no rows in boxel_index_working for this batch — see step 6), it's stuck either in the mtime-walk on the realm-server side (slow EFS / many files) or in Batch.invalidate's consumer fan-out. The CloudWatch line that proves we got past mtime-collection is [job: …] discovering invalidations in dir <realm-url> — emitted on both index-runner and index-perf from discoverInvalidations.ts line 34/37. Absence of that line on a *=debug worker means we're still in the fetch.
4. Reconstructing the invalidation graph for an incremental job
The incremental path (IndexRunner.incremental) skips the mtime walk entirely. The seed is the changes array in the job args, available verbatim in:
-
The jobs.args JSONB row for job_type = 'incremental-index':
SELECT id, args->'changes' AS changes
FROM jobs
WHERE id = <job-id>;
-
The worker's starting incremental indexing for job: … line (worker logger, debug level), which stringifies the entire args.
-
IndexRunner.incremental's own line (index-runner logger, debug level): starting from incremental indexing for <comma-separated-urls> — gives just the URLs, not operations.
Each entry is { url: string, operation: 'update' | 'delete' }. The runner converts that to URL objects, calls Batch.invalidate(urls) once, and proceeds to visit. Skip directly to the consumer fan-out (step 5) using these URLs as the seed.
5. Computing consumers (the fan-out)
The fan-out is iterative, not a single recursive CTE. Batch.invalidate(urls) (packages/runtime-common/index-writer.ts line 826) drives the loop:
-
For each seed URL, collect concrete-URL matches across boxel_index_working (current batch) and boxel_index (production) — urlsMatchingSeed (lines 776-819).
-
For each matched URL, call calculateInvalidations(alias) (line 1066) which finds rows that reference the alias in their deps jsonb array, then recurses into those rows' aliases. Recursion is bounded by a visited set per invalidate() call — there are no fixed iteration counts, the walk continues until visited saturates.
-
The single SQL building block is itemsThatReference(resolvedPath) (line 978), which on Postgres uses jsonb containment. Where to read from depends on the question: at runtime the indexer queries boxel_index_working so mid-batch tombstones and rewrites are visible to subsequent fan-out iterations. For post-mortem reconstruction of a stuck job, prefer boxel_index (committed state) — that gives you the state the runner started with, before its own writes confused the picture. If the job partially advanced, probe both tables side-by-side to see what was already redrawn vs. what was still untouched.
SELECT i.url, i.file_alias, i.type
FROM boxel_index AS i
WHERE i.deps @> '["<seed-url>"]'::jsonb
AND i.realm_url = '<realm-url>'
LIMIT 1000;
SELECT i.url, i.file_alias, i.type
FROM boxel_index_working AS i
WHERE i.deps @> '["<seed-url>"]'::jsonb
AND i.realm_url = '<realm-url>'
LIMIT 1000;
When the seed has a @cardstack/... "registered prefix" form (catalog modules, etc.), the runtime also probes the unresolved form — @> against ["<unresolved-prefix>/..."]. Reproduce by-hand only if your seed URL is one of those (look for unresolveCardReference in card-reference-resolver.ts).
-
The invalidationTraversalAlias rule (line 1095) decides what gets fed into the next iteration:
- For
type = 'instance' rows: the row's own url (the .json URL).
- For executable file rows (
.gts / .ts / .js / .gjs) with a file_alias: the file_alias (path with extension trimmed). Executable consumers see the aliased URL in deps, not the source file with extension.
- Otherwise (non-executable file rows): the row's
url.
-
After the loop converges (no new URLs added to visited), tombstoneEntries(invalidations) (line 684) inserts a is_deleted = true row for every invalidated URL into boxel_index_working with realm_version = <next-version>, stamped with the batch's current invalidationId. This is the first DB-side write of the batch. If the worker died before this, boxel_index_working will not yet contain partial-progress rows for the new realm version (step 6 will be empty).
To reconstruct the consumer set against the live DB, run the iteration manually:
SELECT i.url, i.file_alias, i.type
FROM boxel_index AS i
WHERE i.realm_url = '<realm-url>'
AND i.deps @> '["<seed-url>"]'::jsonb;
For a quick approximation against a stuck job — a single SQL pass that covers most realms (no transitive recursion, but catches one hop):
WITH seeds(url) AS (VALUES
('<seed-url-1>'),
('<seed-url-2>')
)
SELECT DISTINCT i.url, i.type, i.file_alias
FROM boxel_index AS i, seeds
WHERE i.realm_url = '<realm-url>'
AND i.deps @> jsonb_build_array(seeds.url);
Two-hop fan-out: rerun with the first hop's (url, file_alias, type) plugged in via invalidationTraversalAlias (instance → use url; executable file → use file_alias; non-executable file → use url). In practice the runtime walk converges in 2-4 hops for typical realms; if you're still discovering new URLs after 5-6 hops, you've hit a tightly-cycled module graph and reconstruction by hand isn't going to be cheap.
6. Reading partial progress from boxel_index_working
boxel_index_working carries the batch's in-progress writes, keyed by (url, realm_url). The indexer writes here continuously via Batch.updateEntry (line 310). On Batch.done() (line 476), rows are copied into boxel_index with the new realm_version and the working table is left in place — it's not truncated (each invalidation is keyed by realm version inside the table). For a stuck job, the rows already written carry the same invalidationId and bracket the freeze point.
SELECT
url,
type,
has_error,
realm_version,
to_timestamp((diagnostics->>'indexedAt')::bigint / 1000)
AS indexed_at,
diagnostics->>'invalidationId' AS invalidation_id,
diagnostics->>'renderStage' AS render_stage,
diagnostics->>'currentlyEvaluatingModule' AS evaluating_module,
diagnostics->'recentModuleEvaluations'->0->>'url'
AS slowest_module,
jsonb_array_length(
COALESCE(diagnostics->'inFlightModuleImports', '[]'::jsonb)
) AS modules_in_flight,
jsonb_array_length(
COALESCE(diagnostics->'queryLoadsInFlight', '[]'::jsonb)
) AS queries_in_flight
FROM boxel_index_working
WHERE realm_url = '<realm-url>'
AND diagnostics->>'invalidationId' = '<invalidation-id>'
ORDER BY (diagnostics->>'indexedAt')::bigint ASC;
If you don't already have an invalidationId, find the most recent batch's ID against the working table (the last updateEntry for the realm wins):
SELECT
diagnostics->>'invalidationId' AS invalidation_id,
realm_version,
count(*) AS rows_written,
to_timestamp(
min((diagnostics->>'indexedAt')::bigint) / 1000
) AS first_write,
to_timestamp(
max((diagnostics->>'indexedAt')::bigint) / 1000
) AS last_write
FROM boxel_index_working
WHERE realm_url = '<realm-url>'
AND diagnostics->>'invalidationId' IS NOT NULL
GROUP BY 1, 2
ORDER BY last_write DESC
LIMIT 10;
The bottom row of the per-invalidationId query (max indexedAt) is the most recently completed file; the file the worker stalled on is most likely the next one in the planned visit order (which is sorted in index-runner.ts::sortInvalidations — .json files visited after their non-.json counterparts; otherwise lexical by href). Combine three signals to pin it down:
- The bottom row's
url is the last-completed file.
- The worker log's last
begin fused visit of file <url> line for the job (visit-file.ts line 108, index-runner logger, debug level) names the file the visit started on. If there's no matching completed fused visit of file <url> line, that's where the worker froze.
- The bottom row's
currentlyEvaluatingModule / recentModuleEvaluations[0].url / inFlightModuleImports[] say which module inside that visit was the stall point — same field semantics as Mode A.
To read which row would have been visited next from the working table (rows already invalidated but not yet written-with-content — these are the tombstones inserted by Batch.invalidate):
SELECT url, type, file_alias, is_deleted
FROM boxel_index_working
WHERE realm_url = '<realm-url>'
AND realm_version = <realm-version>
AND is_deleted = TRUE
ORDER BY url ASC;
If boxel_index_working has zero rows for this batch's invalidationId, the worker died before any DB write — see step 9.
7. Cross-referencing with worker logs
The worker logs to ecs-boxel-worker-<env> (see the aws-access skill's CloudWatch table). The relevant logger names:
| Logger | Defined at | Lines you care about |
|---|
worker | packages/runtime-common/worker.ts:80, packages/realm-server/worker.ts:22 | starting from-scratch indexing for job: <args> and starting incremental indexing for job: <args> (debug). Includes the full job args — use this to recover the seed for incrementals. |
realm-index-updater | packages/runtime-common/realm-index-updater.ts:29 | Realm <url> is starting indexing (info), Realm <url> has completed indexing in <s>s: <stats> (info). Always on at *=info; coarse but covers job lifecycle. |
index-runner | packages/runtime-common/index-runner.ts:48 | starting from scratch indexing / starting from incremental indexing for <urls> (debug), discovering invalidations in dir <url> (debug), begin fused visit of file <url> / completed fused visit of file <url> per file (debug, both in visit-file.ts), completed from scratch indexing in <ms>ms / completed incremental indexing for <urls> in <ms>ms (debug). This is the per-file progress channel. |
index-perf | packages/runtime-common/index-runner.ts:50, packages/runtime-common/index-writer.ts:173 | Per-stage perf timings (debug): time to get file system mtimes <ms>, time to invalidate <url> <ms>, completed getting index mtimes in <ms>, completed invalidations in <ms>, completed index visit in <ms>, completed index finalization in <ms>, inserted invalidated rows for <urls> in <ms>, time to determine items that reference <path> <ms>. Useful to confirm which phase a stuck job is in. |
LOG_LEVELS is read once at process start in packages/realm-server/setup-logger.ts:4:
(globalThis as any)._logDefinitions = makeLogDefinitions(
process.env.LOG_LEVELS || '*=info',
);
Default is *=info, which means none of the per-file or per-phase indexing lines appear in CloudWatch. To get bisection-grade detail for a worker investigation, set:
LOG_LEVELS=*=info,index-runner=debug,index-perf=debug,worker=debug
In the deployed environments this is an environment variable on the worker ECS task definition; the task reads it from the same place setup-logger.ts reads any other env var. The operator paths to update it:
-
Staging / production: LOG_LEVELS is held in AWS SSM Parameter Store at /<env>/boxel/LOG_LEVELS (e.g. /staging/boxel/LOG_LEVELS, /production/boxel/LOG_LEVELS). The worker ECS task definition references it via valueFrom, so the value is injected as the container's LOG_LEVELS env var at task start. To adjust levels:
- Update the SSM parameter value (AWS Console → Systems Manager → Parameter Store, or
aws ssm put-parameter --name /<env>/boxel/LOG_LEVELS --value '<new-levels>' --overwrite if you have write access — Claude does not).
- Force a new deployment of
boxel-worker-<env> from the ECS console (Services → boxel-worker- → Update → "Force new deployment"). The new task picks up the updated SSM value at boot.
- The realm-server task reads
LOG_LEVELS for its own logging; in deployed envs the worker is a separate task and only its LOG_LEVELS matters for indexing-job logs. If you also want indexing logs that the realm-server emits during invalidation discovery (e.g. for jobs the realm-server queues directly), redeploy boxel-realm-server-<env> too.
Levels apply to subsequently-launched worker processes; a job already in flight keeps the levels it was launched with. So for triage of a future job, update SSM and redeploy first, then trigger the reindex.
-
Locally: prepend the env var, e.g. LOG_LEVELS='*=info,index-runner=debug,index-perf=debug' pnpm start-all — same as the prerenderer-reproduce=debug pattern in the Reproducing a render interactively section.
Sample CloudWatch greps, using cw from the aws-access skill (substitute claude-staging / claude-prod and the matching log group):
cw --profile claude-staging --region us-east-1 tail -b 2h \
-g '[job: 4271.' \
ecs-boxel-worker-staging
cw --profile claude-staging --region us-east-1 tail -b 2h \
-g 'Realm http://realms.example.com/<realm>/' \
ecs-boxel-worker-staging
cw --profile claude-staging --region us-east-1 tail -b 2h \
-g 'fused visit of file' \
ecs-boxel-worker-staging
cw --profile claude-staging --region us-east-1 tail -b 2h \
-g 'completed invalidations\|completed index visit\|completed index finalization' \
ecs-boxel-worker-staging
8. Putting it together — confidence levels
A short rubric for the most common shapes:
-
High confidence the stall is at file X: the bottom row of boxel_index_working (max indexedAt for the batch's invalidationId) is X AND the worker's last begin fused visit of file X line has no matching completed fused visit of file X line AND the bottom row's recentModuleEvaluations[0].url (or currentlyEvaluatingModule / inFlightModuleImports[0]) is a module under X. Treat the row's diagnostics as a Mode A capture and walk the Classify in one pass table.
-
Medium confidence: only two of the three signals agree. Most often the worker log is the dropout — debug-level logging wasn't on. Promote index-runner to debug and trigger a follow-up reindex to validate.
-
Low confidence — the runner stalled before any per-file work: boxel_index_working has no rows for this batch's invalidationId (no row stamped with the batch UUID, no is_deleted = TRUE tombstones at the batch's realm_version). The worker is still in invalidation discovery — either the mtime walk (no discovering invalidations in dir line yet) or the consumer fan-out (the discovering line is there but no per-file visit-start lines). Look at the worker's index-perf time to get file system mtimes / time to invalidate lines — if those are missing too, you're stuck in the realm-server fetch (reader.mtimes() → _mtimes HTTP call) or in Batch.invalidate's own jsonb-containment SQL (itemsThatReference). Then go look at what should have been in the seed but wasn't — cross-check the EFS file listing against the realm's boxel_index.last_modified per step 3.
-
Confirm a "rejected" job actually failed cleanly: jobs.status = 'rejected' should pair with the matching reservation's completed_at IS NOT NULL. If completed_at IS NULL, the worker bailed before its finalize transaction (see pg-queue.ts lines 619-696); the reservation's locked_until will eventually expire and another worker can claim it.
The actual error is in jobs.result (jsonb). When the worker's await job.run(...) throws, pg-queue.ts:627-628 does result = serializableError(err); newStatus = 'rejected'; and the finalize UPDATE writes both into the row. Read it directly:
SELECT id, job_type, status, finished_at,
args->>'realmURL' AS realm_url,
result->>'message' AS error_message,
result->>'name' AS error_class,
result->'stack' AS stack_trace
FROM jobs
WHERE id = <job_id>;
result is the same shape serializableError produces: { message, name, stack, ... }. For triage, error_message + error_class is usually enough; stack_trace is there when you need to find the throw site. Sentry has the same payload (and more breadcrumbs) but you don't need to leave the DB to get the rejection reason.
9. What this mode can't tell you
- If the worker died before any DB write — crashed during
discoverInvalidations, OOM-killed during the mtime walk, or threw inside Batch.invalidate's own SQL — boxel_index_working will have no rows for this batch's invalidationId. The Batch object mints the invalidationId in its constructor, but it only lands on disk when the first updateEntry or tombstoneEntries call runs. Until then the only diagnostic signals are the worker log and the EFS state. Mode C cannot reconstruct which file the worker was processing in that case — you need either index-runner=debug log output or a Sentry trace.
- The
diagnostics for partial-progress rows is the per-render capture for that row's prerender call. It won't tell you why the next render froze. If the bottom-row's diagnostic is clean (low renderElapsedMs, no in-flight loads), the stall is between renders — usually Batch.invalidate recursion against a tightly-cycled module graph, or DB contention on the boxel_index_working upsert. The index-perf time to determine items that reference … lines are the only fingerprints of that loop.
- A
boxel_index row's diagnostics reflects the last successful indexing pass, not the in-flight one. Don't confuse a stale boxel_index indexedAt with the stuck job — always cross-reference against the matching boxel_index_working row (same (url, realm_url)) before drawing conclusions.
Mode D — a module render was slow or hung
Module renders (prerenderModule, used by getDefinition to convert filter JSON into SQL on _federated-search, plus everywhere else a card definition is needed without a card render) go through the same prerender pipeline as card renders, but they land in the modules table — not boxel_index. The diagnostics JSONB column on modules carries the same RenderTimeoutDiagnostics-with-requestId shape, so the field-by-field reading and the Classify in one pass table apply unchanged. Only the lookup queries differ.
When to use this mode: a card render hung waiting on getDefinition (Mode A captured cardDocLoadsInFlight = 0, queryLoadsInFlight = 0, but the realm-server's reply to _federated-search itself was slow — and if the stall was on a query-field search rather than a definition lookup, i.e. queryLoadsInFlight > 0, use Mode G instead); an investigation needs to attribute time across both card renders and the module renders they triggered; or you want to find the slowest module renders fleet-wide. Same payload shape, queryable via SQL.
Step 1 — slowest module renders in a realm.
SELECT m.url,
(m.diagnostics->>'renderElapsedMs')::int AS render_ms,
m.diagnostics->>'renderStage' AS stage,
m.diagnostics->>'requestId' AS request_id,
to_timestamp(m.created_at::bigint / 1000) AS created_at,
m.error_doc IS NOT NULL AS has_error
FROM modules m
WHERE m.resolved_realm_url = '<realm-url>'
AND m.diagnostics IS NOT NULL
ORDER BY render_ms DESC NULLS LAST
LIMIT 20;
Step 2 — find module renders correlated with a known time window. Useful when a card render timed out at wall-clock T and you want to know whether a slow module render was happening at the same moment.
SELECT m.url,
(m.diagnostics->>'renderElapsedMs')::int AS render_ms,
m.diagnostics->>'requestId' AS request_id,
to_timestamp(m.created_at::bigint / 1000) AS created_at
FROM modules m
WHERE m.resolved_realm_url = '<realm-url>'
AND (m.diagnostics->>'renderElapsedMs')::int > 5000
AND m.created_at BETWEEN <window_start_ms> AND <window_end_ms>
ORDER BY render_ms DESC;
window_start_ms and window_end_ms are epoch milliseconds bracketing the suspect period (e.g. the 90s before and including the hung card render's indexedAt).
Step 3 — join card hang to its triggering module render via requestId. When the realm-server's getDefinition round-trip is in scope of a single card render, the requestId propagates from card → manager → module-extract round-trip, so both rows carry the same value.
SELECT 'card' AS kind, url, jsonb_pretty(diagnostics) AS diagnostics
FROM boxel_index
WHERE diagnostics->>'requestId' = '<request-id>'
UNION ALL
SELECT 'module' AS kind, url, jsonb_pretty(diagnostics) AS diagnostics
FROM modules
WHERE diagnostics->>'requestId' = '<request-id>';
(In practice the card-side requestId is the original outer call. Internal sub-prerenders fired by CachingDefinitionLookup typically mint their own requestId per _prerender-module call, so the time-window join in step 2 is usually the one that catches them. The requestId join here works for the rarer in-line case.)
Step 4 — classify the module render with the same rubric. Once you have a slow module's diagnostics, walk it through the Classify in one pass table the same way you would a card render. The interpretation is identical: waiting-stability + queryLoadsInFlight=N is a data stall on a _search (rare for module renders but possible for query-field driven module-extract paths), model:start + inFlightModuleImports>0 is the loader stall, etc. The only field that's not present on module rows is invalidationId (modules don't go through Batch.invalidate), so any Mode B-style cross-row grouping has to use requestId or created_at windows instead.
What Mode D can't tell you
- No partial-progress equivalent.
modules has no working-table sibling; the row only lands on persistModuleCacheEntry after the prerender returns. If a prerenderModule call hangs forever and the worker is killed, no row is written and Mode D has nothing to query. Cross-reference against the prerender server logs for requestId=… directly, same as a hung card render before the host's withTimeout fires.
- No invalidationId, so no Mode B fan-out. Module renders are independent units; they don't belong to a "batch" that you can group by. If you need to attribute a slow
getDefinition storm across many concurrent searches, you're stuck doing it via created_at time windows + the #inFlight dedupe behavior in CachingDefinitionLookup — i.e. one slow row may have been the bottleneck for many in-flight callers, but the modules table doesn't record those waiters.
Mode E — enumerate cards with broken links
Unlike Modes A–D, this isn't a perf investigation: it's a realm-health / content-integrity query. A card whose linksTo / linksToMany target is unreachable (deleted, 404, upstream 5xx, network failure) still indexes as a clean type='instance' — the broken slot renders the placeholder template and the broken reference is preserved on the wire as relationships.<field>.links.self, identical to a not-yet-loaded link. So has_error is false and error_doc is null; nothing in the row's status tells you the link is broken.
What records it is diagnostics.brokenLinks — an array the host's render.meta route builds by running getBrokenLinks(instance) on the settled instance and attaching the findings to the diagnostics block. Each finding is the minimal queryable summary:
"brokenLinks": [
{ "fieldName": "author", "reference": "https://realm.example/people/ringo", "kind": "not-found" },
{ "fieldName": "pets", "reference": "https://realm.example/pets/missing", "kind": "error" }
]
fieldName — the declared linksTo / linksToMany field holding the broken reference. A linksToMany field with one broken element produces one finding for that element; present siblings produce none.
reference — the broken target reference, as captured from relationship state.
kind — 'not-found' for an HTTP 404 (the canonical "target was deleted" case), 'error' for any other upstream failure (5xx, network, fetch error).
errorDoc is not persisted here (it's large) — read it at runtime via getRelationship(card, fieldName) or see it inline in the rendered placeholder. The broken target is also carried in the row's deps, so if the target later reappears the card is invalidated and re-rendered, clearing the finding.
SELECT
i.url,
bl->>'fieldName' AS field_name,
bl->>'reference' AS broken_reference,
bl->>'kind' AS kind
FROM boxel_index i
CROSS JOIN LATERAL jsonb_array_elements(i.diagnostics->'brokenLinks') AS bl
WHERE i.realm_url = 'https://localhost:4201/user/your-realm/'
AND i.type = 'instance'
AND jsonb_typeof(i.diagnostics->'brokenLinks') = 'array'
ORDER BY i.url, field_name;
SELECT count(*) AS cards_with_broken_links
FROM boxel_index
WHERE realm_url = 'https://localhost:4201/user/your-realm/'
AND type = 'instance'
AND jsonb_typeof(diagnostics->'brokenLinks') = 'array';
SELECT i.url, bl->>'fieldName' AS field_name, bl->>'kind' AS kind
FROM boxel_index i
CROSS JOIN LATERAL jsonb_array_elements(i.diagnostics->'brokenLinks') AS bl
WHERE bl->>'reference' = 'https://realm.example/people/ringo';
Caveats:
- Older rows predate the scan. A row last indexed before this capability shipped has no
brokenLinks key even if its links are broken — it'll only appear after the next reindex. Don't read "absent" as "no broken links" for stale rows; check indexedAt if in doubt.
boxel_index_working carries it too, so you can watch broken-link findings accrue mid-reindex the same way as the timing fields (see Reading partial progress).
- This is the cheap enumeration path the rendered-HTML /
getRelationship runtime surfaces were too expensive for — querying the column avoids parsing HTML or re-running getBrokenLinks per read.
Mode F — module pre-warm and definition-cache hit/miss
Use this when you're asking "is the module pre-warm actually populating the definition cache, and are the indexer / prerender reads hitting it — or silently re-computing?" This is about cache effectiveness, not render timing.
What pre-warm is
A from-scratch (and incremental) index runs a pre-warm phase before the visit phase: IndexRunner.preWarmModulesTable walks the realm's modules and calls definitionLookup.populateDefinitionCacheEntry(...), which prerenders each module's definitions and persists them to the modules table. The intent is that the subsequent visit phase (indexing instances) and on-demand reads (the realm-server serving getDefinition to prerender tabs) then find those rows already cached instead of re-prerendering them.
The original failure this guards against: a worker pre-warm that ran with a self-resolved null cache context wrote nothing (or wrote under a key nobody reads), so pre-warm was a silent no-op. The diagnostic below tells you definitively whether that's happening.
The cache key
The modules table row is keyed on (resolved_realm_url, cache_scope, auth_user_id). The two derivations that MUST agree:
- Write (
persistDefinitionCacheEntry): stores auth_user_id = cacheScope === 'public' ? '' : userId.
- Read (
buildLookupContext): looks up with cacheUserId = isPublic ? '' : prerenderUserId.
So the key differs by realm visibility:
- Public realm →
cache_scope='public', auth_user_id='' (empty). The realm owner / render identity is not part of the key.
- Private realm →
cache_scope='realm-auth', auth_user_id=@<owner>:<matrix-domain>.
If write and read ever derive auth_user_id differently for the same module, pre-warm writes a row no reader probes → permanent miss. The hit/miss log is how you catch that.
Enabling the hit/miss log channel
Category: definition-cache-key=debug (and definition-lookup=debug for the pre-warm warnings/skips). Locally:
LOG_LEVELS='*=info,definition-cache-key=debug' mise run dev-all
Deployed: set LOG_LEVELS in the worker's SSM param and redeploy (same mechanics as Mode C step 7). It applies to subsequently-launched workers.
Three events are emitted (all via the framework logger, so the lines carry no [category] prefix — grep the message text, not the word definition-cache-key):
| Line | Where | Meaning |
|---|
WRITE module=<u> scope=<s> user=<id|(empty)> realm=<r> | persistDefinitionCacheEntry | A definition was persisted. The user= shown is the normalized stored key (public → (empty)), not the render identity. |
HIT module=<u> scope=<s> user=<…> realm=<r> alias=<a> | readFromDatabaseCache | A DB read found the row. Always a real hit (logged at the read choke point, covers worker + realm-server). |
MISS source=pre-warm|on-demand module=<u> … | loadDefinitionCacheEntryUncached | A lookup exhausted the cache (primary URL + every alias/extension candidate) and committed to a prerender. Logged once per logical lookup — not per alias probe. source=pre-warm is the pre-warm phase's own cold probe; source=on-demand is a visit-phase / live read. |
Two logging facts that will mislead you if you don't know them:
- Category overrides only take effect because
setup-logger.ts calls reapplyLogLevels() after installing _logDefinitions. Module-scope logger() calls (like this one) are evaluated during the barrel import before _logDefinitions exists, so without the re-apply they stay stuck at loglevel's default and definition-cache-key=debug silently no-ops. If you add a new module-scope category and it won't emit, this is why.
- A bare
readFromDatabaseCache returning no rows is not a real miss — it's one probe (the reader tries foo, foo.ts, foo.js, foo.gts, foo.gjs). Counting those as misses inflates the number ~5×. The MISS source=… line is the de-duplicated, real signal; trust it over raw DB-read counts.
The healthy shape
For a cold from-scratch of a single realm, healthy looks like:
MISS source=pre-warm ≈ one per module being warmed. These are expected — they are the warming (probe cold → prerender → WRITE).
MISS source=on-demand = 0.
- Realm-server on-demand reads = all HIT, 0 miss, after the pre-warm phase.
i.e. misses occur only during the pre-warm phase. Anything else is a bug.
The unhealthy shape (what you're hunting)
MISS source=on-demand > 0 for canonical modules (the .gts/.ts form, not an alias probe), or persistent realm-server misses for a module pre-warm already WRITE-d → the write key ≠ the read key. Compare the user=/scope= on the WRITE line vs the MISS/read line for the same module. The usual culprit is a divergence between persistDefinitionCacheEntry's auth_user_id normalization and buildLookupContext's cacheUserId (e.g. one resolving the owner where the other uses empty). Public realms are the sensitive case — both paths must collapse the user to ''.
- No
WRITE lines at all during pre-warm → pre-warm is skipping (context-resolve failure → definition-lookup warn line, empty user, browser-test env, or empty candidate set). Check definition-lookup=debug.
Verification protocol (isolated, repeatable)
SELECT regexp_replace(resolved_realm_url,'^https?://[^/]+/','') realm, cache_scope, count(*)
FROM modules GROUP BY 1,2 ORDER BY 1,2;
DELETE FROM modules WHERE resolved_realm_url LIKE '%/<realm-path>/';
OFF=$(wc -l < /tmp/stack.log)
curl -sk -X POST "https://localhost:4201/_grafana-reindex?realm=<realm-path>" \
-H "Authorization: Bearer $GRAFANA_SECRET"
tail -n +$((OFF+1)) /tmp/stack.log | grep -a '<realm-path>' \
| grep -aoE 'HIT |MISS source=pre-warm|MISS source=on-demand|WRITE ' | sort | uniq -c
tail -n +$((OFF+1)) /tmp/stack.log | grep -a 'services:realm-server' | grep -a '<realm-path>' \
| grep -acE 'MISS source=on-demand'
Run it once on a private realm and once on a public realm — the public case is where a key-derivation divergence hides. Reference numbers from a healthy run (a private 234-file realm): worker MISS source=pre-warm=159, MISS source=on-demand=0, realm-server on-demand misses=0; pre-warm phase ~8.5s for 86 modules (~99 ms/module), serial.
Pre-warm concurrency
Pre-warm is serial by default (INDEXER_PREWARM_CONCURRENCY=1). It's opt-in tunable — a bounded worker pool over populateDefinitionCacheEntry. On a cold / shared prerender pool, raising it can be slower (tab materialization cost vs warm-tab reuse), so measure the pre-warm-phase wall-clock (the modules.created_at min→max window for the realm) before and after rather than assuming parallel wins. Align the ceiling with the prerender affinity tab budget (PRERENDER_AFFINITY_TAB_MAX); beyond that you just queue inside the prerender server.
What Mode F can't tell you
Pre-warm only populates module definitions. A realm whose card-authored modules fail to evaluate (e.g. a circular-dependency TDZ in a bundled module — Cannot access 'X' before initialization) will still fail the visit phase instance renders regardless of a clean pre-warm; those show up as boxel_index error rows, not cache misses. Mode F confirms the cache is keyed and populated correctly; it says nothing about whether the modules themselves render.
Mode G — an in-render _search was slow (server-side search timing)
When to use this mode. Mode A classified a timed-out (or slow-but-succeeded) card render as a data stall on a _search: renderStage=waiting-stability, cardDocLoadsInFlight=0, and a queryLoadsInFlight entry whose ageMs is most of the render's wall-clock. The card is blocked waiting for the realm-server to answer a query-backed linksTo / linksToMany search (e.g. a policies getter). The boxel_index.diagnostics blob is the client's view — it tells you the host waited N ms on query Q, but nothing about where the realm-server spent that time. The decisive tell: if pg_stat_activity shows no SQL running longer than ~1s while the host waited tens of seconds, the wait is realm-server delivery, not query execution — and that's invisible without this mode. Mode G is the server-side complement that localizes it. (Also the right mode for "a slow _federated-search whose SQL is fast" in general, even outside a timeout.)
The correlation id. The prerendered host stamps x-boxel-logging-correlation-id on each _federated-search fetch it issues — prerender-gated, so live SPA / external traffic never stamps it and never emits these lines. The realm-server reads it back out and keys two lines on corr=<id>: