| 1 | //! Stall watchdog for the real-PTY test binaries. |
| 2 | //! |
| 3 | //! These tests drive a real child process through a real pseudo-terminal, and |
| 4 | //! every wait inside [`super::harness::Harness`] is already bounded. The failure |
| 5 | //! mode they cannot bound themselves is a wedge *outside* those waits — a |
| 6 | //! descendant that keeps the PTY slave open, a child that never reaps, a lock |
| 7 | //! nobody releases. libtest has no per-test timeout, so such a wedge does not |
| 8 | //! fail the test: it hangs the binary, and the CI step runs until the job's own |
| 9 | //! ceiling. On the exact-head 0.9.9 `ci.yml` that cost the macOS leg over an |
| 10 | //! hour on the Skills Manager PTY acceptance step. |
| 11 | //! |
| 12 | //! This turns that hang into a failure with evidence. The harness reports |
| 13 | //! progress on every PTY interaction; if no interaction happens for |
| 14 | //! `QA_PTY_STALL_TIMEOUT_SECS` the watchdog prints where it stalled and aborts |
| 15 | //! the process, so the step fails in minutes with a diagnosable message instead |
| 16 | //! of burning the job. |
| 17 | //! |
| 18 | //! It is a backstop, not a budget: the limit is far above any legitimate gap |
| 19 | //! between harness calls (workspace setup, binary spawn), so it can only fire on |
| 20 | //! a genuine wedge. Set `QA_PTY_STALL_TIMEOUT_SECS=0` to disable it when |
| 21 | //! attaching a debugger. |
| 22 | |
| 23 | use std::sync::OnceLock; |
| 24 | use std::sync::atomic::{AtomicU64, Ordering}; |
| 25 | use std::time::{Duration, Instant}; |
| 26 | |
| 27 | /// Default ceiling on silence between harness interactions. |
| 28 | /// |
| 29 | /// The bounded waits inside the harness are 5–20 s (×4 on CI), and the longest |
| 30 | /// non-interacting gap is workspace setup — seconds. Five minutes is therefore |
| 31 | /// unreachable without a wedge, while still capping a wedged CI step at ~1/12 of |
| 32 | /// what the 0.9.9 incident cost. |
| 33 | const DEFAULT_STALL_TIMEOUT: Duration = Duration::from_secs(300); |
| 34 | const POLL_INTERVAL: Duration = Duration::from_secs(5); |
| 35 | |
| 36 | fn epoch() -> Instant { |
| 37 | static EPOCH: OnceLock<Instant> = OnceLock::new(); |
| 38 | *EPOCH.get_or_init(Instant::now) |
| 39 | } |
| 40 | |
| 41 | fn last_progress_millis() -> &'static AtomicU64 { |
| 42 | static LAST: OnceLock<AtomicU64> = OnceLock::new(); |
| 43 | LAST.get_or_init(|| AtomicU64::new(0)) |
| 44 | } |
| 45 | |
| 46 | fn last_label() -> &'static std::sync::Mutex<String> { |
| 47 | static LABEL: OnceLock<std::sync::Mutex<String>> = OnceLock::new(); |
| 48 | LABEL.get_or_init(|| std::sync::Mutex::new("startup".to_string())) |
| 49 | } |
| 50 | |
| 51 | fn stall_timeout() -> Option<Duration> { |
| 52 | let configured = std::env::var("QA_PTY_STALL_TIMEOUT_SECS") |
| 53 | .ok() |
| 54 | .and_then(|raw| raw.trim().parse::<u64>().ok()); |
| 55 | match configured { |
| 56 | Some(0) => None, |
| 57 | Some(seconds) => Some(Duration::from_secs(seconds)), |
| 58 | None => Some(DEFAULT_STALL_TIMEOUT), |
| 59 | } |
| 60 | } |
| 61 | |
| 62 | /// Record that the harness is still making progress, naming what it just did. |
| 63 | /// |
| 64 | /// Cheap enough to call from the pump loop: one relaxed atomic store, and the |
| 65 | /// label is only taken when the lock is free. |
| 66 | pub fn progress(label: &str) { |
| 67 | let elapsed = epoch().elapsed().as_millis().min(u128::from(u64::MAX)) as u64; |
| 68 | last_progress_millis().store(elapsed, Ordering::Relaxed); |
| 69 | if let Ok(mut slot) = last_label().try_lock() |
| 70 | && slot.as_str() != label |
| 71 | { |
| 72 | slot.clear(); |
| 73 | slot.push_str(label); |
| 74 | } |
| 75 | } |
| 76 | |
| 77 | /// Start the watchdog once per process. Safe and cheap to call on every spawn. |
| 78 | pub fn arm() { |
| 79 | static ARMED: OnceLock<()> = OnceLock::new(); |
| 80 | // Stamp progress before arming so the first interval is measured from now, |
| 81 | // not from process start (the binary may have spent minutes linking). |
| 82 | progress("harness spawn"); |
| 83 | ARMED.get_or_init(|| { |
| 84 | let Some(limit) = stall_timeout() else { |
| 85 | return; |
| 86 | }; |
| 87 | let _ = std::thread::Builder::new() |
| 88 | .name("qa-pty-watchdog".into()) |
| 89 | .spawn(move || { |
| 90 | loop { |
| 91 | std::thread::sleep(POLL_INTERVAL); |
| 92 | let last = |
| 93 | Duration::from_millis(last_progress_millis().load(Ordering::Relaxed)); |
| 94 | let now = epoch().elapsed(); |
| 95 | let silent = now.saturating_sub(last); |
| 96 | if silent < limit { |
| 97 | continue; |
| 98 | } |
| 99 | let label = last_label() |
| 100 | .try_lock() |
| 101 | .map(|slot| slot.clone()) |
| 102 | .unwrap_or_else(|_| "<label lock held>".to_string()); |
| 103 | eprintln!( |
| 104 | "\nqa-pty watchdog: no PTY harness activity for {silent:?} \ |
| 105 | (limit {limit:?}). Last harness step: {label}.\n\ |
| 106 | A real-PTY test is wedged outside its bounded waits — most likely a \ |
| 107 | descendant holding the PTY slave open, or a child that never reaps. \ |
| 108 | Aborting so the step fails now instead of running to the job ceiling. \ |
| 109 | Set QA_PTY_STALL_TIMEOUT_SECS=0 to disable this when debugging." |
| 110 | ); |
| 111 | std::process::abort(); |
| 112 | } |
| 113 | }); |
| 114 | }); |
| 115 | } |
| 116 |