Repository navigation
Tail-hygiene baseline re-stringifies whole tool parts through stableStringify and accounts for 82% of a 47 s stall in large sessions #704
Description
What happened
On the same large edit-heavy sessions that freeze for seconds per message, the host-stall profiler attributes the largest share of the stall to the tail-hygiene baseline refresh. The captured chain is stableStringify ← safeStableStringify ← excludedSnapshot ← measureWithReplay ← refreshTailHygieneBaseline. It accounts for 3,343 of 4,057 samples (82.4%) in a 47.4 s stall window (10 ms sampling interval). The profile's hottest frames are the recursive writer's per-scalar JSON.stringify calls (1,094 samples) and Object.entries (554); the recursion truncates those stacks before they reach the labeled caller.
The containing stage confirms it scales with session size. The post-transform phase, which runs this refresh, logs:
| Session | Passes | Avg | Max |
|---|---|---|---|
| Large, edit-heavy (A) | 936 | 374 ms | 44,559 ms |
| Large, edit-heavy (B) | 287 | 1,770 ms | 66,267 ms |
| Small (same install) | 209 | 30 ms | 377 ms |
Why
excludedSnapshotserializes the entire part for measurement:safeStableStringify(part)(tail-hygiene-walk.ts L558-L559). In these sessions tool parts carry multi-MBstate.metadatapayloads (one measured part: 5.4 MB, ~121k scalar fields), so each measurement materializes a multi-megabyte string. The walk also stringifies selected fields separately — tool output, error, result, and input (L369-L392) — so a part can be serialized more than once per pass.stableStringify(stable-json.ts L20-L67) is the expensive serializer: it recurses withwriteStable, callsObject.entries(...).sort()at every object level (100k+ sorts for a 100k-object diagnostics payload), pushes one piece per scalar token (millions per part), and joins at the end.- Micro-measurement (same machine, Node 24, synthetic replica of the measured part shape, ~0.9M scalar fields, 15.6 MiB as JSON):
stableStringify424–603 ms; nativeJSON.stringify19–25 ms.stableStringifyis roughly 20× slower and materializes a 15.6 MiB string. - The refresh runs on the host's main thread in the post-transform phase (refreshTailHygieneBaseline, called from
runPostTransformPhase). Its memo only hits on a non-cache-busting pass whose replay messages, tag set, and protected/pending tag sets are all unchanged; on a miss, measurement still reuses the previous pass's measured parts for messages whose provider-visible content is unchanged, so the cost comes from the changed subset. That subset is dominated by excluded (dropped/sentinel) parts, whichexcludedSnapshotserializes whole, with multi-MBstate.metadataincluded.
Affected harnesses
- OpenCode 1 (TUI, desktop, and web share one server plugin): measured, as described above.
- OpenCode 2: same shared post-transform phase (
createTransform→runPostTransformPhase→refreshTailHygieneBaseline); identical code path. - Pi / Oh My Pi: a separate Pi-specific walk (
tail-hygiene-walk-pi.ts) with its own serializer, nativeJSON.stringifywith a sorted-key replacer, cheaper than the recursive writer here; the same class of cost exists through different code. Not measured on Pi. - Rust transform mode (OpenCode 1): unaffected. It returns before the TypeScript post-pass.
Fix ideas
- Measure without materializing JSON: walk fields and hash/estimate incrementally (a canonical hash instead of a full string), or measure only the fields the hygiene accounting actually needs.
- Reuse per-part measurements within changed messages when the part is unchanged, instead of re-serializing it.
- If
state.metadatais not provider-visible (worth confirming), exclude it from measurement.
Environment
Plugin 0.48.0 installed; the involved functions are unchanged in v0.49.6 and master. Bun 1.4.2, macOS arm64, OpenCode 1.18.x. The stall report (stack frames, timings, and memory counters only) available as a gist: https://gist.github.com/maxbrunet/34ac60383e285323fb9a4e150985be81. The local profiler store keeps only its 50 newest reports, so the gist is the durable copy. A companion report covers a separate structuredClone cost visible in the same windows with a different root cause (#703).
Activity
magic-alfonso commentedon Oct 16, 2026
Thanks, and for keeping it separate from #703. Agreed that serializing the whole part through the recursive writer, multi-megabyte
state.metadataincluded, is what dominates those windows. A fix is in progress. It first confirms from source exactly what the tail-hygiene measurement needs from each part. It then measures without materializing the whole part, and reuses measurements for unchanged parts. It has to keep every hygiene decision identical to the current build, and we'll check the Pi walk for the same class of cost. We'll post here when it ships.[-]Tail-hygiene baseline re-stringifies whole tool parts through stableStringify — 82% of a 47 s stall in large sessions[/-][+]Tail-hygiene baseline re-stringifies whole tool parts through stableStringify and accounts for 82% of a 47 s stall in large sessions[/+]magic-alfonso commentedon Oct 17, 2026
Released in v0.49.9. Thanks for the profile; it pointed straight at the cause.
The check for whether a dropped tool output changed now reads only what the provider actually receives, not the tool's display metadata. On OpenCode 1 and 2 the step that took 200-300 ms on your 18 MB parts now takes about 0.03-0.05 ms per turn, and Pi's direct providers are similar. One exception: Pi's own native API sends the full metadata, so it still has to read all of it there. The fix also corrected the "unreduced outputs" count in the reminder, which used to be off after a refresh.
If you still see a stall on 0.49.9, please reopen with a fresh profile.