From f6a576d09c69a659f6e938564fe068fcc2b4c54e Mon Sep 17 00:00:00 2001 From: Neil <4138956+nwparker@users.noreply.github.com> Date: Sun, 7 Jun 2026 10:36:26 -0700 Subject: [PATCH] Measure renderer terminal backlog pressure (#4809) --- .../summarize-terminal-perf-report.mjs | 6 ++ .../pane-terminal-output-scheduler.test.ts | 57 +++++++++++++- .../pane-terminal-output-scheduler.ts | 77 ++++++++++++++++++- .../artificial-opencode-terminal-load.spec.ts | 8 +- 4 files changed, 142 insertions(+), 6 deletions(-) diff --git a/config/scripts/summarize-terminal-perf-report.mjs b/config/scripts/summarize-terminal-perf-report.mjs index 743c97bf5..04a80d81d 100644 --- a/config/scripts/summarize-terminal-perf-report.mjs +++ b/config/scripts/summarize-terminal-perf-report.mjs @@ -82,6 +82,12 @@ function printMarkdownTable(rows) { ['Foreground Enqueues', 'deferredForegroundEnqueue'], ['Foreground Writes', 'deferredForegroundWrite'], ['Drains', 'scheduledDrains'], + ['Renderer Queued Terms', 'rendererQueuedTerminals'], + ['Renderer Queued Chars', 'rendererQueuedChars'], + ['Renderer Peak Terms', 'rendererPeakQueuedTerminals'], + ['Renderer Peak Chars', 'rendererPeakQueuedChars'], + ['Renderer Peak By Term', 'rendererPeakQueuedCharsByTerminal'], + ['Renderer Drops', 'rendererDroppedBacklogs'], ['Main Pending PTYs', 'mainPendingPtys'], ['Main Pending Chars', 'mainPendingChars'], ['Main Max Pending', 'mainMaxPendingChars'], diff --git a/src/renderer/src/lib/pane-manager/pane-terminal-output-scheduler.test.ts b/src/renderer/src/lib/pane-manager/pane-terminal-output-scheduler.test.ts index 4d153e007..dbc9fef97 100644 --- a/src/renderer/src/lib/pane-manager/pane-terminal-output-scheduler.test.ts +++ b/src/renderer/src/lib/pane-manager/pane-terminal-output-scheduler.test.ts @@ -1,5 +1,9 @@ /* eslint-disable max-lines -- Why: the scheduler tests cover one queue state machine; keeping ordering and overflow cases together makes regressions easier to audit. */ -import { afterEach, describe, expect, it, vi } from 'vitest' +import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' + +vi.mock('@/lib/e2e-config', () => ({ + e2eConfig: { exposeStore: true } +})) function createTerminal() { const classes = new Set() @@ -45,8 +49,15 @@ async function loadScheduler() { } describe('pane terminal output scheduler', () => { + beforeEach(() => { + vi.stubGlobal('window', globalThis) + }) + afterEach(() => { vi.useRealTimers() + delete (globalThis as { __terminalOutputSchedulerDebug?: unknown }) + .__terminalOutputSchedulerDebug + vi.unstubAllGlobals() }) it('writes foreground output immediately', async () => { @@ -663,6 +674,50 @@ describe('pane terminal output scheduler', () => { expect(terminals[0].write).toHaveBeenCalledTimes(2) }) + it('reports current and peak queued renderer backlog in debug snapshots', async () => { + vi.useFakeTimers() + const { writeTerminalOutput } = await loadScheduler() + const terminalA = createTerminal() + const terminalB = createTerminal() + const debug = ( + window as unknown as { + __terminalOutputSchedulerDebug?: { + snapshot: () => { + queuedTerminalCount: number + queuedChars: number + peakQueuedTerminalCount: number + peakQueuedChars: number + peakQueuedCharsByTerminal: number + droppedBacklogCount: number + } + } + } + ).__terminalOutputSchedulerDebug + + writeTerminalOutput(terminalA, 'a'.repeat(10), { foreground: false }) + writeTerminalOutput(terminalB, 'b'.repeat(20), { foreground: false }) + + expect(debug?.snapshot()).toMatchObject({ + queuedTerminalCount: 2, + queuedChars: 30, + peakQueuedTerminalCount: 2, + peakQueuedChars: 30, + peakQueuedCharsByTerminal: 20, + droppedBacklogCount: 0 + }) + + vi.advanceTimersByTime(50) + + expect(debug?.snapshot()).toMatchObject({ + queuedTerminalCount: 0, + queuedChars: 0, + peakQueuedTerminalCount: 2, + peakQueuedChars: 30, + peakQueuedCharsByTerminal: 20, + droppedBacklogCount: 0 + }) + }) + it('keeps draining background chunks without per-write parse callback backpressure', async () => { vi.useFakeTimers() const { writeTerminalOutput } = await loadScheduler() diff --git a/src/renderer/src/lib/pane-manager/pane-terminal-output-scheduler.ts b/src/renderer/src/lib/pane-manager/pane-terminal-output-scheduler.ts index 832ca7561..506f24300 100644 --- a/src/renderer/src/lib/pane-manager/pane-terminal-output-scheduler.ts +++ b/src/renderer/src/lib/pane-manager/pane-terminal-output-scheduler.ts @@ -105,6 +105,12 @@ type TerminalOutputSchedulerDebugSnapshot = { deferredForegroundWriteCount: number flushWriteCount: number scheduledDrainCount: number + queuedTerminalCount: number + queuedChars: number + peakQueuedTerminalCount: number + peakQueuedChars: number + peakQueuedCharsByTerminal: number + droppedBacklogCount: number drainWrites: number[] } @@ -121,6 +127,12 @@ const debugState: TerminalOutputSchedulerDebugSnapshot = { deferredForegroundWriteCount: 0, flushWriteCount: 0, scheduledDrainCount: 0, + queuedTerminalCount: 0, + queuedChars: 0, + peakQueuedTerminalCount: 0, + peakQueuedChars: 0, + peakQueuedCharsByTerminal: 0, + droppedBacklogCount: 0, drainWrites: [] } @@ -132,9 +144,51 @@ function resetDebugState(): void { debugState.deferredForegroundWriteCount = 0 debugState.flushWriteCount = 0 debugState.scheduledDrainCount = 0 + debugState.queuedTerminalCount = 0 + debugState.queuedChars = 0 + debugState.peakQueuedTerminalCount = 0 + debugState.peakQueuedChars = 0 + debugState.peakQueuedCharsByTerminal = 0 + debugState.droppedBacklogCount = 0 debugState.drainWrites = [] } +function readQueueDebugSnapshot(): { + queuedTerminalCount: number + queuedChars: number + queuedCharsByTerminal: number +} { + let queuedChars = 0 + let queuedCharsByTerminal = 0 + for (const entry of queuedByTerminal.values()) { + queuedChars += entry.queuedChars + queuedCharsByTerminal = Math.max(queuedCharsByTerminal, entry.queuedChars) + } + return { + queuedTerminalCount: queuedByTerminal.size, + queuedChars, + queuedCharsByTerminal + } +} + +function recordQueueDebugPressure(): void { + if (!debugEnabled) { + return + } + const current = readQueueDebugSnapshot() + debugState.queuedTerminalCount = current.queuedTerminalCount + debugState.queuedChars = current.queuedChars + debugState.peakQueuedTerminalCount = Math.max( + debugState.peakQueuedTerminalCount, + current.queuedTerminalCount + ) + debugState.peakQueuedChars = Math.max(debugState.peakQueuedChars, current.queuedChars) + debugState.peakQueuedCharsByTerminal = Math.max( + debugState.peakQueuedCharsByTerminal, + current.queuedCharsByTerminal + ) +} + function exposeDebugApi(): void { if (!debugEnabled || typeof window === 'undefined') { return @@ -146,10 +200,13 @@ function exposeDebugApi(): void { } target.__terminalOutputSchedulerDebug ??= { reset: resetDebugState, - snapshot: () => ({ - ...debugState, - drainWrites: [...debugState.drainWrites] - }) + snapshot: () => { + recordQueueDebugPressure() + return { + ...debugState, + drainWrites: [...debugState.drainWrites] + } + } } } @@ -368,6 +425,7 @@ function takeQueuedChunk(entry: QueueEntry, limit: number): QueuedWrite | null { if (entry.queuedChars < 0) { entry.queuedChars = 0 } + recordQueueDebugPressure() return data ? { data, @@ -412,6 +470,7 @@ function enqueueChunk( stripTransientCursorShows: options?.stripTransientCursorShows === true }) entry.queuedChars += data.length + recordQueueDebugPressure() } function replaceBacklogWithWarning(entry: QueueEntry): void { @@ -431,7 +490,11 @@ function replaceBacklogWithWarning(entry: QueueEntry): void { entry.backgroundBacklogDropped = true entry.highPriority = true entry.foregroundHold = false + if (debugEnabled && shouldNotify) { + debugState.droppedBacklogCount++ + } clearForegroundCoalesce(entry) + recordQueueDebugPressure() if (shouldNotify) { entry.onBackgroundBacklogDropped?.() } @@ -510,6 +573,7 @@ function writeQueuedChunk(entry: QueueEntry): 'foreground' | 'background' | null entry.queuedChars = 0 clearForegroundHoldSafety(entry) clearForegroundCoalesce(entry) + recordQueueDebugPressure() return null } return queuedWrite.foreground ? 'foreground' : 'background' @@ -552,6 +616,7 @@ function drainQueuedOutput(): void { if (debugEnabled && writes > 0) { debugState.drainWrites.push(writes) } + recordQueueDebugPressure() if (queuedByTerminal.size > 0 && hasDrainableBacklog()) { scheduleDrain( hasHighPriorityBacklog() ? HIGH_PRIORITY_DRAIN_INTERVAL_MS : BACKGROUND_DRAIN_INTERVAL_MS @@ -760,6 +825,7 @@ export function flushTerminalOutput( entry.highPriority = false clearForegroundHoldSafety(entry) clearForegroundCoalesce(entry) + recordQueueDebugPressure() return } @@ -792,6 +858,7 @@ export function flushTerminalOutput( // the scheduler for other panes still draining. clearForegroundHoldSafety(entry) clearForegroundCoalesce(entry) + recordQueueDebugPressure() return } if (options?.maxChars !== undefined && flushedChars >= options.maxChars) { @@ -808,6 +875,7 @@ export function flushTerminalOutput( clearForegroundCoalesce(entry) clearForegroundHoldSafety(entry) } + recordQueueDebugPressure() } function requestRegisteredTerminalBacklogRecovery(terminal: TerminalOutputTarget): boolean { @@ -865,6 +933,7 @@ export function discardTerminalOutput(terminal: TerminalOutputTarget): void { queuedByTerminal.delete(terminal) activeOutputTargets.delete(terminal) discardForegroundRenderSettle(terminal) + recordQueueDebugPressure() } exposeDebugApi() diff --git a/tests/e2e/artificial-opencode-terminal-load.spec.ts b/tests/e2e/artificial-opencode-terminal-load.spec.ts index 0cddb77d4..15969b8ea 100644 --- a/tests/e2e/artificial-opencode-terminal-load.spec.ts +++ b/tests/e2e/artificial-opencode-terminal-load.spec.ts @@ -69,6 +69,12 @@ type TerminalOutputSchedulerDebugSnapshot = { deferredForegroundWriteCount: number flushWriteCount: number scheduledDrainCount: number + queuedTerminalCount: number + queuedChars: number + peakQueuedTerminalCount: number + peakQueuedChars: number + peakQueuedCharsByTerminal: number + droppedBacklogCount: number drainWrites: number[] } @@ -468,7 +474,7 @@ function annotateTypingMeasurement( ? ` hiddenSkips=${debug.hiddenRendererSkipCount} hiddenSkippedChars=${debug.hiddenRendererSkippedChars} mode2031Replies=${debug.hiddenRendererMode2031ReplyCount}` : '' const schedulerSummary = scheduler - ? ` deferredForegroundEnqueue=${scheduler.deferredForegroundEnqueueCount} deferredForegroundWrite=${scheduler.deferredForegroundWriteCount} scheduledDrains=${scheduler.scheduledDrainCount}` + ? ` deferredForegroundEnqueue=${scheduler.deferredForegroundEnqueueCount} deferredForegroundWrite=${scheduler.deferredForegroundWriteCount} scheduledDrains=${scheduler.scheduledDrainCount} rendererQueuedTerminals=${scheduler.queuedTerminalCount} rendererQueuedChars=${scheduler.queuedChars} rendererPeakQueuedTerminals=${scheduler.peakQueuedTerminalCount} rendererPeakQueuedChars=${scheduler.peakQueuedChars} rendererPeakQueuedCharsByTerminal=${scheduler.peakQueuedCharsByTerminal} rendererDroppedBacklogs=${scheduler.droppedBacklogCount}` : '' const mainPressureSummary = mainPressure ? ` mainPendingPtys=${mainPressure.pendingPtyCount} mainPendingChars=${mainPressure.pendingChars} mainMaxPendingChars=${mainPressure.maxPendingCharsByPty} mainInFlightPtys=${mainPressure.rendererInFlightPtyCount} mainInFlightChars=${mainPressure.rendererInFlightChars} mainMaxInFlightChars=${mainPressure.maxRendererInFlightCharsByPty} mainActivePtys=${mainPressure.activeRendererPtyCount} mainFlushScheduled=${mainPressure.flushScheduled} mainPeakPendingChars=${mainPressure.peakPendingChars} mainPeakMaxPendingChars=${mainPressure.peakMaxPendingCharsByPty} mainPeakInFlightChars=${mainPressure.peakRendererInFlightChars} mainPeakMaxInFlightChars=${mainPressure.peakMaxRendererInFlightCharsByPty} mainAckGatedFlushSkips=${mainPressure.ackGatedFlushSkipCount}`