From 35fe67b610c4cdc62d67eca5e113d7d4595b741e Mon Sep 17 00:00:00 2001 From: Neil <4138956+nwparker@users.noreply.github.com> Date: Mon, 21 Sep 2026 16:03:40 -0700 Subject: [PATCH] fix(perf): measure terminal latency with presented CI frames (#22096) * fix(perf): present benchmark frames only on isolated CI display * fix(perf): wait for the benchmark page before presenting its window * docs(perf): record full scale pass with unchanged latency budgets * test(perf): document and verify the isolated display exception --- .github/workflows/terminal-perf.yml | 3 +- .../terminal-perf-latency-investigation.md | 106 ++++++++++++++++++ .../window/foreground-activation-policy.ts | 4 +- tests/AGENTS.md | 17 +++ .../artificial-opencode-terminal-load.spec.ts | 6 + tests/e2e/terminal-perf-presentation.ts | 40 +++++++ .../terminal-perf-presentation.unit.test.ts | 84 ++++++++++++++ 7 files changed, 258 insertions(+), 2 deletions(-) create mode 100644 docs/reference/terminal-perf-latency-investigation.md create mode 100644 tests/e2e/terminal-perf-presentation.ts create mode 100644 tests/e2e/terminal-perf-presentation.unit.test.ts diff --git a/.github/workflows/terminal-perf.yml b/.github/workflows/terminal-perf.yml index 72a0fec8992..83ada43d2cf 100644 --- a/.github/workflows/terminal-perf.yml +++ b/.github/workflows/terminal-perf.yml @@ -55,6 +55,7 @@ jobs: timeout-minutes: 45 env: NODE_OPTIONS: --max-old-space-size=4096 + ORCA_BACKGROUND_LAUNCH: '1' ORCA_E2E_FORWARD_APP_LOGS: '1' ORCA_E2E_TERMINAL_PERF_REPORT_PATH: ${{ inputs.report_path || 'test-results/terminal-scale-perf-report.json' }} @@ -128,7 +129,7 @@ jobs: if [ -n "${ORCA_TERMINAL_PERF_SCALE_HIDDEN_PRESSURE_PANES:-}" ]; then export ORCA_E2E_OPENCODE_SCALE_HIDDEN_PRESSURE_PANES="$ORCA_TERMINAL_PERF_SCALE_HIDDEN_PRESSURE_PANES" fi - xvfb-run --auto-servernum env SKIP_BUILD=1 pnpm run test:e2e:terminal-perf:scale:report -- "${args[@]}" + xvfb-run --auto-servernum env SKIP_BUILD=1 ORCA_E2E_TERMINAL_PERF_XVFB=1 pnpm run test:e2e:terminal-perf:scale:report -- "${args[@]}" - name: Upload terminal perf report if: always() diff --git a/docs/reference/terminal-perf-latency-investigation.md b/docs/reference/terminal-perf-latency-investigation.md new file mode 100644 index 00000000000..4e61ab3529c --- /dev/null +++ b/docs/reference/terminal-perf-latency-investigation.md @@ -0,0 +1,106 @@ +# Terminal latency investigation (2026-09-21) + +The September 21 scheduled report has five latency violations: three restores +above 1,000 ms, a worst key around 2,091 ms, and timer drift around 2,034 ms. +These remain failures under the [historically calibrated budgets](terminal-perf-report-budgets.md). +Passing the looser Electron assertions does not establish that the report passed. + +## Historical boundary + +Slow restores predate September: the July 20 scheduled run measured a 1,226.6 ms +Latin restore; August 1 measured 1,492 ms. Earlier June/July logs did not contain +usable summary rows and their artifacts expired. There is no established good/bad +application revision boundary, and no completed git bisect. A newly visible report +failure is not, by itself, evidence of a newly introduced application regression. + +The scheduled workflow uses one Playwright worker. Parallel Electron workers do +not explain these particular failures. Repeated macOS runs did not reproduce the +Linux stalls (15 targeted samples: restore 136–236 ms, hidden worst key ≤23.6 ms). + +## Controlled Linux experiments + +All comparisons use the same application build within their run, one worker, +real PTYs, and the original terminal workload. Diagnostic tracing can perturb +measurements, so it identifies the mechanism rather than setting new budgets. + +| Comparison | Evidence | Finding | +| --- | --- | --- | +| Default versus disabled background throttling | [35657300611](https://github.com/stablyai/orca/actions/runs/35657300611) | 14/20 restores exceed 1 second; four typing measurements approach 1 second. `setBackgroundThrottling(false)` does not remove the stalls. | +| Native browser trace | [35658595456](https://github.com/stablyai/orca/actions/runs/35658595456) | Renderer waits roughly 960–1,010 ms in `LayerTreeHost::WaitForCommitCompletion`. Some typing samples contain consecutive waits. | +| Current flags versus flags preceding `c64777d1bcd` versus SwiftShader | [35659601151](https://github.com/stablyai/orca/actions/runs/35659601151) | All three configurations still trigger undrawn-frame throttling. Reverting the May 26 flags is not a demonstrated fix. | + +In the graphics comparison, current flags had one of six restores above 1 second; +the earlier flags had three and a 1,036 ms worst key. SwiftShader had six measured +restores between 301 and 396 ms, but still contained one-second native waits after +the restore measurement ended, and one 202 ms timer-drift violation. Its faster +restore numbers are insufficient evidence of a fix. + +## Native mechanism + +The trace shows the renderer blocked inside: + +``` +ProxyMain::BeginMainFrame + Commit + ProxyMain::BeginMainFrame::commit + LayerTreeHost::WaitForCommitCompletion +``` + +During the gap, Viz repeatedly emits `SendBeginFrameDecision` with +`reason: ThrottleUndrawnFrames` and `should_send: false`. The graphics comparison +recorded 346 such decisions with current flags, 626 with the earlier flags, and +401 with SwiftShader. Raster work was already ready before the wait ended. + +The [matching Chromium source](https://github.com/chromium/chromium/blob/150.0.7871.250/components/viz/service/frame_sinks/compositor_frame_sink_support.cc) +limits begin frames to once per second when too many submitted frames remain +undrawn. Input can block the renderer waiting for the next compositor commit; +this is not a one-second xterm parse or proof of a second of CPU consumption. +The same throttle is present in Chromium 148.0.7778.218 (Electron 42.3.3) and +146.0.7680.177. This source comparison does not prove identical runtime behavior. + +## Visibility control + +[Run 35660847455](https://github.com/stablyai/orca/actions/runs/35660847455) +compared ten hidden-window samples with ten visible-window samples on the same +isolated Xvfb runner, using SwiftShader in both modes. Actual window visibility +was recorded. The background terminal panes remained hidden in both modes. + +| Measurement | Hidden window | Visible window | +| --- | ---: | ---: | +| Undrawn-frame throttle decisions | 1,251 | 0 | +| Largest worst-key latency | 3,062.8 ms | 30.5 ms | +| Largest timer drift | 3,111.8 ms | 67.0 ms | +| Restore range | 213.8–1,862.2 ms (9 completed) | 223.4–734.3 ms (10 completed) | +| Electron tests passed | 9/10 | 10/10 | + +All ten visible-window samples satisfy the existing latency limits. This isolates +the never-presented Linux test window as the trigger for the reproduced native +stalls. It does not establish a newly introduced application-code regression or +prove that every historical outlier had the same cause. + +## Full scale validation + +[Run 35662787327](https://github.com/stablyai/orca/actions/runs/35662787327) +passed all 21 scenarios and all 32 strict report rows, with zero skipped, +unexpected, or retried tests. All 21 scenarios recorded successful isolated-display +presentation. This run restored the original graphics flags and removed profiling. + +| Metric | Largest measurement | Unchanged report limit | +| --- | ---: | ---: | +| Median typing | 15.5 ms | 25 ms | +| Worst key | 45.7 ms | 300 ms | +| Hidden-output restore | 395.7 ms | 1,000 ms | +| Worktree revisit | 50.3 ms | 300 ms | +| Scroll | 54.7 ms | 150 ms | + +Timer drift and queue/drop checks also passed. Coverage includes 100-pane +same-workspace and cross-workspace redraws, 50 real PTYs under held-ACK pressure, +and the original plain/Latin/title/rich-model hidden-output scenarios. No workload +or performance limit changed. + +The correction presents the benchmark window only when explicitly enabled inside +`xvfb-run` on a GitHub-hosted Linux runner. Ordinary local automation stays +windowless; production launch policy and hidden-terminal delivery remain unchanged. +For comparable Linux latency evidence, use the Terminal Perf workflow: a never- +presented local Linux window can still encounter the same compositor throttle. +Temporary profiling hooks and the comparison workflow were removed before the PR. diff --git a/src/main/window/foreground-activation-policy.ts b/src/main/window/foreground-activation-policy.ts index 5d51f50e487..d010f11c4ec 100644 --- a/src/main/window/foreground-activation-policy.ts +++ b/src/main/window/foreground-activation-policy.ts @@ -7,6 +7,8 @@ import { app as electronApp, type BrowserWindow } from 'electron' * * ORCA_BACKGROUND_LAUNCH=1 keeps automation off screen. Native-focus specs * can use ORCA_E2E_FOREGROUND=1 only without an explicit background request. + * The hosted-Xvfb terminal benchmark explicitly presents after startup; see tests/AGENTS.md. + * This policy still suppresses its automatic reveals and foreground activation. */ type ActivationPolicyApp = { @@ -28,7 +30,7 @@ export function isBackgroundLaunch(env: PolicyEnv = process.env): boolean { return env.ORCA_E2E_HEADLESS === '1' || env.ORCA_E2E_HEADFUL === '1' } -/** True when no window should reach the screen at all (background or headless E2E; Playwright drives via CDP). */ +/** Suppresses automatic presentation on launch; this is not a query of current window visibility. */ export function isWindowlessLaunch(env: PolicyEnv = process.env): boolean { return ( env.ORCA_BACKGROUND_LAUNCH === '1' || diff --git a/tests/AGENTS.md b/tests/AGENTS.md index 30f522652fe..583dda00e8e 100644 --- a/tests/AGENTS.md +++ b/tests/AGENTS.md @@ -20,3 +20,20 @@ Rules when adding tests or scripts: - Tag a spec `@headful` only when it needs real pixels; it still runs in the background. - Native-focus tests belong on an isolated display or CI. Do not set `ORCA_E2E_FOREGROUND=1` on the user’s desktop; it cannot override explicit background mode. + +## Isolated terminal performance presentation + +The Terminal Perf workflow has one explicit exception to the no-reveal rule: after windowless +startup, `terminal-perf-presentation.ts` presents the benchmark window without focus on its +isolated Xvfb display. Chromium otherwise throttles undrawn frames to one per second and makes +typing measurements invalid. This exception requires all of: + +- `ORCA_E2E_TERMINAL_PERF_XVFB=1`, set inside `xvfb-run` by that workflow; +- Linux, `GITHUB_ACTIONS=true`, `RUNNER_ENVIRONMENT=github-hosted`, and a nonempty `DISPLAY`; +- the page fixture to finish loading before presentation, and confirmed native window visibility. + +Keep `ORCA_BACKGROUND_LAUNCH=1`: the application must still suppress automatic reveals and focus. +`isWindowlessLaunch` describes that automatic launch policy, not the window's current visibility. +This exception belongs only to this benchmark fixture; do not generalize it to local or self-hosted +runs, paired-client helpers, native-focus tests, or production window policy. Background terminal +panes remain hidden. Evidence: `docs/reference/terminal-perf-latency-investigation.md`. diff --git a/tests/e2e/artificial-opencode-terminal-load.spec.ts b/tests/e2e/artificial-opencode-terminal-load.spec.ts index bf7b7d2c7db..493dd7794cd 100644 --- a/tests/e2e/artificial-opencode-terminal-load.spec.ts +++ b/tests/e2e/artificial-opencode-terminal-load.spec.ts @@ -1,3 +1,4 @@ +import { presentTerminalPerfWindow } from './terminal-perf-presentation' import type { Page, TestInfo } from '@stablyai/playwright-test' import { randomUUID } from 'node:crypto' import { mkdirSync, rmSync, writeFileSync } from 'node:fs' @@ -29,6 +30,11 @@ import { runMainPressureScenario } from './artificial-opencode-main-pressure-sce import { runRendererBackpressureRevisitScenario } from './artificial-opencode-revisit-pressure-scenario' import { startSyntheticOpenCodeInjection } from './artificial-opencode-synthetic-injection' +test.beforeEach(async ({ electronApp, orcaPage }, testInfo) => { + await orcaPage.waitForLoadState('domcontentloaded') + await presentTerminalPerfWindow(electronApp, testInfo) +}) + type TypingMeasurement = { latencies: number[] medianLatencyMs: number diff --git a/tests/e2e/terminal-perf-presentation.ts b/tests/e2e/terminal-perf-presentation.ts new file mode 100644 index 00000000000..3cb64a0666a --- /dev/null +++ b/tests/e2e/terminal-perf-presentation.ts @@ -0,0 +1,40 @@ +import type { ElectronApplication, TestInfo } from '@stablyai/playwright-test' + +export function shouldPresentTerminalPerfWindow( + env: Readonly> = process.env, + platform: string = process.platform +): boolean { + if (env.ORCA_E2E_TERMINAL_PERF_XVFB !== '1') { + return false + } + if ( + platform !== 'linux' || + env.GITHUB_ACTIONS !== 'true' || + env.RUNNER_ENVIRONMENT !== 'github-hosted' || + !env.DISPLAY + ) { + throw new Error('Terminal perf presentation requires an isolated GitHub Actions Xvfb display') + } + return true +} + +export async function presentTerminalPerfWindow( + electronApp: Pick, + testInfo: Pick +): Promise { + if (!shouldPresentTerminalPerfWindow()) { + return + } + // An unpresented Linux window triggers Chromium's one-second undrawn-frame throttle. + const visible = await electronApp.evaluate(({ BrowserWindow }) => { + const windows = BrowserWindow.getAllWindows() + for (const window of windows) { + window.showInactive() + } + return windows.length > 0 && windows.every((window) => window.isVisible()) + }) + if (!visible) { + throw new Error('Terminal perf window was not presented on the isolated display') + } + testInfo.annotations.push({ type: 'terminal-perf-presentation', description: 'isolated-xvfb' }) +} diff --git a/tests/e2e/terminal-perf-presentation.unit.test.ts b/tests/e2e/terminal-perf-presentation.unit.test.ts new file mode 100644 index 00000000000..51c67e8fe9e --- /dev/null +++ b/tests/e2e/terminal-perf-presentation.unit.test.ts @@ -0,0 +1,84 @@ +import type { ElectronApplication, TestInfo } from '@stablyai/playwright-test' +import { afterEach, describe, expect, it, vi } from 'vitest' +import { + presentTerminalPerfWindow, + shouldPresentTerminalPerfWindow +} from './terminal-perf-presentation' + +describe('terminal perf window presentation', () => { + afterEach(() => vi.unstubAllGlobals()) + const isolatedDisplay = { + ORCA_E2E_TERMINAL_PERF_XVFB: '1', + ORCA_BACKGROUND_LAUNCH: '1', + GITHUB_ACTIONS: 'true', + RUNNER_ENVIRONMENT: 'github-hosted', + DISPLAY: ':99' + } + + it.each(['darwin', 'linux', 'win32'])('keeps ordinary %s runs hidden', (platform) => { + expect(shouldPresentTerminalPerfWindow({}, platform)).toBe(false) + expect( + shouldPresentTerminalPerfWindow( + { ...isolatedDisplay, ORCA_E2E_TERMINAL_PERF_XVFB: '0' }, + platform + ) + ).toBe(false) + }) + + it('permits the explicit hosted Linux CI display', () => { + expect(shouldPresentTerminalPerfWindow(isolatedDisplay, 'linux')).toBe(true) + }) + + it.each(['darwin', 'win32'])('rejects visible diagnostics on %s', (platform) => { + expect(() => shouldPresentTerminalPerfWindow(isolatedDisplay, platform)).toThrow('isolated') + }) + + it.each([ + { ...isolatedDisplay, GITHUB_ACTIONS: undefined }, + { ...isolatedDisplay, GITHUB_ACTIONS: 'false' }, + { ...isolatedDisplay, RUNNER_ENVIRONMENT: 'self-hosted' }, + { ...isolatedDisplay, RUNNER_ENVIRONMENT: undefined }, + { ...isolatedDisplay, DISPLAY: undefined }, + { ...isolatedDisplay, DISPLAY: '' } + ])('rejects a missing isolated display: %j', (env) => { + expect(() => shouldPresentTerminalPerfWindow(env, 'linux')).toThrow('isolated') + }) + + function presentationFixture(env: Record, platform = 'linux') { + vi.stubGlobal('process', { ...process, platform, env }) + const app = { evaluate: vi.fn() } + const info: Pick = { annotations: [] } + return { app, info } + } + + it('does not contact Electron during an ordinary local run', async () => { + const { app, info } = presentationFixture({ ORCA_BACKGROUND_LAUNCH: '1' }) + await presentTerminalPerfWindow(app, info) + expect(app.evaluate).not.toHaveBeenCalled() + expect(info.annotations).toEqual([]) + }) + + it('rejects a local opt-in before contacting Electron', async () => { + const { app, info } = presentationFixture({ ...isolatedDisplay, GITHUB_ACTIONS: undefined }) + await expect(presentTerminalPerfWindow(app, info)).rejects.toThrow('isolated') + expect(app.evaluate).not.toHaveBeenCalled() + expect(info.annotations).toEqual([]) + }) + + it('records presentation only after Electron confirms visibility', async () => { + const { app, info } = presentationFixture(isolatedDisplay) + app.evaluate.mockResolvedValue(true) + await presentTerminalPerfWindow(app, info) + expect(app.evaluate).toHaveBeenCalledOnce() + expect(info.annotations).toEqual([ + { type: 'terminal-perf-presentation', description: 'isolated-xvfb' } + ]) + }) + + it('fails instead of measuring an absent or still-hidden window', async () => { + const { app, info } = presentationFixture(isolatedDisplay) + app.evaluate.mockResolvedValue(false) + await expect(presentTerminalPerfWindow(app, info)).rejects.toThrow('not presented') + expect(info.annotations).toEqual([]) + }) +})