From 747b241145cf02c48819d7508015461143240b63 Mon Sep 17 00:00:00 2001 From: Brennan Benson <79079362+brennanb2025@users.noreply.github.com> Date: Tue, 28 Jul 2026 16:43:30 -0700 Subject: [PATCH] feat(main): record main-thread hangs so we can measure them (#10256) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A deadlocked main thread never crashes, so it leaves no crash report and no artifact — incidence has been unmeasurable (n=1 confirmed, macOS 26.5.1, FB24004458 / electron#52437). This forks a plain-Node watchdog sibling under ELECTRON_RUN_AS_NODE that survives the deadlock, listens for a 2s heartbeat, and after 45s of silence writes a marker to userData. The next launch consumes it, records a durable crash breadcrumb, and emits a main_thread_hang_detected telemetry event carrying unresponsive_ms and self_recovered. Observes only — it never kills or relaunches the parent. A true positive recovers nothing force-quitting wouldn't, while a false positive would SIGKILL a live main thread mid-write. self_recovered counts exactly the stalls such a killer would have gotten wrong, so recovery can be built on evidence if the field numbers justify it. macOS-only, packaged-only (ORCA_HANG_WATCHDOG_FORCE=1 to test), with sleep-gap suppression and idempotent shutdown on will-quit. --- build-plugins/plain-node-entry-guard.ts | 1 + config/electron-builder.config.cjs | 1 + .../scripts/electron-builder-config.test.mjs | 8 ++ electron.vite.config.ts | 6 + .../hang-detection-marker.test.ts | 76 ++++++++++ .../hang-watchdog/hang-detection-marker.ts | 54 +++++++ .../hang-watchdog-child-loop.test.ts | 131 +++++++++++++++++ .../hang-watchdog/hang-watchdog-child-loop.ts | 51 +++++++ .../hang-watchdog/hang-watchdog-entry-path.ts | 17 +++ .../main-thread-hang-telemetry.test.ts | 39 ++++++ .../main-thread-hang-watchdog-entry.test.ts | 106 ++++++++++++++ .../main-thread-hang-watchdog-entry.ts | 72 ++++++++++ .../main-thread-hang-watchdog.test.ts | 132 ++++++++++++++++++ .../main-thread-hang-watchdog.ts | 81 +++++++++++ src/main/index.ts | 26 ++++ src/shared/telemetry-events.ts | 13 ++ 16 files changed, 814 insertions(+) create mode 100644 src/main/hang-watchdog/hang-detection-marker.test.ts create mode 100644 src/main/hang-watchdog/hang-detection-marker.ts create mode 100644 src/main/hang-watchdog/hang-watchdog-child-loop.test.ts create mode 100644 src/main/hang-watchdog/hang-watchdog-child-loop.ts create mode 100644 src/main/hang-watchdog/hang-watchdog-entry-path.ts create mode 100644 src/main/hang-watchdog/main-thread-hang-telemetry.test.ts create mode 100644 src/main/hang-watchdog/main-thread-hang-watchdog-entry.test.ts create mode 100644 src/main/hang-watchdog/main-thread-hang-watchdog-entry.ts create mode 100644 src/main/hang-watchdog/main-thread-hang-watchdog.test.ts create mode 100644 src/main/hang-watchdog/main-thread-hang-watchdog.ts diff --git a/build-plugins/plain-node-entry-guard.ts b/build-plugins/plain-node-entry-guard.ts index a7ad171a4..6638cca97 100644 --- a/build-plugins/plain-node-entry-guard.ts +++ b/build-plugins/plain-node-entry-guard.ts @@ -21,6 +21,7 @@ type OutputChunk = Rollup.OutputChunk const PLAIN_NODE_ENTRY_NAMES = [ 'daemon-entry', 'parcel-watcher-process-entry', + 'main-thread-hang-watchdog-entry', 'computer-sidecar', 'agent-hooks/managed-agent-hook-controls', 'codex/codex-app-server-grant-entry' diff --git a/config/electron-builder.config.cjs b/config/electron-builder.config.cjs index 0a96abb6d..91cb45da2 100644 --- a/config/electron-builder.config.cjs +++ b/config/electron-builder.config.cjs @@ -153,6 +153,7 @@ module.exports = { 'out/main/plugin-host-entry.js', 'out/main/computer-sidecar.js', 'out/main/parcel-watcher-process-entry.js', + 'out/main/main-thread-hang-watchdog-entry.js', 'out/main/chunks/**', 'resources/**', 'node_modules/ws/**', diff --git a/config/scripts/electron-builder-config.test.mjs b/config/scripts/electron-builder-config.test.mjs index 442b7bd84..9712e5eda 100644 --- a/config/scripts/electron-builder-config.test.mjs +++ b/config/scripts/electron-builder-config.test.mjs @@ -166,6 +166,14 @@ describe('electron-builder config', () => { ) }) + // Why: the watchdog only arms in packaged builds, and its ELECTRON_RUN_AS_NODE + // fork resolves the entry from app.asar.unpacked — inside the asar it never runs. + it('unpacks the forked main-thread hang-watchdog entry', () => { + expect(electronBuilderConfig.asarUnpack).toEqual( + expect.arrayContaining(['out/main/main-thread-hang-watchdog-entry.js']) + ) + }) + it('uses the multi-size icon source for Linux packages', () => { expect(electronBuilderConfig.linux.icon).toBe('resources/build/icon.icns') }) diff --git a/electron.vite.config.ts b/electron.vite.config.ts index d5fb6ebd1..738821148 100644 --- a/electron.vite.config.ts +++ b/electron.vite.config.ts @@ -208,6 +208,12 @@ export const electronViteConfig: UserConfig = { // Why: forked with ELECTRON_RUN_AS_NODE so @parcel/watcher faults // can't take down the main process (issue #7547). 'parcel-watcher-process-entry': resolve('src/main/ipc/parcel-watcher-process-entry.ts'), + // Why: forked with ELECTRON_RUN_AS_NODE so it survives a deadlocked + // main thread (macOS 26 AppKit scene-update deadlock) and can record + // the stall for the next launch to report. + 'main-thread-hang-watchdog-entry': resolve( + 'src/main/hang-watchdog/main-thread-hang-watchdog-entry.ts' + ), // Why: run under ELECTRON_RUN_AS_NODE while the caller blocks on // spawnSync — codex app-server trust grants need a live event loop // but must finish before a Codex pane launch proceeds. diff --git a/src/main/hang-watchdog/hang-detection-marker.test.ts b/src/main/hang-watchdog/hang-detection-marker.test.ts new file mode 100644 index 000000000..17dbd3716 --- /dev/null +++ b/src/main/hang-watchdog/hang-detection-marker.test.ts @@ -0,0 +1,76 @@ +import { mkdtempSync, rmSync, writeFileSync, existsSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { afterEach, beforeEach, describe, expect, it } from 'vitest' +import { + consumeHangDetectionMarker, + hangDetectionMarkerPath, + writeHangDetectionMarker +} from './hang-detection-marker' + +describe('hang detection marker', () => { + let dir: string + + beforeEach(() => { + dir = mkdtempSync(join(tmpdir(), 'hang-marker-')) + }) + + afterEach(() => { + rmSync(dir, { recursive: true, force: true }) + }) + + it('round-trips a marker and deletes it on consume', () => { + const markerPath = hangDetectionMarkerPath(dir) + writeHangDetectionMarker(markerPath, { + detectedAt: 123, + parentPid: 456, + unresponsiveMs: 45000, + selfRecovered: false + }) + expect(consumeHangDetectionMarker(markerPath)).toEqual({ + detectedAt: 123, + parentPid: 456, + unresponsiveMs: 45000, + selfRecovered: false + }) + expect(existsSync(markerPath)).toBe(false) + expect(consumeHangDetectionMarker(markerPath)).toBeNull() + }) + + it('round-trips a self-recovered marker', () => { + const markerPath = hangDetectionMarkerPath(dir) + writeHangDetectionMarker(markerPath, { + detectedAt: 1, + parentPid: 2, + unresponsiveMs: 61000, + selfRecovered: true + }) + expect(consumeHangDetectionMarker(markerPath)?.selfRecovered).toBe(true) + }) + + it('returns null for a missing marker', () => { + expect(consumeHangDetectionMarker(hangDetectionMarkerPath(dir))).toBeNull() + }) + + // Why: a marker written by the detect leg has no selfRecovered field until the resolve leg + // rewrites it, and "never resolved" is the conservative reading of its absence. + it('treats a missing selfRecovered flag as an unresolved hang', () => { + const markerPath = hangDetectionMarkerPath(dir) + writeFileSync( + markerPath, + JSON.stringify({ detectedAt: 1, parentPid: 2, unresponsiveMs: 45000 }) + ) + expect(consumeHangDetectionMarker(markerPath)?.selfRecovered).toBe(false) + }) + + it('returns null for corrupted or incomplete markers and still deletes them', () => { + const markerPath = hangDetectionMarkerPath(dir) + writeFileSync(markerPath, 'not json') + expect(consumeHangDetectionMarker(markerPath)).toBeNull() + expect(existsSync(markerPath)).toBe(false) + + writeFileSync(markerPath, JSON.stringify({ detectedAt: 1 })) + expect(consumeHangDetectionMarker(markerPath)).toBeNull() + expect(existsSync(markerPath)).toBe(false) + }) +}) diff --git a/src/main/hang-watchdog/hang-detection-marker.ts b/src/main/hang-watchdog/hang-detection-marker.ts new file mode 100644 index 000000000..a6e6fbddd --- /dev/null +++ b/src/main/hang-watchdog/hang-detection-marker.ts @@ -0,0 +1,54 @@ +import { readFileSync, rmSync, writeFileSync } from 'node:fs' +import { join } from 'node:path' + +// Why: written by the plain-Node watchdog child when main-thread heartbeats stop, and rewritten if +// they resume; consumed on the next launch to report how long the stall lasted and whether it ever +// cleared. `selfRecovered` separates a real deadlock from a long-but-survivable stall — the two are +// indistinguishable at detection time, and only the latter would have been a destructive kill. +export type HangDetectionMarker = { + detectedAt: number + parentPid: number + unresponsiveMs: number + selfRecovered: boolean +} + +export function hangDetectionMarkerPath(userDataPath: string): string { + return join(userDataPath, 'main-thread-hang.json') +} + +export function writeHangDetectionMarker(markerPath: string, marker: HangDetectionMarker): void { + writeFileSync(markerPath, JSON.stringify(marker)) +} + +export function consumeHangDetectionMarker(markerPath: string): HangDetectionMarker | null { + let raw: string + try { + raw = readFileSync(markerPath, 'utf8') + } catch { + return null + } + try { + rmSync(markerPath, { force: true }) + } catch { + // Why: a marker that cannot be deleted must not block startup; worst case is one duplicate breadcrumb. + } + try { + const parsed = JSON.parse(raw) as Partial + if ( + typeof parsed.detectedAt !== 'number' || + typeof parsed.parentPid !== 'number' || + typeof parsed.unresponsiveMs !== 'number' + ) { + return null + } + return { + detectedAt: parsed.detectedAt, + parentPid: parsed.parentPid, + unresponsiveMs: parsed.unresponsiveMs, + // Why: a marker left by the detect leg and never rewritten means the stall never cleared. + selfRecovered: parsed.selfRecovered === true + } + } catch { + return null + } +} diff --git a/src/main/hang-watchdog/hang-watchdog-child-loop.test.ts b/src/main/hang-watchdog/hang-watchdog-child-loop.test.ts new file mode 100644 index 000000000..8d390c04e --- /dev/null +++ b/src/main/hang-watchdog/hang-watchdog-child-loop.test.ts @@ -0,0 +1,131 @@ +import { describe, expect, it, vi } from 'vitest' +import { createHangWatchdogChildLoop } from './hang-watchdog-child-loop' + +const TIMEOUT_MS = 45_000 +const CHECK_INTERVAL_MS = 5_000 + +function loopWithClock(startAt = 0) { + let now = startAt + const onHangDetected = vi.fn() + const onHangResolved = vi.fn() + const loop = createHangWatchdogChildLoop({ + timeoutMs: TIMEOUT_MS, + checkIntervalMs: CHECK_INTERVAL_MS, + now: () => now, + onHangDetected, + onHangResolved + }) + return { loop, onHangDetected, onHangResolved, advance: (ms: number) => (now += ms) } +} + +describe('createHangWatchdogChildLoop', () => { + it('does not fire while heartbeats keep arriving', () => { + const { loop, onHangDetected, advance } = loopWithClock() + for (let i = 0; i < 100; i++) { + advance(CHECK_INTERVAL_MS) + loop.recordHeartbeat() + loop.tick() + } + expect(onHangDetected).not.toHaveBeenCalled() + }) + + it('fires once when heartbeats stop for longer than the timeout', () => { + const { loop, onHangDetected, advance } = loopWithClock() + loop.recordHeartbeat() + for (let i = 0; i < 12; i++) { + advance(CHECK_INTERVAL_MS) + loop.tick() + } + expect(onHangDetected).toHaveBeenCalledTimes(1) + advance(CHECK_INTERVAL_MS) + loop.tick() + expect(onHangDetected).toHaveBeenCalledTimes(1) + }) + + // Why: the breadcrumb reports observed silence, so it must be the measured gap at the firing + // tick (the first one strictly past the timeout), not the timeout constant. + it('reports the measured stall duration, not the timeout', () => { + const { loop, onHangDetected, advance } = loopWithClock() + loop.recordHeartbeat() + for (let i = 0; i < 12; i++) { + advance(CHECK_INTERVAL_MS) + loop.tick() + } + expect(onHangDetected).toHaveBeenCalledWith(50_000) + }) + + it('does not fire at exactly the timeout boundary', () => { + const { loop, onHangDetected, advance } = loopWithClock() + loop.recordHeartbeat() + for (let i = 0; i < 9; i++) { + advance(CHECK_INTERVAL_MS) + loop.tick() + } + expect(onHangDetected).not.toHaveBeenCalled() + }) + + it('treats a large tick gap as system sleep and restarts the wait', () => { + const { loop, onHangDetected, advance } = loopWithClock() + loop.recordHeartbeat() + // Simulate suspension: the check timer did not run for far longer than the timeout. + advance(TIMEOUT_MS * 4) + loop.tick() + expect(onHangDetected).not.toHaveBeenCalled() + // A responsive parent resumes heartbeats after wake; the loop must fire only after a fresh full timeout of silence. + for (let i = 0; i < 9; i++) { + advance(CHECK_INTERVAL_MS) + loop.tick() + } + expect(onHangDetected).not.toHaveBeenCalled() + for (let i = 0; i < 3; i++) { + advance(CHECK_INTERVAL_MS) + loop.tick() + } + expect(onHangDetected).toHaveBeenCalledTimes(1) + }) + + // Why: this is the measurement the whole PR exists for — a stall that clears would have been a + // destructive kill under the SIGKILL design, so it has to be counted separately. + it('reports resolution when heartbeats resume after a detected hang', () => { + const { loop, onHangDetected, onHangResolved, advance } = loopWithClock() + loop.recordHeartbeat() + for (let i = 0; i < 12; i++) { + advance(CHECK_INTERVAL_MS) + loop.tick() + } + expect(onHangDetected).toHaveBeenCalledTimes(1) + advance(CHECK_INTERVAL_MS) + loop.recordHeartbeat() + expect(onHangResolved).toHaveBeenCalledTimes(1) + expect(onHangResolved).toHaveBeenCalledWith(13 * CHECK_INTERVAL_MS) + }) + + it('does not report resolution when no hang was ever detected', () => { + const { loop, onHangResolved, advance } = loopWithClock() + for (let i = 0; i < 5; i++) { + advance(CHECK_INTERVAL_MS) + loop.recordHeartbeat() + loop.tick() + } + expect(onHangResolved).not.toHaveBeenCalled() + }) + + it('can detect a second hang after the first one resolved', () => { + const { loop, onHangDetected, onHangResolved, advance } = loopWithClock() + loop.recordHeartbeat() + for (let i = 0; i < 12; i++) { + advance(CHECK_INTERVAL_MS) + loop.tick() + } + advance(CHECK_INTERVAL_MS) + loop.recordHeartbeat() + expect(onHangResolved).toHaveBeenCalledTimes(1) + // Why: the tick clock must keep advancing during the first hang, or this first tick reads as a + // sleep gap and silently restarts the wait instead of arming it. + for (let i = 0; i < 12; i++) { + advance(CHECK_INTERVAL_MS) + loop.tick() + } + expect(onHangDetected).toHaveBeenCalledTimes(2) + }) +}) diff --git a/src/main/hang-watchdog/hang-watchdog-child-loop.ts b/src/main/hang-watchdog/hang-watchdog-child-loop.ts new file mode 100644 index 000000000..3a8ebb34f --- /dev/null +++ b/src/main/hang-watchdog/hang-watchdog-child-loop.ts @@ -0,0 +1,51 @@ +export type HangWatchdogChildLoopConfig = { + timeoutMs: number + checkIntervalMs: number + now: () => number + onHangDetected: (unresponsiveMs: number) => void + /** Heartbeats resumed after a detected hang — the main thread was stalled, not deadlocked. */ + onHangResolved: (unresponsiveMs: number) => void +} + +export type HangWatchdogChildLoop = { + recordHeartbeat: () => void + tick: () => void +} + +export function createHangWatchdogChildLoop( + config: HangWatchdogChildLoopConfig +): HangWatchdogChildLoop { + let lastHeartbeatAt = config.now() + let lastTickAt = config.now() + let detected = false + return { + recordHeartbeat: () => { + const now = config.now() + if (detected) { + detected = false + config.onHangResolved(now - lastHeartbeatAt) + } + lastHeartbeatAt = now + }, + tick: () => { + const now = config.now() + const tickGap = now - lastTickAt + // Why: advance the tick clock even while a hang is outstanding, or the first tick after the + // stall clears reads as a huge gap and gets misread as system sleep. + lastTickAt = now + if (detected) { + return + } + // Why: system sleep suspends this process too; a huge tick gap means suspension, not a parent hang, so restart the wait from scratch. + if (tickGap > config.checkIntervalMs * 3) { + lastHeartbeatAt = now + return + } + const unresponsiveMs = now - lastHeartbeatAt + if (unresponsiveMs > config.timeoutMs) { + detected = true + config.onHangDetected(unresponsiveMs) + } + } + } +} diff --git a/src/main/hang-watchdog/hang-watchdog-entry-path.ts b/src/main/hang-watchdog/hang-watchdog-entry-path.ts new file mode 100644 index 000000000..74f8b1d00 --- /dev/null +++ b/src/main/hang-watchdog/hang-watchdog-entry-path.ts @@ -0,0 +1,17 @@ +import { existsSync } from 'node:fs' +import { join } from 'node:path' + +export function resolveHangWatchdogEntryPath( + appPath: string, + isPackaged: boolean, + pathExists: (candidate: string) => boolean = existsSync +): string { + // Why: ELECTRON_RUN_AS_NODE bypasses asar integration, so the packaged entry must be forked from app.asar.unpacked. + const basePath = isPackaged ? appPath.replace('app.asar', 'app.asar.unpacked') : appPath + const adjacentBuildEntry = join(basePath, 'main-thread-hang-watchdog-entry.js') + // Why: electron-vite's unpackaged appPath is already out/main; appending out/main again would silently disable the watchdog in dev and E2E builds. + if (!isPackaged && pathExists(adjacentBuildEntry)) { + return adjacentBuildEntry + } + return join(basePath, 'out', 'main', 'main-thread-hang-watchdog-entry.js') +} diff --git a/src/main/hang-watchdog/main-thread-hang-telemetry.test.ts b/src/main/hang-watchdog/main-thread-hang-telemetry.test.ts new file mode 100644 index 000000000..1ef4d0536 --- /dev/null +++ b/src/main/hang-watchdog/main-thread-hang-telemetry.test.ts @@ -0,0 +1,39 @@ +import { describe, expect, it } from 'vitest' +import { eventSchemas } from '../../shared/telemetry-events' + +describe('main_thread_hang_detected telemetry schema', () => { + it('accepts an unresolved hang', () => { + expect( + eventSchemas.main_thread_hang_detected.safeParse({ + unresponsive_ms: 50_000, + self_recovered: false + }).success + ).toBe(true) + }) + + it('accepts a self-recovered stall', () => { + expect( + eventSchemas.main_thread_hang_detected.safeParse({ + unresponsive_ms: 61_000, + self_recovered: true + }).success + ).toBe(true) + }) + + // Why: strict() keeps unplanned fields (paths, pids, window titles) off the wire. + it('rejects unknown fields and non-integer durations', () => { + expect( + eventSchemas.main_thread_hang_detected.safeParse({ + unresponsive_ms: 50_000, + self_recovered: false, + parent_pid: 4242 + }).success + ).toBe(false) + expect( + eventSchemas.main_thread_hang_detected.safeParse({ + unresponsive_ms: 50_000.5, + self_recovered: false + }).success + ).toBe(false) + }) +}) diff --git a/src/main/hang-watchdog/main-thread-hang-watchdog-entry.test.ts b/src/main/hang-watchdog/main-thread-hang-watchdog-entry.test.ts new file mode 100644 index 000000000..0f36e8aca --- /dev/null +++ b/src/main/hang-watchdog/main-thread-hang-watchdog-entry.test.ts @@ -0,0 +1,106 @@ +import { mkdtempSync, rmSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' +import { consumeHangDetectionMarker } from './hang-detection-marker' + +const { spawnMock } = vi.hoisted(() => ({ + spawnMock: vi.fn(() => ({ unref: vi.fn() })) +})) + +vi.mock('node:child_process', () => ({ + spawn: spawnMock +})) + +import { recordHangObservation } from './main-thread-hang-watchdog-entry' + +describe('recordHangObservation', () => { + let dir: string + let killSpy: ReturnType + let exitSpy: ReturnType + + beforeEach(() => { + dir = mkdtempSync(join(tmpdir(), 'hang-detect-')) + spawnMock.mockClear() + killSpy = vi.spyOn(process, 'kill').mockImplementation(() => true) + exitSpy = vi.spyOn(process, 'exit').mockImplementation(() => undefined as never) + }) + + afterEach(() => { + killSpy.mockRestore() + exitSpy.mockRestore() + rmSync(dir, { recursive: true, force: true }) + }) + + it('records an unresolved hang', () => { + const markerPath = join(dir, 'marker.json') + recordHangObservation({ + parentPid: 4242, + markerPath, + unresponsiveMs: 47_000, + selfRecovered: false + }) + expect(consumeHangDetectionMarker(markerPath)).toMatchObject({ + parentPid: 4242, + unresponsiveMs: 47_000, + selfRecovered: false + }) + }) + + it('overwrites the marker when the stall clears, keeping one observation per stall', () => { + const markerPath = join(dir, 'marker.json') + recordHangObservation({ + parentPid: 4242, + markerPath, + unresponsiveMs: 47_000, + selfRecovered: false + }) + recordHangObservation({ + parentPid: 4242, + markerPath, + unresponsiveMs: 62_000, + selfRecovered: true + }) + expect(consumeHangDetectionMarker(markerPath)).toMatchObject({ + unresponsiveMs: 62_000, + selfRecovered: true + }) + }) + + // Why: this is the safety contract of the whole PR. Observing a hang must never kill, relaunch, + // or exit — a false positive would SIGKILL a live main thread mid-write. If a future change + // reintroduces recovery, this test must fail loudly rather than ship silently. + it('never spawns, signals, or exits', () => { + recordHangObservation({ + parentPid: 4242, + markerPath: join(dir, 'marker.json'), + unresponsiveMs: 45_000, + selfRecovered: false + }) + expect(spawnMock).not.toHaveBeenCalled() + expect(killSpy).not.toHaveBeenCalled() + expect(exitSpy).not.toHaveBeenCalled() + }) + + it('survives an unwritable marker path', () => { + expect(() => + recordHangObservation({ + parentPid: 4242, + markerPath: join(dir, 'missing-subdir', 'marker.json'), + unresponsiveMs: 45_000, + selfRecovered: false + }) + ).not.toThrow() + }) + + it('is a no-op when no marker path is configured', () => { + expect(() => + recordHangObservation({ + parentPid: 4242, + markerPath: '', + unresponsiveMs: 45_000, + selfRecovered: false + }) + ).not.toThrow() + }) +}) diff --git a/src/main/hang-watchdog/main-thread-hang-watchdog-entry.ts b/src/main/hang-watchdog/main-thread-hang-watchdog-entry.ts new file mode 100644 index 000000000..8d45c725a --- /dev/null +++ b/src/main/hang-watchdog/main-thread-hang-watchdog-entry.ts @@ -0,0 +1,72 @@ +// Forked with ELECTRON_RUN_AS_NODE from the main process. Watches heartbeats from the main +// thread; if they stop (e.g. the macOS 26 AppKit scene-update deadlock) it records a marker so +// the next launch can report the stall, and rewrites it if the heartbeats come back. +// +// Why no kill: a deadlocked main thread has already lost whatever sat in the persistence debounce +// window, so killing it recovers nothing the user could not recover by force-quitting. A false +// positive, though, would SIGKILL a live main thread that was merely blocked — most plausibly on +// I/O, i.e. exactly when writes are in flight. All of the downside sits in the misfire, so this +// measures first: `selfRecovered` counts the stalls a killer would have gotten wrong. +// +// Must never import electron. +import { createHangWatchdogChildLoop } from './hang-watchdog-child-loop' +import { writeHangDetectionMarker } from './hang-detection-marker' + +const DEFAULT_TIMEOUT_MS = 45_000 +const DEFAULT_CHECK_INTERVAL_MS = 5_000 + +export function recordHangObservation(options: { + parentPid: number + markerPath: string + unresponsiveMs: number + selfRecovered: boolean +}): void { + if (!options.markerPath) { + return + } + try { + writeHangDetectionMarker(options.markerPath, { + detectedAt: Date.now(), + parentPid: options.parentPid, + unresponsiveMs: options.unresponsiveMs, + selfRecovered: options.selfRecovered + }) + } catch { + // Why: telemetry is best-effort; a marker that cannot be written must not take down the watchdog. + } +} + +function runWatchdog(parentPid: number): void { + const markerPath = process.env.ORCA_HANG_WATCHDOG_MARKER_PATH ?? '' + const timeoutMs = Number(process.env.ORCA_HANG_WATCHDOG_TIMEOUT_MS) || DEFAULT_TIMEOUT_MS + const checkIntervalMs = + Number(process.env.ORCA_HANG_WATCHDOG_CHECK_INTERVAL_MS) || DEFAULT_CHECK_INTERVAL_MS + + const loop = createHangWatchdogChildLoop({ + timeoutMs, + checkIntervalMs, + now: () => Date.now(), + onHangDetected: (unresponsiveMs) => + recordHangObservation({ parentPid, markerPath, unresponsiveMs, selfRecovered: false }), + // Why: rewriting the marker keeps one observation per stall rather than two rows to reconcile. + onHangResolved: (unresponsiveMs) => + recordHangObservation({ parentPid, markerPath, unresponsiveMs, selfRecovered: true }) + }) + + process.on('message', (message) => { + const type = (message as { type?: string } | null)?.type + if (type === 'heartbeat') { + loop.recordHeartbeat() + } else if (type === 'shutdown') { + process.exit(0) + } + }) + // Why: a normal parent exit closes the IPC channel; the watchdog must not outlive it and misfire. + process.on('disconnect', () => process.exit(0)) + setInterval(() => loop.tick(), checkIntervalMs) +} + +const configuredParentPid = Number(process.env.ORCA_HANG_WATCHDOG_PARENT_PID) +if (Number.isInteger(configuredParentPid) && configuredParentPid > 0) { + runWatchdog(configuredParentPid) +} diff --git a/src/main/hang-watchdog/main-thread-hang-watchdog.test.ts b/src/main/hang-watchdog/main-thread-hang-watchdog.test.ts new file mode 100644 index 000000000..b5c1063a9 --- /dev/null +++ b/src/main/hang-watchdog/main-thread-hang-watchdog.test.ts @@ -0,0 +1,132 @@ +import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' + +const { forkMock, appMock } = vi.hoisted(() => ({ + forkMock: vi.fn(), + appMock: { + isPackaged: true, + getAppPath: vi.fn(() => '/apps/orca/app.asar'), + on: vi.fn() + } +})) + +vi.mock('node:child_process', () => ({ + fork: forkMock +})) + +vi.mock('electron', () => ({ + app: appMock +})) + +import { installMainThreadHangWatchdog } from './main-thread-hang-watchdog' + +function withPlatform(platform: NodeJS.Platform, run: () => T): T { + const original = process.platform + Object.defineProperty(process, 'platform', { configurable: true, value: platform }) + try { + return run() + } finally { + Object.defineProperty(process, 'platform', { configurable: true, value: original }) + } +} + +function fakeChild() { + return { + connected: true, + stderr: { on: vi.fn() }, + on: vi.fn(), + send: vi.fn(), + disconnect: vi.fn(), + kill: vi.fn() + } +} + +describe('installMainThreadHangWatchdog', () => { + beforeEach(() => { + vi.useFakeTimers() + forkMock.mockReset() + appMock.on.mockReset() + appMock.isPackaged = true + delete process.env.ORCA_HANG_WATCHDOG_FORCE + }) + + afterEach(() => { + vi.useRealTimers() + }) + + it('is a no-op off macOS', () => { + expect( + withPlatform('win32', () => installMainThreadHangWatchdog({ userDataPath: '/ud' })) + ).toBeNull() + expect( + withPlatform('linux', () => installMainThreadHangWatchdog({ userDataPath: '/ud' })) + ).toBeNull() + expect(forkMock).not.toHaveBeenCalled() + }) + + it('is a no-op in unpackaged builds unless forced', () => { + appMock.isPackaged = false + expect( + withPlatform('darwin', () => installMainThreadHangWatchdog({ userDataPath: '/ud' })) + ).toBeNull() + process.env.ORCA_HANG_WATCHDOG_FORCE = '1' + const child = fakeChild() + forkMock.mockReturnValue(child) + expect( + withPlatform('darwin', () => installMainThreadHangWatchdog({ userDataPath: '/ud' })) + ).not.toBeNull() + delete process.env.ORCA_HANG_WATCHDOG_FORCE + }) + + it('forks the watchdog as plain Node with pid, bundle, and marker config', () => { + const child = fakeChild() + forkMock.mockReturnValue(child) + const handle = withPlatform('darwin', () => + installMainThreadHangWatchdog({ userDataPath: '/ud' }) + ) + expect(handle).not.toBeNull() + const [, , options] = forkMock.mock.calls[0] + expect(options.env.ELECTRON_RUN_AS_NODE).toBe('1') + expect(options.env.ORCA_HANG_WATCHDOG_PARENT_PID).toBe(String(process.pid)) + expect(options.env.ORCA_HANG_WATCHDOG_MARKER_PATH).toContain('/ud') + }) + + it('sends heartbeats on an interval and shutdown+disconnect on stop', () => { + const child = fakeChild() + forkMock.mockReturnValue(child) + const handle = withPlatform('darwin', () => + installMainThreadHangWatchdog({ userDataPath: '/ud' }) + ) + vi.advanceTimersByTime(6_000) + const heartbeats = child.send.mock.calls.filter(([m]) => m.type === 'heartbeat') + expect(heartbeats.length).toBe(3) + + handle?.stop() + expect(child.send.mock.calls.some(([m]) => m.type === 'shutdown')).toBe(true) + expect(child.disconnect).toHaveBeenCalled() + + // Why: quit fires will-quit twice; a second stop must not resend or throw. + handle?.stop() + const shutdowns = child.send.mock.calls.filter(([m]) => m.type === 'shutdown') + expect(shutdowns.length).toBe(1) + + vi.advanceTimersByTime(10_000) + const heartbeatsAfterStop = child.send.mock.calls.filter(([m]) => m.type === 'heartbeat') + expect(heartbeatsAfterStop.length).toBe(3) + }) + + it('registers stop on will-quit', () => { + const child = fakeChild() + forkMock.mockReturnValue(child) + withPlatform('darwin', () => installMainThreadHangWatchdog({ userDataPath: '/ud' })) + expect(appMock.on).toHaveBeenCalledWith('will-quit', expect.any(Function)) + }) + + it('returns null and stays inert when the fork itself fails', () => { + forkMock.mockImplementation(() => { + throw new Error('spawn failure') + }) + expect( + withPlatform('darwin', () => installMainThreadHangWatchdog({ userDataPath: '/ud' })) + ).toBeNull() + }) +}) diff --git a/src/main/hang-watchdog/main-thread-hang-watchdog.ts b/src/main/hang-watchdog/main-thread-hang-watchdog.ts new file mode 100644 index 000000000..f859f8b57 --- /dev/null +++ b/src/main/hang-watchdog/main-thread-hang-watchdog.ts @@ -0,0 +1,81 @@ +import { fork, type ChildProcess } from 'node:child_process' +import { app } from 'electron' +import { resolveHangWatchdogEntryPath } from './hang-watchdog-entry-path' +import { hangDetectionMarkerPath } from './hang-detection-marker' + +const HEARTBEAT_INTERVAL_MS = 2_000 + +export type MainThreadHangWatchdogHandle = { + stop: () => void + child: ChildProcess +} + +// Why: macOS 26 scene-backed AppKit windows can deadlock the main thread inside +// FrontBoardServices with no crash and no event loop left to self-report. A plain-Node sibling +// process watches heartbeats and records the stall so the next launch can report it. It observes +// only — see main-thread-hang-watchdog-entry.ts for why it does not kill the parent. +export function installMainThreadHangWatchdog(options: { + userDataPath: string +}): MainThreadHangWatchdogHandle | null { + if (process.platform !== 'darwin') { + return null + } + // Why: dev main threads pause in debuggers routinely; watch packaged builds only unless forced. + if (!app.isPackaged && process.env.ORCA_HANG_WATCHDOG_FORCE !== '1') { + return null + } + const entryPath = resolveHangWatchdogEntryPath(app.getAppPath(), app.isPackaged) + let child: ChildProcess + try { + child = fork(entryPath, [], { + stdio: ['ignore', 'ignore', 'pipe', 'ipc'], + env: { + ...process.env, + ELECTRON_RUN_AS_NODE: '1', + ORCA_HANG_WATCHDOG_PARENT_PID: String(process.pid), + ORCA_HANG_WATCHDOG_MARKER_PATH: hangDetectionMarkerPath(options.userDataPath) + } + }) + } catch (error) { + console.error('[hang-watchdog] failed to fork watchdog process:', error) + return null + } + child.stderr?.on('data', (chunk: Buffer) => { + console.error('[hang-watchdog]', String(chunk).trimEnd()) + }) + // Why: the watchdog is a safety net — if it dies, run without it; a restart loop here must never affect the app. + child.on('error', () => {}) + const heartbeatTimer = setInterval(() => { + if (child.connected) { + try { + child.send({ type: 'heartbeat' }, () => {}) + } catch { + // Channel raced closed between the check and the send. + } + } + }, HEARTBEAT_INTERVAL_MS) + let stopped = false + const stop = (): void => { + if (stopped) { + return + } + stopped = true + clearInterval(heartbeatTimer) + if (child.connected) { + try { + child.send({ type: 'shutdown' }, () => {}) + } catch { + // Already disconnecting. + } + } + // Why: disconnect guarantees the child observes parent shutdown and exits instead of misreading quit as a hang. + try { + child.disconnect() + } catch { + // Channel already closed. + } + } + // Why: will-quit fires twice during quit; stop is idempotent. + app.on('will-quit', stop) + return { stop, child } +} diff --git a/src/main/index.ts b/src/main/index.ts index e0930ae90..95c214cf8 100644 --- a/src/main/index.ts +++ b/src/main/index.ts @@ -248,6 +248,11 @@ import { recordCrashBreadcrumb } from './crash-reporting/crash-breadcrumb-store' import { recordDurableCrashBreadcrumb } from './crash-reporting/durable-crash-breadcrumb' +import { installMainThreadHangWatchdog } from './hang-watchdog/main-thread-hang-watchdog' +import { + consumeHangDetectionMarker, + hangDetectionMarkerPath +} from './hang-watchdog/hang-detection-marker' import { getMainProcessLifecycleIdentity } from './crash-reporting/main-process-lifecycle-identity' import { CrashReportStore } from './crash-reporting/crash-report-store' import { @@ -1860,6 +1865,17 @@ function shouldSuppressCodexAutoApprovalSyntheticTitleFromHook(args: { void app.whenReady().then(async () => { logStartupMilestone('app-ready') + installMainThreadHangWatchdog({ userDataPath: getCanonicalUserDataPath() }) + const hangDetection = consumeHangDetectionMarker( + hangDetectionMarkerPath(getCanonicalUserDataPath()) + ) + if (hangDetection) { + recordDurableCrashBreadcrumb('main_thread_hang_detected', { + unresponsiveMs: hangDetection.unresponsiveMs, + previousPid: hangDetection.parentPid, + selfRecovered: hangDetection.selfRecovered + }) + } // Why: install certificate decisions before any webview or headless window issues its first TLS request. app.on( 'certificate-error', @@ -1987,6 +2003,16 @@ void app.whenReady().then(async () => { } // Why: telemetry must init before any IPC handler/renderer can call track(); it's a no-op in dev and while TELEMETRY_ENABLED is false, so it's safe early. initTelemetry(store) + // Why: the breadcrumb alone never leaves the machine — it rides crash reports, and a hang is not + // a crash (the app is force-quit, so no report is ever generated). Without this the incidence + // number the watchdog exists to produce would sit unread on the user's disk. Must run after + // initTelemetry: track() drops silently until the client and store are wired. + if (hangDetection) { + track('main_thread_hang_detected', { + unresponsive_ms: Math.round(hangDetection.unresponsiveMs), + self_recovered: hangDetection.selfRecovered + }) + } // Why: the trust-grant module is bundled into plain-node CLI entries where // the telemetry client cannot load, so the tracker is injected here instead // of imported there. diff --git a/src/shared/telemetry-events.ts b/src/shared/telemetry-events.ts index a98ece28d..4428bdc95 100644 --- a/src/shared/telemetry-events.ts +++ b/src/shared/telemetry-events.ts @@ -385,6 +385,18 @@ const runtimeRpcStartFailedSchema = z .object({ error_class: runtimeRpcStartErrorClassSchema }) .strict() +// Why: a deadlocked main thread never crashes, so it produces no crash report and no user report +// beyond "it froze" — incidence has been unmeasurable. `self_recovered` splits stalls that cleared +// from ones that never did, which is the number that decides whether auto-recovery is ever safe to +// build: every self-recovered stall is a kill that design would have gotten wrong. `unresponsive_ms` +// is the observed silence, kept raw so the 45s threshold can be calibrated against real tails. +const mainThreadHangDetectedSchema = z + .object({ + unresponsive_ms: z.number().int().nonnegative(), + self_recovered: z.boolean() + }) + .strict() + // Why: daemon replace/retire lifecycle signal — issue #7936 was undiagnosable without asking a user for daemon.log. // Enum-only + bucketed session count so no paths, raw versions, or exact counts reach the wire. // The union keeps each reason pinned to its transition, so a death can't be reported as a replace. @@ -1397,6 +1409,7 @@ export const eventSchemas = { agent_hook_unattributed: agentHookUnattributedSchema, daemon_start_failed: daemonStartFailedSchema, + main_thread_hang_detected: mainThreadHangDetectedSchema, daemon_lifecycle: daemonLifecycleSchema, runtime_rpc_start_failed: runtimeRpcStartFailedSchema,