diff --git a/src/main/macos-tcc-log-stream-orphans.test.ts b/src/main/macos-tcc-log-stream-orphans.test.ts new file mode 100644 index 00000000000..a5c8f2ab7fd --- /dev/null +++ b/src/main/macos-tcc-log-stream-orphans.test.ts @@ -0,0 +1,85 @@ +import { describe, expect, it, vi } from 'vitest' +import { + findOrphanedTccLogStreams, + reclaimOrphanedTccLogStreams +} from './macos-tcc-log-stream-orphans' +import { parsePsArgsLine, type ProcessIdentityRow } from './opencode/opencode-client-sweep' + +// Captured from `ps -eo pid=,ppid=,etime=,args=` on a Mac holding leaked watchers. +const LEGACY_ARGS = + '/usr/bin/log stream --predicate subsystem == "com.apple.TCC" AND eventMessage CONTAINS "AUTHREQ_PROMPTING" --info --style compact' + +function row( + pid: number, + ppid: number, + args = LEGACY_ARGS, + executable = '/usr/bin/log' +): ProcessIdentityRow { + const parsed = parsePsArgsLine(`${pid} ${ppid} 01:00 ${args}`, Date.now()) + if (!parsed) { + throw new Error('unparseable fixture') + } + return { ...parsed, executable } +} + +describe('findOrphanedTccLogStreams', () => { + it('matches only launchd-parented copies of the exact watcher command', () => { + expect( + findOrphanedTccLogStreams([ + row(10, 1), + row(11, 4321), + row(12, 1, '/usr/bin/log stream --predicate subsystem == "com.apple.TCC" --style compact'), + row(13, 1, '/usr/bin/log show --last 1m'), + // A pid recycled between the args and comm sweeps, or an unreadable comm. + row(14, 1, LEGACY_ARGS, '/usr/bin/yes'), + row(15, 1, LEGACY_ARGS, '') + ]).map((match) => match.pid) + ).toEqual([10]) + }) +}) + +describe('reclaimOrphanedTccLogStreams', () => { + it('terminates each orphan and tolerates ones that already exited', async () => { + const kill = vi.fn((pid: number) => { + if (pid === 21) { + throw new Error('ESRCH') + } + }) + const reclaimed = await reclaimOrphanedTccLogStreams({ + platform: 'darwin', + sweep: async () => [row(20, 1), row(21, 1), row(22, 99)], + readProcess: async (pid) => row(pid, 1), + kill + }) + expect(kill.mock.calls).toEqual([ + [20, 'SIGTERM'], + [21, 'SIGTERM'] + ]) + expect(reclaimed).toBe(1) + }) + + it('skips a pid whose identity changed or cannot be re-read before signalling', async () => { + const kill = vi.fn() + const restarted = { ...row(42, 1), startedAtMs: Date.now() + 60_000 } + const current = new Map([ + [40, null], + [41, row(41, 1, '/usr/bin/log stream --style compact')], + [42, restarted], + [43, row(43, 777)] + ]) + const reclaimed = await reclaimOrphanedTccLogStreams({ + platform: 'darwin', + sweep: async () => [row(40, 1), row(41, 1), row(42, 1), row(43, 1)], + readProcess: async (pid) => current.get(pid) ?? null, + kill + }) + expect(kill).not.toHaveBeenCalled() + expect(reclaimed).toBe(0) + }) + + it('never sweeps off macOS', async () => { + const sweep = vi.fn(async () => [row(30, 1)]) + expect(await reclaimOrphanedTccLogStreams({ platform: 'linux', sweep })).toBe(0) + expect(sweep).not.toHaveBeenCalled() + }) +}) diff --git a/src/main/macos-tcc-log-stream-orphans.ts b/src/main/macos-tcc-log-stream-orphans.ts new file mode 100644 index 00000000000..8503fab6354 --- /dev/null +++ b/src/main/macos-tcc-log-stream-orphans.ts @@ -0,0 +1,82 @@ +import { runProcess } from '@orca/process-host' +import { + parsePsArgsLine, + splitCommandLineArgv, + sweepProcessIdentities, + type ProcessIdentityRow +} from './opencode/opencode-client-sweep' +import { LOG_PREDICATE } from './macos-tcc-prompt-watch' + +/** The exact argv that Orca builds before the sh wrapper spawned `log stream` directly. */ +const LEGACY_LOG_STREAM_COMMAND = splitCommandLineArgv( + ['/usr/bin/log', 'stream', '--predicate', LOG_PREDICATE, '--info', '--style', 'compact'].join(' ') +).join(' ') + +// Why: `etime` has 1 s resolution and two reads of it can straddle a tick. +const START_TIME_TOLERANCE_MS = 2_000 + +function isLegacyOrphan(row: ProcessIdentityRow): boolean { + return row.ppid === 1 && row.argv.join(' ') === LEGACY_LOG_STREAM_COMMAND +} + +/** + * Why: older builds left this `log stream` running under launchd whenever Orca died + * uncleanly, and those orphans outlive every later launch. A live watcher's + * `log stream` is parented by its wrapper, so only launchd's children (ppid 1) match. + * `executable` comes from a later `ps` than argv, so a pid recycled between them fails. + */ +export function findOrphanedTccLogStreams( + rows: readonly ProcessIdentityRow[] +): ProcessIdentityRow[] { + return rows.filter((row) => row.executable === '/usr/bin/log' && isLegacyOrphan(row)) +} + +/** One-snapshot re-read of a single pid, so its ppid, start time and argv agree. */ +async function readProcessIdentity(pid: number): Promise { + const result = await runProcess({ + program: 'ps', + args: ['-o', 'pid=,ppid=,etime=,args=', '-p', String(pid)], + timeoutMs: 5_000 + }) + return result.code === 0 && !result.timedOut ? parsePsArgsLine(result.stdout, Date.now()) : null +} + +export async function reclaimOrphanedTccLogStreams( + deps: { + platform?: NodeJS.Platform + sweep?: () => Promise + readProcess?: (pid: number) => Promise + kill?: (pid: number, signal: NodeJS.Signals) => void + } = {} +): Promise { + if ((deps.platform ?? process.platform) !== 'darwin') { + return 0 + } + const readProcess = deps.readProcess ?? readProcessIdentity + const kill = deps.kill ?? ((pid, signal) => process.kill(pid, signal)) + let reclaimed = 0 + for (const candidate of findOrphanedTccLogStreams( + await (deps.sweep ?? sweepProcessIdentities)() + )) { + try { + // Why: the sweep joins two `ps` snapshots, so re-read right before signalling + // and skip anything whose identity changed or can no longer be confirmed. + const current = await readProcess(candidate.pid) + if ( + !current || + !isLegacyOrphan(current) || + Math.abs(current.startedAtMs - candidate.startedAtMs) > START_TIME_TOLERANCE_MS + ) { + continue + } + kill(candidate.pid, 'SIGTERM') + reclaimed++ + } catch { + // Already gone, or another user's process. + } + } + if (reclaimed > 0) { + console.info(`[tcc-prompt-watch] reclaimed ${reclaimed} orphaned log stream process(es)`) + } + return reclaimed +} diff --git a/src/main/macos-tcc-prompt-notice.test.ts b/src/main/macos-tcc-prompt-notice.test.ts index e8745b67c61..2190f13211b 100644 --- a/src/main/macos-tcc-prompt-notice.test.ts +++ b/src/main/macos-tcc-prompt-notice.test.ts @@ -10,6 +10,9 @@ vi.mock('./codex-accounts/fs-utils', () => ({ writeFileAtomically: (...args: unknown[]) => writeFileAtomically(...args) })) vi.mock('./persistence', () => ({ getCanonicalUserDataPath: () => '/tmp/orca-tcc-notice-test' })) +vi.mock('./macos-tcc-log-stream-orphans', () => ({ + reclaimOrphanedTccLogStreams: vi.fn(async () => 0) +})) vi.mock('./macos-tcc-prompt-watch', () => ({ MacosTccPromptWatch: class { constructor(options: { onPrompt: () => void }) { diff --git a/src/main/macos-tcc-prompt-notice.ts b/src/main/macos-tcc-prompt-notice.ts index c51367d8c6a..595b8fe9363 100644 --- a/src/main/macos-tcc-prompt-notice.ts +++ b/src/main/macos-tcc-prompt-notice.ts @@ -4,6 +4,7 @@ import type { BrowserWindow } from 'electron' import { writeFileAtomically } from './codex-accounts/fs-utils' import { getCanonicalUserDataPath } from './persistence' import { MacosTccPromptWatch } from './macos-tcc-prompt-watch' +import { reclaimOrphanedTccLogStreams } from './macos-tcc-log-stream-orphans' /** * Surfaces Full Disk Access guidance only to users macOS is actually prompting @@ -53,6 +54,7 @@ let nextClaimId = 0 let pendingClaim: { claimId: number; ownerToken: number } | null = null let deferredWatchStartTimer: ReturnType | null = null let deferredWatchStartGeneration = 0 +let orphanReclaimScheduled = false function tallyPath(): string { return join(getCanonicalUserDataPath(), 'macos-tcc-prompt-tally.json') @@ -223,6 +225,14 @@ export function initTccPromptNotice( if (process.platform !== 'darwin') { return } + if (!orphanReclaimScheduled) { + orphanReclaimScheduled = true + // Why: runs even after the notice is dismissed, since older builds' orphans are still alive. + setTimeout( + () => void reclaimOrphanedTccLogStreams(), + TCC_PROMPT_WATCH_START_FALLBACK_MS + ).unref() + } if (watch) { trackMainWindow(mainWindow) startWatchAfterFirstVisibleProgress( diff --git a/src/main/macos-tcc-prompt-watch.test.ts b/src/main/macos-tcc-prompt-watch.test.ts index a0e9d9370a6..025cbc843f4 100644 --- a/src/main/macos-tcc-prompt-watch.test.ts +++ b/src/main/macos-tcc-prompt-watch.test.ts @@ -91,12 +91,16 @@ describe('isOrcaAttributedPrompt', () => { function createFakeLogStream(): { child: LogStreamChild + stdin: PassThrough stdout: PassThrough killed: string[] } { + const stdin = new PassThrough() const stdout = new PassThrough() const killed: string[] = [] + // oxlint-disable-next-line typescript/consistent-type-assertions -- SAFETY: the watcher only touches stdin/stdout/kill and EventEmitter events, all provided here. const child = Object.assign(new EventEmitter(), { + stdin, stdout, stderr: new PassThrough(), kill: (signal?: string) => { @@ -104,7 +108,7 @@ function createFakeLogStream(): { return true } }) as unknown as LogStreamChild - return { child, stdout, killed } + return { child, stdin, stdout, killed } } // Why: the watcher is darwin-gated, so CI (Linux) would silently no-op every @@ -158,11 +162,26 @@ describe('MacosTccPromptWatch', () => { }) it('kills the child on stop so it cannot outlive app quit', () => { - const { child, killed } = createFakeLogStream() + const { child, stdin, killed } = createFakeLogStream() const watch = new MacosTccPromptWatch({ onPrompt: vi.fn(), spawnLogStream: () => child }) watch.start() watch.stop() expect(killed).toEqual(['SIGTERM']) + // Why: closing the parent-death pipe is the backstop if the wrapper missed the signal. + expect(stdin.destroyed).toBe(true) + }) + + it('closes the parent-death pipe of a child that terminated on its own', () => { + const { child, stdin } = createFakeLogStream() + const watch = new MacosTccPromptWatch({ + onPrompt: vi.fn(), + spawnLogStream: () => child, + restartDelayMs: 60_000 + }) + watch.start() + child.emit('exit', 1) + expect(stdin.destroyed).toBe(true) + watch.stop() }) it('restarts once after an unexpected termination without creating a retry loop', async () => { diff --git a/src/main/macos-tcc-prompt-watch.ts b/src/main/macos-tcc-prompt-watch.ts index acff095a82b..95d65a99e31 100644 --- a/src/main/macos-tcc-prompt-watch.ts +++ b/src/main/macos-tcc-prompt-watch.ts @@ -1,9 +1,9 @@ import { spawn, type ChildProcessByStdio } from 'node:child_process' import { createInterface, type Interface } from 'node:readline' -import type { Readable } from 'node:stream' +import type { Readable, Writable } from 'node:stream' -/** Why: stdin is 'ignore', so this is narrower than ChildProcessWithoutNullStreams. */ -export type LogStreamChild = ChildProcessByStdio +/** Why: stdin is a never-written pipe whose EOF tells the wrapper that Orca died. */ +export type LogStreamChild = ChildProcessByStdio /** * Counts the macOS TCC consent dialogs that name Orca as the responsible @@ -36,7 +36,8 @@ const WATCHED_SERVICES = new Set([ 'kTCCServiceSystemPolicyDownloadsFolder' ]) -const LOG_PREDICATE = 'subsystem == "com.apple.TCC" AND eventMessage CONTAINS "AUTHREQ_PROMPTING"' +export const LOG_PREDICATE = + 'subsystem == "com.apple.TCC" AND eventMessage CONTAINS "AUTHREQ_PROMPTING"' export type TccPromptEvent = { /** TCC service the dialog was raised for, e.g. `kTCCServiceSystemPolicyAppData`. */ @@ -88,14 +89,33 @@ export type TccPromptWatchOptions = { restartDelayMs?: number } +// Why: `log stream` never notices its parent dying (it only writes on a rare +// match), so a crashed or SIGKILLed Orca orphaned it forever. The wrapper kills +// it when our stdin pipe hits EOF, and exits when it exits. fd 3 is needed +// because async lists in a non-interactive sh get stdin=/dev/null. The trap is +// armed before the fork; `term` covers a signal that lands before `log_pid` is set. +// `set +eu` because an inherited SHELLOPTS=errexit would end the reader on read's EOF status. +const LOG_STREAM_WRAPPER_SCRIPT = `set +eu +exec 3<&0 +log_pid= +term= +trap 'term=1; [ -n "$log_pid" ] && kill "$log_pid" 2>/dev/null' TERM INT HUP +/usr/bin/log stream --predicate "$1" --info --style compact /dev/null +{ read -r _ <&3; kill "$log_pid" 2>/dev/null; } & +reader_pid=$! +wait "$log_pid" +status=$? +kill "$reader_pid" 2>/dev/null +exit "$status"` + function spawnDefaultLogStream(): LogStreamChild { // Why: the predicate is evaluated inside the logging system, so this delivers // ~1 line per real dialog instead of the ~30/s the TCC subsystem emits raw. - return spawn( - '/usr/bin/log', - ['stream', '--predicate', LOG_PREDICATE, '--info', '--style', 'compact'], - { stdio: ['ignore', 'pipe', 'pipe'] } - ) + return spawn('/bin/sh', ['-c', LOG_STREAM_WRAPPER_SCRIPT, 'sh', LOG_PREDICATE], { + stdio: ['pipe', 'pipe', 'pipe'] + }) } /** @@ -138,6 +158,8 @@ export class MacosTccPromptWatch { this.reader?.close() this.reader = null this.child = null + // Why: EOF on stdin makes any surviving wrapper reader kill its log stream. + child.stdin.destroy() if (this.stopped || this.restartAttempted) { return } @@ -167,6 +189,7 @@ export class MacosTccPromptWatch { this.reader = null // Why: log stream ignores a closed stdout, so the child needs an explicit kill or it outlives quit. this.child?.kill('SIGTERM') + this.child?.stdin.destroy() this.child = null } }