Skip to content

agentHost: batch AHP log writes and skip URI deep clone#318864

Merged
roblourens merged 2 commits into
mainfrom
agents/analyze-these-traces-find-out-what-s-slow-ba324980
May 29, 2026
Merged

agentHost: batch AHP log writes and skip URI deep clone#318864
roblourens merged 2 commits into
mainfrom
agents/analyze-these-traces-find-out-what-s-slow-ba324980

Conversation

@roblourens
Copy link
Copy Markdown
Member

Two perf fixes for AhpJsonlLogger, the per-message JSONL transport logger used by AHP-based agent host connections.

Why

CPU traces of the agents window under heavy AHP traffic showed ~23% of wall time in MajorGC (3.3 s of a 14.16 s trace) on the sessions/agents renderer. The hot stack was:

VSBuffer.set / concat
 FileService.writeFile
 AhpJsonlLogger._appendLine

main writeFile IPC. Each call allocated a fresh VSBuffer, marshalled it through the IPC channel proxy, and got a reply buffer back. With sustained rates of 1300 messages/s the GC simply couldn't keep up.500

A second cost was _replaceUris, which deep-cloned every JSON-RPC message before JSON.stringify so it could rewrite URI instances to once per log line.strings

What changed

1. Batched writes via natural backpressure. log() now appends to a _pending: VSBuffer[] and schedules a single drain on the write queue. While a writeFile is in flight, all subsequent log calls accumulate and land in the next drain via VSBuffer. capped at 1 MiB per write so the concat itself doesn't create new GC pressure. Rotation is still checked per-entry inside the batch. flush()and ordering semantics are preserved via a_drainScheduledinvariant: pending entries always have a drain on the queue, soawait this._queue is sufficient. **Zero added batching only happens when writes are already backed up.latency** concat

2. Replaced _replaceUris deep clone with a JSON.stringify replacer. URI.prototype.toJSON() already stamps its output with $mid: MarshalledId.Uri. The new replacer detects that marker (guarded by isUriComponents to avoid false positives on user payloads that happen to carry $mid: 1) and rewrites to the canonical URI string via URI.revive(...).toString(). The previous comment in the code warned against using a replacer because toJSON runs but that's actually what makes this approach work: we use the post-toJSON marker as our signal.first

Tests

Added 7 tests on top of the existing 2:

  • Coalescence: 50 sync log() calls produce all 50 lines in order but far fewer writes
  • Flush ordering across interleaved log/flush/log calls
  • URI replacer: top-level URI, nested in arrays/objects, raw UriComponents from a prior toJSON(), URI-shaped objects without $mid (left alone), and $mid: 1 on a non-UriComponents payload (left alone)

All 10 AhpJsonlLogger tests pass and the existing localAhpJsonlLogging tests are unaffected.

Notes for reviewers

emit) with no application-level handlers above, which suggests the inbound load is mostly *replies* to outbound requests rather than a stream of notifications. Identifying the producer would benefit from per-method counters in AhpJsonlLogger.log`.

  • The 1 MiB batch cap and the per-entry rotation check are a single oversized message can still rotate mid-batch, matching previous behavior.independent

(Written by Copilot)

Two perf fixes for AhpJsonlLogger, the per-message JSONL transport
logger. CPU traces of the agents window under heavy AHP traffic showed
~23% of wall time in MajorGC, dominated by VSBuffer allocations from
renderer-side writeFile IPCs and the recursive _replaceUris deep clone
applied to every message before JSON.stringify.

- log() now appends to a pending buffer list and schedules a single
  drain on the write queue. While a writeFile is in flight, all
  subsequent log() calls accumulate and land in the next drain via
  VSBuffer.concat, capped at 1 MiB per write. Rotation is still
  checked per entry, and flush()/ordering semantics are preserved
  via a _drainScheduled invariant.
- stringifyAhpLogEntry() now uses a JSON.stringify replacer instead
  of a tree-walking deep clone. URI.toJSON() stamps the output with
  $mid: MarshalledId.Uri, which the replacer detects (guarded by
  isUriComponents) and rewrites to the canonical URI string. This
  removes per-message allocation of a clone of the entire message
  payload.

Adds tests for batching, flush ordering across drains, and URI
replacer edge cases (nested URIs, raw UriComponents from prior
toJSON, URI-shaped objects without $mid, and non-URI objects that
happen to carry $mid: 1).

(Written by Copilot)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Copilot AI review requested due to automatic review settings May 28, 2026 22:53
Copy link
Copy Markdown
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR improves AhpJsonlLogger performance for high-volume Agent Host Protocol traffic by reducing per-message write overhead and avoiding a full deep clone for URI serialization.

Changes:

  • Batches pending JSONL log buffers into capped writes while preserving ordering and rotation behavior.
  • Replaces URI deep-cloning with a JSON.stringify replacer that detects marshalled URI components.
  • Adds tests for batching, flush ordering, and URI serialization behavior.
Show a summary per file
File Description
src/vs/platform/agentHost/common/ahpJsonlLogger.ts Implements batched writes and URI-aware JSON serialization.
src/vs/platform/agentHost/test/common/ahpJsonlLogger.test.ts Adds coverage for batching, flush ordering, and URI stringification cases.

Copilot's findings

  • Files reviewed: 2/2 changed files
  • Comments generated: 1

Comment thread src/vs/platform/agentHost/test/common/ahpJsonlLogger.test.ts Outdated
Addresses review feedback: the previous `writeCount < messageCount`
assertion would pass even with a near-pathological 49-writes-for-50-logs
regression. All 50 log() calls are queued synchronously and must land in
the very first drain, so assert writeCount === 1.

(Written by Copilot)

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@roblourens roblourens marked this pull request as ready for review May 29, 2026 02:05
@roblourens roblourens enabled auto-merge (squash) May 29, 2026 02:05
@roblourens roblourens merged commit 5dcafbd into main May 29, 2026
39 of 40 checks passed
@roblourens roblourens deleted the agents/analyze-these-traces-find-out-what-s-slow-ba324980 branch May 29, 2026 18:32
@vs-code-engineering vs-code-engineering Bot added this to the 1.123.0 milestone May 29, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants