perf/
stats.rs

1use hdrhistogram::Histogram;
2use quinn::StreamId;
3use std::sync::atomic::{AtomicBool, AtomicU64, AtomicUsize, Ordering};
4use std::sync::{Arc, Mutex};
5use std::time::{Duration, Instant, SystemTime};
6#[cfg(feature = "json-output")]
7use {std::fs::File, std::io, std::path::Path};
8
9pub struct Stats {
10    /// Test start time
11    start_instant: Instant,
12    /// Test start system time
13    start: SystemTime,
14    /// Durations of uploads
15    upload_duration: Histogram<u64>,
16    /// Durations of downloads
17    download_duration: Histogram<u64>,
18    /// Time from finishing the upload until receiving the first byte of the response
19    fbl: Histogram<u64>,
20    /// Throughput for uploads
21    upload_throughput: Histogram<u64>,
22    /// Throughput for downloads
23    download_throughput: Histogram<u64>,
24    /// The total amount of requests executed
25    requests: usize,
26    /// Stats accumulated over each interval
27    intervals: Vec<Interval>,
28}
29
30impl Default for Stats {
31    fn default() -> Self {
32        Self {
33            start_instant: Instant::now(),
34            start: SystemTime::now(),
35            upload_duration: Histogram::new(3).unwrap(),
36            download_duration: Histogram::new(3).unwrap(),
37            fbl: Histogram::new(3).unwrap(),
38            upload_throughput: Histogram::new(3).unwrap(),
39            download_throughput: Histogram::new(3).unwrap(),
40            requests: 0,
41            intervals: vec![],
42        }
43    }
44}
45
46impl Stats {
47    pub fn on_interval(&mut self, start: Instant, stream_stats: &OpenStreamStats) {
48        let mut interval = Interval::new(start - self.start_instant, self.start_instant.elapsed());
49        let mut guard = stream_stats.0.lock().unwrap();
50
51        guard.retain(|stream_stats| {
52            self.record(stream_stats.clone());
53            interval.record_stream_stats(stream_stats.clone());
54            // Retain if not finished yet
55            !stream_stats.finished.load(Ordering::SeqCst)
56        });
57
58        self.intervals.push(interval);
59    }
60
61    fn record(&mut self, stream_stats: Arc<StreamStats>) {
62        if stream_stats.finished.load(Ordering::SeqCst) {
63            let duration = stream_stats.duration.load(Ordering::SeqCst);
64            let bps = throughput_bytes_per_second(duration, stream_stats.request_size);
65
66            if stream_stats.sender {
67                self.upload_throughput.record(bps as u64).unwrap();
68                self.upload_duration.record(duration).unwrap();
69            } else {
70                self.download_throughput.record(bps as u64).unwrap();
71                self.download_duration.record(duration).unwrap();
72                self.fbl
73                    .record(stream_stats.first_byte_latency.load(Ordering::SeqCst))
74                    .unwrap();
75                self.requests += 1;
76            }
77        }
78    }
79
80    pub fn print(&self) {
81        let dt = self.start_instant.elapsed();
82        let rps = self.requests as f64 / dt.as_secs_f64();
83
84        println!("Overall stats:");
85        println!(
86            "RPS: {:.2} ({} requests in {:4.2?})",
87            rps, self.requests, dt,
88        );
89        println!();
90
91        println!("Stream metrics:\n");
92
93        println!(
94            "      │ Upload Duration │ Download Duration | FBL        | Upload Throughput | Download Throughput"
95        );
96        println!(
97            "──────┼─────────────────┼───────────────────┼────────────┼───────────────────┼────────────────────"
98        );
99
100        let print_metric = |label: &'static str, get_metric: fn(&Histogram<u64>) -> u64| {
101            println!(
102                " {} │ {:>15.2?} │ {:>17.2?} │  {:>9.2?} │ {:12.2} Mb/s │ {:13.2} Mb/s",
103                label,
104                Duration::from_micros(get_metric(&self.upload_duration)),
105                Duration::from_micros(get_metric(&self.download_duration)),
106                Duration::from_micros(get_metric(&self.fbl)),
107                get_metric(&self.upload_throughput) as f64 * 8.0 / 1000.0 / 1000.0,
108                get_metric(&self.download_throughput) as f64 * 8.0 / 1000.0 / 1000.0,
109            );
110        };
111
112        print_metric("AVG ", |hist| hist.mean() as u64);
113        print_metric("P0  ", |hist| hist.value_at_quantile(0.00));
114        print_metric("P10 ", |hist| hist.value_at_quantile(0.10));
115        print_metric("P50 ", |hist| hist.value_at_quantile(0.50));
116        print_metric("P90 ", |hist| hist.value_at_quantile(0.90));
117        print_metric("P100", |hist| hist.value_at_quantile(1.00));
118        println!();
119    }
120
121    #[cfg(feature = "json-output")]
122    pub fn print_json(&self, path: &Path) -> io::Result<()> {
123        match path {
124            path if path == Path::new("-") => json::print(self, std::io::stdout()),
125            _ => {
126                let file = File::create(path)?;
127                json::print(self, file)
128            }
129        }
130        Ok(())
131    }
132}
133
134/// Statistics for the currently open streams
135#[derive(Clone, Default)]
136pub struct OpenStreamStats(Arc<Mutex<Vec<Arc<StreamStats>>>>);
137
138impl OpenStreamStats {
139    pub fn new_sender(&self, stream: &quinn::SendStream, upload_size: u64) -> Arc<StreamStats> {
140        let send_stream_stats = StreamStats {
141            id: stream.id(),
142            request_size: upload_size,
143            bytes: Default::default(),
144            sender: true,
145            finished: Default::default(),
146            duration: Default::default(),
147            first_byte_latency: Default::default(),
148        };
149        let send_stream_stats = Arc::new(send_stream_stats);
150        self.push(send_stream_stats.clone());
151        send_stream_stats
152    }
153
154    pub fn new_receiver(&self, stream: &quinn::RecvStream, download_size: u64) -> Arc<StreamStats> {
155        let recv_stream_stats = StreamStats {
156            id: stream.id(),
157            request_size: download_size,
158            bytes: Default::default(),
159            sender: false,
160            finished: Default::default(),
161            duration: Default::default(),
162            first_byte_latency: Default::default(),
163        };
164        let recv_stream_stats = Arc::new(recv_stream_stats);
165        self.push(recv_stream_stats.clone());
166        recv_stream_stats
167    }
168
169    fn push(&self, stream_stats: Arc<StreamStats>) {
170        self.0.lock().unwrap().push(stream_stats);
171    }
172}
173
174pub struct StreamStats {
175    id: StreamId,
176    request_size: u64,
177    bytes: AtomicUsize,
178    sender: bool,
179    finished: AtomicBool,
180    duration: AtomicU64,
181    first_byte_latency: AtomicU64,
182}
183
184impl StreamStats {
185    pub fn on_first_byte(&self, latency: Duration) {
186        self.first_byte_latency
187            .store(latency.as_micros() as u64, Ordering::SeqCst);
188    }
189
190    pub fn on_bytes(&self, bytes: usize) {
191        self.bytes.fetch_add(bytes, Ordering::SeqCst);
192    }
193
194    pub fn finish(&self, duration: Duration) {
195        self.duration
196            .store(duration.as_micros() as u64, Ordering::SeqCst);
197        self.finished.store(true, Ordering::SeqCst);
198    }
199}
200
201struct Interval {
202    streams: Vec<StreamIntervalStats>,
203    period: IntervalPeriod,
204}
205
206impl Interval {
207    fn new(start: Duration, end: Duration) -> Self {
208        let period = IntervalPeriod {
209            start: start.as_secs_f64(),
210            end: end.as_secs_f64(),
211            seconds: (end - start).as_secs_f64(),
212        };
213
214        Self {
215            streams: vec![],
216            period,
217        }
218    }
219
220    fn record_stream_stats(&mut self, stream_stats: Arc<StreamStats>) {
221        let bytes = stream_stats.bytes.swap(0, Ordering::SeqCst);
222        self.streams.push(StreamIntervalStats {
223            id: stream_stats.id,
224            bytes,
225            sender: stream_stats.sender,
226        })
227    }
228}
229
230struct IntervalPeriod {
231    start: f64,
232    end: f64,
233    seconds: f64,
234}
235
236struct StreamIntervalStats {
237    id: StreamId,
238    bytes: usize,
239    sender: bool,
240}
241
242fn throughput_bytes_per_second(duration_in_micros: u64, size: u64) -> f64 {
243    (size as f64) / (duration_in_micros as f64 / 1000000.0)
244}
245
246#[cfg(feature = "json-output")]
247mod json {
248    use crate::stats;
249    use crate::stats::{Stats, StreamIntervalStats};
250    use quinn::StreamId;
251    use serde::{self, Serialize, Serializer, ser::SerializeStruct};
252    use std::io::Write;
253    use std::time::{SystemTime, UNIX_EPOCH};
254
255    pub(crate) fn print<W: Write>(stats: &Stats, out: W) {
256        let report = Report {
257            start: Start {
258                timestamp: stats.start,
259            },
260            intervals: &stats
261                .intervals
262                .iter()
263                .map(Interval::from_stats_interval)
264                .collect(),
265        };
266
267        serde_json::to_writer(out, &report).unwrap();
268    }
269
270    #[derive(Serialize)]
271    struct Report<'a> {
272        start: Start,
273        intervals: &'a Vec<Interval>,
274        // TODO: add end stats
275    }
276
277    #[derive(Serialize)]
278    struct Start {
279        #[serde(serialize_with = "serialize_timestamp")]
280        timestamp: SystemTime,
281    }
282
283    fn serialize_timestamp<S>(time: &SystemTime, s: S) -> Result<S::Ok, S::Error>
284    where
285        S: serde::Serializer,
286    {
287        use serde::ser::SerializeMap;
288        let mut state = s.serialize_map(Some(1))?;
289        state.serialize_entry(
290            "timesecs",
291            &time.duration_since(UNIX_EPOCH).unwrap().as_secs(),
292        )?;
293        state.end()
294    }
295
296    struct Interval {
297        streams: Vec<Stream>,
298        recv_sum: Sum,
299        send_sum: Sum,
300    }
301
302    impl Interval {
303        fn from_stats_interval(interval: &stats::Interval) -> Self {
304            Self {
305                streams: interval
306                    .streams
307                    .iter()
308                    .map(|stats| Stream::from_stream_interval_stats(stats, &interval.period))
309                    .collect(),
310                recv_sum: Sum::from_stream_interval_stats(
311                    &interval.streams,
312                    &interval.period,
313                    false,
314                ),
315                send_sum: Sum::from_stream_interval_stats(
316                    &interval.streams,
317                    &interval.period,
318                    true,
319                ),
320            }
321        }
322    }
323
324    impl Serialize for Interval {
325        fn serialize<S>(
326            &self,
327            serializer: S,
328        ) -> Result<<S as Serializer>::Ok, <S as Serializer>::Error>
329        where
330            S: Serializer,
331        {
332            let mut state = serializer.serialize_struct("Interval", 2)?;
333            state.serialize_field("streams", &self.streams)?;
334            // iperf3 outputs duplicate "sum" entries when run in bidirectional mode
335            // serde does not support duplicate keys, so only output one of the sums
336            if self.send_sum.bytes > 0 {
337                state.serialize_field("sum", &self.send_sum)?;
338            } else {
339                state.serialize_field("sum", &self.recv_sum)?;
340            }
341            state.end()
342        }
343    }
344
345    #[derive(Serialize)]
346    struct Stream {
347        #[serde(serialize_with = "serialize_stream_id")]
348        id: StreamId,
349        start: f64,
350        end: f64,
351        seconds: f64,
352        bytes: usize,
353        bits_per_second: f64,
354        sender: bool,
355    }
356
357    impl Stream {
358        fn from_stream_interval_stats(
359            stats: &stats::StreamIntervalStats,
360            period: &stats::IntervalPeriod,
361        ) -> Self {
362            let bits_per_second = stats.bytes as f64 * 8.0 / period.seconds;
363
364            Self {
365                id: stats.id,
366                start: period.start,
367                end: period.end,
368                seconds: period.seconds,
369                bytes: stats.bytes,
370                bits_per_second,
371                sender: stats.sender,
372            }
373        }
374    }
375
376    fn serialize_stream_id<S: Serializer>(id: &StreamId, serializer: S) -> Result<S::Ok, S::Error> {
377        serializer.serialize_u64(u64::from(*id))
378    }
379
380    #[derive(Serialize)]
381    struct Sum {
382        start: f64,
383        end: f64,
384        seconds: f64,
385        bytes: usize,
386        bits_per_second: f64,
387        sender: bool,
388    }
389
390    impl Sum {
391        fn from_stream_interval_stats(
392            stats: &[StreamIntervalStats],
393            period: &stats::IntervalPeriod,
394            sender: bool,
395        ) -> Self {
396            let bytes = stats
397                .iter()
398                .filter(|stat| stat.sender == sender)
399                .map(|stat| stat.bytes)
400                .sum();
401            let bits_per_second = bytes as f64 * 8.0 / period.seconds;
402
403            Self {
404                start: period.start,
405                end: period.end,
406                seconds: period.seconds,
407                bytes,
408                bits_per_second,
409                sender,
410            }
411        }
412    }
413}