Skip to main content

orch/engine/
suspend.rs

1//! Host suspend/resume detection.
2//!
3//! `Instant` is monotonic and does not advance while the host is asleep; wall-clock
4//! time does. Comparing the two across a checkpoint reveals suspend/resume gaps that
5//! would otherwise be misread by wall-clock-only comparisons as a stalled tick loop
6//! (the watchdog in `engine::mod`) or a hung agent (`stuck_task_timing_from_map` in
7//! `engine::tick`).
8//!
9//! `checkpoint()` is the primary detection point, called once per main tick loop
10//! iteration; `suspended_duration_since` pulls from its gap log instead of re-deriving
11//! suspend information from its own wall-clock deltas. Callers that run on an
12//! independent timer and can't wait for the main loop's checkpoint (e.g. the tick
13//! watchdog, which would otherwise race it on wake from suspend) should use their own
14//! `SuspendDetector` instance instead.
15
16use chrono::{DateTime, Duration as ChronoDuration, Utc};
17use std::sync::Mutex;
18use std::time::{Duration, Instant};
19
20/// Wall-clock-minus-monotonic gap large enough to be a host suspend rather than
21/// scheduling jitter or a slow tick.
22const SUSPEND_GAP_THRESHOLD: Duration = Duration::from_secs(20);
23
24/// Bound on retained gap history so a long-running process doesn't grow this
25/// unboundedly; suspend events are rare so this comfortably covers any realistic
26/// task age window.
27const MAX_GAP_LOG: usize = 128;
28
29struct GapRecord {
30    detected_at: DateTime<Utc>,
31    gap: ChronoDuration,
32}
33
34#[derive(Debug)]
35struct Checkpoint {
36    instant: Instant,
37    wall: DateTime<Utc>,
38}
39
40/// Compare a previous checkpoint against now and return the suspend gap, if the
41/// wall-clock-minus-monotonic delta clears `SUSPEND_GAP_THRESHOLD`. Shared by the
42/// global checkpoint log and by independent `SuspendDetector` instances so both use
43/// identical detection math.
44fn gap_since(
45    prev: &Checkpoint,
46    now_instant: Instant,
47    now_wall: DateTime<Utc>,
48) -> Option<ChronoDuration> {
49    let monotonic_elapsed = now_instant.saturating_duration_since(prev.instant);
50    let wall_elapsed = (now_wall - prev.wall).to_std().unwrap_or_default();
51    let gap = wall_elapsed.saturating_sub(monotonic_elapsed);
52    if gap < SUSPEND_GAP_THRESHOLD {
53        return None;
54    }
55    Some(ChronoDuration::from_std(gap).unwrap_or_else(|_| ChronoDuration::zero()))
56}
57
58static LAST_CHECKPOINT: Mutex<Option<Checkpoint>> = Mutex::new(None);
59static GAP_LOG: Mutex<Vec<GapRecord>> = Mutex::new(Vec::new());
60
61/// Record a checkpoint and return the suspend gap (if any) detected since the
62/// previous one. Call this once per main tick loop iteration.
63pub fn checkpoint() -> Option<ChronoDuration> {
64    let now_instant = Instant::now();
65    let now_wall = Utc::now();
66
67    let prev = {
68        let mut guard = LAST_CHECKPOINT
69            .lock()
70            .unwrap_or_else(std::sync::PoisonError::into_inner);
71        guard.replace(Checkpoint {
72            instant: now_instant,
73            wall: now_wall,
74        })
75    };
76    let prev = prev?;
77    let gap = gap_since(&prev, now_instant, now_wall)?;
78
79    let mut log = GAP_LOG
80        .lock()
81        .unwrap_or_else(std::sync::PoisonError::into_inner);
82    log.push(GapRecord {
83        detected_at: now_wall,
84        gap,
85    });
86    if log.len() > MAX_GAP_LOG {
87        let excess = log.len() - MAX_GAP_LOG;
88        log.drain(0..excess);
89    }
90    Some(gap)
91}
92
93/// Independent suspend detector for callers that run on their own timer and can't
94/// rely on the shared `checkpoint()`/`GAP_LOG` pair, which is only written by the
95/// main tick loop. Two independently-scheduled tokio tasks that both freeze during a
96/// host suspend become "due" at roughly the same instant on wake with no ordering
97/// guarantee between them — a caller reading `GAP_LOG` right after wake can race the
98/// main loop's own `checkpoint()` call and observe no gap yet. A `SuspendDetector`
99/// avoids the race by tracking its own Instant/wall-clock baseline, so it detects the
100/// gap from its own frozen timer instead of waiting on another task to record it.
101#[derive(Debug)]
102pub struct SuspendDetector {
103    last: Option<Checkpoint>,
104}
105
106impl SuspendDetector {
107    pub fn new() -> Self {
108        Self { last: None }
109    }
110
111    /// Record a checkpoint on this detector and return the suspend gap (if any)
112    /// detected since the previous call.
113    pub fn check(&mut self) -> Option<ChronoDuration> {
114        let now_instant = Instant::now();
115        let now_wall = Utc::now();
116        let prev = self.last.replace(Checkpoint {
117            instant: now_instant,
118            wall: now_wall,
119        })?;
120        gap_since(&prev, now_instant, now_wall)
121    }
122}
123
124impl Default for SuspendDetector {
125    fn default() -> Self {
126        Self::new()
127    }
128}
129
130/// Total suspend time detected since `since`. Subtract this from a wall-clock age
131/// computation to avoid mistaking suspend time for hung agent/tick runtime.
132pub fn suspended_duration_since(since: DateTime<Utc>) -> ChronoDuration {
133    let log = GAP_LOG
134        .lock()
135        .unwrap_or_else(std::sync::PoisonError::into_inner);
136    log.iter()
137        .filter(|r| r.detected_at > since)
138        .fold(ChronoDuration::zero(), |acc, r| acc + r.gap)
139}
140
141/// Most recent suspend gap detected within the last `window`, if any. Lets the tick
142/// watchdog downgrade a stale-tick alert to informational when it is fully explained
143/// by a host suspend rather than an actual stall.
144pub fn gap_detected_within(window: Duration) -> Option<ChronoDuration> {
145    let window = ChronoDuration::from_std(window).unwrap_or_else(|_| ChronoDuration::zero());
146    let cutoff = Utc::now() - window;
147    let log = GAP_LOG
148        .lock()
149        .unwrap_or_else(std::sync::PoisonError::into_inner);
150    log.iter()
151        .rev()
152        .find(|r| r.detected_at >= cutoff)
153        .map(|r| r.gap)
154}
155
156/// Test-only helper to inject a synthetic gap record without going through the real
157/// `Instant`/wall-clock comparison in `checkpoint()`, which can't be driven
158/// deterministically in tests.
159#[cfg(test)]
160pub(crate) fn inject_gap_for_test(detected_at: DateTime<Utc>, gap: ChronoDuration) {
161    let mut log = GAP_LOG
162        .lock()
163        .unwrap_or_else(std::sync::PoisonError::into_inner);
164    log.push(GapRecord { detected_at, gap });
165}
166
167/// Test-only helper to reset shared gap state between tests. Callers must run
168/// `#[serial(suspend_state)]` since `GAP_LOG` is a process-wide static.
169#[cfg(test)]
170pub(crate) fn clear_for_test() {
171    let mut log = GAP_LOG
172        .lock()
173        .unwrap_or_else(std::sync::PoisonError::into_inner);
174    log.clear();
175}
176
177#[cfg(test)]
178mod tests {
179    use super::*;
180    use serial_test::serial;
181
182    #[test]
183    #[serial(suspend_state)]
184    fn suspended_duration_since_sums_only_later_gaps() {
185        clear_for_test();
186        let t0 = Utc::now() - ChronoDuration::minutes(10);
187        let t1 = Utc::now() - ChronoDuration::minutes(5);
188        inject_gap_for_test(t0, ChronoDuration::minutes(3));
189        inject_gap_for_test(t1, ChronoDuration::minutes(2));
190
191        // Since before t0: both gaps count.
192        let total = suspended_duration_since(t0 - ChronoDuration::seconds(1));
193        assert_eq!(total, ChronoDuration::minutes(5));
194
195        // Since between t0 and t1: only the later gap counts.
196        let total = suspended_duration_since(t0 + ChronoDuration::seconds(1));
197        assert_eq!(total, ChronoDuration::minutes(2));
198
199        // Since after t1: no gaps count.
200        let total = suspended_duration_since(t1 + ChronoDuration::seconds(1));
201        assert_eq!(total, ChronoDuration::zero());
202
203        clear_for_test();
204    }
205
206    #[test]
207    fn suspend_detector_first_check_has_no_baseline() {
208        let mut detector = SuspendDetector::new();
209        assert_eq!(detector.check(), None);
210    }
211
212    #[test]
213    fn suspend_detector_reports_no_gap_for_normal_elapsed_time() {
214        let mut detector = SuspendDetector::new();
215        detector.check();
216        std::thread::sleep(Duration::from_millis(10));
217        assert_eq!(detector.check(), None);
218    }
219
220    #[test]
221    #[serial(suspend_state)]
222    fn gap_detected_within_finds_recent_gap() {
223        clear_for_test();
224        inject_gap_for_test(Utc::now(), ChronoDuration::minutes(7));
225
226        let found = gap_detected_within(Duration::from_secs(60));
227        assert_eq!(found, Some(ChronoDuration::minutes(7)));
228
229        clear_for_test();
230    }
231}