From 540532de44b98141ccb0d9c69da7b1d2d2600144 Mon Sep 17 00:00:00 2001 From: Johnathan Corgan Date: Sun, 26 Jul 2026 18:50:31 +0000 Subject: [PATCH] Make the test backdating seams fail loudly instead of moving time forward Windows unit tests have been reding on next at a rekey-drain assertion that reads like a defect in the drain logic. The drain logic is correct; the test never reached the state it asserts on. All three test-only backdating seams shared the fallback checked_sub(age).unwrap_or_else(Instant::now). When the requested backdate falls outside the monotonic clock's representable range, that assigns the present instant, moving the timestamp forward rather than backward. A fresh Windows CI runner has been up for less than the 600 seconds the drain test asked for, so the window looked brand new, check_rekey correctly declined to release the demoted session, and the assertion fired against innocent code. The seams now route through a shared helper that panics naming the field, the requested age and the real cause. The drain test asks for 30 seconds, three times the ten-second window it needs to clear, rather than sixty times it. Both properties were established by breaking them. Backdating by five seconds, inside the window, reds the test, so it still depends on expiry rather than passing vacuously at the smaller margin. Forcing the subtraction to fail produces the new panic and its explanation rather than a silent reset. Full cargo test --lib green at 1742, fmt and clippy clean. No step ran on Windows, so the platform mechanism is inferred from the split between runners and confirmed only when that job goes green on this tip. --- src/node/tests/handshake.rs | 7 ++++++- src/peer/active.rs | 34 ++++++++++++++++++++++++---------- 2 files changed, 30 insertions(+), 11 deletions(-) diff --git a/src/node/tests/handshake.rs b/src/node/tests/handshake.rs index e8b9a60..69a4b29 100644 --- a/src/node/tests/handshake.rs +++ b/src/node/tests/handshake.rs @@ -2315,11 +2315,16 @@ async fn test_non_initiating_responder_completes_rekey_drain() { // Window expires. This is the only path that releases the demoted session, // and a node that does not initiate rekeys still has to run it. + // + // Backdate by three times the 10s drain window rather than by minutes: the + // backdate cannot reach past the monotonic clock's epoch, so a margin larger + // than the machine's uptime is unrepresentable, and a freshly booted CI + // runner is exactly that machine. responder .node .get_peer_mut(&initiator_addr) .unwrap() - .test_backdate_drain_start(std::time::Duration::from_secs(600)); + .test_backdate_drain_start(std::time::Duration::from_secs(30)); responder.node.check_rekey().await; let peer = responder.node.get_peer(&initiator_addr).unwrap(); diff --git a/src/peer/active.rs b/src/peer/active.rs index 50db4ec..9218ce3 100644 --- a/src/peer/active.rs +++ b/src/peer/active.rs @@ -1008,6 +1008,26 @@ impl ActivePeer { )); } + /// Shift `instant` back by `age`, panicking rather than falling back. + /// + /// `Instant::checked_sub` returns `None` when the result would precede the + /// monotonic clock's epoch, which on a freshly booted machine means any + /// backdate larger than the uptime. The fallback these seams used to share + /// was `unwrap_or_else(Instant::now)`, which moved the timestamp *forward* + /// to now — the opposite of every caller's intent — so the caller's + /// assertion then failed for a reason its message did not describe. Failing + /// loudly keeps a machine-dependent limit from reading as a logic bug. + #[cfg(test)] + fn backdate(instant: Instant, age: std::time::Duration, what: &str) -> Instant { + instant.checked_sub(age).unwrap_or_else(|| { + panic!( + "cannot backdate {what} by {age:?}: the monotonic clock's epoch is more \ + recent than that, so the result is unrepresentable. This machine has been \ + up for less than the requested age — use a smaller backdate." + ) + }) + } + /// Test-only seam: backdate the session-start instant so a test can make /// `session_elapsed_ms()` read as `age`-old (needed to synthesize a /// positive RTT sample from a crafted ReceiverReport). This only shifts the @@ -1015,11 +1035,7 @@ impl ActivePeer { /// is compiled out of release builds. #[cfg(test)] pub(crate) fn test_backdate_session_start(&mut self, age: std::time::Duration) { - self.send.session_start = self - .send - .session_start - .checked_sub(age) - .unwrap_or_else(Instant::now); + self.send.session_start = Self::backdate(self.send.session_start, age, "session_start"); } /// Test-only seam: backdate the session-established instant so a test can @@ -1034,10 +1050,8 @@ impl ActivePeer { /// test depend on the draw. #[cfg(test)] pub(crate) fn test_backdate_session_established(&mut self, age: std::time::Duration) { - self.session_established_at = self - .session_established_at - .checked_sub(age) - .unwrap_or_else(Instant::now); + self.session_established_at = + Self::backdate(self.session_established_at, age, "session_established_at"); } /// Test-only seam: backdate the drain-start instant so a test can make @@ -1048,7 +1062,7 @@ impl ActivePeer { #[cfg(test)] pub(crate) fn test_backdate_drain_start(&mut self, age: std::time::Duration) { if let Some(started) = self.send.drain_started { - self.send.drain_started = Some(started.checked_sub(age).unwrap_or_else(Instant::now)); + self.send.drain_started = Some(Self::backdate(started, age, "drain_started")); } }