fix(performance): count one transcript read per history load and measure the conversations catalog

docs/plans/2026-09-26-monitor-transcript-operations.md

@@ -0,0 +1,32 @@
+# Measure transcript and catalog work before moving it off the main thread (#769, first step)
+
+## Problem
+#769 asks to move history loads (and the since-replaced session index) off the main thread. A re-check on origin/main `b3a2c481` (comment on #769) found that every transcript read and parse still runs on main. But the recordings cannot say whether that work is what stalls main:
+- **Few slow reads:** 2,436 `transcript.read` samples across all monitor runs, only 3 slow-operation incidents (1.0 s, 1.3 s, 1.8 s).
+- **No link to stalls:** 14 `main-stall` incidents, none within 10 s of a slow read. Main-stall incidents carry no operation attribution.
+- **Double sample:** each IPC initial history load records `transcript.read` twice. `loadInitialHistoryChunk` opens a span, ends it after path resolution (`result: 'delegated'`), then `loadInitialHistoryChunkFromFile` opens a second span with the same name for the real read. Half the samples measure path resolution only, which skews the percentiles low.
+- **Blind spot:** the conversations catalog is invisible to the monitor. `sessionIndex.extractPrompts` (a synchronous parse over windows of up to 16 MiB), catalog search's prompt gathering (up to 150 rows), and discovery have no monitor operation.
+
+## Decisions (defaults)
+- **The path-resolution span gets its own name,** `historyLoader.resolveInitialPath`. It stays in the perf journal and is not a monitor operation, so each initial load records exactly one `transcript.read`.
+- **Three monitor operations** join the finite vocabulary:
+  - `conversations.discover`: the existing `conversations.discover` span.
+  - `conversations.extract`: the existing `sessionIndex.extractPrompts` span.
+  - `conversations.search`: a new span around search's prompt gathering.
+- **Slow-operation thresholds:** extract 250 ms (one file's synchronous parse), search 1000 ms, discover 2000 ms. Picked like the existing ones: a user-visible delay, not a precise budget.
+- **No worker yet.** Moving work to a worker waits until the data says which path stalls main.
+
+## Tests
+- **History loader:** one initial load through `loadInitialHistoryChunk` records exactly one `transcript.read` (red on main: two).
+- **Catalog:** a search with a query records `conversations.search`, and an extract records `conversations.extract`, driven on the recorded conversations corpus.
+
+## Round 1 review decisions (#1352)
+- **a1: a discovery that rejects left its span open.** It became a `timeout` sample at the sweep. The earlier call that discovery "cannot fail" was wrong: family resolution rejects a malformed cwd. The span now closes with `fail(error)`. Test added; red before.
+- **a2: the vocabulary outgrew the histogram cap.** 26 operations × 4 outcomes is 104 pairs, but the aggregator, the snapshot parser and the history store each hard-coded 100. One derived constant, `MAX_MONITOR_OPERATION_PAIRS`, now serves all three. Test: every legal pair is stored and the snapshot parses. Red before.
+- **a3, b1, c2: no test pinned the three new thresholds.** Each now gets a sample just above (a named slow-operation incident) and just below (none).
+- **c1: discovery's 2000 ms threshold sat above main-stall's 1000 ms band.** A 1.5 s discovery stall raised no named incident, so discovery and search are now both 1000 ms.
+- **b2: the extraction assertion ignored whether prompts came back.** It now requires at least one prompt.
+- **c3: the load-time test counted samples but not which span.** With the resolver taking 80 ms, the single sample must be shorter than that, so it timed the read, not the lookup. Mapping the lookup span instead fails it.
+- **Declined:**
+  - b3 and c5, the corpus-install `beforeAll` timing out under heavy load: the hook predates this PR and CI runs it. Timeouts are never widened.
+  - c4, a 60 s cooldown slot per scope shared by all main-scope slow operations: pre-existing semantics, outside this PR.

src/main/conversations/service.system.test.ts

@@ -6,6 +6,7 @@ import { ClaudeConversationSource } from './sources/claude.js'
 import { CodexConversationSource } from './sources/codex.js'
 import { OpencodeConversationSource } from './sources/opencode.js'
 import { ConversationService } from './service.js'
+import { setMainOperationSink } from '@main/performance/operations.js'
 import { corpusWorktreesPorcelain, installConversationCorpus, type InstalledCorpus } from '../../../testing/support/conversations/installCorpus.js'
 
 // One corpus install per file: the install copies 450 files and costs more
@@ -67,4 +68,44 @@ describe('ConversationService', () => {
     expect(second.rows.map(r => r.nativeId)).toEqual(first.rows.map(r => r.nativeId))
     expect(s.discoveriesForTests()).toBe(1)
   })
+
+  // #769 (measure first): the catalog's discovery, search and per-file prompt
+  // extraction had no monitor boundary, so nothing could tell whether they
+  // are what stalls main. Driven on the recorded corpus.
+  it('records discovery, search and prompt extraction as monitor operations', async () => {
+    const operations: Array<{ name: string; outcome: string }> = []
+    setMainOperationSink(record => { operations.push(record) })
+    try {
+      const s = service()
+      const all = await s.list({ cwd: '/fixture/repo', scope: 'repository', includeChildren: true, limit: 5000 })
+      const codex = all.rows.find(r => r.provider === 'codex' && r.cwd)!
+      // #1352 review b: the extraction measured must be a real one.
+      expect((await s.prompts({ provider: 'codex', nativeId: codex.nativeId, cwd: codex.cwd! })).length).toBeGreaterThan(0)
+      await s.list({ cwd: '/fixture/repo', scope: 'repository', query: 'the', limit: 50 })
+    } finally {
+      setMainOperationSink(() => {})
+    }
+    const names = new Set(operations.map(op => op.name))
+    expect(names).toContain('conversations.discover')
+    expect(names).toContain('conversations.search')
+    expect(names).toContain('conversations.extract')
+  })
+
+  // #1352 review a: a discovery that rejects closes its span as an error,
+  // instead of leaving it pending until the sweep reports a timeout.
+  it('closes a failed discovery as an error, not a pending span', async () => {
+    const { mainOperations } = await import('@main/performance/operations.js')
+    const operations: Array<{ name: string; outcome: string }> = []
+    setMainOperationSink(record => { operations.push(record) })
+    const pendingBefore = mainOperations.size
+    try {
+      const failing = new ConversationService({ sources: [], ledger: null, listWorktrees: async () => [], claudeHistory: null })
+      await expect(failing.list({ cwd: null, scope: 'repository', limit: 1 } as never)).rejects.toThrow()
+    } finally {
+      setMainOperationSink(() => {})
+    }
+    expect(operations.filter(op => op.name === 'conversations.discover').map(op => op.outcome)).toEqual(['error'])
+    expect(mainOperations.size).toBe(pendingBefore)
+  })
 })
+

src/main/conversations/service.ts

@@ -99,6 +99,14 @@ export class ConversationService {
         this.discoveries++
         span.end({ rows: discovery.sources.length })
         return discovery
+      } catch (error) {
+        // #1352 review a: family resolution can reject (a malformed cwd from a
+        // future caller; IPC validates it first today). Left open, the span
+        // became a `timeout` sample at the ten-minute sweep and could raise a
+        // slow-operation incident blaming discovery for a stall it never
+        // caused. Close it as the error it is.
+        span.fail(error)
+        throw error
       } finally {
         // Only one flight per key can exist (identical keys coalesce above),
         // so clearing by key is clearing this flight.
@@ -118,6 +126,21 @@ export class ConversationService {
   }
 
   private async promptTextsFor(rows: readonly Conversation[]): Promise<Map<string, string[]>> {
+    // Search's prompt gathering is the catalog's widest synchronous parse
+    // (up to SEARCH_PROMPT_ROWS rows of extraction on main), so it is a
+    // monitor boundary of its own (#769).
+    const span = performanceService.span('conversations.search', { rows: rows.length })
+    try {
+      const out = await this.gatherPromptTexts(rows)
+      span.end({ rows: out.size })
+      return out
+    } catch (error) {
+      span.fail(error)
+      throw error
+    }
+  }
+
+  private async gatherPromptTexts(rows: readonly Conversation[]): Promise<Map<string, string[]>> {
     const out = new Map<string, string[]>()
     const candidates = [...rows].sort((a, b) => b.lastUserActivityAt - a.lastUserActivityAt).slice(0, SEARCH_PROMPT_ROWS)
     await Promise.all(candidates.map(async row => {

src/main/performance/IncidentEngine.test.ts

@@ -133,4 +133,23 @@ describe('incident evidence and exclusion rules', () => {
     engine.loss(901, 0, 2000)
     expect(engine.summaries()[0]!.truncated).toBe(true)
   })
+
+  // #1352 reviews a, b, c: the three catalog thresholds are the point of the
+  // PR, and moving any of them left every test green. Each gets a sample just
+  // above (a named slow-operation incident) and just below (none). The
+  // "above" sample sits exactly AT the threshold (the rule is >=), so moving
+  // a threshold up by even 1 ms fails (#1352 verification b).
+  it.each([
+    ['conversations.extract', 250],
+    ['conversations.search', 1000],
+    ['conversations.discover', 1000],
+  ] as const)('raises a slow-operation incident for %s from %i ms', (name, threshold) => {
+    const above = new IncidentEngine()
+    above.accept([{ kind: 'operation', at: 1000, windowId: null, sample: { kind: 'operation', name, durationMs: threshold, outcome: 'success' } }], 1000, 1000)
+    expect(above.summaries().map(row => [row.rule, row.operation])).toEqual([['slow-operation', name]])
+    const below = new IncidentEngine()
+    below.accept([{ kind: 'operation', at: 1000, windowId: null, sample: { kind: 'operation', name, durationMs: threshold - 1, outcome: 'success' } }], 1000, 1000)
+    expect(below.summaries()).toEqual([])
+  })
 })
+

src/main/performance/IncidentEngine.ts

@@ -8,6 +8,12 @@ const operationThresholds: Partial<Record<MonitorOperationName, number>> = {
   'transcript.read': 1000, 'transcript.parse': 100, 'transcript.fold': 100,
   'transcript.commit': 100, 'terminal.write': 250, 'persistence.serialize': 100,
   'persistence.write': 2000, 'worktree.refresh': 5000,
+  // One file's synchronous extraction, then a search's prompt gathering and a
+  // full discovery pass (#769). Search and discovery sit AT the main-stall
+  // band (loopMax >= 1000 ms), not above it (#1352 review c): above it, a
+  // discovery that stalled main for 1.5 s raised a main-stall with no named
+  // operation incident, which is the attribution this vocabulary exists for.
+  'conversations.extract': 250, 'conversations.search': 1000, 'conversations.discover': 1000,
 }
 // Each capture retains at most 160 evidence points. Eight simultaneous scopes
 // bound post-trigger memory to ~1.3k points even during an app-wide storm,

src/main/performance/MonitorAggregator.test.ts

@@ -17,4 +17,24 @@ describe('worker evidence bounds', () => {
     expect(JSON.stringify(snapshot)).not.toContain('session-')
     expect(aggregator.snapshot(11000 * 1000, 100).recent).toEqual([])
   })
+
+  // #1352 review a: every legal (operation, outcome) pair must fit. The
+  // aggregator, the snapshot parser and the history store each capped at a
+  // literal 100, and 26 operations x 4 outcomes = 104 silently lost the last
+  // four pairs.
+  it('keeps a histogram for every legal operation and outcome, and the snapshot parses', async () => {
+    const { MONITOR_OPERATIONS, MONITOR_OUTCOMES } = await import('@shared/performance/monitorPolicy.js')
+    const { parseMonitorSnapshot } = await import('@shared/performance/parseMonitorSnapshot.js')
+    const aggregator = new MonitorAggregator()
+    for (const name of MONITOR_OPERATIONS) {
+      for (const outcome of MONITOR_OUTCOMES) {
+        aggregator.accept([{ kind: 'operation', at: 1000, windowId: null, sample: { kind: 'operation', name, outcome, durationMs: 5 } }])
+      }
+    }
+    const snapshot = aggregator.snapshot(2000, 100)
+    expect(snapshot.operations).toHaveLength(MONITOR_OPERATIONS.length * MONITOR_OUTCOMES.length)
+    expect(snapshot.operations.map(entry => `${entry.name}:${entry.outcome}`)).toContain('heap.snapshot:timeout')
+    expect(parseMonitorSnapshot(JSON.parse(JSON.stringify(snapshot)))).not.toBeNull()
+  })
 })
+

src/main/performance/MonitorAggregator.ts

@@ -1,6 +1,6 @@
 import { BoundedQueue } from '@shared/performance/boundedQueue.js'
 import { LatencyHistogram } from '@shared/performance/latencyHistogram.js'
-import { MONITOR_POLICY } from '@shared/performance/monitorPolicy.js'
+import { MAX_MONITOR_OPERATION_PAIRS, MONITOR_POLICY } from '@shared/performance/monitorPolicy.js'
 import type { MonitorEnvelope, MonitorMainSample, MonitorWindowSample, MonitorOperationSummary, MonitorWorkerSnapshot } from '@shared/performance/monitorSnapshot.js'
 
 /** Worker-owned evidence. Every cardinality is bounded independently of run length. */
@@ -30,7 +30,7 @@ export class MonitorAggregator {
           const { name, outcome, durationMs } = record.sample
           const key = `${name}:${outcome}`
           let entry = this.operations.get(key)
-          if (!entry && this.operations.size < 100) {
+          if (!entry && this.operations.size < MAX_MONITOR_OPERATION_PAIRS) {
             entry = { summary: { name, outcome }, histogram: new LatencyHistogram() }
             this.operations.set(key, entry)
           }

src/main/performance/MonitorHistoryStore.test.ts

@@ -54,6 +54,29 @@ describe('bounded local performance history', () => {
     expect((await store.query(20_000, 20_000, undefined, 7)).points).toHaveLength(1)
   })
 
+  // #1352 verification b: the store's persistence slice is the third place
+  // that capped operation histograms at a literal 100 (26 operations x 4
+  // outcomes = 104). The aggregator test cannot see this path; only the
+  // saved operations.json shows whether every legal pair reaches history.
+  it('persists a histogram for every legal operation and outcome', async () => {
+    const { MONITOR_OPERATIONS, MONITOR_OUTCOMES } = await import('@shared/performance/monitorPolicy.js')
+    const { MonitorAggregator } = await import('./MonitorAggregator.js')
+    const aggregator = new MonitorAggregator()
+    for (const name of MONITOR_OPERATIONS) {
+      for (const outcome of MONITOR_OUTCOMES) {
+        aggregator.accept([{ kind: 'operation', at: 1000, windowId: null, sample: { kind: 'operation', name, outcome, durationMs: 5 } }])
+      }
+    }
+    const root = await mkdtemp(join(tmpdir(), 'agent-code-monitor-'))
+    roots.push(root)
+    const store = new MonitorHistoryStore(root, 'run-ops', () => 2000)
+    store.record({ ...snapshot(2000), operations: aggregator.snapshot(2000, 100).operations }, null, null, 0, 0)
+    await store.settled()
+    const saved = JSON.parse(await readFile(join(root, 'runs', 'run-ops', 'operations.json'), 'utf8')) as Array<{ name: string; outcome: string }>
+    expect(saved).toHaveLength(MONITOR_OPERATIONS.length * MONITOR_OUTCOMES.length)
+    expect(saved.map(entry => `${entry.name}:${entry.outcome}`)).toContain('heap.snapshot:timeout')
+  })
+
   it('keeps an existing destination intact when report creation fails', async () => {
     const root = await mkdtemp(join(tmpdir(), 'agent-code-monitor-'))
     roots.push(root)

src/main/performance/MonitorHistoryStore.ts

@@ -8,7 +8,7 @@ import type { MonitorIncident } from '@shared/performance/monitorIncidents.js'
 import { parseMonitorIncident } from '@shared/performance/parseMonitorIncident.js'
 import { parseMonitorHistoryPoint } from '@shared/performance/parseMonitorHistory.js'
 import { parseMonitorSnapshot } from '@shared/performance/parseMonitorSnapshot.js'
-import { MONITOR_POLICY } from '@shared/performance/monitorPolicy.js'
+import { MAX_MONITOR_OPERATION_PAIRS, MONITOR_POLICY } from '@shared/performance/monitorPolicy.js'
 import type {
   MonitorHistoryPage, MonitorHistoryPoint, MonitorHistoryResolution,
   MonitorHistoryStatus, MonitorReportPreview, MonitorReportResult,
@@ -121,7 +121,7 @@ export class MonitorHistoryStore {
     // fingerprint; stringifying up to fifty full evidence sets here every
     // second cost ~1 MiB of JSON per second of helper CPU for no new data.
     if (incidents) this.pendingIncidents = incidents.slice(-INCIDENT_LIMIT)
-    const operationJson = JSON.stringify(snapshot.operations.slice(0, 100))
+    const operationJson = JSON.stringify(snapshot.operations.slice(0, MAX_MONITOR_OPERATION_PAIRS))
     if (operationJson !== this.operationFingerprint) {
       this.operationFingerprint = operationJson
       this.pendingOperations = operationJson

src/main/sessions/historyLoader.monitor.test.ts

@@ -0,0 +1,36 @@
+import { join } from 'node:path'
+
+import { afterEach, expect, it, vi } from 'vitest'
+
+// #769 (measure first): each IPC initial history load recorded
+// `transcript.read` TWICE. The outer span ended after path resolution
+// ("delegated") and the file read opened a second span with the same name,
+// so half the monitor's samples timed only the path lookup and the
+// percentiles read low. One load must be one sample.
+const fixture = join(
+  import.meta.dirname,
+  '../../../testing/fixtures/conversations/claude/projects/-fixture-repo--worktrees-feat-api-key-vault/fc475787-6395-4cda-8bd2-1faacaa18bc7.jsonl',
+)
+// The resolver takes a measurable 80 ms, so the one sample can be checked to
+// time the READ, not the path lookup (#1352 review c: a count alone passed
+// when the lookup span was mapped instead of the read span).
+const RESOLVE_MS = 80
+vi.mock('@main/providerSwitch/shared.js', () => ({
+  resolveProviderTranscriptPath: vi.fn(async () => { await new Promise(resolve => setTimeout(resolve, RESOLVE_MS)); return fixture }),
+}))
+vi.mock('@providers/registry.main.js', () => ({ getMainProvider: () => ({}) }))
+
+const { setMainOperationSink } = await import('@main/performance/operations.js')
+const { loadInitialHistoryChunk } = await import('./historyLoader.js')
+
+afterEach(() => setMainOperationSink(() => {}))
+
+it('records one transcript.read per initial history load', async () => {
+  const operations: Array<{ name: string; durationMs?: number }> = []
+  setMainOperationSink(record => { operations.push(record) })
+  const chunk = await loadInitialHistoryChunk({ kind: 'claude', cwd: '/fixture/repo', providerSessionId: 'fc475787-6395-4cda-8bd2-1faacaa18bc7', limit: 20 } as never)
+  expect(chunk.entries.length).toBeGreaterThan(0)
+  const reads = operations.filter(op => op.name === 'transcript.read') as Array<{ name: string; durationMs: number }>
+  expect(reads).toHaveLength(1)
+  expect(reads[0]!.durationMs).toBeLessThan(RESOLVE_MS)
+})

src/main/sessions/historyLoader.ts

@@ -792,7 +792,12 @@ export async function loadInitialHistoryChunk(
       providerSource({ cwd: params.cwd, providerSessionId: params.providerSessionId, limit: params.limit }),
     )
   }
-  const span = performanceService.span('historyLoader.loadInitialChunk', {
+  // WHY its own name (#769): this span ends once the path is resolved, and
+  // loadInitialHistoryChunkFromFile opens the span that times the read. Under
+  // the same name the monitor counted every load twice, half of them timing
+  // only the path lookup, which pulled transcript.read's percentiles down.
+  // This one stays in the perf journal and is not a monitor operation.
+  const span = performanceService.span('historyLoader.resolveInitialPath', {
     kind: params.kind,
     limit: params.limit,
   })