Server trace log volume makes it Defender's top scanned file on Windows and rotates history out in about two hours #28196

Activity

1. onlydole commented on Nov 3, 2026

   

   onlydole

   on Nov 3, 2026

   Contributor

   More actions

   Same two-hour window on macOS. These are bytes by span family from 113 MB of server.trace (all 11 files, 112 minutes) on 0.1.7-nightly.20261102.4093, macOS 27.2:

   Span family	Bytes	Share
   sqlite	28.5 MB	25%
   findRepositoryRoot + findPluginRepositoryRoot	15.1 MB	13%
   ThreadLiveEventCoalescer (flushPending, cancelWindow, offerAll)	9.2 MB	8%
   sql.transaction	5.6 MB	5%
   PortDiscovery (six span names)	5.5 MB	5%
   runGitCommand	2.9 MB	3%
   GitManager.rememberPrLookupGitState	2.2 MB	2%
   WorkspacePaths.resolveRelativePathWithinRoot	1.3 MB	1%

   A second capture on the same Mac later that day also covered 111 minutes.

   On another Mac, 63% of server.trace bytes (107 MB over 2 h 10 min) were otlp-span records forwarded from the web client (service.runtime: t3-web). Most had durationMs: 0. The top ones were EnvironmentThreadState.applyEventsLocked (5,711) and applyItems (5,673), then EnvironmentRegistry.getEntry, withLeaseLock and acquireSupervisor (4,456 each), and EnvironmentRpc.request, authorize and currentSession (3,877 each). The EnvironmentRegistry rows in your table come from packages/client-runtime too, so they are probably the same forwarding. #26511 stopped tracing unchanged platform registrations, but these spans are still sent.

   I opened #29757 (skill discovery resolves each repository root once) and #29758 (stop tracing per-event coalescer work) for two of the rows above.
2. onlydole commented on Nov 4, 2026

   

   onlydole

   on Nov 4, 2026

   Contributor

   More actions

   Update from the same Mac on today's 0.1.8 nightlies (macOS 27.2). The repo-root and coalescer rows from my table above are gone after #29757 and #29758. Retention is still short while agents are working. Two captures today covered 68 minutes at about 96 MB an hour, and 47 minutes at about 144 MB an hour.

   The 47-minute capture, per hour:

   Span family	Per hour	Share
   sqlite	43.9 MB	30%
   sql.transaction + BEGIN + COMMIT	23.2 MB	16%
   runGitCommand	6.7 MB	5%
   GitManager.rememberPrLookupGitState	5.8 MB	4%
   GitVcsDriver.readConfigValue	3.2 MB	2%
   PortDiscovery.*	1.8 MB	1%

   The SQL rows are 46% of the file. That's about 60k sqlite spans and 48k transaction spans an hour. db.query.text is only 28% of the sqlite span bytes, so the span count is the bigger lever.

   I opened #31147 for the rememberPrLookupGitState row.
3. yaacovcorcos commented on Nov 11, 2026

   

   yaacovcorcos

   on Nov 11, 2026

   Contributor

   More actions

   Where the SQL rows come from, from a T3-based desktop build at upstream 44ebb2f (Nov 10), macOS. 114 MB of server.trace.ndjson over 93 minutes with agent threads streaming:

   Source of sqlite / sql.transaction / BEGIN / COMMIT spans	Share of the file
   Shell stream reads: ws.orchestrationV2.projectShellItems → OrchestratorV2.getThreadShell	12%
   Provider batch commits: ProviderCommitBatch.flush → EventSink.providerBatch	11%
   Everything else	9%

   Shell stream reads. projectShellItems re-reads the changed threads' shells for every event batch (50 ms window) and for every shell subscriber, so open windows multiply it: getShellSnapshot({ threadIds }) when several threads changed, getThreadShell for one thread or when the batch read fails. In this capture almost all were the single-thread path (3,052 getThreadShell for 3,063 projectShellItems). ProjectionStore.getThreadShell walks the parent chain with one SELECT per ancestor, then up to five batch reads, inside a read transaction, and every statement gets a span; one getThreadShell plus one getShellSnapshot for a two-thread family wrote 19 spans in a test. Turning tracing off inside these reads, as EventSink.write does since #19430, is the obvious fix, but ProjectionStore.test.ts observes their SQL through spans (traceSqlStatements for shell query shape, traceSqlRouting for reader routing), so it needs a maintainer call on how those tests observe SQL.

   Provider batch commits. 57% of the 8,431 EventSink.providerBatch spans had event_count: 0 and still opened a writer transaction (sql.transaction → BEGIN → COMMIT). Snapshot work enters commit(work) (ProviderCommitBatch.ts) and withProviderBatch opens the transaction before routing and assistant-text filtering decide, inside the work, to hold or drop the snapshot (RunExecutionService.ts). Held text that only waits for an idle flush still pays for a transaction and its spans. Skipping on event_count === 0 after the fact isn't safe: held text can still allocate a turn item position, and writeWithEffects can enqueue outbox effects without events. It would need the hold/drop decision made, in ingestion order, before the transaction opens.

   Measured from the retained rotations with a span-name/parent-chain count; happy to share the script.
4. juliusmarminge

   added 2 commits that reference this issue on Nov 12, 2026

   fix(server): trace file skips every fast successful span

   ...

   This issue will close once commit 60a769a is merged into the 'main' branch.

   60a769a

   fix(server): trace file counts fast spans instead of dropping them

   ...

   This issue will close once commit 8ea6102 is merged into the 'main' branch.

   8ea6102