fix(hook): give the macOS tap's capability probes their own watchdog budget - #1282
Merged
AprilNEA merged 3 commits intoSep 29, 2026
Merged
Conversation
6 of 15 tasks
|
AprilNEA
force-pushed
the
fix/macos-hook-watchdog-display-sleep
branch
from
September 29, 2026 09:09
ac999a9 to
84f2327
Compare
AprilNEA
added a commit
to hyspacex/OpenLogi
that referenced
this pull request
Sep 29, 2026
… running The lifecycle watchdog evaluates every 100 ms against a 1.5 s budget, so a genuine stall is caught with elapsed_ms in 1500-1600. On the reporting host two of three AprilNEA#952 exits fired far later than that — 2515 ms and 6325 ms — which a thread evaluating every poll cannot do: the watchdog thread itself was not running for at least 1.0 s and 4.8 s around the sleep transition, and neither was the tap thread it judges. The third exit (1561 ms) fired on time and is the slow-probe case AprilNEA#1282 addresses; the two commits cover the two halves. Each evaluation now credits at most OBSERVATION_GAP (5 polls, 500 ms) for the time since the previous one, and a stall is judged by the time the watchdog was awake to see. A starved-but-running watchdog still accumulates, so repeated starvation cannot hide a wedged tap. The decision carries both figures and the exit log prints stalled_ms next to watched_ms; a wide gap between them is the process-frozen signature. A budget change is a new stall: a stop that waited out a slow probe under the probe budget gets the short budget afresh for the teardown, instead of being exited the moment the probe returns because the probe alone outlasted 1.5 s. Also refresh the progress mark before publishing Armed after a probe (the Greptile P1 on AprilNEA#1282): the watchdog reads the phase first, and would otherwise judge a probe that already returned against the pre-probe mark. Refs AprilNEA#952
Owner
|
Pushed two changes on top of your commit, rebased onto master:
Details in the second commit's message. If you can run a lid-close cycle on the clamshell setup, that is the test neither of us has done on the combined branch. |
…budget `service_tap` marks tap progress immediately before and immediately after its 500 ms `CFRunLoopRunInMode` slice, then runs the between-slice capability probe — `AXIsProcessTrusted()`, the throwaway `CGEventTapCreate` in `can_filter_events()`, `CGEventTapIsEnabled`, `CGEventTapEnable` — without marking again until the top of the next iteration. That window is charged to `TAP_SHUTDOWN_BUDGET`, so a probe slower than 1.5 s reads as a wedged tap thread and the lifecycle watchdog force-exits the agent with `FREEZE_HAZARD_EXIT_CODE`. Those calls are WindowServer and TCC round trips, and while the display is asleep they take seconds. A user's agent log shows the resulting exit repeat 27 times across 2.5 h of display sleep, always `reason="HID tap thread stopped making progress while tap remained active"`, `phase=Armed`, `elapsed_ms` between 1555 and 1740, with launchd restarting the agent 4-8 s later each time. Since the run-loop slice is bounded at 500 ms and re-marks progress on both sides, the whole overrun is inside the probe. The tap thread now publishes `TapPhase::Probing` for that window and returns to `Armed` with a fresh progress mark once `CGEventTapEnable` returns. The watchdog judges `Probing` against a separate `TAP_PROBE_BUDGET` for both exit reasons, so a stop request landing on a slow probe is treated the same way; a thread that reached the `Probing` store is demonstrably alive and inside a named CoreGraphics/TCC call rather than wedged servicing the tap. Everything else keeps the 1.5 s budget, `Probing` stays hazardous for the re-check before exiting, and a probe that never returns — the TCC-revocation stall this watchdog exists for — still force-exits. The freeze exposure does not grow with the budget: an active tap whose thread is not servicing its run loop is already bounded by CoreGraphics' own tap timeout, which disables the tap and lets events through. The break paths deliberately leave `Probing` published; the thread is still inside CoreGraphics for the synchronous teardown, and the watchdog stays armed on that phase either way. Refs AprilNEA#952
… running The lifecycle watchdog evaluates every 100 ms against a 1.5 s budget, so a genuine stall is caught with elapsed_ms in 1500-1600. On the reporting host two of three AprilNEA#952 exits fired far later than that — 2515 ms and 6325 ms — which a thread evaluating every poll cannot do: the watchdog thread itself was not running for at least 1.0 s and 4.8 s around the sleep transition, and neither was the tap thread it judges. The third exit (1561 ms) fired on time and is the slow-probe case AprilNEA#1282 addresses; the two commits cover the two halves. Each evaluation now credits at most OBSERVATION_GAP (5 polls, 500 ms) for the time since the previous one, and a stall is judged by the time the watchdog was awake to see. A starved-but-running watchdog still accumulates, so repeated starvation cannot hide a wedged tap. The decision carries both figures and the exit log prints stalled_ms next to watched_ms; a wide gap between them is the process-frozen signature. A budget change is a new stall: a stop that waited out a slow probe under the probe budget gets the short budget afresh for the teardown, instead of being exited the moment the probe returns because the probe alone outlasted 1.5 s. Also refresh the progress mark before publishing Armed after a probe (the Greptile P1 on AprilNEA#1282): the watchdog reads the phase first, and would otherwise judge a probe that already returned against the pre-probe mark. Refs AprilNEA#952
…p or wake The previous commit discounted every gap in the lifecycle watchdog's schedule above 500 ms. That also discounts a gap caused by scheduling delay alone, so a tap thread wedged while the watchdog was merely starved could hold an active HID tap for several times the 1.5 s budget (review finding on AprilNEA#1282). Both late AprilNEA#952 exits on the reporting host straddled a kernel sleep/wake: one fired 5 ms after System Wake, the other within the second of a DarkWake. The watchdog now reads kern.sleeptime and kern.waketime on each poll and discounts a gap only when either moved inside it. A gap with no transition in it is charged in full, as before this PR, so a delayed watchdog still exits a wedged tap on the first poll past the budget; a gap with one is capped at 500 ms, and repeated cycles still accumulate. kern.waketime moves on every wake from sleep, dark or full, and not on a DarkWake's promotion to a full wake (checked against pmset -g log on the reporting host). A freeze during sleep entry that thaws before the kernel actually sleeps is not covered; none has been observed. Refs AprilNEA#952
AprilNEA
force-pushed
the
fix/macos-hook-watchdog-display-sleep
branch
from
September 29, 2026 11:32
84f2327 to
25c6cd2
Compare
AprilNEA
added a commit
that referenced
this pull request
Sep 29, 2026
… running The lifecycle watchdog evaluates every 100 ms against a 1.5 s budget, so a genuine stall is caught with elapsed_ms in 1500-1600. On the reporting host two of three #952 exits fired far later than that — 2515 ms and 6325 ms — which a thread evaluating every poll cannot do: the watchdog thread itself was not running for at least 1.0 s and 4.8 s around the sleep transition, and neither was the tap thread it judges. The third exit (1561 ms) fired on time and is the slow-probe case #1282 addresses; the two commits cover the two halves. Each evaluation now credits at most OBSERVATION_GAP (5 polls, 500 ms) for the time since the previous one, and a stall is judged by the time the watchdog was awake to see. A starved-but-running watchdog still accumulates, so repeated starvation cannot hide a wedged tap. The decision carries both figures and the exit log prints stalled_ms next to watched_ms; a wide gap between them is the process-frozen signature. A budget change is a new stall: a stop that waited out a slow probe under the probe budget gets the short budget afresh for the teardown, instead of being exited the moment the probe returns because the probe alone outlasted 1.5 s. Also refresh the progress mark before publishing Armed after a probe (the Greptile P1 on #1282): the watchdog reads the phase first, and would otherwise judge a probe that already returned against the pre-probe mark. Refs #952
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
When the Mac goes to sleep, the agent force-exits and launchd restarts it. Two distinct things go wrong at the sleep transition, and this PR has one commit for each. Refs #952.
AXIsProcessTrusted, the throwawayCGEventTapCreate,CGEventTapIsEnabled,CGEventTapEnable) is a WindowServer/TCC round trip that takes seconds while the system is going down, and it was charged to the 1.5 s stall budget. 43 of 43 exits on one machine sit at a sleep transition withelapsed_msin 1555–1809: the watchdog fired on time, the tap thread was slow, not wedged.elapsed_ms=2515and6325— 1.0 s and 4.8 s past the budget, which a thread evaluating every 100 ms cannot do — and the tap thread it judges was not running either. Charging that gap to the tap thread force-exited a healthy agent.Changes
openlogi-hook: newTapPhase::Probing, published by the tap thread around the post-slice probe and judged against a separateTAP_PROBE_BUDGET(10 s) for both exit reasons; the progress mark is refreshed beforeArmedis re-published.openlogi-hook: each lifecycle evaluation credits at mostOBSERVATION_GAP(5 polls, 500 ms) for the time since the previous one, and a stall is judged by the time the watchdog was awake to see. A starved-but-running watchdog still accumulates.LifecycleDecision::Exitcarrieswatchedandstalled, and the exit log prints both — a wide gap between them is the process-frozen signature.openlogi-hook: a budget change is a new stall, so a stop that waited out a slow probe gets the short budget afresh for the teardown instead of being exited the moment the probe returns.crates/openlogi-hook/AGENTS.md: the invariants above.Testing
Run on macOS 26 (arm64) with
RUSTFLAGS="-D warnings", rebased onto master 5cca3f5:cargo fmt --all -- --check,cargo clippy --workspace --all-targets -- -D warnings,cargo test --workspace, the non-GUI rustdoc job,cargo xtask ci clippy-windows. Watchdog decision tests drive the pureLifecycleWatchdogat the real 100 ms poll cadence; mutation checks confirm the freeze tests fail without the gap credit and the teardown test fails without the budget in the stall identity.Not run:
tests (linux),msrv,cargo-deny. Not runtime-tested through a lid-close cycle on the combined branch; the agent log lines to look for after one areHID CGEventTap lifecycle did not make progress(should be gone) and, in any that remain,stalled_msvswatched_ms.