From 14d55137d585f47547c0270486d624f55ac97865 Mon Sep 17 00:00:00 2001
From: Stefan Steiner <ssteiner@tableau.com>
Date: Sun, 6 Sep 2026 02:15:37 -0700
Subject: [PATCH] test(mcp): measure daemon idle timeout from before the
 countdown starts
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

`daemon_idle_timeout_shuts_down_daemon` captured its `Instant::now()`
reference after `DaemonState::new()` had already started the idle
countdown, so `elapsed` under-reported the interval the monitor actually
waited by however long this thread took to construct the state and spawn
the monitor. The `elapsed >= 2s` lower bound then rested entirely on the
accumulated overshoot of the monitor's twenty 100ms sleeps — about 60ms
on an idle Apple Silicon host, and a property of the host's timer slack
rather than anything the test controls. A parent stall exceeding that
cushion, which an oversubscribed runner can produce between `spawn`
returning and `Instant::now()`, drives `elapsed` under two seconds and
fails the assertion. Seen once on the macos-14 leg; the same commit
passed on re-run.

Taking the reference before `DaemonState::new()` makes the bound follow
from the monotonic clock instead of a race: the monitor requests
shutdown only once `last_activity.elapsed() >= idle_timeout`, and the
reference is at or before `last_activity`, so `elapsed >= idle_timeout`
always holds. Injecting a 150ms stall after the spawn reproduces the
original failure exactly and passes with the new reference, as does
1500ms.

`daemon_heartbeat_prevents_idle_shutdown` shared the defect behind a
larger accidental cushion, measuring from after its heartbeat thread was
joined rather than from the last `touch()`. It now reports the instant
taken before its final touch and asserts the whole idle timeout instead
of an arbitrary 500ms. Both assertions also gained messages that print
the observed duration, which the original failure did not.
---
 hyperdb-mcp/tests/daemon_tests.rs | 39 +++++++++++++++++++++++--------
 1 file changed, 29 insertions(+), 10 deletions(-)

diff --git a/hyperdb-mcp/tests/daemon_tests.rs b/hyperdb-mcp/tests/daemon_tests.rs
index 9dc5df92..76c61198 100644
--- a/hyperdb-mcp/tests/daemon_tests.rs
+++ b/hyperdb-mcp/tests/daemon_tests.rs
@@ -758,9 +758,17 @@ fn run_engine_report_child() {
 
 #[test]
 fn daemon_idle_timeout_shuts_down_daemon() {
-    let state = Arc::new(DaemonState::new());
     let idle_timeout = Duration::from_secs(2);
 
+    // Captured before `DaemonState::new()`, which is what starts the idle
+    // countdown. The monitor decides against `last_activity`, so a reference
+    // taken after construction measures a shorter interval than the one the
+    // daemon actually waited, and the lower bound below would then turn on how
+    // long this thread took to get from `new()` to `Instant::now()` rather
+    // than on the timeout under test.
+    let start = Instant::now();
+    let state = Arc::new(DaemonState::new());
+
     let monitor_state = Arc::clone(&state);
     let monitor = std::thread::spawn(move || {
         loop {
@@ -775,13 +783,18 @@ fn daemon_idle_timeout_shuts_down_daemon() {
         }
     });
 
-    let start = Instant::now();
     monitor.join().unwrap();
     let elapsed = start.elapsed();
 
     assert!(state.should_shutdown());
-    assert!(elapsed >= Duration::from_secs(2));
-    assert!(elapsed < Duration::from_secs(4));
+    assert!(
+        elapsed >= idle_timeout,
+        "idle shutdown fired after {elapsed:?}, before the {idle_timeout:?} idle period elapsed"
+    );
+    assert!(
+        elapsed < idle_timeout * 2,
+        "idle shutdown took {elapsed:?}, far beyond the {idle_timeout:?} timeout"
+    );
 }
 
 #[test]
@@ -792,12 +805,19 @@ fn daemon_heartbeat_prevents_idle_shutdown() {
     let monitor_state = Arc::clone(&state);
     let heartbeat_state = Arc::clone(&state);
 
+    // Reports back the instant taken just before its final `touch()`. The
+    // monitor counts from what that `touch()` stored, so measuring from this
+    // reference — rather than from whenever the heartbeat thread happened to
+    // be joined — keeps the wait below tied to the reset the monitor saw.
     let heartbeat = std::thread::spawn(move || {
         let start = Instant::now();
+        let mut last_heartbeat = start;
         while start.elapsed() < Duration::from_millis(1500) {
+            last_heartbeat = Instant::now();
             heartbeat_state.touch();
             std::thread::sleep(Duration::from_millis(200));
         }
+        last_heartbeat
     });
 
     let monitor = std::thread::spawn(move || {
@@ -813,16 +833,15 @@ fn daemon_heartbeat_prevents_idle_shutdown() {
         }
     });
 
-    heartbeat.join().unwrap();
-    let start = Instant::now();
+    let last_heartbeat = heartbeat.join().unwrap();
     monitor.join().unwrap();
-    let after_heartbeat_stop = start.elapsed();
+    let waited = last_heartbeat.elapsed();
 
     assert!(state.should_shutdown());
     assert!(
-        after_heartbeat_stop >= Duration::from_millis(500),
-        "daemon should have waited for idle timeout after heartbeats stopped, \
-         but only waited {after_heartbeat_stop:?}"
+        waited >= idle_timeout,
+        "daemon shut down {waited:?} after the last heartbeat, before the \
+         {idle_timeout:?} idle period elapsed"
     );
 }