From 3b5336a4873930800b4fe3b82193ac60063f2c16 Mon Sep 17 00:00:00 2001 From: Nils Andreas Svee Date: Sun, 17 May 2026 23:55:01 +0700 Subject: [PATCH] refactor(client): use SignedDuration for one-way delay to support negative values Allow one-way delay samples to represent negative values caused by wall-clock skew between client and server. Update CLI output and statistics collection to correctly handle and report these signed durations. --- crates/irtt-cli/src/lib.rs | 66 ++++++++++++++++--- crates/irtt-client/src/client.rs | 4 +- .../tests/probes_replies/timing_math.rs | 66 ++++++++++++++++++- crates/irtt-client/src/event.rs | 22 ++++++- crates/irtt-stats/src/normalization.rs | 4 +- crates/irtt-stats/tests/common/mod.rs | 4 +- crates/irtt-stats/tests/stats.rs | 46 ++++++++++++- 7 files changed, 193 insertions(+), 19 deletions(-) diff --git a/crates/irtt-cli/src/lib.rs b/crates/irtt-cli/src/lib.rs index 9c32ed6..4ee268b 100644 --- a/crates/irtt-cli/src/lib.rs +++ b/crates/irtt-cli/src/lib.rs @@ -681,10 +681,10 @@ fn write_server_timing(out: &mut String, timing: Option) { fn write_one_way(out: &mut String, one_way: Option) { if let Some(one_way) = one_way { if let Some(value) = one_way.client_to_server { - write!(out, " client_to_server_us={}", duration_us(value)).unwrap(); + write!(out, " client_to_server_us={}", signed_duration_us(value)).unwrap(); } if let Some(value) = one_way.server_to_client { - write!(out, " server_to_client_us={}", duration_us(value)).unwrap(); + write!(out, " server_to_client_us={}", signed_duration_us(value)).unwrap(); } } } @@ -716,8 +716,8 @@ fn write_human_one_way(out: &mut String, one_way: Option) { write!( out, " rd={} sd={}", - format_optional_duration(one_way.server_to_client), - format_optional_duration(one_way.client_to_server) + format_optional_signed_duration(one_way.server_to_client), + format_optional_signed_duration(one_way.client_to_server) ) .unwrap(); } @@ -777,9 +777,9 @@ fn signed_duration_us(duration: SignedDuration) -> i128 { duration.as_micros() } -fn format_optional_duration(duration: Option) -> String { +fn format_optional_signed_duration(duration: Option) -> String { duration - .map(format_duration) + .map(format_signed_duration) .unwrap_or_else(|| "n/a".to_owned()) } @@ -882,8 +882,8 @@ mod tests { processing: Some(Duration::from_micros(300)), }), one_way: Some(OneWayDelaySample { - client_to_server: Some(Duration::from_micros(400)), - server_to_client: Some(Duration::from_micros(500)), + client_to_server: Some(SignedDuration::from_nanos(400_000)), + server_to_client: Some(SignedDuration::from_nanos(500_000)), }), received_stats: Some(ReceivedStatsSample { count: Some(9), @@ -922,6 +922,40 @@ mod tests { } } + fn negative_one_way_reply_event() -> ClientEvent { + let ClientEvent::EchoReply { + seq, + remote, + sent_at, + received_at, + rtt, + server_timing, + received_stats, + bytes, + packet_meta, + .. + } = reply_event() + else { + unreachable!(); + }; + + ClientEvent::EchoReply { + seq, + remote, + sent_at, + received_at, + rtt, + server_timing, + one_way: Some(OneWayDelaySample { + client_to_server: Some(SignedDuration::from_nanos(-400_000)), + server_to_client: Some(SignedDuration::from_nanos(-500_000)), + }), + received_stats, + bytes, + packet_meta, + } + } + fn late_event_with_meta(packet_meta: PacketMeta) -> ClientEvent { ClientEvent::LateReply { seq: 4, @@ -1238,6 +1272,14 @@ mod tests { assert!(line.contains("server_received_count=9")); } + #[test] + fn machine_prints_negative_one_way_delay_values() { + let line = format_event(&negative_one_way_reply_event(), OutputMode::Machine).unwrap(); + + assert!(line.contains("client_to_server_us=-400")); + assert!(line.contains("server_to_client_us=-500")); + } + #[test] fn machine_echo_reply_metadata_prints_observed_and_unavailable_values() { let cases = [ @@ -1300,6 +1342,14 @@ mod tests { assert!(!OutputMode::RttUs.prints_summary()); } + #[test] + fn human_prints_negative_one_way_delay_values() { + let line = format_event(&negative_one_way_reply_event(), OutputMode::Human).unwrap(); + + assert!(line.contains("rd=-500.0µs")); + assert!(line.contains("sd=-400.0µs")); + } + #[test] fn verbose_human_reply_includes_extra_fields() { let line = format_human_event_with_options( diff --git a/crates/irtt-client/src/client.rs b/crates/irtt-client/src/client.rs index e666677..58e46e3 100644 --- a/crates/irtt-client/src/client.rs +++ b/crates/irtt-client/src/client.rs @@ -789,11 +789,11 @@ fn compute_one_way( let c2s = server_recv_wall .zip(client_send_ns) .and_then(|(srv, cli)| srv.checked_sub(cli)) - .and_then(|d| u64::try_from(d).ok().map(Duration::from_nanos)); + .map(|d| SignedDuration::from_nanos(i128::from(d))); let s2c = client_recv_ns .zip(server_send_wall) .and_then(|(cli, srv)| cli.checked_sub(srv)) - .and_then(|d| u64::try_from(d).ok().map(Duration::from_nanos)); + .map(|d| SignedDuration::from_nanos(i128::from(d))); if c2s.is_none() && s2c.is_none() { return None; diff --git a/crates/irtt-client/src/client/tests/probes_replies/timing_math.rs b/crates/irtt-client/src/client/tests/probes_replies/timing_math.rs index 85b9acf..a207be7 100644 --- a/crates/irtt-client/src/client/tests/probes_replies/timing_math.rs +++ b/crates/irtt-client/src/client/tests/probes_replies/timing_math.rs @@ -90,6 +90,68 @@ fn compute_one_way_returns_available_direction_samples() { }; let sample = compute_one_way(&sent_at, &received_at, &ts).unwrap(); - assert_eq!(sample.client_to_server, Some(Duration::from_millis(15))); - assert_eq!(sample.server_to_client, Some(Duration::from_millis(15))); + assert_eq!( + sample.client_to_server, + Some(SignedDuration::from_nanos(15_000_000)) + ); + assert_eq!( + sample.server_to_client, + Some(SignedDuration::from_nanos(15_000_000)) + ); +} + +#[test] +fn compute_one_way_preserves_negative_client_to_server_delay() { + let sent_at = ClientTimestamp { + mono: Instant::now(), + wall: SystemTime::UNIX_EPOCH + Duration::from_secs(10), + }; + let received_at = ClientTimestamp { + mono: sent_at.mono + Duration::from_millis(40), + wall: SystemTime::UNIX_EPOCH + Duration::from_secs(10) + Duration::from_millis(40), + }; + let ts = TimestampFields { + recv_wall: Some(10_000_000_000 - 5_000_000), + send_wall: Some(10_000_000_000 + 25_000_000), + ..Default::default() + }; + + let sample = compute_one_way(&sent_at, &received_at, &ts).unwrap(); + + assert_eq!( + sample.client_to_server, + Some(SignedDuration::from_nanos(-5_000_000)) + ); + assert_eq!( + sample.server_to_client, + Some(SignedDuration::from_nanos(15_000_000)) + ); +} + +#[test] +fn compute_one_way_preserves_negative_server_to_client_delay() { + let sent_at = ClientTimestamp { + mono: Instant::now(), + wall: SystemTime::UNIX_EPOCH + Duration::from_secs(10), + }; + let received_at = ClientTimestamp { + mono: sent_at.mono + Duration::from_millis(40), + wall: SystemTime::UNIX_EPOCH + Duration::from_secs(10) + Duration::from_millis(40), + }; + let ts = TimestampFields { + recv_wall: Some(10_000_000_000 + 15_000_000), + send_wall: Some(10_000_000_000 + 45_000_000), + ..Default::default() + }; + + let sample = compute_one_way(&sent_at, &received_at, &ts).unwrap(); + + assert_eq!( + sample.client_to_server, + Some(SignedDuration::from_nanos(15_000_000)) + ); + assert_eq!( + sample.server_to_client, + Some(SignedDuration::from_nanos(-5_000_000)) + ); } diff --git a/crates/irtt-client/src/event.rs b/crates/irtt-client/src/event.rs index 08ce284..2e0834f 100644 --- a/crates/irtt-client/src/event.rs +++ b/crates/irtt-client/src/event.rs @@ -168,9 +168,27 @@ pub struct ServerTiming { } #[derive(Debug, Clone, Copy, PartialEq, Eq)] +/// Directional one-way delay samples computed from wall-clock timestamps. +/// +/// Each directional field is an `Option`. `None` means the +/// required client or server wall-clock timestamp was unavailable, or the +/// timestamp arithmetic was out of range. `Some(value)` means the delay was +/// computed from available timestamps. +/// +/// Negative computed values are preserved as `Some` instead of being clamped to +/// zero or dropped. A negative one-way delay usually indicates wall-clock skew +/// between the client and server. pub struct OneWayDelaySample { - pub client_to_server: Option, - pub server_to_client: Option, + /// Client-to-server delay. + /// + /// This is computed from the client send wall time and the server receive + /// wall time when both are available. + pub client_to_server: Option, + /// Server-to-client delay. + /// + /// This is computed from the server send wall time and the client receive + /// wall time when both are available. + pub server_to_client: Option, } #[derive(Debug, Clone, Copy, PartialEq, Eq)] diff --git a/crates/irtt-stats/src/normalization.rs b/crates/irtt-stats/src/normalization.rs index 4aafd74..5445961 100644 --- a/crates/irtt-stats/src/normalization.rs +++ b/crates/irtt-stats/src/normalization.rs @@ -163,10 +163,10 @@ impl ReplySample { rtt_adjusted_ns: rtt.adjusted.map(signed_duration_ns), send_delay_ns: one_way .and_then(|sample| sample.client_to_server) - .map(duration_ns_i128), + .map(signed_duration_ns), receive_delay_ns: one_way .and_then(|sample| sample.server_to_client) - .map(duration_ns_i128), + .map(signed_duration_ns), server_processing_ns: server_timing .and_then(|timing| timing.processing) .map(duration_ns_i128), diff --git a/crates/irtt-stats/tests/common/mod.rs b/crates/irtt-stats/tests/common/mod.rs index 678964f..bb60b2d 100644 --- a/crates/irtt-stats/tests/common/mod.rs +++ b/crates/irtt-stats/tests/common/mod.rs @@ -72,8 +72,8 @@ fn reply_with_rtt(seq: u32, raw_ms: u64, rtt: RttSample) -> ClientEvent { processing: Some(Duration::from_millis(1)), }), one_way: Some(OneWayDelaySample { - client_to_server: Some(Duration::from_millis(1)), - server_to_client: Some(Duration::from_millis(2)), + client_to_server: Some(SignedDuration::from_nanos(1_000_000)), + server_to_client: Some(SignedDuration::from_nanos(2_000_000)), }), received_stats: Some(ReceivedStatsSample { count: Some(seq + 1), diff --git a/crates/irtt-stats/tests/stats.rs b/crates/irtt-stats/tests/stats.rs index c0ee352..dd487f5 100644 --- a/crates/irtt-stats/tests/stats.rs +++ b/crates/irtt-stats/tests/stats.rs @@ -3,7 +3,9 @@ mod common; use std::time::{Duration, Instant, UNIX_EPOCH}; use common::{adjusted_reply, sent, ts, unadjusted_late_reply, unadjusted_reply}; -use irtt_client::{ClientEvent, ClientTimestamp, PacketMeta, RttSample, SignedDuration}; +use irtt_client::{ + ClientEvent, ClientTimestamp, OneWayDelaySample, PacketMeta, RttSample, SignedDuration, +}; use irtt_stats::{EventStatsUpdate, IpdvPairUpdate, SampleMode, StatsCollector, StatsConfig}; #[test] @@ -280,6 +282,48 @@ fn server_processing_and_one_way_require_available_samples() { assert_eq!(snapshot.packets.bytes_received, 128); } +#[test] +fn negative_one_way_delay_samples_are_included_in_stats() { + let mut collector = StatsCollector::new(StatsConfig::finite()); + let sent_at = ts(0); + let received_at = ClientTimestamp { + mono: sent_at.mono + Duration::from_millis(10), + wall: sent_at.wall + Duration::from_millis(10), + }; + + collector.process(&ClientEvent::EchoReply { + seq: 0, + remote: "127.0.0.1:2112".parse().unwrap(), + sent_at, + received_at, + rtt: RttSample { + raw: Duration::from_millis(10), + adjusted: None, + effective: SignedDuration::from_nanos(10_000_000), + }, + server_timing: None, + one_way: Some(OneWayDelaySample { + client_to_server: Some(SignedDuration::from_nanos(-1_000_000)), + server_to_client: Some(SignedDuration::from_nanos(-2_000_000)), + }), + received_stats: None, + bytes: 64, + packet_meta: PacketMeta::default(), + }); + + let snapshot = collector.snapshot(); + + assert_eq!(snapshot.one_way_delay.send_delay.count, 1); + assert_eq!(snapshot.one_way_delay.send_delay.min_ns, Some(-1_000_000)); + assert_eq!(snapshot.one_way_delay.send_delay.total_ns, -1_000_000); + assert_eq!(snapshot.one_way_delay.receive_delay.count, 1); + assert_eq!( + snapshot.one_way_delay.receive_delay.min_ns, + Some(-2_000_000) + ); + assert_eq!(snapshot.one_way_delay.receive_delay.total_ns, -2_000_000); +} + #[test] fn older_cumulative_server_receive_count_does_not_regress() { let mut collector = StatsCollector::new(StatsConfig::finite());