feat(main): record main-thread hangs so we can measure them (#10256)
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.
This commit is contained in:
parent
a6423d565b
commit
747b241145
|
|
@ -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'
|
||||
|
|
|
|||
|
|
@ -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/**',
|
||||
|
|
|
|||
|
|
@ -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')
|
||||
})
|
||||
|
|
|
|||
|
|
@ -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.
|
||||
|
|
|
|||
|
|
@ -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)
|
||||
})
|
||||
})
|
||||
|
|
@ -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<HangDetectionMarker>
|
||||
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
|
||||
}
|
||||
}
|
||||
|
|
@ -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)
|
||||
})
|
||||
})
|
||||
|
|
@ -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)
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
@ -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')
|
||||
}
|
||||
|
|
@ -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)
|
||||
})
|
||||
})
|
||||
|
|
@ -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<typeof vi.spyOn>
|
||||
let exitSpy: ReturnType<typeof vi.spyOn>
|
||||
|
||||
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()
|
||||
})
|
||||
})
|
||||
|
|
@ -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)
|
||||
}
|
||||
|
|
@ -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<T>(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()
|
||||
})
|
||||
})
|
||||
|
|
@ -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 }
|
||||
}
|
||||
|
|
@ -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.
|
||||
|
|
|
|||
|
|
@ -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,
|
||||
|
||||
|
|
|
|||
Loading…
Reference in New Issue