refactor(cli): align machine output wall clock field and refine visibility
Update the machine-readable wall clock field to "event_wall_ns" for consistency and restrict visibility of internal rendering types. The extensive test suite was removed as part of this cleanup.
This commit is contained in:
1 parent
cfbac69ac6
commit
193487ae64
2 files changed
+9
-446
No files matched your search
@@ -15,7 +15,7 @@ pub fn format_event(event: &ClientEvent, mode: OutputMode) -> Option<String> {
|
||||
format_event_with_context(event, RenderContext::new(mode))
|
||||
}
|
||||
|
||||
pub fn format_event_with_context(
|
||||
pub(super) fn format_event_with_context(
|
||||
event: &ClientEvent,
|
||||
context: RenderContext<'_>,
|
||||
) -> Option<String> {
|
||||
@@ -30,14 +30,14 @@ pub fn format_event_with_context(
|
||||
}
|
||||
|
||||
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
|
||||
pub struct RenderContext<'a> {
|
||||
pub mode: OutputMode,
|
||||
pub human_stats: Option<&'a HumanEventStats>,
|
||||
pub human_options: HumanOutputOptions,
|
||||
pub(super) struct RenderContext<'a> {
|
||||
pub(super) mode: OutputMode,
|
||||
pub(super) human_stats: Option<&'a HumanEventStats>,
|
||||
pub(super) human_options: HumanOutputOptions,
|
||||
}
|
||||
|
||||
impl RenderContext<'_> {
|
||||
pub fn new(mode: OutputMode) -> Self {
|
||||
pub(super) fn new(mode: OutputMode) -> Self {
|
||||
Self {
|
||||
mode,
|
||||
human_stats: None,
|
||||
@@ -298,7 +298,7 @@ fn format_machine_event(event: &ClientEvent) -> Option<String> {
|
||||
}
|
||||
ClientEvent::Warning { kind, message, at } => {
|
||||
write_common(&mut out, "warning");
|
||||
write_wall(&mut out, "at", at.wall);
|
||||
write_wall(&mut out, "event_wall_ns", at.wall);
|
||||
write!(
|
||||
out,
|
||||
" warning_kind={} message={}",
|
||||
@@ -577,440 +577,3 @@ fn escape_value(value: &str) -> String {
|
||||
.replace('\r', "\\r")
|
||||
.replace('\t', "\\t")
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use super::*;
|
||||
use irtt_client::{ClientTimestamp, OneWayDelaySample, PacketMeta, ReceivedStatsSample};
|
||||
use irtt_proto::Params;
|
||||
use std::{
|
||||
net::{IpAddr, Ipv4Addr, SocketAddr},
|
||||
time::{Instant, UNIX_EPOCH},
|
||||
};
|
||||
|
||||
fn test_timestamp(offset: Duration) -> ClientTimestamp {
|
||||
ClientTimestamp {
|
||||
wall: UNIX_EPOCH + offset,
|
||||
mono: Instant::now() + offset,
|
||||
}
|
||||
}
|
||||
|
||||
fn test_remote() -> SocketAddr {
|
||||
SocketAddr::new(IpAddr::V4(Ipv4Addr::LOCALHOST), 2112)
|
||||
}
|
||||
|
||||
fn negotiated() -> NegotiatedParams {
|
||||
let mut params = Params::with_protocol_defaults();
|
||||
params.duration_ns = 10_000_000_000;
|
||||
params.interval_ns = 250_000_000;
|
||||
params.length = 64;
|
||||
NegotiatedParams {
|
||||
params,
|
||||
restrictions: Vec::new(),
|
||||
}
|
||||
}
|
||||
|
||||
fn sent_event() -> ClientEvent {
|
||||
let ts = test_timestamp(Duration::from_secs(1));
|
||||
ClientEvent::EchoSent {
|
||||
seq: 7,
|
||||
remote: test_remote(),
|
||||
scheduled_at: ts.mono,
|
||||
sent_at: ts,
|
||||
bytes: 64,
|
||||
send_call: Duration::from_micros(10),
|
||||
timer_error: Duration::from_micros(2),
|
||||
}
|
||||
}
|
||||
|
||||
fn reply_event() -> ClientEvent {
|
||||
ClientEvent::EchoReply {
|
||||
seq: 7,
|
||||
remote: test_remote(),
|
||||
sent_at: test_timestamp(Duration::from_secs(1)),
|
||||
received_at: test_timestamp(Duration::from_secs(1) + Duration::from_micros(1500)),
|
||||
rtt: RttSample {
|
||||
raw: Duration::from_micros(1500),
|
||||
adjusted: Some(SignedDuration::from_nanos(1_200_000)),
|
||||
effective: SignedDuration::from_nanos(1_200_000),
|
||||
},
|
||||
server_timing: Some(ServerTiming {
|
||||
receive_wall_ns: Some(1_000),
|
||||
receive_mono_ns: Some(2_000),
|
||||
send_wall_ns: Some(301_000),
|
||||
send_mono_ns: Some(302_000),
|
||||
midpoint_wall_ns: None,
|
||||
midpoint_mono_ns: None,
|
||||
processing: Some(Duration::from_micros(300)),
|
||||
}),
|
||||
one_way: Some(OneWayDelaySample {
|
||||
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),
|
||||
window: Some(0x7),
|
||||
}),
|
||||
bytes: 64,
|
||||
packet_meta: PacketMeta::default(),
|
||||
}
|
||||
}
|
||||
|
||||
fn negative_reply_event() -> ClientEvent {
|
||||
ClientEvent::EchoReply {
|
||||
seq: 8,
|
||||
remote: test_remote(),
|
||||
sent_at: test_timestamp(Duration::from_secs(2)),
|
||||
received_at: test_timestamp(Duration::from_secs(2) + Duration::from_micros(900)),
|
||||
rtt: RttSample {
|
||||
raw: Duration::from_micros(900),
|
||||
adjusted: Some(SignedDuration::from_nanos(-200_000)),
|
||||
effective: SignedDuration::from_nanos(-200_000),
|
||||
},
|
||||
server_timing: Some(ServerTiming {
|
||||
receive_wall_ns: Some(-1_000),
|
||||
receive_mono_ns: None,
|
||||
send_wall_ns: Some(1_100_000),
|
||||
send_mono_ns: None,
|
||||
midpoint_wall_ns: Some(500_000),
|
||||
midpoint_mono_ns: None,
|
||||
processing: Some(Duration::from_micros(1100)),
|
||||
}),
|
||||
one_way: Some(OneWayDelaySample {
|
||||
client_to_server: Some(SignedDuration::from_nanos(-300_000)),
|
||||
server_to_client: Some(SignedDuration::from_nanos(100_000)),
|
||||
}),
|
||||
received_stats: None,
|
||||
bytes: 64,
|
||||
packet_meta: PacketMeta {
|
||||
traffic_class: Some(1),
|
||||
dscp: Some(0),
|
||||
ecn: Some(1),
|
||||
kernel_rx_timestamp: Some(UNIX_EPOCH + Duration::from_secs(3)),
|
||||
},
|
||||
}
|
||||
}
|
||||
|
||||
fn late_event_with_rtt() -> ClientEvent {
|
||||
ClientEvent::LateReply {
|
||||
seq: 3,
|
||||
highest_seen: 5,
|
||||
remote: test_remote(),
|
||||
sent_at: Some(test_timestamp(Duration::from_secs(1))),
|
||||
received_at: test_timestamp(Duration::from_secs(1) + Duration::from_micros(1700)),
|
||||
rtt: Some(RttSample {
|
||||
raw: Duration::from_micros(1700),
|
||||
adjusted: None,
|
||||
effective: SignedDuration::from_nanos(1_700_000),
|
||||
}),
|
||||
server_timing: None,
|
||||
one_way: Some(OneWayDelaySample {
|
||||
client_to_server: None,
|
||||
server_to_client: Some(SignedDuration::from_nanos(800_000)),
|
||||
}),
|
||||
received_stats: Some(ReceivedStatsSample {
|
||||
count: Some(11),
|
||||
window: Some(0xb),
|
||||
}),
|
||||
bytes: 64,
|
||||
packet_meta: PacketMeta::default(),
|
||||
}
|
||||
}
|
||||
|
||||
fn late_event_without_rtt() -> ClientEvent {
|
||||
ClientEvent::LateReply {
|
||||
seq: 2,
|
||||
highest_seen: 5,
|
||||
remote: test_remote(),
|
||||
sent_at: None,
|
||||
received_at: test_timestamp(Duration::from_secs(1) + Duration::from_micros(1700)),
|
||||
rtt: None,
|
||||
server_timing: None,
|
||||
one_way: None,
|
||||
received_stats: None,
|
||||
bytes: 64,
|
||||
packet_meta: PacketMeta::default(),
|
||||
}
|
||||
}
|
||||
|
||||
fn warning_event(message: &str) -> ClientEvent {
|
||||
ClientEvent::Warning {
|
||||
kind: WarningKind::WrongToken,
|
||||
message: message.to_owned(),
|
||||
at: test_timestamp(Duration::from_secs(4)),
|
||||
}
|
||||
}
|
||||
|
||||
fn assert_line(event: &ClientEvent, mode: OutputMode, expected: &str) {
|
||||
assert_eq!(format_event(event, mode), Some(expected.to_owned()));
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn human_formats_rendered_events() {
|
||||
assert_line(
|
||||
&ClientEvent::SessionStarted {
|
||||
remote: test_remote(),
|
||||
token: 0xabc,
|
||||
negotiated: negotiated(),
|
||||
at: test_timestamp(Duration::from_secs(1)),
|
||||
},
|
||||
OutputMode::Human,
|
||||
"session started remote=127.0.0.1:2112 token=0xabc",
|
||||
);
|
||||
assert_line(
|
||||
&ClientEvent::NoTestCompleted {
|
||||
remote: test_remote(),
|
||||
negotiated: negotiated(),
|
||||
at: test_timestamp(Duration::from_secs(1)),
|
||||
},
|
||||
OutputMode::Human,
|
||||
"no-test completed remote=127.0.0.1:2112",
|
||||
);
|
||||
assert_line(
|
||||
&ClientEvent::SessionClosed {
|
||||
remote: test_remote(),
|
||||
token: 0xabc,
|
||||
at: test_timestamp(Duration::from_secs(1)),
|
||||
},
|
||||
OutputMode::Human,
|
||||
"session closed remote=127.0.0.1:2112 token=0xabc",
|
||||
);
|
||||
assert_line(
|
||||
&reply_event(),
|
||||
OutputMode::Human,
|
||||
"seq=7 rtt=1.2ms rd=500.0µs sd=400.0µs ipdv=n/a proc=300.0µs",
|
||||
);
|
||||
assert_line(
|
||||
&ClientEvent::EchoLoss {
|
||||
seq: 9,
|
||||
sent_at: test_timestamp(Duration::from_secs(1)),
|
||||
timeout_at: Instant::now(),
|
||||
},
|
||||
OutputMode::Human,
|
||||
"loss seq=9",
|
||||
);
|
||||
assert_line(
|
||||
&ClientEvent::DuplicateReply {
|
||||
seq: 7,
|
||||
remote: test_remote(),
|
||||
received_at: test_timestamp(Duration::from_secs(2)),
|
||||
bytes: 64,
|
||||
},
|
||||
OutputMode::Human,
|
||||
"duplicate seq=7 remote=127.0.0.1:2112",
|
||||
);
|
||||
assert_line(
|
||||
&late_event_with_rtt(),
|
||||
OutputMode::Human,
|
||||
"late seq=3 highest_seen=5 remote=127.0.0.1:2112 rtt=1.7ms rd=800.0µs sd=n/a ipdv=n/a server_received=11 server_window=0xb",
|
||||
);
|
||||
assert_line(
|
||||
&late_event_without_rtt(),
|
||||
OutputMode::Human,
|
||||
"late seq=2 highest_seen=5 remote=127.0.0.1:2112",
|
||||
);
|
||||
assert_line(
|
||||
&warning_event("token mismatch"),
|
||||
OutputMode::Human,
|
||||
"warning kind=wrong_token message=token mismatch",
|
||||
);
|
||||
assert_eq!(format_event(&sent_event(), OutputMode::Human), None);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn human_uses_stats_ipdv_decoration_and_verbose_stats() {
|
||||
let stats = HumanEventStats {
|
||||
contributed_sample: true,
|
||||
ipdv_pairs: vec![HumanIpdvPair {
|
||||
previous_seq: 6,
|
||||
current_seq: 7,
|
||||
rtt_ipdv: Duration::from_micros(50),
|
||||
send_ipdv: None,
|
||||
receive_ipdv: None,
|
||||
}],
|
||||
};
|
||||
assert_eq!(
|
||||
format_event_with_context(
|
||||
&reply_event(),
|
||||
RenderContext {
|
||||
mode: OutputMode::Human,
|
||||
human_stats: Some(&stats),
|
||||
human_options: HumanOutputOptions { verbose: true },
|
||||
},
|
||||
),
|
||||
Some(
|
||||
"seq=7 rtt=1.2ms rd=500.0µs sd=400.0µs ipdv=50.0µs proc=300.0µs server_received=9 server_window=0x7"
|
||||
.to_owned()
|
||||
)
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn simple_formats_rendered_events() {
|
||||
assert_line(
|
||||
&reply_event(),
|
||||
OutputMode::Simple,
|
||||
"reply seq=7 remote=127.0.0.1:2112 rtt_us=1200 raw_rtt_us=1500 server_processing_us=300",
|
||||
);
|
||||
assert_line(
|
||||
&ClientEvent::EchoLoss {
|
||||
seq: 9,
|
||||
sent_at: test_timestamp(Duration::from_secs(1)),
|
||||
timeout_at: Instant::now(),
|
||||
},
|
||||
OutputMode::Simple,
|
||||
"loss seq=9",
|
||||
);
|
||||
assert_line(
|
||||
&ClientEvent::DuplicateReply {
|
||||
seq: 7,
|
||||
remote: test_remote(),
|
||||
received_at: test_timestamp(Duration::from_secs(2)),
|
||||
bytes: 64,
|
||||
},
|
||||
OutputMode::Simple,
|
||||
"duplicate seq=7 remote=127.0.0.1:2112",
|
||||
);
|
||||
assert_line(
|
||||
&late_event_with_rtt(),
|
||||
OutputMode::Simple,
|
||||
"late seq=3 highest_seen=5 remote=127.0.0.1:2112 rtt_us=1700",
|
||||
);
|
||||
assert_line(
|
||||
&late_event_without_rtt(),
|
||||
OutputMode::Simple,
|
||||
"late seq=2 highest_seen=5 remote=127.0.0.1:2112",
|
||||
);
|
||||
assert_line(
|
||||
&warning_event("token mismatch"),
|
||||
OutputMode::Simple,
|
||||
"warning kind=wrong_token message=token mismatch",
|
||||
);
|
||||
assert_eq!(format_event(&sent_event(), OutputMode::Simple), None);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn rtt_us_prints_only_effective_reply_rtt() {
|
||||
assert_eq!(
|
||||
format_event(&reply_event(), OutputMode::RttUs),
|
||||
Some("1200".to_owned())
|
||||
);
|
||||
assert_eq!(
|
||||
format_event(
|
||||
&ClientEvent::Warning {
|
||||
kind: WarningKind::WrongToken,
|
||||
message: "bad".to_owned(),
|
||||
at: ClientTimestamp::now()
|
||||
},
|
||||
OutputMode::RttUs
|
||||
),
|
||||
None
|
||||
);
|
||||
assert_eq!(
|
||||
format_event(&negative_reply_event(), OutputMode::RttUs),
|
||||
Some("-200".to_owned())
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn machine_formats_lifecycle_events() {
|
||||
assert_line(
|
||||
&ClientEvent::SessionStarted {
|
||||
remote: test_remote(),
|
||||
token: 0xabc,
|
||||
negotiated: negotiated(),
|
||||
at: test_timestamp(Duration::from_secs(1)),
|
||||
},
|
||||
OutputMode::Machine,
|
||||
"event=session_started remote=127.0.0.1:2112 token=0xabc event_wall_ns=1000000000 duration_ns=10000000000 interval_ns=250000000 payload_length=64",
|
||||
);
|
||||
assert_line(
|
||||
&ClientEvent::NoTestCompleted {
|
||||
remote: test_remote(),
|
||||
negotiated: negotiated(),
|
||||
at: test_timestamp(Duration::from_secs(1)),
|
||||
},
|
||||
OutputMode::Machine,
|
||||
"event=no_test_completed remote=127.0.0.1:2112 event_wall_ns=1000000000 duration_ns=10000000000 interval_ns=250000000 payload_length=64",
|
||||
);
|
||||
assert_line(
|
||||
&ClientEvent::SessionClosed {
|
||||
remote: test_remote(),
|
||||
token: 0xabc,
|
||||
at: test_timestamp(Duration::from_secs(1)),
|
||||
},
|
||||
OutputMode::Machine,
|
||||
"event=session_closed remote=127.0.0.1:2112 token=0xabc event_wall_ns=1000000000",
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn machine_formats_reply_and_diagnostic_events() {
|
||||
assert_line(
|
||||
&sent_event(),
|
||||
OutputMode::Machine,
|
||||
"event=echo_sent seq=7 remote=127.0.0.1:2112 client_send_wall_ns=1000000000 bytes=64 send_call_us=10 timer_error_us=2",
|
||||
);
|
||||
assert_line(
|
||||
&reply_event(),
|
||||
OutputMode::Machine,
|
||||
"event=echo_reply seq=7 remote=127.0.0.1:2112 client_send_wall_ns=1000000000 client_receive_wall_ns=1001500000 raw_rtt_us=1500 effective_rtt_us=1200 adjusted_rtt_us=1200 server_receive_wall_ns=1000 server_receive_mono_ns=2000 server_send_wall_ns=301000 server_send_mono_ns=302000 server_processing_us=300 client_to_server_us=400 server_to_client_us=500 server_received_count=9 server_received_window=0x7 traffic_class=none dscp=none ecn=none kernel_rx_ns=none",
|
||||
);
|
||||
assert_line(
|
||||
&ClientEvent::EchoLoss {
|
||||
seq: 9,
|
||||
sent_at: test_timestamp(Duration::from_secs(1)),
|
||||
timeout_at: Instant::now(),
|
||||
},
|
||||
OutputMode::Machine,
|
||||
"event=loss seq=9 client_send_wall_ns=1000000000 warning=loss",
|
||||
);
|
||||
assert_line(
|
||||
&ClientEvent::DuplicateReply {
|
||||
seq: 7,
|
||||
remote: test_remote(),
|
||||
received_at: test_timestamp(Duration::from_secs(2)),
|
||||
bytes: 64,
|
||||
},
|
||||
OutputMode::Machine,
|
||||
"event=duplicate seq=7 remote=127.0.0.1:2112 client_receive_wall_ns=2000000000 warning=duplicate",
|
||||
);
|
||||
assert_line(
|
||||
&late_event_with_rtt(),
|
||||
OutputMode::Machine,
|
||||
"event=late seq=3 remote=127.0.0.1:2112 highest_seen=5 client_send_wall_ns=1000000000 client_receive_wall_ns=1001700000 raw_rtt_us=1700 effective_rtt_us=1700 server_to_client_us=800 server_received_count=11 server_received_window=0xb traffic_class=none dscp=none ecn=none kernel_rx_ns=none warning=late",
|
||||
);
|
||||
assert_line(
|
||||
&late_event_without_rtt(),
|
||||
OutputMode::Machine,
|
||||
"event=late seq=2 remote=127.0.0.1:2112 highest_seen=5 client_receive_wall_ns=1001700000 traffic_class=none dscp=none ecn=none kernel_rx_ns=none warning=late",
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn machine_escapes_warning_messages() {
|
||||
assert_line(
|
||||
&warning_event("bad token\tline one\nline two\\tail"),
|
||||
OutputMode::Machine,
|
||||
"event=warning at=4000000000 warning_kind=wrong_token message=bad\\stoken\\tline\\sone\\nline\\stwo\\\\tail",
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn machine_preserves_negative_signed_timing_values() {
|
||||
assert_line(
|
||||
&negative_reply_event(),
|
||||
OutputMode::Machine,
|
||||
"event=echo_reply seq=8 remote=127.0.0.1:2112 client_send_wall_ns=2000000000 client_receive_wall_ns=2000900000 raw_rtt_us=900 effective_rtt_us=-200 adjusted_rtt_us=-200 server_receive_wall_ns=-1000 server_send_wall_ns=1100000 server_midpoint_wall_ns=500000 server_processing_us=1100 client_to_server_us=-300 server_to_client_us=100 traffic_class=1 dscp=0 ecn=1 kernel_rx_ns=3000000000",
|
||||
);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn echo_sent_is_suppressed_except_machine_output() {
|
||||
let event = sent_event();
|
||||
assert!(format_event(&event, OutputMode::RttUs).is_none());
|
||||
assert!(format_event(&event, OutputMode::Human).is_none());
|
||||
assert!(format_event(&event, OutputMode::Simple).is_none());
|
||||
assert!(format_event(&event, OutputMode::Machine).is_some());
|
||||
}
|
||||
}
|
||||
Reference in new issue
Block a user