Name the module in a prerender stall, and log definition-cache populates - #6185
Conversation
A prerender abort reported only the realm it had affinity for, so every module of a realm read identically and a stall could not be attributed to one. It now carries the subject URL. A definition-cache populate is the expensive path a cache hit avoids, and it happened silently, so a module that populates on every read — a cache that never takes — was indistinguishable from one that populates once. Each populate now logs its module and realm. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Codex Review SummaryThis comment shows the latest Codex review activity on this pull request.
ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
Codex reacts with 👀 while any review is running, comments if it has suggestions, and reacts with 👍 once all reviews finish with no findings. |
Host Test Results 1 files ±0 1 suites ±0 2h 44m 36s ⏱️ + 6m 54s Results for commit 8168614. ± Comparison against earlier commit 3988965. Realm Server Test Results 1 files ± 0 244 suites ±0 1h 25m 36s ⏱️ - 6m 1s Results for commit 8168614. ± Comparison against earlier commit 3988965. |
habdelra
left a comment
There was a problem hiding this comment.
[Claude Code 🤖] Reviewed both diagnostics against the paths that produce them — which callers reach the timeout branch and with what attributes, and how often getModuleDefinitionsViaPrerenderer actually runs per lookup. I did not exercise either line at runtime.
No blocking issues. The prerender-timeout half is correct: prerenderModule, prerenderVisit and prerenderScreenshot all pass url, so the stalled subject is named, and runCommand (no url) falls to the empty string rather than url=undefined. The definition-cache line has an accuracy problem worth settling before anyone counts with it.
definition-lookup.ts— the populate line fires once per extension candidate, not once per lookup, so it over-reports populates and can name modules that don't exist; it also opens a second, always-on signal next to the existing once-per-lookupkeyLogMISS line that answers the same question with more key detail. See the inline thread.remote-prerenderer.ts—runCommandtimeouts remain unidentifiable;attributes.commandwould name them the same way. One-line suggestion inline, take or leave.
CI is green.
Generated by Claude Code
The populate line sat inside `getModuleDefinitionsViaPrerenderer`, which runs once per extension candidate rather than once per lookup, so a single miss on an extensionless URL emitted several lines and named modules that need not exist. Counting them would have overstated populates, which is the one thing the line was for. The file already warns about exactly this: the MISS line in `loadDefinitionCacheEntryUncached` excludes per-probe reads because "those alias probes inflate the count with non-real misses", and it already answers cache effectiveness once per lookup with more key detail. So the cache-effectiveness claim goes and the one fact the MISS line does not carry stays: which candidate was sent. It moves to `definition-cache-key`, which is off unless `LOG_LEVELS` asks for it, rather than standing as a second always-on signal on a channel where `info` is the default. A command request carries no url, so its timeouts kept the anonymity this branch removes. The command name identifies them; `commandInput`, which is the part that would carry data, stays out of the message. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This is a diagnostic change that helped with the bundling of the base realm.
Claude: Split out of #6087 so it can be reviewed on its own. Observability only, no behavior change.
Two lines that cost me real time to work without while debugging a prerender stall:
A prerender timeout names only the realm. The affinity tag is
realm:<url>, so every module of a realm produces the same message and there is no way to tell which one never came back. Adding the subject URL makes the stalled request identifiable.A definition-cache populate is invisible. A populate happens only when no cached row satisfied the lookup, so a module that populates on every read is a cache that never takes — and nothing said so. One
infoline per populate makes that legible.🤖 Generated with Claude Code