fix(daemon): cover in-flight sleep in PAM watch (#11921)
* fix(daemon): rebaseline in-flight PAM suspension * test(activity): await portal readiness commits
This commit is contained in:
parent
33c14bc716
commit
16c5526dfd
|
|
@ -26,13 +26,13 @@
|
|||
"providers": ["local-daemon"],
|
||||
"coveredPlatforms": ["macos"],
|
||||
"coveredProviders": ["local-daemon"],
|
||||
"coverageNotes": "A deterministic fake clock covers short-burst recovery, sustained session death, event-trigger preemption, timer suspension, resolver corroboration, and shutdown cancellation. The production-only watch remains behind the macOS GUI launch flag; SSH/headless, WSL, Linux, Windows, mobile, and relay paths are unaffected.",
|
||||
"coverageNotes": "A deterministic fake clock covers short-burst recovery, sustained session death, pending-timer and in-flight-probe suspension, event-trigger preemption, resolver corroboration, and shutdown cancellation. The production-only watch remains behind the macOS GUI launch flag; SSH/headless, WSL, Linux, Windows, mobile, and relay paths are unaffected.",
|
||||
"motivatingLinks": [
|
||||
"https://github.com/stablyai/orca/issues/11749",
|
||||
"https://github.com/stablyai/orca/issues/7936"
|
||||
],
|
||||
"invariant": "A GUI-spawned macOS daemon may retire for PAM rejections only after it previously accepted login wrapping, receives three conclusive rejections spanning at least one uninterrupted 120-second observation window, and observes explicitly unhealthy in-process resolver state. A conclusive acceptance or a sleep/App Nap-sized timer gap resets the rejection window, and client or PTY activity cannot shorten its scheduled backoff.",
|
||||
"oracle": "Arm the watch with an accepted probe, inject three rejections over 20 seconds plus unhealthy resolver state, then inject client and PTY activity and require zero resolver reads, zero retirement calls, and exactly four probes until the 120-second boundary. Return acceptance at that boundary and require the daemon to survive. Jump wall time by one hour without firing the scheduled timer, require rejection evidence to restart after wake, and again recover without retirement. Separately keep rejecting through an uninterrupted boundary and require one retirement, while healthy or unknown resolver state suppresses it and stop aborts an in-flight resolver check.",
|
||||
"invariant": "A GUI-spawned macOS daemon may retire for PAM rejections only after it previously accepted login wrapping, receives three conclusive rejections spanning at least one uninterrupted 120-second observation window, and observes explicitly unhealthy in-process resolver state. A conclusive acceptance or a sleep/App Nap-sized gap before or during a probe resets the rejection window to the periodic cadence, and client or PTY activity cannot shorten its scheduled backoff.",
|
||||
"oracle": "Arm the watch with an accepted probe, inject three rejections over 20 seconds plus unhealthy resolver state, then inject client and PTY activity and require zero resolver reads, zero retirement calls, and exactly four probes until the 120-second boundary. Return acceptance at that boundary and require the daemon to survive. Jump wall time by one hour while a timer is pending and while a PAM probe promise is unresolved; require rejection evidence to restart after wake, zero probes for the next 119,999 milliseconds, and recovery without retirement in both cases. Repeatedly delay timers beyond the suspension threshold for one hour and require the periodic probe bound, one live timer, and zero resolver or retirement calls. Separately keep rejecting through an uninterrupted boundary and require one retirement, while healthy or unknown resolver state suppresses it and stop aborts an in-flight resolver check.",
|
||||
"commands": [
|
||||
"pnpm exec vitest run --config config/vitest.config.ts src/main/daemon/macos-login-session-death-watch.test.ts --reporter=dot"
|
||||
],
|
||||
|
|
@ -43,6 +43,8 @@
|
|||
"assertions": [
|
||||
"preserves the daemon when a short PAM rejection burst recovers after wake",
|
||||
"does not count a suspended timer gap as rejection evidence",
|
||||
"does not count suspension during an in-flight probe as rejection evidence",
|
||||
"backs off repeated timer lateness to the periodic probe cadence",
|
||||
"retires only after sustained conclusive rejections with a degraded resolver",
|
||||
"suppresses retirement while resolver health is healthy or unknown, then retires on explicit degradation",
|
||||
"stop prevents an in-flight resolver check from retiring the daemon"
|
||||
|
|
@ -57,7 +59,7 @@
|
|||
"command": "pnpm exec vitest run --config config/vitest.config.ts src/main/daemon/macos-login-session-death-watch.test.ts --reporter=dot",
|
||||
"result": "passed",
|
||||
"durationSeconds": 0.1,
|
||||
"summary": "The focused state-machine suite passed 19 tests, including the field-shaped 20-second rejection burst, suspended-timer rebaselining, bounded recovery retry, sustained-death convergence, resolver suppression, trigger coalescing, and shutdown cancellation."
|
||||
"summary": "The focused state-machine suite passed 21 tests, including the field-shaped 20-second rejection burst, pending-timer and in-flight-probe suspension rebaselining, repeated-lateness backoff, bounded recovery retry, sustained-death convergence, resolver suppression, trigger coalescing, and shutdown cancellation."
|
||||
}
|
||||
],
|
||||
"runtimeBudget": {
|
||||
|
|
@ -74,7 +76,7 @@
|
|||
},
|
||||
"performanceBudget": {
|
||||
"required": true,
|
||||
"evidence": "The watch retains one timer and one in-flight probe. A rejection burst runs the existing two 10-second confirmation probes, then one recovery probe at the 120-second boundary; client and PTY activity cannot pull that deadline earlier. Resolver work is skipped until the time floor. No polling loop, startup await, session scan, renderer work, provider fanout, listener, or retained payload was added."
|
||||
"evidence": "The watch retains one timer and one in-flight probe. A rejection burst runs the existing two 10-second confirmation probes, then one recovery probe at the 120-second boundary; client and PTY activity cannot pull that deadline earlier. Timer lateness and in-flight probe suspension both rebaseline evidence to the periodic cadence, preventing an App Nap retry loop, and resolver work is skipped until the time floor. No polling loop, startup await, session scan, renderer work, provider fanout, listener, or retained payload was added."
|
||||
},
|
||||
"promotionCriteria": [
|
||||
"Collect 100 consecutive focused CI passes or 14 days of soak history.",
|
||||
|
|
@ -83,7 +85,7 @@
|
|||
],
|
||||
"knownGaps": [
|
||||
"A real dead macOS GUI login session cannot be fabricated without ending the runner's login session; sustained-death coverage uses deterministic PAM and resolver oracles.",
|
||||
"The two-minute production window and one-hour timer suspension are covered by fake-clock tests rather than a real sleep/wake run.",
|
||||
"The two-minute production window and one-hour pending/in-flight suspension cases are covered by fake-clock tests rather than a real sleep/wake run.",
|
||||
"No multi-process aggregate throttle is added; each stale daemon independently obeys the same non-preemptible observation window."
|
||||
],
|
||||
"demotionRule": "Keep experimental or demote if any activity trigger shortens the rejection window, a transient burst reaches resolver retirement authority, sustained dead-session evidence no longer converges, shutdown permits late retirement, or the focused gate flakes without an identified product or harness fault."
|
||||
|
|
|
|||
|
|
@ -0,0 +1,17 @@
|
|||
export type LoginSessionWatchClock = {
|
||||
setTimeout(callback: () => void, delayMs: number): unknown
|
||||
clearTimeout(handle: unknown): void
|
||||
now(): number
|
||||
}
|
||||
|
||||
export function createLoginSessionWatchClock(): LoginSessionWatchClock {
|
||||
return {
|
||||
setTimeout: (callback, delayMs) => {
|
||||
const timer = setTimeout(callback, delayMs)
|
||||
timer.unref()
|
||||
return timer
|
||||
},
|
||||
clearTimeout: (handle) => clearTimeout(handle as ReturnType<typeof setTimeout>),
|
||||
now: () => Date.now()
|
||||
}
|
||||
}
|
||||
|
|
@ -0,0 +1,19 @@
|
|||
export type LoginSessionWatchTiming = {
|
||||
periodicProbeMs: number
|
||||
rejectionRecheckMs: number
|
||||
minimumRejectionSpanMs: number
|
||||
ptyExitDebounceMs: number
|
||||
clientActivityMinGapMs: number
|
||||
minProbeGapMs: number
|
||||
}
|
||||
|
||||
export const DEFAULT_LOGIN_SESSION_WATCH_TIMING: LoginSessionWatchTiming = {
|
||||
periodicProbeMs: 120_000,
|
||||
rejectionRecheckMs: 10_000,
|
||||
// Why: a full periodic window separates logout from short wake/PAM recovery bursts.
|
||||
minimumRejectionSpanMs: 120_000,
|
||||
ptyExitDebounceMs: 2_000,
|
||||
// Why: steady reconnects must not turn client hellos into a PAM probe storm.
|
||||
clientActivityMinGapMs: 30_000,
|
||||
minProbeGapMs: 5_000
|
||||
}
|
||||
|
|
@ -158,7 +158,7 @@ describe('MacosLoginSessionDeathWatch', () => {
|
|||
it('does not count a suspended timer gap as rejection evidence', async () => {
|
||||
const readResolverHealth = vi.fn(async () => 'unhealthy' as const)
|
||||
const { watch, clock, onRetire, probe } = createWatch({
|
||||
outcomes: [ACCEPTED, REJECTED, REJECTED, REJECTED, REJECTED, ACCEPTED],
|
||||
outcomes: [ACCEPTED, REJECTED, REJECTED, ACCEPTED],
|
||||
readResolverHealth
|
||||
})
|
||||
watch.start()
|
||||
|
|
@ -167,15 +167,69 @@ describe('MacosLoginSessionDeathWatch', () => {
|
|||
await clock.advance(120_000)
|
||||
clock.suspend(60 * 60 * 1000)
|
||||
await clock.advance(0)
|
||||
await clock.advance(10_000)
|
||||
await clock.advance(10_000)
|
||||
|
||||
expect(probe).toHaveBeenCalledTimes(5)
|
||||
expect(probe).toHaveBeenCalledTimes(3)
|
||||
expect(readResolverHealth).not.toHaveBeenCalled()
|
||||
expect(onRetire).not.toHaveBeenCalled()
|
||||
|
||||
await clock.advance(100_000)
|
||||
expect(probe).toHaveBeenCalledTimes(6)
|
||||
await clock.advance(119_999)
|
||||
expect(probe).toHaveBeenCalledTimes(3)
|
||||
await clock.advance(1)
|
||||
expect(probe).toHaveBeenCalledTimes(4)
|
||||
expect(onRetire).not.toHaveBeenCalled()
|
||||
})
|
||||
|
||||
it('does not count suspension during an in-flight probe as rejection evidence', async () => {
|
||||
let resolveProbe!: (outcome: LoginPreflightOutcome) => void
|
||||
const deferredProbe = new Promise<LoginPreflightOutcome>((resolve) => {
|
||||
resolveProbe = resolve
|
||||
})
|
||||
const probe = vi
|
||||
.fn<MacosLoginSessionDeathWatchOptions['probeLoginSession']>()
|
||||
.mockResolvedValueOnce(ACCEPTED)
|
||||
.mockResolvedValueOnce(REJECTED)
|
||||
.mockReturnValueOnce(deferredProbe)
|
||||
.mockResolvedValueOnce(ACCEPTED)
|
||||
const readResolverHealth = vi.fn(async () => 'unhealthy' as const)
|
||||
const { watch, clock, onRetire } = createWatch({ probeLoginSession: probe, readResolverHealth })
|
||||
watch.start()
|
||||
await drainMicrotasks()
|
||||
|
||||
await clock.advance(120_000)
|
||||
await clock.advance(10_000)
|
||||
clock.suspend(60 * 60 * 1000)
|
||||
resolveProbe(REJECTED)
|
||||
await drainMicrotasks()
|
||||
|
||||
expect(probe).toHaveBeenCalledTimes(3)
|
||||
expect(readResolverHealth).not.toHaveBeenCalled()
|
||||
expect(onRetire).not.toHaveBeenCalled()
|
||||
|
||||
await clock.advance(119_999)
|
||||
expect(probe).toHaveBeenCalledTimes(3)
|
||||
await clock.advance(1)
|
||||
expect(probe).toHaveBeenCalledTimes(4)
|
||||
expect(onRetire).not.toHaveBeenCalled()
|
||||
})
|
||||
|
||||
it('backs off repeated timer lateness to the periodic probe cadence', async () => {
|
||||
const readResolverHealth = vi.fn(async () => 'unhealthy' as const)
|
||||
const { watch, clock, onRetire, probe } = createWatch({
|
||||
outcomes: [ACCEPTED, ...Array.from({ length: 30 }, () => REJECTED)],
|
||||
readResolverHealth
|
||||
})
|
||||
watch.start()
|
||||
await drainMicrotasks()
|
||||
await clock.advance(120_000)
|
||||
|
||||
for (let i = 0; i < 27; i++) {
|
||||
clock.suspend(135_001)
|
||||
await clock.advance(0)
|
||||
}
|
||||
|
||||
expect(probe).toHaveBeenCalledTimes(29)
|
||||
expect(clock.pendingCount()).toBe(1)
|
||||
expect(readResolverHealth).not.toHaveBeenCalled()
|
||||
expect(onRetire).not.toHaveBeenCalled()
|
||||
})
|
||||
|
||||
|
|
|
|||
|
|
@ -1,24 +1,17 @@
|
|||
import type { LoginPreflightOutcome } from '../providers/macos-tcc-login-shell'
|
||||
import type { DaemonFileLog } from './daemon-file-log'
|
||||
import {
|
||||
createLoginSessionWatchClock,
|
||||
type LoginSessionWatchClock
|
||||
} from './login-session-watch-clock'
|
||||
import {
|
||||
DEFAULT_LOGIN_SESSION_WATCH_TIMING,
|
||||
type LoginSessionWatchTiming
|
||||
} from './login-session-watch-timing'
|
||||
import type { SystemResolverHealth } from './types'
|
||||
|
||||
// Why: retain count confirmation while the elapsed window below blocks short bursts.
|
||||
const REQUIRED_CONSECUTIVE_REJECTIONS = 3
|
||||
const PERIODIC_PROBE_MS = 120_000
|
||||
const REJECTION_RECHECK_MS = 10_000
|
||||
// Why: a full periodic window separates logout from short wake/PAM recovery bursts.
|
||||
const MINIMUM_REJECTION_SPAN_MS = PERIODIC_PROBE_MS
|
||||
const PTY_EXIT_DEBOUNCE_MS = 2_000
|
||||
// Why: a client hello right after login is the fastest death signal for a stale
|
||||
// daemon, but steady reconnects must not turn hellos into a PAM probe storm.
|
||||
const CLIENT_ACTIVITY_MIN_GAP_MS = 30_000
|
||||
const MIN_PROBE_GAP_MS = 5_000
|
||||
|
||||
type WatchClock = {
|
||||
setTimeout(callback: () => void, delayMs: number): unknown
|
||||
clearTimeout(handle: unknown): void
|
||||
now(): number
|
||||
}
|
||||
|
||||
export type MacosLoginSessionDeathWatchOptions = {
|
||||
/** Fresh PAM probe (cache-bypassing); null when the login wrapper doesn't apply on this host. */
|
||||
|
|
@ -31,15 +24,8 @@ export type MacosLoginSessionDeathWatchOptions = {
|
|||
}) => void
|
||||
log: DaemonFileLog
|
||||
/** Direct-construction seam for deterministic tests; production uses real timers. */
|
||||
clock?: WatchClock
|
||||
timing?: Partial<{
|
||||
periodicProbeMs: number
|
||||
rejectionRecheckMs: number
|
||||
minimumRejectionSpanMs: number
|
||||
ptyExitDebounceMs: number
|
||||
clientActivityMinGapMs: number
|
||||
minProbeGapMs: number
|
||||
}>
|
||||
clock?: LoginSessionWatchClock
|
||||
timing?: Partial<LoginSessionWatchTiming>
|
||||
}
|
||||
|
||||
/**
|
||||
|
|
@ -63,7 +49,7 @@ export class MacosLoginSessionDeathWatch {
|
|||
private readonly readResolverHealth: MacosLoginSessionDeathWatchOptions['readResolverHealth']
|
||||
private readonly onRetire: MacosLoginSessionDeathWatchOptions['onRetire']
|
||||
private readonly log: DaemonFileLog
|
||||
private readonly clock: WatchClock
|
||||
private readonly clock: LoginSessionWatchClock
|
||||
private readonly periodicProbeMs: number
|
||||
private readonly rejectionRecheckMs: number
|
||||
private readonly minimumRejectionSpanMs: number
|
||||
|
|
@ -91,21 +77,16 @@ export class MacosLoginSessionDeathWatch {
|
|||
this.readResolverHealth = opts.readResolverHealth
|
||||
this.onRetire = opts.onRetire
|
||||
this.log = opts.log
|
||||
this.clock = opts.clock ?? {
|
||||
setTimeout: (callback, delayMs) => {
|
||||
const timer = setTimeout(callback, delayMs)
|
||||
timer.unref()
|
||||
return timer
|
||||
},
|
||||
clearTimeout: (handle) => clearTimeout(handle as ReturnType<typeof setTimeout>),
|
||||
now: () => Date.now()
|
||||
}
|
||||
this.periodicProbeMs = opts.timing?.periodicProbeMs ?? PERIODIC_PROBE_MS
|
||||
this.rejectionRecheckMs = opts.timing?.rejectionRecheckMs ?? REJECTION_RECHECK_MS
|
||||
this.minimumRejectionSpanMs = opts.timing?.minimumRejectionSpanMs ?? MINIMUM_REJECTION_SPAN_MS
|
||||
this.ptyExitDebounceMs = opts.timing?.ptyExitDebounceMs ?? PTY_EXIT_DEBOUNCE_MS
|
||||
this.clientActivityMinGapMs = opts.timing?.clientActivityMinGapMs ?? CLIENT_ACTIVITY_MIN_GAP_MS
|
||||
this.minProbeGapMs = opts.timing?.minProbeGapMs ?? MIN_PROBE_GAP_MS
|
||||
this.clock = opts.clock ?? createLoginSessionWatchClock()
|
||||
const defaults = DEFAULT_LOGIN_SESSION_WATCH_TIMING
|
||||
this.periodicProbeMs = opts.timing?.periodicProbeMs ?? defaults.periodicProbeMs
|
||||
this.rejectionRecheckMs = opts.timing?.rejectionRecheckMs ?? defaults.rejectionRecheckMs
|
||||
this.minimumRejectionSpanMs =
|
||||
opts.timing?.minimumRejectionSpanMs ?? defaults.minimumRejectionSpanMs
|
||||
this.ptyExitDebounceMs = opts.timing?.ptyExitDebounceMs ?? defaults.ptyExitDebounceMs
|
||||
this.clientActivityMinGapMs =
|
||||
opts.timing?.clientActivityMinGapMs ?? defaults.clientActivityMinGapMs
|
||||
this.minProbeGapMs = opts.timing?.minProbeGapMs ?? defaults.minProbeGapMs
|
||||
}
|
||||
|
||||
start(): void {
|
||||
|
|
@ -222,10 +203,12 @@ export class MacosLoginSessionDeathWatch {
|
|||
}
|
||||
const timerGapMs =
|
||||
scheduledAtMs === undefined ? 0 : Math.max(0, this.clock.now() - scheduledAtMs)
|
||||
let rejectionWindowRebased = false
|
||||
if (this.consecutiveRejections > 0 && timerGapMs > this.minProbeGapMs * 3) {
|
||||
// Why: sleep/App Nap pauses probes; elapsed wall time is not rejection evidence.
|
||||
this.consecutiveRejections = 0
|
||||
this.firstRejectionAtMs = null
|
||||
rejectionWindowRebased = true
|
||||
this.log.log('login-session-rejection-window-reset', {
|
||||
cause: 'timer-gap',
|
||||
timerGapMs
|
||||
|
|
@ -242,7 +225,8 @@ export class MacosLoginSessionDeathWatch {
|
|||
return
|
||||
}
|
||||
this.probeInFlight = true
|
||||
this.lastProbeStartedAtMs = this.clock.now()
|
||||
const probeStartedAtMs = this.clock.now()
|
||||
this.lastProbeStartedAtMs = probeStartedAtMs
|
||||
const abortController = new AbortController()
|
||||
this.probeAbortController = abortController
|
||||
try {
|
||||
|
|
@ -250,6 +234,17 @@ export class MacosLoginSessionDeathWatch {
|
|||
if (this.stopped || this.retired) {
|
||||
return
|
||||
}
|
||||
const probeGapMs = Math.max(0, this.clock.now() - probeStartedAtMs)
|
||||
if (this.consecutiveRejections > 0 && probeGapMs > this.minProbeGapMs * 3) {
|
||||
// Why: sleep can suspend an in-flight PAM probe after the timer-gap check.
|
||||
this.consecutiveRejections = 0
|
||||
this.firstRejectionAtMs = null
|
||||
rejectionWindowRebased = true
|
||||
this.log.log('login-session-rejection-window-reset', {
|
||||
cause: 'probe-gap',
|
||||
probeGapMs
|
||||
})
|
||||
}
|
||||
if (outcome === null) {
|
||||
// Why: no wrapper machinery means no PAM oracle — watching would only ever misfire.
|
||||
this.log.log('login-session-watch-disabled', { trigger })
|
||||
|
|
@ -284,7 +279,9 @@ export class MacosLoginSessionDeathWatch {
|
|||
rejections: this.consecutiveRejections
|
||||
})
|
||||
if (this.consecutiveRejections < REQUIRED_CONSECUTIVE_REJECTIONS) {
|
||||
this.scheduleNextProbe(this.rejectionRecheckMs)
|
||||
this.scheduleNextProbe(
|
||||
rejectionWindowRebased ? this.periodicProbeMs : this.rejectionRecheckMs
|
||||
)
|
||||
return
|
||||
}
|
||||
const rejectionSpanMs = this.clock.now() - this.firstRejectionAtMs
|
||||
|
|
|
|||
|
|
@ -76,6 +76,15 @@ function installAnimationFrameController(): {
|
|||
}
|
||||
}
|
||||
|
||||
async function flushPortalFramesUntil(
|
||||
frames: ReturnType<typeof installAnimationFrameController>,
|
||||
settled: () => boolean
|
||||
): Promise<void> {
|
||||
for (let frame = 0; frame < 4 && !settled(); frame += 1) {
|
||||
await frames.flush()
|
||||
}
|
||||
}
|
||||
|
||||
// Models the tab-root DOM and sibling hiding emitted by a portaled TerminalPane.
|
||||
function renderPortaledTerminalPane(target: HTMLElement, tabId: string, leafIds: string[]): void {
|
||||
const isolatedLeafId = leafIds[0]
|
||||
|
|
@ -345,7 +354,7 @@ describe('Activity portal pane switching', () => {
|
|||
await act(async () => {
|
||||
root.render(<ActivityTerminalSlot />)
|
||||
})
|
||||
await frames.flush()
|
||||
await flushPortalFramesUntil(frames, () => statuses.at(-1) === 'unavailable')
|
||||
expect(statuses.at(-1)).toBe('unavailable')
|
||||
|
||||
// Feed each observed DOM state separately so MutationObserver cannot coalesce the flips.
|
||||
|
|
@ -362,7 +371,7 @@ describe('Activity portal pane switching', () => {
|
|||
buildRoot('ready')
|
||||
await Promise.resolve()
|
||||
})
|
||||
await frames.flush()
|
||||
await flushPortalFramesUntil(frames, () => statuses.at(-1) === 'ready')
|
||||
expect(statuses.at(-1)).toBe('ready')
|
||||
})
|
||||
})
|
||||
|
|
|
|||
Loading…
Reference in New Issue