docs(perf): design and specification for client-side performance telemetry (#3167) - #3180
Conversation
A companion to PLAN.md aimed at making the one open decision reviewable without reading the full plan. Four diagrams: - why subtracting provider time from elapsed time cannot work (streaming means our render and decode work happens INSIDE the provider's interval, so subtracting it removes the very thing we want to measure) - full vs halved design, component by component, showing that the first six components are identical and only four are disputed - none of which change the trend number - that the operation grouping id already exists as a prompt-id prefix, so threading a new one through packages/agents rebuilds what a string split already gives us - the package layering, which settles ownership: telemetry is the lowest layer involved, so the writer belongs there and agents stays untouched Also records two things the plan missed: FileOutput.ts already implements most of the proposed writer (and never deletes anything, the same unbounded growth as #3164), and the record schema - the contract between writer and reader - is still undefined, which is exactly how #3164 happened. Refs #3167
Adds specification.md, which the plan named as a task and never delivered. The schema is the contract between writer and reader, and #3164 is what happens when those drift: a reader matching .json against a writer emitting .jsonl deleted nothing for months, with passing tests, because the fixtures encoded the old shape. Settled here, all independent of the outstanding full-vs-halved decision: - The full field set: envelope, #3130 identity keys reused verbatim, terminal status including superseded, build identity, comparison dimensions, the five client stopwatches, and provider/tool sum AND union marked explicitly non-additive. unclassified_elapsed_ms is reported honestly, never clamped. - Compatibility: readers ignore unknown fields (so adding one is not a bump), a bump means changed meaning or removal, and a reader seeing a higher version skips and counts rather than coercing. Truncated final lines are expected, not exceptional. - Placement, from the verified dependency edges: telemetry sits below core, so it owns schema/sink/retention; core owns only the stdout hook; cli owns the lifecycle, Ink wiring, setting and consumers; agents owns nothing and must not acquire a telemetry dependency. - Reuse: FileOutput.ts already provides most of the writer. Extend it and fix its four defects rather than build a parallel one - notably that it never deletes anything (verified: zero unlink calls), the same unbounded growth as #3164 in the package this feature would join. - Live-writer safety without a lock, and an honest eventual-bound retention guarantee instead of an impossible instantaneous cap. Two fields are tagged DECISION pending full-vs-halved, and the variable-length prompt_ids/turn_ids arrays are flagged as needing a cap or hash before any size budget can be computed. Refs #3167
Each load-bearing claim in the spec was checked against source rather than carried over from a review. Earlier in this effort a finding was propagated into three documents before turning out to be a test artifact, so the evidence is recorded to stop that recurring. All four confirmed: - Dependency edges: agents depends on auth/core/ide-integration/policy/ providers/settings/tools and NOT telemetry; telemetry depends only on storage. So telemetry is the lowest layer involved and agents must stay untouched. - The superseded case: the ownership release at useSubmitQuery.ts:657 sits inside an isCurrentTurn guard (:656, comment cites issue #2954), the acquire at :620 is unconditional, and there is a second release site at :293. A superseded turn therefore never finalises via ownership. - IntervalUnion: add() calls recomputeDuration(), which walks the whole interval list per insertion, and the class is not among the file's exports. - FileOutput: zero unlink/rm/rmSync calls in the entire file. Refs #3167
|
Important Review skippedReview was skipped due to path filters ⛔ Files ignored due to path filters (3)
CodeRabbit blocks several paths by default. You can override this behavior by explicitly including those paths in the path filters. For example, including ⚙️ Run configurationConfiguration used: Path: .coderabbit.yaml Review profile: CHILL Plan: Pro Plus Run ID: You can disable this status message by setting the Use the checkbox below for a quick retry:
Comment |
OpenCodeReview — PR #3180
|
WalkthroughBefore this PR, llxprt had no concrete design for client-side performance telemetry: existing telemetry was backend-facing, there was no JSONL record schema, no writer-reader contract, and no plan for directly measuring client phases, operation ownership, or memory trends. After this PR, the repository contains a complete design and specification for client-side performance telemetry, including a JSONL record schema, writer-reader contract, direct phase measurement model, memory trend design, reuse of existing telemetry infrastructure, and a phased implementation plan with rejected approaches and runtime traps documented. Documentation
Changes
Magnitude🎯 2 (M) Related
Pre-merge Checks
Walkthrough generated by LLxprt PR Review. Planner issue: #2256 |
Memory trend is now first-class in this issue and ships in this PR rather than trailing as a separable phase. All accepted work for #3167 goes out together. Sampling design, specified in specification.md section 7: - Memory columns ride the operation record for the per-operation axis; a record_type memory_sample row carries ms_since_last_operation for the per-minute axis. The discriminated record stream from section 1.1 earns its keep, and readers that ignore unknown record types need no version bump. - Two slopes rather than one number, because absolute memory says nothing: a large context legitimately uses a lot. Growth tracking work is normal; growth tracking uptime is the issue 3114 leak signature. - Slopes derived at read time, never stored, so fixing the regression maths does not require re-collecting data. - external and arrayBuffers are first-class - that is where the mass hid under Bun/JSC in issue 3112. Performance, which was the stated concern: - ZERO new timers. useMemoryMonitor already runs an unconditional 60s interval calling process.memoryUsage().rss, which is the right cadence for an uptime slope. Extend it. Footer's 2s interval is explicitly excluded as a host because it is gated on showMemoryUsage and on being mounted, so telemetry hung off it would silently collect nothing. - Two defects in that hook must be fixed: it clearIntervals itself after warning once, so today it stops monitoring exactly when memory is known to be a problem; and the live view needs a fixed-capacity ring, since a leak detector that leaks would be absurd. - Cost re-measured on a 233MB fragmented heap rather than idle, resolving the earlier caveat: 0.44us Bun and 0.65us Node, ratios 1.03x and 0.98x versus idle. Cost is independent of heap size and fragmentation, which is the property that matters because leak investigations run when the heap is large. One sample per 60s is around 1e-6 percent of wall time. Off switch: telemetry.perf.memory, independent of the telemetry.perf master, both defaulting off. Disabling omits the fields rather than writing zeros, because a zero is indistinguishable from a real measurement. Also settles the delivery shape rather than leaving it open, and records the two excluded fields with the reasoning so they are not reintroduced without new argument: contended is dropped because its ~10Hz probe would be about 1,820 wakeups/second at the observed 182-instance peak, materially contributing to the contention it measures - concurrent_instances carries the signal at no timer cost; records_dropped is meaningless without a bounded queue, and one record per operation through a serialized chain has no burst to absorb. operation_id is derived from the prompt-id prefix, keeping packages/agents free of a telemetry dependency. Refs #3167
TLDR
Planning documents only — no code, no behaviour change. Adds the design artifacts for #3167 (measuring llxprt's own performance, separately from provider latency) to
project-plans/issue3167/.Worth flagging for reviewers: two earlier revisions of this design were wrong and the corrections are recorded rather than quietly dropped. The headline model was algebraically invalid, and a storage scheme lost 49% of records under concurrency. The rejected approaches are documented in place so the reasoning is auditable.
Scope is one issue, one PR — that includes the memory-trend / leak-detection half, which is specified here rather than deferred.
Start with
decision.html(open in a browser) — it explains the whole thing in four diagrams.specification.mdis the binding contract;PLAN.mdhas the phases.Dive Deeper
The mistake that shaped the design
The first design derived "llxprt time" by subtracting provider and tool time from elapsed time. That cannot work.
ApiAttemptRecord.durationMsis the whole request wall duration and the entire interval enters the activity union — but during a streaming request we are decoding deltas and Ink is painting inside that interval. So the subtraction removes the very work it claims to measure, andcoreMs = llxprtMs − uiMscan go negative on an ordinary turn. Provider/tool figures are also sums while the residual used a union, so the three quantities were never a partition.Replaced by: directly measured client phases, provider/tool reported as explicitly overlapping
*_sum_msand*_union_ms, and the leftover namedunclassified_elapsed_msrather than assumed to be ours.What the documents settle
specification.md— the record schema (whichPLAN.mdhad listed as a task and never delivered), compatibility rules, package placement, reuse decisions, and the live-writer rule. Includes a verification appendix with line-level evidence for every load-bearing claim.telemetrysits belowcoreandagentshas no telemetry dependency. Sotelemetryowns the schema/sink/retention,coreowns only the stdout hook,cliowns the lifecycle and consumers, andagentsowns nothing.packages/telemetry/src/debug/FileOutput.tsalready implements most of the proposed writer. It also never deletes anything (verified: zerounlinkcalls), sollxprt-debug-*.jsonlgrows forever — the same unbounded-growth bug as Session cleanup is completely non-functional: 3.8 GB accumulates, 10k orphaned project dirs, 417 stale locks (five independent defects) #3164, in the package this feature would join.Memory trend is in scope, and adds no timers
Two axes, not one number. Absolute memory says nothing — a large context legitimately uses a lot of it. What is diagnostic is what the growth tracks: growth per operation that flattens while idle is normal; growth per minute while idle is a leak, and is exactly the #3114 signature. Memory columns ride the operation record for the per-operation axis; a
record_type: "memory_sample"row carriesms_since_last_operationfor the per-minute axis. Slopes are derived at read time, never stored.external/arrayBuffersare first-class — that is where the mass hid under Bun/JSC in #3112.On not hurting the thing we're measuring:
useMemoryMonitoralready runs an unconditional 60 s interval callingprocess.memoryUsage().rss— the right cadence for an uptime slope. Extend it.Footer.tsx's 2 s interval is explicitly rejected as a host: it is gated onshowMemoryUsageand on being mounted, so telemetry hung off it would silently collect nothing depending on unrelated UI config.clearIntervals itself after warning once, so today it stops monitoring precisely when memory is known to be a problem; and the live view needs a fixed-capacity ring rather than a growing array, because a leak detector that leaks would be absurd.telemetry.perf.memory, separate from thetelemetry.perfmaster; both default off. Disabling omits the fields rather than writing zeros, because a zero is indistinguishable from a real measurement.Excluded, with reasons recorded
contendedis dropped: its ~10 Hz drift probe would be ≈1,820 wakeups/second machine-wide at the observed 182-instance peak, so the measurement would materially contribute to the contention it reports.concurrent_instancescarries that signal at zero timer cost.records_droppedis dropped: meaningless without a bounded queue, and one record per operation through a serialized write chain has no burst to absorb.operation_idis derived from the prompt-id prefix rather than plumbed throughpackages/agents, which keeps a measurement concern out of the agent loop — the deciding factor, given the verified dependency edges.Withdrawn claims, listed for transparency
The overhead budget (summed primitive costs, not end-to-end), the record-size and retention budgets (priced the rejected field set), the "load-invariant counters" claim (downgraded to covariates), and a "negative mtime age" finding that turned out to be an artifact of testing with
grace = 0, a configuration the design never uses.Still open
One process question: whether we produce the full
dev-docs/PLAN.mdphase structure (analysis/pseudocode/, numbered phase files) or record a deliberate deviation. Noted inspecification.md§9. Scope, schema, placement, delivery shape and memory are all settled.Reviewer Test Plan
No code to run. To review:
project-plans/issue3167/decision.htmlin a browser. §02 is why the original model was invalid; §04 is the component breakdown; §05 is the identity finding; §06 is placement.project-plans/issue3167/specification.md— particularly §1 (schema), §2 (compatibility rules), §7 (memory trend and its sampling/off-switch design) and §8 (claim verification, which cites exact lines so you can check the reasoning rather than take it on trust).grep -c 'unlink' packages/telemetry/src/debug/FileOutput.tsreturns 0;useSubmitQuery.ts:656shows theisCurrentTurnguard that makes a superseded turn never finalise; anduseMemoryMonitor.tsshows both the 60 s interval we intend to extend and theclearIntervalthat currently stops it.Guards run locally, all passing:
format:check,lint:doc-placement,lint:doc-links,lint:no-new-js,lint:copyright-year,lint:legacy-paths,lint:eslint-guard.Testing Matrix
Not applicable — documentation only, no runtime code paths touched.
Linked issues / bugs
This PR makes progress on #3167 — it adds the design and specification but implements none of it, so the issue stays open.
Related to #3164 (session cleanup non-functional): this design deliberately reacts to it — the perf log is global rather than under a project hash so it cannot become unreachable, and the
FileOutputfinding above is the same unbounded-growth class of bug.Related to #3130 (token-usage telemetry), which has landed: the perf record reuses its identity keys verbatim so the two logs and the session recordings join.