From f72f8fda5a94b56f85046b0ab7fd8cf18c1d11ff Mon Sep 17 00:00:00 2001 From: Nils Andreas Svee Date: Sun, 21 Jun 2026 00:10:56 +0700 Subject: [PATCH] refactor(cli): harden client output formatter --- README.md | 14 +- crates/irtt-cli/src/cmd/client/mod.rs | 4 +- crates/irtt-cli/src/cmd/client/output.rs | 484 ++++++++++++++++++++--- crates/irtt-cli/src/cmd/client/run.rs | 30 +- 4 files changed, 446 insertions(+), 86 deletions(-) diff --git a/README.md b/README.md index 6d149fb..9a6e29a 100644 --- a/README.md +++ b/README.md @@ -116,16 +116,18 @@ irtt-cli --duration 0 --interval 250ms --output machine Each line represents one client event and starts with an `event` field, for example: ```text +event=echo_sent seq=4 remote=203.0.113.10:2112 client_send_wall_ns=1760000000000000000 bytes=64 send_call_us=10 timer_error_us=2 event=echo_reply seq=4 remote=203.0.113.10:2112 client_send_wall_ns=1760000000000000000 client_receive_wall_ns=1760000000012400000 raw_rtt_us=12400 effective_rtt_us=12100 adjusted_rtt_us=12100 server_receive_wall_ns=1760000000006100000 server_receive_mono_ns=5000006100000 server_send_wall_ns=1760000000006400000 server_send_mono_ns=5000006400000 server_processing_us=300 client_to_server_us=6100 server_to_client_us=6000 server_received_count=5 server_received_window=0x1f dscp=0 ecn=0 kernel_rx_ns=none ``` Consumers should match on `event=...` and read the fields they need. Unknown fields should be ignored. -RTT fields are reported in microseconds. `raw_rtt_us` is the measured client -send-to-receive RTT. `effective_rtt_us` and `adjusted_rtt_us` are signed and may -be negative when server processing exceeds the raw RTT or timing correction -produces a negative adjusted value. When one-way delay fields are present, -`client_to_server_us` and `server_to_client_us` are also signed microseconds and -may be negative due to wall-clock skew. +RTT, send-call, and timer-error fields are reported in microseconds. +`raw_rtt_us` is the measured client send-to-receive RTT. `effective_rtt_us` and +`adjusted_rtt_us` are signed and may be negative when server processing exceeds +the raw RTT or timing correction produces a negative adjusted value. When +one-way delay fields are present, `client_to_server_us` and +`server_to_client_us` are also signed microseconds and may be negative due to +wall-clock skew. For consumers that only need RTT values, use: diff --git a/crates/irtt-cli/src/cmd/client/mod.rs b/crates/irtt-cli/src/cmd/client/mod.rs index 33c7abf..70e1e5c 100644 --- a/crates/irtt-cli/src/cmd/client/mod.rs +++ b/crates/irtt-cli/src/cmd/client/mod.rs @@ -6,7 +6,7 @@ pub mod summary; pub use args::{ClientArgs, OutputMode}; pub use output::{ - format_event, format_human_event, format_human_event_with_options, HumanEventStats, - HumanIpdvPair, HumanOutputOptions, + format_event, format_event_with_context, format_human_event, format_human_event_with_options, + HumanEventStats, HumanIpdvPair, HumanOutputOptions, RenderContext, }; pub use run::run_stream; diff --git a/crates/irtt-cli/src/cmd/client/output.rs b/crates/irtt-cli/src/cmd/client/output.rs index 34963f9..bbaf497 100644 --- a/crates/irtt-cli/src/cmd/client/output.rs +++ b/crates/irtt-cli/src/cmd/client/output.rs @@ -12,14 +12,37 @@ use irtt_client::{ use super::args::OutputMode; pub fn format_event(event: &ClientEvent, mode: OutputMode) -> Option { - if matches!(event, ClientEvent::EchoSent { .. }) { - return None; + format_event_with_context(event, RenderContext::new(mode)) +} + +pub fn format_event_with_context( + event: &ClientEvent, + context: RenderContext<'_>, +) -> Option { + match context.mode { + OutputMode::Human => { + format_human_event_line(event, context.human_stats.cloned(), context.human_options) + } + OutputMode::Simple => format_simple_event(event), + OutputMode::Machine => format_machine_event(event), + OutputMode::RttUs => format_rtt_us_event(event), } - match mode { - OutputMode::RttUs => format_rtt_us(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)] +pub struct RenderContext<'a> { + pub mode: OutputMode, + pub human_stats: Option<&'a HumanEventStats>, + pub human_options: HumanOutputOptions, +} + +impl RenderContext<'_> { + pub fn new(mode: OutputMode) -> Self { + Self { + mode, + human_stats: None, + human_options: HumanOutputOptions::default(), + } } } @@ -75,9 +98,17 @@ pub fn format_human_event_with_options( stats: Option, options: HumanOutputOptions, ) -> String { + format_human_event_line(event, stats, options).unwrap_or_default() +} + +fn format_human_event_line( + event: &ClientEvent, + stats: Option, + options: HumanOutputOptions, +) -> Option { let stats = stats.as_ref(); - match event { + let line = match event { ClientEvent::SessionStarted { remote, token, .. } => { format!("session started remote={remote} token={token:#x}") } @@ -87,7 +118,7 @@ pub fn format_human_event_with_options( ClientEvent::SessionClosed { remote, token, .. } => { format!("session closed remote={remote} token={token:#x}") } - ClientEvent::EchoSent { .. } => String::new(), + ClientEvent::EchoSent { .. } => return None, ClientEvent::EchoReply { seq, rtt, @@ -135,17 +166,18 @@ pub fn format_human_event_with_options( ClientEvent::Warning { kind, message, .. } => { format!("warning kind={} message={message}", warning_kind(*kind)) } - } + }; + Some(line) } -fn format_rtt_us(event: &ClientEvent) -> Option { +fn format_rtt_us_event(event: &ClientEvent) -> Option { match event { ClientEvent::EchoReply { rtt, .. } => Some(signed_duration_us(rtt.effective).to_string()), _ => None, } } -fn format_machine(event: &ClientEvent) -> String { +fn format_machine_event(event: &ClientEvent) -> Option { let mut out = String::new(); match event { ClientEvent::SessionStarted { @@ -176,7 +208,23 @@ fn format_machine(event: &ClientEvent) -> String { write_token(&mut out, *token); write_wall(&mut out, "event_wall_ns", at.wall); } - ClientEvent::EchoSent { .. } => {} + ClientEvent::EchoSent { + seq, + remote, + sent_at, + bytes, + send_call, + timer_error, + .. + } => { + write_common(&mut out, "echo_sent"); + write_seq(&mut out, *seq); + write_remote(&mut out, *remote); + write_wall(&mut out, "client_send_wall_ns", sent_at.wall); + write!(out, " bytes={bytes}").unwrap(); + write!(out, " send_call_us={}", duration_us(*send_call)).unwrap(); + write!(out, " timer_error_us={}", duration_us(*timer_error)).unwrap(); + } ClientEvent::EchoReply { seq, remote, @@ -260,11 +308,11 @@ fn format_machine(event: &ClientEvent) -> String { .unwrap(); } } - out + Some(out) } -fn format_simple(event: &ClientEvent) -> String { - match event { +fn format_simple_event(event: &ClientEvent) -> Option { + let line = match event { ClientEvent::SessionStarted { remote, token, .. } => { format!("session started remote={remote} token={token:#x}") } @@ -274,7 +322,7 @@ fn format_simple(event: &ClientEvent) -> String { ClientEvent::SessionClosed { remote, token, .. } => { format!("session closed remote={remote} token={token:#x}") } - ClientEvent::EchoSent { .. } => String::new(), + ClientEvent::EchoSent { .. } => return None, ClientEvent::EchoReply { seq, remote, @@ -317,7 +365,8 @@ fn format_simple(event: &ClientEvent) -> String { ClientEvent::Warning { kind, message, .. } => { format!("warning kind={} message={message}", warning_kind(*kind)) } - } + }; + Some(line) } fn write_common(out: &mut String, event: &str) { @@ -533,6 +582,7 @@ fn escape_value(value: &str) -> String { 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}, @@ -549,6 +599,30 @@ mod tests { 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, @@ -582,6 +656,239 @@ mod tests { } } + 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!( @@ -599,58 +906,111 @@ mod tests { ), None ); - } - - #[test] - fn machine_prints_stable_key_value_fields() { - let line = format_event(&reply_event(), OutputMode::Machine).unwrap(); - assert!(line.starts_with("event=echo_reply ")); - assert!(line.contains("seq=7")); - assert!(line.contains("remote=127.0.0.1:2112")); - assert!(line.contains("client_send_wall_ns=1000000000")); - assert!(line.contains("client_receive_wall_ns=1001500000")); - assert!(line.contains("raw_rtt_us=1500")); - assert!(line.contains("adjusted_rtt_us=1200")); - assert!(line.contains("effective_rtt_us=1200")); - assert!(line.contains("server_processing_us=300")); - assert!(line.contains("server_received_count=9")); - } - - #[test] - fn simple_and_human_use_readable_reply_lines() { assert_eq!( - format_event(&reply_event(), OutputMode::Simple), - Some( - "reply seq=7 remote=127.0.0.1:2112 rtt_us=1200 raw_rtt_us=1500 server_processing_us=300" - .to_owned() - ) + format_event(&negative_reply_event(), OutputMode::RttUs), + Some("-200".to_owned()) ); - - let human = format_event(&reply_event(), OutputMode::Human).unwrap(); - assert!(human.starts_with("seq=7 rtt=1.2ms")); - assert!(human.contains("rd=500.0µs")); - assert!(human.contains("sd=400.0µs")); - assert!(human.contains("ipdv=n/a")); - assert!(human.contains("proc=300.0µs")); - assert!(!human.contains("rtt_us=")); } #[test] - fn echo_sent_is_not_formatted_for_stream_outputs() { - let ts = test_timestamp(Duration::from_secs(1)); - let event = ClientEvent::EchoSent { - seq: 1, - remote: test_remote(), - scheduled_at: ts.mono, - sent_at: ts, - bytes: 64, - send_call: Duration::from_micros(10), - timer_error: Duration::ZERO, - }; + 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::Machine).is_none()); assert!(format_event(&event, OutputMode::Simple).is_none()); + assert!(format_event(&event, OutputMode::Machine).is_some()); } } diff --git a/crates/irtt-cli/src/cmd/client/run.rs b/crates/irtt-cli/src/cmd/client/run.rs index a68210e..ea1f156 100644 --- a/crates/irtt-cli/src/cmd/client/run.rs +++ b/crates/irtt-cli/src/cmd/client/run.rs @@ -9,7 +9,7 @@ use irtt_client::{ClientTimestamp, PacketMeta, RttSample, SignedDuration}; use super::{ args::{ClientArgs, OutputMode}, - output::{format_event, format_human_event_with_options, HumanOutputOptions}, + output::{format_event_with_context, HumanEventStats, HumanOutputOptions, RenderContext}, }; #[cfg(feature = "stats")] use crate::shared::client::expected_probe_count; @@ -132,23 +132,21 @@ impl StreamOutput<'_, W> { let stats_update = self.stats.process(event); #[cfg(not(feature = "stats"))] - let stats_update = crate::cmd::client::HumanEventStats::default(); + let stats_update = HumanEventStats::default(); - let line = - if self.mode == OutputMode::Human && !matches!(event, ClientEvent::EchoSent { .. }) { - #[cfg(feature = "stats")] - let human_stats = stats_update.into(); - #[cfg(not(feature = "stats"))] - let human_stats = stats_update; + #[cfg(feature = "stats")] + let human_stats = HumanEventStats::from(stats_update); + #[cfg(not(feature = "stats"))] + let human_stats = stats_update; - Some(format_human_event_with_options( - event, - Some(human_stats), - self.human_options, - )) - } else { - format_event(event, self.mode) - }; + let line = format_event_with_context( + event, + RenderContext { + mode: self.mode, + human_stats: Some(&human_stats), + human_options: self.human_options, + }, + ); if let Some(line) = line { writeln!(self.out, "{line}")?;