Docs

Dev Terminal Noise & Freeze Diagnostics — Delivery Notes

Delivery summary for two linked pieces of work: making the yarn start terminal quiet enough to read, and adding the instrumentation that was missing when a freeze needed explaining. The searchfield-cancel-button fix that came out of it is recorded separately in Pulsar Upstream Fix Candidates. This note says what changed and what it was measured against.

Status

Implemented; awaiting a manual pass in-app.

PieceState
Drop per-navigation and startup logging from tranquil-rpc✅ done
Report trusted roots at registration instead of at activate✅ done
Remove leftover debug logging from tranquil-browser; tag its catch-block errors✅ done
Rewrite keepConsoleRecord in scripts/dev.js as an allowlist✅ done
Delete the dead searchfield-cancel-button declaration and the filter masking it✅ done
Capped-backoff reconnect for the ops-demo /_reload channel✅ done
Main-process event-loop and window-hang watchdogs✅ done
Renderer stall watchdog in tranquil-config✅ done
Classifier and watchdog behaviour covered by direct checks✅ passed

How the noise was measured

The terminal is a pipe with no log file behind it, so the starting point was the renderers themselves. Chromium keeps a per-renderer console buffer and replays it to any newly attached inspector session, so connecting to the running app’s CDP endpoint and enabling Runtime and Log on all 11 targets recovered a 646-record history without restarting anything.

Those records were then replayed through keepConsoleRecord() — a pure function — to establish which ones actually reach the terminal rather than guessing from the source paths:

VolumeMessageOrigin
244[tranquil-rpc] untrusted — no runtime injected: <url>ours; fired on every navigation in every tab
138Failed to load resource: ERR_* @ localhost:3000/_reloadthe ops-demo live-reload channel
123Third-party cookie will be blocked.Chromium, from pages in browser guests
12host module loaded / activated; trusted roots: []ours; two lines per window
3marked() ×2, xterm task queue exceeded deadlinedependencies under node_modules/

What was actually wrong

Our own packages logged expected conditions. tranquil-rpc announced every untrusted page load, which is the default-deny path taken by every ordinary navigation — the interesting events are a trusted session opening or an injection failing, both already logged and both rare. Its activation line printed trusted roots: [] in every window, always, because roots are registered by other packages after activate; the reporting moved into addTrustedRoot(), where it fires when a root genuinely arrives. tranquil-browser still carried debug lines from earlier work (openLinkInNewWindow, a pong echo) and four console.log(e) catch blocks that reported caught exceptions at log level with no tag.

The filter was a denylist. keepConsoleRecord dropped only node:electron sources and remote http(s) origins, and kept everything else. That let through Blink warnings attributed to the window shell’s file:// URL, dependency warnings whose source path happens to be local, error pages, and every resource-load failure from localhost. It is now an allowlist: explicit LOG_FILTERS patterns first, then anything carrying a [tranquil-*] tag is kept unconditionally, then structural rules drop resource-load failures, node:electron, chrome-error: and file: sources, node_modules/ paths, and remote pages.

The [tranquil-*] rule is deliberate: it runs before the structural rules so that a future tightening cannot silently swallow the watchdog output below.

The freeze, and why nothing explained it

The investigation began with a 10–30 second freeze during ordinary use. The console history did not explain it, and could not have: there was no exception, no long-task violation, no renderer crash, and memory was unremarkable at 3.2 GB across 19 processes.

The absence was the finding. Three gaps stacked:

  • atom-window.js handles unresponsive, but only to open a dialog. Nothing is recorded, so once the dialog is dismissed the event is gone.
  • unresponsive is emitted by the main process about a renderer. When the main process is what blocked, every window freezes together and the process that would have to notice is the one that is stuck.
  • Chromium does not consider a renderer hung until roughly 30s of unacknowledged input, so a shorter freeze produces no event at all. No dialog appearing ruled nothing out.

What was added

Two watchdogs, both passive — they report and never intervene.

Main process (tranquil-client/src/main-process/stall-watchdog.js, wired from cz-init.js): a one-second interval measuring event-loop drift, reporting past a second of lag. It logs after the stall clears, which is what lets the record survive. Alongside it, per-window unresponsive / responsive listeners that record which window hung and for how long, and powerMonitor suspend/resume markers — without those, telling a hang from a closed laptop means going to pmset -g log afterwards and aligning timestamps by hand.

Renderer (tranquil-config/src/stall-watchdog.js): the same technique on the renderer main thread at a 1.5s threshold, deliberately far below Chromium’s, since that band is exactly what produced no dialog. It reports the window title, so the next occurrence answers the main-process-versus-renderer question that could not be answered this time.

Both had to be taught the difference between a stall and a stopped clock. The main-process timer rebases on resume and skips the following tick. The renderer has no view of the power state, so it ignores any tick where the window was hidden — Chromium throttles timers in background windows to roughly once a minute, which would otherwise read as a permanent stall — and caps reports at 60s, above which a gap is a suspend rather than a freeze. Nothing is lost at the ceiling: a freeze that long crosses Chromium’s hang threshold and is logged by the main process instead.

Verification

Behavioural rather than incidental, since both pieces are logic that only runs in rare states:

  • Classifier. keepConsoleRecord is pure, so it was exercised directly against one real record of each class — our own logs, node_modules/, file://, chrome-error:, resource-load failures, localhost app output, and a [tranquil-*] line. All 14 behave as intended.
  • Watchdogs. Driven against stubbed app / BrowserWindow / powerMonitor / document objects with the event loop genuinely blocked: both report a real stall, window hang events log with their duration, a simulated suspend/resume logs as sleep and produces no false stall, and a hidden window stays silent. The 60s ceiling was checked across the range — 1.5s through 60s reports, a 20-minute gap does not.
  • Stylesheet. The edited .input-search block was compiled against stubs; output is identical apart from the removed pseudo-element rule.

Follow-ups

  • The watchdogs produce evidence, not a fix. The next freeze should say which process stalled and for how long; the actual cause follows from that.
  • tranquil-rpc still registers no trusted roots outside the smoke suite — a known gap, recorded in the RPC trust-gap note, untouched here.