Skip to content

perf(logging): move local trace and provider log writes off the event loop - #19303

Closed
daniyal-sh wants to merge 1 commit into
pingdotgg:mainfrom
daniyal-sh:perf/async-observability-writes-sol61
Closed

daniyal-sh wants to merge 1 commit into
pingdotgg:mainfrom
daniyal-sh:perf/async-observability-writes-sol61

Conversation

@daniyal-sh

Copy link
Copy Markdown
Contributor

Problem

Local trace and provider event logging append and rotate files synchronously on the server event loop. Batching still blocks unrelated work while Windows storage is slow. A two-minute Windows CPU capture sampled about 5,049 ms inside the synchronous append/write stack, and the same capture's server log recorded a 2.6-second event-loop warning.

Change

Add a shared asynchronous rotating sink with serialized writes and use it for both local trace and provider event logs. Trace producers enqueue a bounded next batch; excess pressure and failed writes drop trace records with bounded failure/recovery warnings. Provider logging preserves batching, per-thread ordering, attribution, and backpressure. Provider retention reads and removals are asynchronous too. Accepted writes finish before another flush rotates files or shutdown drains the scope.

Both producers require the same sink and shutdown ordering to remove the underlying synchronous local-observability I/O problem. The existing synchronous sink remains available to its other consumers. The internal performance note records the batching/async-I/O trap.

Scope and approval

Submitted as a focused fix for demonstrably blocking local observability I/O: the sink, its trace/provider consumers, their tests, and the relevant internal constraint. No new user-facing feature, telemetry endpoint, SQLite durability default, or logging setting is introduced. The focused obvious-defect exception is requested on that basis; no prior maintainer approval is claimed. This PR does not include reconnect hydration, asset fan-out, credential, Git, or preview-scanning changes.

Verification

  • vp test run packages/shared/src/logging.test.ts packages/shared/src/observability.test.ts apps/server/src/provider/EventNdjsonLogger.test.ts: 57 passed, 1 existing platform skip. Held-write tests prove unrelated fibers run while disk I/O is pending, the trace backlog stays bounded, and close drains accepted records. Tests also check concurrent append/rotation ordering, reopening, failed-append recovery, provider retention, and partial-write attribution.
  • Two 120-second, 1 ms sampled isolated-server captures: synchronous append/write stack samples 5,048.6 → 0 ms. The later event-loop sampler recorded no one-second windows over 500 ms (before: one). Startup/client activity differed on a shared machine; this is evidence of removal of the synchronous stack, not a controlled whole-app CPU percentage.
  • Warm-file benchmark, three interleaved runs per version, 7,680 records in 30 batches of 256 (~8 MB), 5 MB rotation/three backups: producer-call median 56.24 → 26.16 ms. Total wall median was 60.14 → 65.06 ms, so no disk-throughput improvement is claimed.
  • Raw measurements and caveats and CPU comparison. Timing baseline 107f6024, Windows/Node 24.19.0; submission based on 8b460a3c.
  • No live user database was opened read-write. Native Electron FPS and a complete inventory of OS-level stalls were not measured.

Post-rebase validation on this branch at 8b460a3c (Effect 4.0.4): 57 logging/trace/provider tests passed, one existing platform skip. vp run --filter t3 --filter @t3tools/shared --filter @t3tools/desktop typecheck, changed-file lint/format, and patch whitespace checks passed. Production server/desktop bundles and sandboxed preload verification passed on the original benchmark checkout with these fixes, before upstream's dependency upgrade.

Implemented and validated using GPT-6.1 Sol in T3 Code through the Codex harness.

@github-actions github-actions Bot added vouch:unvouched PR author is not yet trusted in the VOUCHED list. size:L 100-499 changed lines (additions + deletions). labels Oct 14, 2026
@macroscopeapp

macroscopeapp Bot commented Oct 14, 2026

Copy link
Copy Markdown
Contributor

Approvability

Verdict: Not approved

Macroscope's review found this PR not approvable — This PR changes existing production trace and provider-log behavior by introducing asynchronous rotation, bounded trace buffering with possible drops, and new shutdown/retention coordination. It also adds a line-level static-analysis diagnostic suppression, so the runtime and tooling changes warrant human review.

You can add or adjust custom eligibility rules. Learn more.

@coderabbitai

coderabbitai Bot commented Oct 14, 2026

Copy link
Copy Markdown

Review in Change Stack →

No actionable comments were generated in the recent review. 🎉

ℹ️ Recent review info
⚙️ Run configuration
  • Configuration used: Path: .coderabbit.config.ts
  • Review profile: CHILL
  • Plan: Advanced
  • Run ID: 06163069-3f95-44c5-9d35-0fd02362e9cc
📥 Commits

Reviewing files that changed from the base of the PR and between 8855a6d and 6fd1017.

📒 Files selected for processing: 7
  • apps/server/src/provider/EventNdjsonLogger.test.ts
  • apps/server/src/provider/EventNdjsonLogger.ts
  • docs/internals/performance-regressions.md
  • packages/shared/src/logging.test.ts
  • packages/shared/src/logging.ts
  • packages/shared/src/observability.test.ts
  • packages/shared/src/observability.ts

Included review availability: This review used your included allowance. Your plan provides up to 10 included reviews per hour; 5 remain after this review.

📝 Walkthrough

The shared logging package adds an asynchronous rotating file sink. The trace and provider event loggers use it for asynchronous writes. Trace buffering is bounded, while provider log writes retain backpressure.

Changes: Asynchronous logging

Layer / File(s) Summary
Shared rotating sink
packages/shared/src/logging.ts, packages/shared/src/logging.test.ts
Adds a filesystem-service-based sink that serializes writes, rotates files by size, prunes excess backups, and reports operation-specific failures. Tests cover concurrent writes, resuming a log, rotation, and recovery after a write failure.
Buffered trace writes
packages/shared/src/observability.ts, packages/shared/src/observability.test.ts, docs/internals/performance-regressions.md
Trace records are buffered with byte counts and dropped when buffer limits are reached. Flushes use the asynchronous sink. Tests cover bounded buffering, shutdown draining, and write failure recovery. The documentation describes trace logging behavior.
Provider event log writes
apps/server/src/provider/EventNdjsonLogger.ts, apps/server/src/provider/EventNdjsonLogger.test.ts
Provider log batching, sink creation, and retention operations use asynchronous filesystem operations. Tests cover partial-batch attribution and confirm that close waits for a pending write.

Priority: ➖ Normal

Estimated code review effort: 3 (Moderate) | ~25 minutes

Change: Bug fix

Sequence Diagram(s)

sequenceDiagram
  participant Producer as Trace producer
  participant TraceSink as makeTraceSink
  participant AsyncSink as Async rotating sink
  participant FileSystem
  Producer->>TraceSink: Push serialized record
  TraceSink->>TraceSink: Buffer record and request flush
  TraceSink->>AsyncSink: Write flushed batch
  AsyncSink->>FileSystem: Append or rotate files
Loading

Suggested reviewers: juliusmarminge

Merge Risk: ⚪ Minimal · up to 6fd10

No actionable logging or shutdown issue remains from this review; the PR is mergeable after normal checks.

Security architecture risk: 🔵 Low · up to 6fd10

The change is confined to local logging and preserves provider ordering and failure containment. No introduced security vulnerability was established. Trace logging remains best-effort, and complete shutdown draining depends on producers stopping before the final flush.

Retained concerns
No architecture-level concerns identified.

Security review details

Security Blast Radius

  • inferred — The demonstrated exposure is local log files and diagnostic availability within the existing server and desktop processes. The inspected change does not establish new cross-service reachability, credentials, or privileged execution.

Trust Boundaries and Controls

  • observed — Trace pressure is contained by byte and record caps plus a single sliding flush-request slot. Provider pressure is handled through synchronized buffering and awaited flushing. These are resource-containment controls, not guarantees of durable audit evidence.

Resilience and Maintainability Implications

  • inferred — Trace close waits for serialized writes but drains only the batch captured by its flush. Producers can refill the buffer during asynchronous I/O, so terminal draining requires producer quiescence. The flush-only API predates this PR, but the asynchronous interleaving window is new. Actual shutdown loss was not established, and the slow-write test demonstrates pressure loss rather than pushes during the closing flush.

Hardening Proposals

  • proposed — If terminal trace draining is required, explicitly define producer quiescence as a close precondition or coordinate admission with a closed state. This would strengthen the best-effort lifecycle contract; it is not a verified security finding.
Pre-merge checks: Passed 4
Passed Passed checks: 4 passed
Check name Status Explanation
Title check Passed The title clearly and concisely describes the main change: moving local trace and provider log writes off the event loop.
Description check Passed The description includes all required sections. It explains the problem, change, scope rationale, focused verification, observed results, limitations, and tool usage.
Linked Issues check Passed Check skipped because no linked issues were found for this pull request.
Out of Scope Changes check Passed Check skipped because no linked issues were found for this pull request.
✨ Finishing Touches
🧪 Generate unit tests (beta)
  • Create a new PR
  • Autofix · Keep fixing CodeRabbit findings and required CI, and resolving merge conflicts

Comment @coderabbitai help to get the list of available commands.

AdEx-Partners-DE added a commit to AdEx-Partners-DE/t3code that referenced this pull request Oct 14, 2026
… loop (adopts upstream pingdotgg#19303)

Own diff of pingdotgg#19303 at 6fd1017 against its merge base.
logging.test.ts and observability.test.ts: 34 passed before, 37 after;
EventNdjsonLogger.test.ts: 19 passed before, 20 after; tsc clean in
apps/server and packages/shared.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@juliusmarminge

Copy link
Copy Markdown
Member

Note

Grok responding on behalf of Julius.

Superseded by #19430, which combines and finishes this work. Closing in favor of that PR.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size:L 100-499 changed lines (additions + deletions). vouch:unvouched PR author is not yet trusted in the VOUCHED list.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants