From 8809ea04ab8f849c72bec605213359200521313c Mon Sep 17 00:00:00 2001 From: Nils Andreas Svee Date: Fri, 8 May 2026 13:02:01 +0700 Subject: [PATCH] feat(cli): improve human event output --- crates/irtt-cli/src/lib.rs | 221 +++++++++++++++++++++++++++++++++++- crates/irtt-cli/src/main.rs | 66 ++++++++++- 2 files changed, 280 insertions(+), 7 deletions(-) diff --git a/crates/irtt-cli/src/lib.rs b/crates/irtt-cli/src/lib.rs index cb49c49..ae00d6a 100644 --- a/crates/irtt-cli/src/lib.rs +++ b/crates/irtt-cli/src/lib.rs @@ -55,7 +55,12 @@ pub struct CliArgs { pub tstamp: TimestampArg, /// Received-stats mode to request. - #[arg(long = "stats", value_enum, default_value_t = ReceivedStatsArg::Both)] + #[arg( + long = "stats", + value_enum, + default_value_t = ReceivedStatsArg::Both, + help = "Server received-stats negotiation mode" + )] pub stats: ReceivedStatsArg, /// Server payload fill string to request, up to 32 bytes. @@ -79,6 +84,7 @@ pub struct CliArgs { #[arg(long)] pub loose: bool, + /// Output format: human, simple, machine, or rtt-us. #[arg(long, value_enum, default_value_t = OutputMode::Human)] pub output: OutputMode, } @@ -178,9 +184,13 @@ impl From for ReceivedStats { #[derive(Debug, Clone, Copy, PartialEq, Eq, ValueEnum)] pub enum OutputMode { + /// Readable terminal output with a final summary. Human, + /// Parseable full event fields. Machine, + /// Simple key=value-ish event stream. Simple, + /// RTT microseconds only. RttUs, } @@ -298,12 +308,101 @@ pub fn format_event(event: &ClientEvent, mode: OutputMode) -> Option { } match mode { OutputMode::RttUs => format_rtt_us(event), - OutputMode::Human => Some(format_simple(event)), + OutputMode::Human => Some(format_human_event(event, None)), OutputMode::Machine => Some(format_machine(event)), OutputMode::Simple => Some(format_simple(event)), } } +#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)] +pub struct HumanEventStats { + pub contributed_sample: bool, + pub rtt_ipdv: Option, + pub send_ipdv: Option, + pub receive_ipdv: Option, +} + +#[cfg(feature = "stats")] +impl From for HumanEventStats { + fn from(value: irtt_stats::EventStatsUpdate) -> Self { + Self { + contributed_sample: value.contributed_sample, + rtt_ipdv: value.rtt_ipdv, + send_ipdv: value.send_ipdv, + receive_ipdv: value.receive_ipdv, + } + } +} + +pub fn format_human_event(event: &ClientEvent, stats: Option) -> String { + match event { + ClientEvent::SessionStarted { remote, token, .. } => { + format!("session started remote={remote} token={token:#x}") + } + ClientEvent::NoTestCompleted { remote, .. } => { + format!("no-test completed remote={remote}") + } + ClientEvent::SessionClosed { remote, token, .. } => { + format!("session closed remote={remote} token={token:#x}") + } + ClientEvent::EchoSent { .. } => String::new(), + ClientEvent::EchoReply { + seq, + logical_seq, + rtt, + server_timing, + one_way, + received_stats, + .. + } => { + let mut out = format!( + "seq={seq} logical_seq={logical_seq} rtt={}", + format_duration(rtt.effective) + ); + write_human_one_way(&mut out, *one_way); + write!(out, " ipdv={}", format_human_ipdv(stats)).unwrap(); + if let Some(processing) = server_timing.and_then(|timing| timing.processing) { + write!(out, " proc={}", format_duration(processing)).unwrap(); + } + write_human_received_stats(&mut out, *received_stats); + out + } + ClientEvent::EchoLoss { + seq, logical_seq, .. + } => { + format!("loss seq={seq} logical_seq={logical_seq}") + } + ClientEvent::DuplicateReply { seq, remote, .. } => { + format!("duplicate seq={seq} remote={remote}") + } + ClientEvent::LateReply { + seq, + logical_seq, + highest_seen, + remote, + rtt, + one_way, + received_stats, + .. + } => { + let mut out = format!( + "late seq={seq} logical_seq={} highest_seen={highest_seen} remote={remote}", + optional_u64(*logical_seq) + ); + if let Some(rtt) = rtt { + write!(out, " rtt={}", format_duration(rtt.effective)).unwrap(); + write_human_one_way(&mut out, *one_way); + write!(out, " ipdv={}", format_human_ipdv(stats)).unwrap(); + } + write_human_received_stats(&mut out, *received_stats); + out + } + ClientEvent::Warning { kind, message } => { + format!("warning kind={} message={message}", warning_kind(*kind)) + } + } +} + fn format_rtt_us(event: &ClientEvent) -> Option { match event { ClientEvent::EchoReply { rtt, .. } => Some(duration_us(rtt.effective).to_string()), @@ -592,6 +691,39 @@ fn write_packet_meta(out: &mut String, meta: PacketMeta) { } } +fn write_human_one_way(out: &mut String, one_way: Option) { + match one_way { + Some(one_way) => { + write!( + out, + " rd={} sd={}", + format_optional_duration(one_way.server_to_client), + format_optional_duration(one_way.client_to_server) + ) + .unwrap(); + } + None => out.push_str(" rd=n/a sd=n/a"), + } +} + +fn write_human_received_stats(out: &mut String, stats: Option) { + if let Some(stats) = stats { + if let Some(count) = stats.count { + write!(out, " server_received={count}").unwrap(); + } + if let Some(window) = stats.window { + write!(out, " server_window={window:#x}").unwrap(); + } + } +} + +fn format_human_ipdv(stats: Option) -> String { + match stats.and_then(|stats| stats.rtt_ipdv) { + Some(ipdv) => format_duration(ipdv), + None => "n/a".to_owned(), + } +} + fn write_optional_u8(out: &mut String, key: &str, value: Option) { match value { Some(value) => write!(out, " {key}={value}").unwrap(), @@ -609,6 +741,28 @@ fn duration_us(duration: Duration) -> u128 { duration.as_micros() } +fn format_optional_duration(duration: Option) -> String { + duration + .map(format_duration) + .unwrap_or_else(|| "n/a".to_owned()) +} + +fn format_duration(duration: Duration) -> String { + format_ns(duration.as_nanos() as f64) +} + +fn format_ns(ns: f64) -> String { + if ns < 1_000.0 { + format!("{ns:.0}ns") + } else if ns < 1_000_000.0 { + format!("{:.1}µs", ns / 1_000.0) + } else if ns < 1_000_000_000.0 { + format!("{:.1}ms", ns / 1_000_000.0) + } else { + format!("{:.3}s", ns / 1_000_000_000.0) + } +} + fn optional_u64(value: Option) -> String { value .map(|value| value.to_string()) @@ -1123,9 +1277,15 @@ mod tests { #[test] fn human_uses_readable_per_event_lines() { let line = format_event(&reply_event(), OutputMode::Human).unwrap(); - assert_eq!( + assert!(line.starts_with("seq=7 logical_seq=8 rtt=1.2ms")); + assert!(line.contains("rd=500.0µs")); + assert!(line.contains("sd=400.0µs")); + assert!(line.contains("ipdv=n/a")); + assert!(line.contains("proc=300.0µs")); + assert!(!line.contains("rtt_us=")); + assert_ne!( line, - "reply seq=7 logical_seq=8 remote=127.0.0.1:2112 rtt_us=1200 raw_rtt_us=1500 server_processing_us=300" + format_event(&reply_event(), OutputMode::Simple).unwrap() ); assert!(OutputMode::Human.prints_summary()); assert!(!OutputMode::Simple.prints_summary()); @@ -1133,6 +1293,59 @@ mod tests { assert!(!OutputMode::RttUs.prints_summary()); } + #[test] + fn human_reply_uses_supplied_ipdv_update() { + let line = format_human_event( + &reply_event(), + Some(HumanEventStats { + contributed_sample: true, + rtt_ipdv: Some(Duration::from_micros(47)), + send_ipdv: None, + receive_ipdv: None, + }), + ); + + assert!(line.contains("ipdv=47.0µs")); + } + + #[test] + fn human_reply_marks_missing_one_way_delay_unavailable() { + let ClientEvent::EchoReply { + seq, + logical_seq, + remote, + sent_at, + received_at, + rtt, + server_timing, + received_stats, + bytes, + packet_meta, + .. + } = reply_event() + else { + unreachable!(); + }; + let event = ClientEvent::EchoReply { + seq, + logical_seq, + remote, + sent_at, + received_at, + rtt, + server_timing, + one_way: None, + received_stats, + bytes, + packet_meta, + }; + + let line = format_human_event(&event, None); + + assert!(line.contains("rd=n/a")); + assert!(line.contains("sd=n/a")); + } + #[test] fn echo_sent_is_not_formatted_for_stream_outputs() { let ts = test_timestamp(Duration::from_secs(1)); diff --git a/crates/irtt-cli/src/main.rs b/crates/irtt-cli/src/main.rs index d61e610..b290b94 100644 --- a/crates/irtt-cli/src/main.rs +++ b/crates/irtt-cli/src/main.rs @@ -10,7 +10,7 @@ use std::{ }; use clap::Parser; -use irtt_cli::{format_event, CliArgs}; +use irtt_cli::{format_event, format_human_event, CliArgs, OutputMode}; use irtt_client::{Client, ClientEvent, ClientTimestamp, OpenOutcome, RecvBudget}; #[cfg(feature = "stats")] use irtt_stats::{StatsCollector, StatsConfig}; @@ -194,9 +194,19 @@ impl EventOutput<'_, W> { fn print_event(&mut self, event: &ClientEvent) -> io::Result<()> { #[cfg(feature = "stats")] - self.stats.process(event); + let stats_update = self.stats.process(event); - if let Some(line) = format_event(event, self.mode) { + #[cfg(not(feature = "stats"))] + let stats_update = irtt_cli::HumanEventStats::default(); + + let line = + if self.mode == OutputMode::Human && !matches!(event, ClientEvent::EchoSent { .. }) { + Some(format_human_event(event, Some(stats_update.into()))) + } else { + format_event(event, self.mode) + }; + + if let Some(line) = line { writeln!(self.out, "{line}")?; } Ok(()) @@ -284,6 +294,35 @@ mod tests { SocketAddr::new(IpAddr::V4(Ipv4Addr::LOCALHOST), 2112) } + fn reply_event(logical_seq: u64, rtt_us: u64) -> ClientEvent { + let sent_at = test_timestamp(Duration::from_millis(logical_seq)); + let received_at = ClientTimestamp { + wall: sent_at.wall + Duration::from_micros(rtt_us), + mono: sent_at.mono + Duration::from_micros(rtt_us), + }; + ClientEvent::EchoReply { + seq: logical_seq as u32, + logical_seq, + remote: test_remote(), + sent_at, + received_at, + rtt: RttSample { + raw: Duration::from_micros(rtt_us), + adjusted: None, + effective: Duration::from_micros(rtt_us), + adjusted_signed: None, + effective_signed: SignedDuration { + ns: i128::from(rtt_us) * 1_000, + }, + }, + server_timing: None, + one_way: None, + received_stats: None, + bytes: 64, + packet_meta: PacketMeta::default(), + } + } + #[test] fn output_helper_streams_and_collects_events() { let sent_at = test_timestamp(Duration::from_secs(1)); @@ -357,6 +396,27 @@ mod tests { assert!(out.is_empty()); } + #[test] + fn human_output_prints_ipdv_from_stats_update() { + let events = [reply_event(0, 1200), reply_event(1, 1250)]; + let mut stats = StatsCollector::new(StatsConfig::finite()); + let mut out = Vec::new(); + { + let mut output = EventOutput { + mode: irtt_cli::OutputMode::Human, + print_finite_summary: false, + out: &mut out, + stats: &mut stats, + }; + output.print_events(&events).unwrap(); + } + + let rendered = String::from_utf8(out).unwrap(); + let mut lines = rendered.lines(); + assert!(lines.next().unwrap().contains("ipdv=n/a")); + assert!(lines.next().unwrap().contains("ipdv=50.0µs")); + } + #[test] fn continuous_mode_uses_continuous_stats_config() { let mut collector = StatsCollector::new(stats_config(true));