From c2d46671946576a3dd359f4725f03ac2d321fee0 Mon Sep 17 00:00:00 2001 From: Jinwoo-H Date: Fri, 11 Sep 2026 16:53:03 -0400 Subject: [PATCH] fix: address performance review findings --- config/scripts/lag-probe-failures.test.mjs | 82 +++++++++++++++++++ config/scripts/main-blocking-probe.mjs | 4 + .../orca-main-inspector-connection.mjs | 19 ++++- .../reference/orca-live-lag-investigation.md | 10 ++- .../orca-persistence-design-assessment.md | 2 +- .../orca-persistence-design-visual.html | 0 ...ty-runtime-ssh-binding-persistence.test.ts | 22 +++++ ...sistence-flush-and-save-scheduling.test.ts | 4 +- .../loading-store/pty-binding-span.ts | 6 +- .../terminal-tab-pty-ownership.test.ts | 6 +- .../terminal-tab-pty-ownership.ts | 9 +- 11 files changed, 147 insertions(+), 17 deletions(-) create mode 100644 config/scripts/lag-probe-failures.test.mjs rename orca-live-lag-investigation.md => docs/reference/orca-live-lag-investigation.md (97%) rename orca-persistence-design-assessment.md => docs/reference/orca-persistence-design-assessment.md (98%) rename orca-persistence-design-visual.html => docs/reference/orca-persistence-design-visual.html (100%) diff --git a/config/scripts/lag-probe-failures.test.mjs b/config/scripts/lag-probe-failures.test.mjs new file mode 100644 index 00000000000..47bada8e051 --- /dev/null +++ b/config/scripts/lag-probe-failures.test.mjs @@ -0,0 +1,82 @@ +import assert from 'node:assert/strict' +import { test } from 'node:test' +import { runInNewContext } from 'node:vm' +import { installRendererIpcProbe } from './main-blocking-probe.mjs' +import { connectOrcaMainInspector } from './orca-main-inspector-connection.mjs' + +test('IPC polling records a rejection and permits the next poll', async () => { + let poll + let calls = 0 + const window = { + api: { + app: { + getIdentity: async () => { + if (++calls === 1) { + throw new Error('IPC disconnected') + } + } + } + } + } + runInNewContext(`(${installRendererIpcProbe})()`, { + window, + performance, + Date, + document: { addEventListener() {}, removeEventListener() {} }, + setInterval(callback) { + poll = callback + return 1 + }, + clearInterval() {} + }) + await poll() + await poll() + const { requests } = window.__orcaIpcTimingProbe.stop() + assert.equal(requests.length, 2) + assert.match(requests[0].failed, /IPC disconnected/) + assert.equal(requests[1].failed, undefined) +}) + +test('socket closure rejects outstanding and subsequent requests without timeout timers', async () => { + let socket + const timers = new Set() + class FakeSocket { + static OPEN = 1 + readyState = 1 + constructor() { + socket = this + queueMicrotask(() => this.onopen()) + } + send(payload) { + const { id, params } = JSON.parse(payload) + if (params.expression === 'process.pid') { + queueMicrotask(() => + this.onmessage({ data: JSON.stringify({ id, result: { result: { value: 42 } } }) }) + ) + } + } + close() { + this.readyState = 3 + this.onclose() + } + } + const connect = runInNewContext(`(${connectOrcaMainInspector})`, { + fetch: async () => ({ json: async () => [{ webSocketDebuggerUrl: 'ws://fixture' }] }), + WebSocket: FakeSocket, + setTimeout(callback) { + timers.add(callback) + return callback + }, + clearTimeout(timer) { + timers.delete(timer) + } + }) + const connection = await connect(42) + const first = connection.send('Profiler.start') + const second = connection.send('Profiler.stop') + socket.close() + await assert.rejects(first, /Inspector socket closed/) + await assert.rejects(second, /Inspector socket closed/) + await assert.rejects(connection.send('Profiler.enable'), /not open/) + assert.equal(timers.size, 0) +}) diff --git a/config/scripts/main-blocking-probe.mjs b/config/scripts/main-blocking-probe.mjs index 90a082d7971..93a5372a765 100644 --- a/config/scripts/main-blocking-probe.mjs +++ b/config/scripts/main-blocking-probe.mjs @@ -89,6 +89,10 @@ export function installRendererIpcProbe() { if (requests.length < 2000) { requests.push({ epoch, durationMs: performance.now() - start }) } + } catch (error) { + if (requests.length < 2000) { + requests.push({ epoch, durationMs: performance.now() - start, failed: String(error) }) + } } finally { pending = false } diff --git a/config/scripts/orca-main-inspector-connection.mjs b/config/scripts/orca-main-inspector-connection.mjs index e07630b9a80..1d77e728f89 100644 --- a/config/scripts/orca-main-inspector-connection.mjs +++ b/config/scripts/orca-main-inspector-connection.mjs @@ -7,6 +7,13 @@ export async function connectOrcaMainInspector(expectedPid, rendererId = 1) { }) const pending = new Map() let nextId = 0 + socket.onclose = () => { + for (const [id, callback] of pending) { + pending.delete(id) + clearTimeout(callback.timer) + callback.reject(new Error('Inspector socket closed')) + } + } socket.onmessage = (event) => { const message = JSON.parse(event.data) const callback = pending.get(message.id) @@ -23,13 +30,23 @@ export async function connectOrcaMainInspector(expectedPid, rendererId = 1) { } function send(method, params = {}) { return new Promise((resolve, reject) => { + if (socket.readyState !== WebSocket.OPEN) { + reject(new Error('Inspector socket is not open')) + return + } const id = ++nextId const timer = setTimeout(() => { pending.delete(id) reject(new Error(`Timed out: ${method}`)) }, 15_000) pending.set(id, { resolve, reject, timer }) - socket.send(JSON.stringify({ id, method, params })) + try { + socket.send(JSON.stringify({ id, method, params })) + } catch (error) { + pending.delete(id) + clearTimeout(timer) + reject(error) + } }) } async function evaluateMain(expression) { diff --git a/orca-live-lag-investigation.md b/docs/reference/orca-live-lag-investigation.md similarity index 97% rename from orca-live-lag-investigation.md rename to docs/reference/orca-live-lag-investigation.md index 924ae173278..59053afeaef 100644 --- a/orca-live-lag-investigation.md +++ b/docs/reference/orca-live-lag-investigation.md @@ -61,7 +61,7 @@ Source: `debug-orca-performance` session `3a100df6`, 2026-09-10, packaged | H2 | Activity Monitor (PID 67969) leaked to a 99 GB footprint, all dirty malloc, after 7 days, burning 82–101% CPU | Killing it: swap 47.0→16 GB, RAM used 124→95 GB, free 3→31 GB, CPU idle 0.3%→20% | Resolved by SIGKILL | | H3 | A Codex-spawned `rg --hidden` scanning the whole home directory | PID 65656, 130–340% CPU for over 3 minutes, ~16k IOPS | Operational | | H4 | 179 agent CLI processes (93 codex, 65 claude, 11 agy, 10 opencode) plus four dev Orca instances, one renderer at 2.6 GB | 27 GB RSS, ~200% CPU combined | Operational | -| H5 | Earlier (2026-09-05/07) skill-discovery scan storm from release agents: `find /Users/jinjingliang -path */SKILL.md` and `rg --hidden --glob SKILL.md` over the home directory | `rg` at 314%, 351% and 390% CPU; 18 CPUs, 3,075 processes, 33,750 threads, 73.86% system, 4.92% idle, load 17.13. Remediation is targeted skill-directory discovery and dedup across release workers | Open (agent-side) | +| H5 | Earlier (2026-09-05/07) skill-discovery scan storm from release agents over the home directory | `rg` at 314%, 351% and 390% CPU; 18 CPUs, 3,075 processes, 33,750 threads, 73.86% system, 4.92% idle, load 17.13. Remediation is targeted skill-directory discovery and dedup across release workers | Open (agent-side) | Keystroke path context: every keystroke crosses six process hops (renderer, main, daemon, shell, back, GPU, WindowServer). Under H1 each hop competes with a @@ -149,6 +149,10 @@ the real profile. Full numbers are in the PR body. | After tab-row fix (17 calls) | 13 | 2 (0 ms total) | 15 | 337 ms, of which 209 ms was `not_durable` alone | | After per-pane durability | — | expected to absorb that 209 ms | — | — | +`Reattaches` counts a subset of all calls by origin; it overlaps the outcome columns. +`Fast lane` and `Flushed` are mutually exclusive outcomes and sum to the call count +(0 + 22 and 2 + 15 respectively). Do not add `Reattaches` to those outcomes. + Real-profile eligibility: 1,078 of 1,764 panes (61%) before the tab-row fix, all 1,764 after it, subject to the durability check. @@ -317,7 +321,7 @@ Terminal replay/rendering is a lead, not an established root cause. Ghostty's re ## Deeper checks -- Mapped the replay breadcrumb workspace hash `db7a2eae` to the main Orca repository workspace (`/Users/jinjingliang/Documents/projects/orca`), rather than this debug worktree. The two tab hashes were not found in the persisted terminal-tab inventory. No additional wedge breadcrumbs appeared through approximately 21:52. The initial warnings cannot establish the cause of current typing lag. +- Mapped the replay breadcrumb workspace hash `db7a2eae` to the main Orca repository workspace (``), rather than this debug worktree. The two tab hashes were not found in the persisted terminal-tab inventory. No additional wedge breadcrumbs appeared through approximately 21:52. The initial warnings cannot establish the cause of current typing lag. - Read `replay-guard.ts`: the warning can follow a rejected write (including disposal), or a FIFO probe with no parse progress. The default stalled-write path waits 10 seconds to probe and another quiet 10 seconds before declaring a wedge. It is not a measurement of per-keystroke latency. - A second, 15-second renderer sample contained 12,899 main-thread samples, including 11,280 in the idle wait: approximately 12.5% outside idle. File: `/tmp/orca-live-renderer-long.sample.txt`. This does not support continuous renderer saturation; short stalls remain possible. Native Electron symbols are insufficient to identify the JavaScript functions responsible. - Confirmed recurring Git fan-out: recent bursts frequently contain 18 `show-ref` calls, 17 failing, with individual maximum durations around 20–31 ms. Source path: `getPullRequestRemoteRefState` → `listExactRemoteBaseRefs` in `src/main/text-generation/pull-request-remote-ref-probes.ts` → `probeExactRefs` in `src/main/git/exact-ref-probe.ts`. It builds a candidate for every configured remote and runs separate processes with concurrency eight. This explains the observed probe pattern, but does not prove typing stalls. @@ -344,7 +348,7 @@ The improvement coincides with an actual update/restart and a much lighter rende - Latest terminal rendering diagnostics show 12–13 mounted managers, versus roughly 33–35 earlier. Recent renderer JS heap snapshots fall from 167 MB to 133 MB; private memory is approximately 534–587 MB. The resource population is lower, but not identical to just after restart. - Orca's resource inventory reports 458 managed sessions across 133 workspaces, totaling approximately 65.6 GiB RSS. RSS sums include shared pages and are not unique physical memory. The app's aggregate RSS was approximately 2.55 GiB, including all renderer processes; this is not comparable directly to the main renderer's private-memory breadcrumb. - The `1.4.198-release` workspace accounted for approximately 346% CPU in the inventory. Direct OS sampling then found `rg` processes at 314%, 351%, and 390% CPU, plus several `find` processes around 33–40% each. -- Confirmed search commands include `find /Users/jinjingliang -path */SKILL.md -type f` and `rg -l --hidden --glob SKILL.md prod-release-scan|release scan|production release /Users/jinjingliang /tmp`. Two surviving `rg` processes had cwd `/Users/jinjingliang/Documents/projects/orca/1.4.198-release`. These scans were launched by other agents, not this investigation. +- Confirmed search commands include `find -path */SKILL.md -type f` and `rg -l --hidden --glob SKILL.md prod-release-scan|release scan|production release /tmp`. Two surviving `rg` processes had cwd `/1.4.198-release`. These scans were launched by other agents, not this investigation. - System snapshot at 22:56:57: 18 logical CPUs, 3,075 processes, 33,750 threads; CPU 21.21% user, 73.86% system, only 4.92% idle; one-minute load average 17.13. The scan storm is therefore material system contention, not merely a large percentage on one otherwise-idle core. This establishes a current source of CPU/filesystem pressure: overlapping whole-home skill-discovery scans from release agents. Similar `find` activity appeared in the original capture, but these later scans do not retrospectively prove the original typing bottleneck. The appropriate remediation for this confirmed waste is targeted skill-directory discovery and deduplication across release workers. No agents were messaged, stopped, or modified, and no user processes were killed. diff --git a/orca-persistence-design-assessment.md b/docs/reference/orca-persistence-design-assessment.md similarity index 98% rename from orca-persistence-design-assessment.md rename to docs/reference/orca-persistence-design-assessment.md index 6607c1f8ced..d70c33cd62e 100644 --- a/orca-persistence-design-assessment.md +++ b/docs/reference/orca-persistence-design-assessment.md @@ -54,7 +54,7 @@ When the predicate holds, `return true`. The `true` return matters: `persistAdmi A tab row names one PTY, but a split tab holds several panes. The renderer keeps the row on the first pane and refuses to let later split-pane spawns steal it, because a remount reattaches the tab to whatever the row says. Until this change the main-process write path overwrote the row with whichever pane was binding, and the renderer's next session publish put the first pane back. On the dev profile that ping-pong was the sole reason all four reattach-shaped calls in the first 22-span capture fell through: they matched on layout, leaf PTY, and incarnation and missed only on `tab_pty`. On the real profile 310 of 1,424 terminal tabs are split, holding 674 of 1,764 panes, so 38% of remounts could never have hit the fast lane. -`terminal-tab-pty-ownership.ts` holds the rule both sides now follow. The row is rewritten only when it names nothing useful: it is null, it points at the PTY this leaf is replacing, or it names a PTY no leaf of the layout holds. A sibling pane's bind leaves it alone. The predicate compares the row against what that rule would write, so a sibling reattach counts as a match. Every main-process reader of the row already falls back to the per-leaf map, so none depends on it naming the most recent pane. The two existing tests that pin a null row being filled stay valid. +`terminal-tab-pty-ownership.ts` holds the rule both sides now follow. The row is rewritten only when it is null or points at the PTY this leaf is replacing. A non-null row absent from the leaf map stays unchanged until the renderer clears or replaces it. A sibling pane's bind leaves it alone. The predicate compares the row against what that rule would write, so a sibling reattach counts as a match. Every main-process reader of the row already falls back to the per-leaf map, so none depends on it naming the most recent pane. The two existing tests that pin a null row being filled stay valid. ### Durability check diff --git a/orca-persistence-design-visual.html b/docs/reference/orca-persistence-design-visual.html similarity index 100% rename from orca-persistence-design-visual.html rename to docs/reference/orca-persistence-design-visual.html diff --git a/src/main/ipc/pty-runtime-ssh-binding-persistence.test.ts b/src/main/ipc/pty-runtime-ssh-binding-persistence.test.ts index b66cd30e71f..988a180c627 100644 --- a/src/main/ipc/pty-runtime-ssh-binding-persistence.test.ts +++ b/src/main/ipc/pty-runtime-ssh-binding-persistence.test.ts @@ -2,6 +2,7 @@ import { describe, expect, it, vi } from 'vitest' import { spawnMock, openCodeClearPtyMock, piClearPtyMock } from './pty-ipc-mock-registry' import { setupPtyIpcSuite } from './pty-ipc-test-harness' import { makePaneKey } from '../../shared/stable-pane-id' +import { commitRuntimePtySpawn } from './pty/runtime/spawn-commit' import { SSH_SESSION_EXPIRED_ERROR, SshPtyAbsentFromRelayError } from '../providers/ssh-pty-errors' import { registerPtyHandlers, @@ -58,6 +59,27 @@ vi.mock('../codex/codex-state-db-backfill-recovery', () => describe('registerPtyHandlers', () => { const { mainWindow, mainWindowIpcEvent, getPtyWriteListener } = setupPtyIpcSuite() + it('labels an adopted relay binding as reattach even without an isReattach flag', async () => { + const persistPtyBinding = vi.fn(() => false) + await expect( + commitRuntimePtySpawn({ + args: { connectionId: 'ssh-adopted' }, + result: { id: 'relay-pty', agentSessionEnsure: { disposition: 'adopted' } }, + hostSessionBinding: { store: { persistPtyBinding }, worktreeId: 'wt-remote' }, + stablePaneOwner: { + ptyId: 'relay-pty', + tabId: 'tab-remote', + leafId: 'leaf-remote', + hasPersistedBinding: true + } + } as never) + ).rejects.toThrow('terminal_pane_owner_changed') + expect(persistPtyBinding).toHaveBeenCalledWith( + expect.objectContaining({ origin: 'reattach', ptyId: 'relay-pty' }), + 'ssh:ssh-adopted' + ) + }) + it('rejects runtime-owned binding persistence without complete stable identity', async () => { type RuntimeSpawnController = { spawn(args: { diff --git a/src/main/persistence-flush-and-save-scheduling.test.ts b/src/main/persistence-flush-and-save-scheduling.test.ts index 9e1b092e798..78d6a41858f 100644 --- a/src/main/persistence-flush-and-save-scheduling.test.ts +++ b/src/main/persistence-flush-and-save-scheduling.test.ts @@ -18,6 +18,7 @@ import { TEST_LEAF_1, TEST_LEAF_2 } from './persistence-session-fixtures' import { getDefaultPersistedState, getDefaultWorkspaceSession } from '../shared/constants' import type { WorkspaceSessionState } from '../shared/workspace-session-state-types' import { _resetTracerForTests, setActiveSink } from './observability/tracer' +import { _resetPtyBindingSpanSamplingForTests } from './persistence/loading-store/pty-binding-span' // Stub the ~/.ssh/config parser so the SSH-import test drives the real Store with deterministic hosts, not the operator's actual ~/.ssh/config. const { loadUserSshConfigMock, sshConfigHostsToTargetsMock } = vi.hoisted(() => ({ @@ -68,6 +69,8 @@ describe('Store', () => { }) afterEach(() => { + vi.restoreAllMocks() + _resetPtyBindingSpanSamplingForTests() rmSync(testState.dir, { recursive: true, force: true }) }) // ── 10. flush writes synchronously ───────────────────────────────── @@ -439,7 +442,6 @@ describe('Store', () => { expect(flushSpy).not.toHaveBeenCalled() expect(cloneSpy).not.toHaveBeenCalled() expect(statSync(dataFile()).ino).toBe(inoBefore) - cloneSpy.mockRestore() } ) diff --git a/src/main/persistence/loading-store/pty-binding-span.ts b/src/main/persistence/loading-store/pty-binding-span.ts index 63874be6117..58bed424a51 100644 --- a/src/main/persistence/loading-store/pty-binding-span.ts +++ b/src/main/persistence/loading-store/pty-binding-span.ts @@ -12,13 +12,15 @@ export type PtyBindingOrigin = 'reattach' | 'spawn' | 'relay_reattach' | 'split' /** The spawn-commit paths share one rule: a split outranks a reattach, a reattach outranks a spawn. */ export function spawnCommitBindingOrigin( - commit: { isReattach?: boolean }, + commit: { isReattach?: boolean; agentSessionEnsure?: { disposition: string } }, expectedSourceBinding?: unknown ): PtyBindingOrigin { if (expectedSourceBinding !== undefined) { return 'split' } - return commit.isReattach === true ? 'reattach' : 'spawn' + return commit.isReattach === true || commit.agentSessionEnsure?.disposition === 'adopted' + ? 'reattach' + : 'spawn' } // Bound frequent no-op traces; writes, refusals, and failures are always recorded. diff --git a/src/main/persistence/loading-store/terminal-tab-pty-ownership.test.ts b/src/main/persistence/loading-store/terminal-tab-pty-ownership.test.ts index cb266d1b16a..730eca1a8dd 100644 --- a/src/main/persistence/loading-store/terminal-tab-pty-ownership.test.ts +++ b/src/main/persistence/loading-store/terminal-tab-pty-ownership.test.ts @@ -31,12 +31,12 @@ describe('tabRowPtyIdAfterLeafBinding', () => { ).toBe('pty-1') }) - it('reclaims a row that names a PTY no leaf holds', () => { + it('preserves a non-null row until the renderer clears or replaces it', () => { expect( tabRowPtyIdAfterLeafBinding({ ptyId: 'pty-gone' }, { [LEAF_A]: 'pty-1' }, LEAF_B, 'pty-2') - ).toBe('pty-2') + ).toBe('pty-gone') expect(tabRowPtyIdAfterLeafBinding({ ptyId: 'pty-gone' }, undefined, LEAF_A, 'pty-1')).toBe( - 'pty-1' + 'pty-gone' ) }) }) diff --git a/src/main/persistence/loading-store/terminal-tab-pty-ownership.ts b/src/main/persistence/loading-store/terminal-tab-pty-ownership.ts index 1004dd27593..d353309bf35 100644 --- a/src/main/persistence/loading-store/terminal-tab-pty-ownership.ts +++ b/src/main/persistence/loading-store/terminal-tab-pty-ownership.ts @@ -8,8 +8,8 @@ type LeafPtyIds = Readonly> | undefined * because a remount reattaches the tab to whatever the row says. Main must agree, or every * sibling pane's reattach rewrites the row and the two sides ping-pong forever. * - * The row is rewritten only when it names nothing useful: it is null, it points at the PTY this - * very leaf is replacing, or it names a PTY no leaf of the layout holds any more. + * The row is rewritten only when it is null or points at the PTY this leaf is replacing. + * A missing leaf is not evidence that a non-null row can be reassigned. */ export function tabRowPtyIdAfterLeafBinding( tab: Pick, @@ -21,8 +21,5 @@ export function tabRowPtyIdAfterLeafBinding( if (current === null || current === ptyIdsByLeafId?.[leafId]) { return ptyId } - const heldByAnotherLeaf = Object.entries(ptyIdsByLeafId ?? {}).some( - ([otherLeafId, otherPtyId]) => otherLeafId !== leafId && otherPtyId === current - ) - return heldByAnotherLeaf ? current : ptyId + return current }