qlog/
streamer.rs

1// Copyright (C) 2021, Cloudflare, Inc.
2// All rights reserved.
3//
4// Redistribution and use in source and binary forms, with or without
5// modification, are permitted provided that the following conditions are
6// met:
7//
8//     * Redistributions of source code must retain the above copyright notice,
9//       this list of conditions and the following disclaimer.
10//
11//     * Redistributions in binary form must reproduce the above copyright
12//       notice, this list of conditions and the following disclaimer in the
13//       documentation and/or other materials provided with the distribution.
14//
15// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS
16// IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
17// THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
18// PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR
19// CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL,
20// EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
21// PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR
22// PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF
23// LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING
24// NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
25// SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
26
27use crate::events::EventData;
28use crate::events::EventImportance;
29use crate::events::EventType;
30use crate::events::Eventable;
31use crate::events::ExData;
32
33/// Controls the time precisions of events.
34///
35/// Times are always logged in units of whole milliseconds with optional
36/// precision, determining the number of decimal places output by the
37/// serializer.
38pub enum EventTimePrecision {
39    /// Logging may contain 1 decimal place to ensure float serialization e.g.,
40    /// 1.0, 2.0,
41    MilliSeconds,
42    /// Logged up to 3 decimal places e.g., 1.234, 2.001
43    MicroSeconds,
44    /// Logged up to 6 decimal places e.g., 1.234567, 2.001001
45    NanoSeconds,
46}
47
48/// Converts a [`Duration`] to milliseconds as `f64` using the requested
49/// precision variant.
50fn duration_to_millis(
51    dur: std::time::Duration, precision: &EventTimePrecision,
52) -> f64 {
53    match precision {
54        EventTimePrecision::MilliSeconds => dur.as_millis() as f64,
55        EventTimePrecision::MicroSeconds => dur.as_micros() as f64 / 1_000.0,
56        EventTimePrecision::NanoSeconds => dur.as_nanos() as f64 / 1_000_000.0,
57    }
58}
59
60/// Computes elapsed time in milliseconds since `start`, based on the provided
61/// `precision`. In test builds, always returns 0.0 for deterministic output.
62fn elapsed_millis(
63    start: std::time::Instant, now: std::time::Instant,
64    precision: &EventTimePrecision,
65) -> f64 {
66    if cfg!(test) {
67        return 0.0;
68    }
69
70    let dur = now.saturating_duration_since(start);
71    duration_to_millis(dur, precision)
72}
73
74/// A helper object specialized for streaming JSON-serialized qlog to a
75/// [`Write`] trait.
76///
77/// The object is responsible for the `Qlog` object that contains the
78/// provided `Trace`.
79///
80/// Serialization is progressively driven by method calls; once log streaming
81/// is started, `event::Events` can be written using `add_event()`.
82///
83/// [`Write`]: https://doc.rust-lang.org/std/io/trait.Write.html
84use super::*;
85
86#[derive(PartialEq, Eq, Debug)]
87pub enum StreamerState {
88    Initial,
89    Ready,
90    Finished,
91}
92
93pub struct QlogStreamer {
94    start_time: std::time::Instant,
95    writer: Box<dyn std::io::Write + Send + Sync>,
96    qlog: QlogSeq,
97    state: StreamerState,
98    log_level: EventImportance,
99    time_precision: EventTimePrecision,
100}
101
102impl QlogStreamer {
103    /// Creates a [QlogStreamer] object.
104    ///
105    /// It owns a [QlogSeq] object that contains the provided [TraceSeq]
106    /// containing [Event]s.
107    ///
108    /// All serialization will be written to the provided [`Write`] using the
109    /// JSON-SEQ format.
110    ///
111    /// [`Write`]: https://doc.rust-lang.org/std/io/trait.Write.html
112    #[allow(clippy::too_many_arguments)]
113    pub fn new(
114        title: Option<String>, description: Option<String>,
115        start_time: std::time::Instant, trace: TraceSeq,
116        log_level: EventImportance, time_precision: EventTimePrecision,
117        writer: Box<dyn std::io::Write + Send + Sync>,
118    ) -> Self {
119        let qlog = QlogSeq {
120            file_schema: QLOGFILESEQ_URI.to_string(),
121            serialization_format: "JSON-SEQ".to_string(),
122            title,
123            description,
124            trace,
125        };
126
127        QlogStreamer {
128            start_time,
129            writer,
130            qlog,
131            state: StreamerState::Initial,
132            log_level,
133            time_precision,
134        }
135    }
136
137    /// Starts qlog streaming serialization.
138    ///
139    /// This writes out the JSON-SEQ-serialized form of all initial qlog
140    /// information. [Event]s are separately appended using [add_event()],
141    /// [add_event_with_instant()], [add_event_now()],
142    /// [add_event_data_with_instant()], or [add_event_data_now()].
143    ///
144    /// [add_event()]: #method.add_event
145    /// [add_event_with_instant()]: #method.add_event_with_instant
146    /// [add_event_now()]: #method.add_event_now
147    /// [add_event_data_with_instant()]: #method.add_event_data_with_instant
148    /// [add_event_data_now()]: #method.add_event_data_now
149    pub fn start_log(&mut self) -> Result<()> {
150        if self.state != StreamerState::Initial {
151            return Err(Error::Done);
152        }
153
154        self.writer.as_mut().write_all(b"")?;
155        serde_json::to_writer(self.writer.as_mut(), &self.qlog)
156            .map_err(|_| Error::Done)?;
157        self.writer.as_mut().write_all(b"\n")?;
158
159        self.state = StreamerState::Ready;
160
161        Ok(())
162    }
163
164    /// Finishes qlog streaming serialization.
165    ///
166    /// After this is called, no more serialization will occur.
167    pub fn finish_log(&mut self) -> Result<()> {
168        if self.state == StreamerState::Initial ||
169            self.state == StreamerState::Finished
170        {
171            return Err(Error::InvalidState);
172        }
173
174        self.state = StreamerState::Finished;
175
176        self.writer.as_mut().flush()?;
177
178        Ok(())
179    }
180
181    /// Writes a serializable to a JSON-SEQ record using
182    /// [std::time::Instant::now()].
183    pub fn add_event_now<E: Serialize + Eventable>(
184        &mut self, event: E,
185    ) -> Result<()> {
186        let now = std::time::Instant::now();
187
188        self.add_event_with_instant(event, now)
189    }
190
191    /// Writes a serializable to a pretty-printed JSON-SEQ record using
192    /// [std::time::Instant::now()].
193    pub fn add_event_now_pretty<E: Serialize + Eventable>(
194        &mut self, event: E,
195    ) -> Result<()> {
196        let now = std::time::Instant::now();
197
198        self.add_event_with_instant_pretty(event, now)
199    }
200
201    /// Writes a serializable to a JSON-SEQ record using the provided
202    /// [std::time::Instant].
203    pub fn add_event_with_instant<E: Serialize + Eventable>(
204        &mut self, event: E, now: std::time::Instant,
205    ) -> Result<()> {
206        self.event_with_instant(event, now, false)
207    }
208
209    /// Writes a serializable to a pretty-printed JSON-SEQ record using the
210    /// provided [std::time::Instant].
211    pub fn add_event_with_instant_pretty<E: Serialize + Eventable>(
212        &mut self, event: E, now: std::time::Instant,
213    ) -> Result<()> {
214        self.event_with_instant(event, now, true)
215    }
216
217    fn event_with_instant<E: Serialize + Eventable>(
218        &mut self, mut event: E, now: std::time::Instant, pretty: bool,
219    ) -> Result<()> {
220        if self.state != StreamerState::Ready {
221            return Err(Error::InvalidState);
222        }
223
224        if !event.importance().is_contained_in(&self.log_level) {
225            return Err(Error::Done);
226        }
227
228        event.set_time(elapsed_millis(
229            self.start_time,
230            now,
231            &self.time_precision,
232        ));
233
234        if pretty {
235            self.add_event_pretty(event)
236        } else {
237            self.add_event(event)
238        }
239    }
240
241    /// Writes an [Event] based on the provided [EventData] to a JSON-SEQ record
242    /// at time [std::time::Instant::now()].
243    pub fn add_event_data_now(&mut self, event_data: EventData) -> Result<()> {
244        self.add_event_data_ex_now(event_data, Default::default())
245    }
246
247    /// Writes an [Event] based on the provided [EventData] to a pretty-printed
248    /// JSON-SEQ record at time [std::time::Instant::now()].
249    pub fn add_event_data_now_pretty(
250        &mut self, event_data: EventData,
251    ) -> Result<()> {
252        self.add_event_data_ex_now_pretty(event_data, Default::default())
253    }
254
255    /// Writes an [Event] based on the provided [EventData] and [ExData] to a
256    /// JSON-SEQ record at time [std::time::Instant::now()].
257    pub fn add_event_data_ex_now(
258        &mut self, event_data: EventData, ex_data: ExData,
259    ) -> Result<()> {
260        let now = std::time::Instant::now();
261
262        self.add_event_data_ex_with_instant(event_data, ex_data, now)
263    }
264
265    /// Writes an [Event] based on the provided [EventData] and [ExData] to a
266    /// pretty-printed JSON-SEQ record at time [std::time::Instant::now()].
267    pub fn add_event_data_ex_now_pretty(
268        &mut self, event_data: EventData, ex_data: ExData,
269    ) -> Result<()> {
270        let now = std::time::Instant::now();
271
272        self.add_event_data_ex_with_instant_pretty(event_data, ex_data, now)
273    }
274
275    /// Writes an [Event] based on the provided [EventData] and
276    /// [std::time::Instant] to a JSON-SEQ record.
277    pub fn add_event_data_with_instant(
278        &mut self, event_data: EventData, now: std::time::Instant,
279    ) -> Result<()> {
280        self.add_event_data_ex_with_instant(event_data, Default::default(), now)
281    }
282
283    /// Writes an [Event] based on the provided [EventData] and
284    /// [std::time::Instant] to a pretty-printed JSON-SEQ record.
285    pub fn add_event_data_with_instant_pretty(
286        &mut self, event_data: EventData, now: std::time::Instant,
287    ) -> Result<()> {
288        self.add_event_data_ex_with_instant_pretty(
289            event_data,
290            Default::default(),
291            now,
292        )
293    }
294
295    /// Writes an [Event] based on the provided [EventData], [ExData], and
296    /// [std::time::Instant] to a JSON-SEQ record.
297    pub fn add_event_data_ex_with_instant(
298        &mut self, event_data: EventData, ex_data: ExData,
299        now: std::time::Instant,
300    ) -> Result<()> {
301        self.event_data_ex_with_instant(event_data, ex_data, now, false)
302    }
303
304    // Writes an [Event] based on the provided [EventData], [ExData], and
305    /// [std::time::Instant] to a pretty-printed JSON-SEQ record.
306    pub fn add_event_data_ex_with_instant_pretty(
307        &mut self, event_data: EventData, ex_data: ExData,
308        now: std::time::Instant,
309    ) -> Result<()> {
310        self.event_data_ex_with_instant(event_data, ex_data, now, true)
311    }
312
313    fn event_data_ex_with_instant(
314        &mut self, event_data: EventData, ex_data: ExData,
315        now: std::time::Instant, pretty: bool,
316    ) -> Result<()> {
317        if self.state != StreamerState::Ready {
318            return Err(Error::InvalidState);
319        }
320
321        let ty = EventType::from(&event_data);
322        if !EventImportance::from(ty).is_contained_in(&self.log_level) {
323            return Err(Error::Done);
324        }
325
326        let event = Event::with_time_ex(
327            elapsed_millis(self.start_time, now, &self.time_precision),
328            event_data,
329            ex_data,
330        );
331
332        if pretty {
333            self.add_event_pretty(event)
334        } else {
335            self.add_event(event)
336        }
337    }
338
339    /// Writes a JSON-SEQ-serialized [Event] using the provided [Event].
340    pub fn add_event<E: Serialize + Eventable>(
341        &mut self, event: E,
342    ) -> Result<()> {
343        self.write_event(event, false)
344    }
345
346    /// Writes a pretty-printed JSON-SEQ-serialized [Event] using the provided
347    /// [Event].
348    pub fn add_event_pretty<E: Serialize + Eventable>(
349        &mut self, event: E,
350    ) -> Result<()> {
351        self.write_event(event, true)
352    }
353
354    /// Writes a JSON-SEQ-serialized [Event] using the provided [Event].
355    fn write_event<E: Serialize + Eventable>(
356        &mut self, event: E, pretty: bool,
357    ) -> Result<()> {
358        if self.state != StreamerState::Ready {
359            return Err(Error::InvalidState);
360        }
361
362        if !event.importance().is_contained_in(&self.log_level) {
363            return Err(Error::Done);
364        }
365
366        self.writer.as_mut().write_all(b"")?;
367        if pretty {
368            serde_json::to_writer_pretty(self.writer.as_mut(), &event)
369                .map_err(|_| Error::Done)?;
370        } else {
371            serde_json::to_writer(self.writer.as_mut(), &event)
372                .map_err(|_| Error::Done)?;
373        }
374        self.writer.as_mut().write_all(b"\n")?;
375
376        Ok(())
377    }
378
379    /// Returns the writer.
380    #[allow(clippy::borrowed_box)]
381    pub fn writer(&self) -> &Box<dyn std::io::Write + Send + Sync> {
382        &self.writer
383    }
384
385    pub fn start_time(&self) -> std::time::Instant {
386        self.start_time
387    }
388}
389
390impl Drop for QlogStreamer {
391    fn drop(&mut self) {
392        let _ = self.finish_log();
393    }
394}
395
396#[cfg(test)]
397mod tests {
398    use std::collections::BTreeMap;
399
400    use super::*;
401    use crate::events::quic;
402    use crate::events::quic::QuicFrame;
403    use crate::events::RawInfo;
404    use testing::*;
405
406    use serde_json::json;
407
408    #[test]
409    fn serialization_states() {
410        let v: Vec<u8> = Vec::new();
411        let buff = std::io::Cursor::new(v);
412        let writer = Box::new(buff);
413
414        let trace = make_trace_seq();
415        let pkt_hdr = make_pkt_hdr(quic::PacketType::Handshake);
416        let raw = Some(RawInfo {
417            length: Some(1251),
418            payload_length: Some(1224),
419            data: None,
420        });
421
422        let frame1 = QuicFrame::Stream {
423            stream_id: 40,
424            offset: Some(40),
425            raw: Some(Box::new(RawInfo {
426                length: None,
427                payload_length: Some(400),
428                data: None,
429            })),
430            fin: Some(true),
431        };
432
433        let event_data1 = EventData::QuicPacketSent(quic::PacketSent {
434            header: pkt_hdr.clone(),
435            frames: Some(vec![frame1]),
436            raw: raw.clone(),
437            ..Default::default()
438        });
439
440        let ev1 = Event::with_time(0.0, event_data1);
441
442        let frame2 = QuicFrame::Stream {
443            stream_id: 0,
444            offset: Some(0),
445            raw: Some(Box::new(RawInfo {
446                length: None,
447                payload_length: Some(100),
448                data: None,
449            })),
450            fin: Some(true),
451        };
452
453        let frame3 = QuicFrame::Stream {
454            stream_id: 0,
455            offset: Some(0),
456            raw: Some(Box::new(RawInfo {
457                length: None,
458                payload_length: Some(100),
459                data: None,
460            })),
461            fin: Some(true),
462        };
463
464        let event_data2 = EventData::QuicPacketSent(quic::PacketSent {
465            header: pkt_hdr.clone(),
466            frames: Some(vec![frame2]),
467            raw: raw.clone(),
468            ..Default::default()
469        });
470
471        let ev2 = Event::with_time(0.0, event_data2);
472
473        let event_data3 = EventData::QuicPacketSent(quic::PacketSent {
474            header: pkt_hdr,
475            frames: Some(vec![frame3]),
476            stateless_reset_token: Some(Box::new("reset_token".to_string())),
477            raw,
478            ..Default::default()
479        });
480
481        let ev3 = Event::with_time(0.0, event_data3);
482
483        let mut s = streamer::QlogStreamer::new(
484            Some("title".to_string()),
485            Some("description".to_string()),
486            std::time::Instant::now(),
487            trace,
488            EventImportance::Base,
489            EventTimePrecision::NanoSeconds,
490            writer,
491        );
492
493        // Before the log is started all other operations should fail.
494        assert!(matches!(s.add_event(ev2.clone()), Err(Error::InvalidState)));
495        assert!(matches!(s.finish_log(), Err(Error::InvalidState)));
496
497        // Start log and add a simple event.
498        assert!(matches!(s.start_log(), Ok(())));
499        assert!(matches!(s.add_event(ev1), Ok(())));
500
501        // Add some more events.
502        assert!(matches!(s.add_event(ev2), Ok(())));
503        assert!(matches!(s.add_event(ev3.clone()), Ok(())));
504
505        // Adding an event with an external time should work too.
506        // For tests, it will resolve to 0 but we care about proving the API
507        // here, not timing specifics.
508        let now = std::time::Instant::now();
509
510        assert!(matches!(s.add_event_with_instant(ev3, now), Ok(())));
511
512        assert!(matches!(s.finish_log(), Ok(())));
513
514        let r = s.writer();
515        #[allow(clippy::borrowed_box)]
516        let w: &Box<std::io::Cursor<Vec<u8>>> = unsafe { std::mem::transmute(r) };
517
518        let log_string = r#"{"file_schema":"urn:ietf:params:qlog:file:sequential","serialization_format":"JSON-SEQ","title":"title","description":"description","trace":{"title":"Quiche qlog trace","description":"Quiche qlog trace description","vantage_point":{"type":"server"},"event_schemas":[]}}
519{"time":0.0,"name":"quic:packet_sent","data":{"header":{"packet_type":"handshake","packet_number":0,"version":"1","scil":8,"dcil":8,"scid":"7e37e4dcc6682da8","dcid":"36ce104eee50101c"},"raw":{"length":1251,"payload_length":1224},"frames":[{"frame_type":"stream","stream_id":40,"offset":40,"fin":true,"raw":{"payload_length":400}}]}}
520{"time":0.0,"name":"quic:packet_sent","data":{"header":{"packet_type":"handshake","packet_number":0,"version":"1","scil":8,"dcil":8,"scid":"7e37e4dcc6682da8","dcid":"36ce104eee50101c"},"raw":{"length":1251,"payload_length":1224},"frames":[{"frame_type":"stream","stream_id":0,"offset":0,"fin":true,"raw":{"payload_length":100}}]}}
521{"time":0.0,"name":"quic:packet_sent","data":{"header":{"packet_type":"handshake","packet_number":0,"version":"1","scil":8,"dcil":8,"scid":"7e37e4dcc6682da8","dcid":"36ce104eee50101c"},"stateless_reset_token":"reset_token","raw":{"length":1251,"payload_length":1224},"frames":[{"frame_type":"stream","stream_id":0,"offset":0,"fin":true,"raw":{"payload_length":100}}]}}
522{"time":0.0,"name":"quic:packet_sent","data":{"header":{"packet_type":"handshake","packet_number":0,"version":"1","scil":8,"dcil":8,"scid":"7e37e4dcc6682da8","dcid":"36ce104eee50101c"},"stateless_reset_token":"reset_token","raw":{"length":1251,"payload_length":1224},"frames":[{"frame_type":"stream","stream_id":0,"offset":0,"fin":true,"raw":{"payload_length":100}}]}}
523"#;
524
525        let written_string = std::str::from_utf8(w.as_ref().get_ref()).unwrap();
526
527        pretty_assertions::assert_eq!(log_string, written_string);
528    }
529
530    #[test]
531    fn stream_json_event() {
532        let data = json!({"foo": "Bar", "hello": 123});
533        let ev = events::JsonEvent {
534            time: 0.0,
535            importance: events::EventImportance::Core,
536            name: "jsonevent:sample".into(),
537            data,
538        };
539
540        let v: Vec<u8> = Vec::new();
541        let buff = std::io::Cursor::new(v);
542        let writer = Box::new(buff);
543
544        let trace = make_trace_seq();
545
546        let mut s = streamer::QlogStreamer::new(
547            Some("title".to_string()),
548            Some("description".to_string()),
549            std::time::Instant::now(),
550            trace,
551            EventImportance::Base,
552            EventTimePrecision::NanoSeconds,
553            writer,
554        );
555
556        assert!(matches!(s.start_log(), Ok(())));
557        assert!(matches!(s.add_event(ev), Ok(())));
558        assert!(matches!(s.finish_log(), Ok(())));
559
560        let r = s.writer();
561        #[allow(clippy::borrowed_box)]
562        let w: &Box<std::io::Cursor<Vec<u8>>> = unsafe { std::mem::transmute(r) };
563
564        let log_string = r#"{"file_schema":"urn:ietf:params:qlog:file:sequential","serialization_format":"JSON-SEQ","title":"title","description":"description","trace":{"title":"Quiche qlog trace","description":"Quiche qlog trace description","vantage_point":{"type":"server"},"event_schemas":[]}}
565{"time":0.0,"name":"jsonevent:sample","data":{"foo":"Bar","hello":123}}
566"#;
567
568        let written_string = std::str::from_utf8(w.as_ref().get_ref()).unwrap();
569
570        pretty_assertions::assert_eq!(log_string, written_string);
571    }
572
573    #[test]
574    fn stream_data_ex() {
575        let v: Vec<u8> = Vec::new();
576        let buff = std::io::Cursor::new(v);
577        let writer = Box::new(buff);
578
579        let trace = make_trace_seq();
580        let pkt_hdr = make_pkt_hdr(quic::PacketType::Handshake);
581        let raw = Some(RawInfo {
582            length: Some(1251),
583            payload_length: Some(1224),
584            data: None,
585        });
586
587        let frame1 = QuicFrame::Stream {
588            stream_id: 40,
589            offset: Some(40),
590            raw: Some(Box::new(RawInfo {
591                length: None,
592                payload_length: Some(400),
593                data: None,
594            })),
595            fin: Some(true),
596        };
597
598        let event_data1 = EventData::QuicPacketSent(quic::PacketSent {
599            header: pkt_hdr.clone(),
600            frames: Some(vec![frame1]),
601            raw: raw.clone(),
602            ..Default::default()
603        });
604        let j1 = json!({"foo": "Bar", "hello": 123});
605        let j2 = json!({"baz": [1,2,3,4]});
606        let mut ex_data = BTreeMap::new();
607        ex_data.insert("first".to_string(), j1);
608        ex_data.insert("second".to_string(), j2);
609
610        let ev1 = Event::with_time_ex(0.0, event_data1, ex_data);
611
612        let frame2 = QuicFrame::Stream {
613            stream_id: 1,
614            offset: Some(0),
615            raw: Some(Box::new(RawInfo {
616                length: None,
617                payload_length: Some(100),
618                data: None,
619            })),
620            fin: Some(true),
621        };
622
623        let event_data2 = EventData::QuicPacketSent(quic::PacketSent {
624            header: pkt_hdr.clone(),
625            frames: Some(vec![frame2]),
626            raw: raw.clone(),
627            ..Default::default()
628        });
629
630        let ev2 = Event::with_time(0.0, event_data2);
631
632        let mut s = streamer::QlogStreamer::new(
633            Some("title".to_string()),
634            Some("description".to_string()),
635            std::time::Instant::now(),
636            trace,
637            EventImportance::Base,
638            EventTimePrecision::NanoSeconds,
639            writer,
640        );
641
642        assert!(matches!(s.start_log(), Ok(())));
643        assert!(matches!(s.add_event(ev1), Ok(())));
644        assert!(matches!(s.add_event(ev2), Ok(())));
645        assert!(matches!(s.finish_log(), Ok(())));
646
647        let r = s.writer();
648        #[allow(clippy::borrowed_box)]
649        let w: &Box<std::io::Cursor<Vec<u8>>> = unsafe { std::mem::transmute(r) };
650
651        let log_string = r#"{"file_schema":"urn:ietf:params:qlog:file:sequential","serialization_format":"JSON-SEQ","title":"title","description":"description","trace":{"title":"Quiche qlog trace","description":"Quiche qlog trace description","vantage_point":{"type":"server"},"event_schemas":[]}}
652{"time":0.0,"name":"quic:packet_sent","data":{"header":{"packet_type":"handshake","packet_number":0,"version":"1","scil":8,"dcil":8,"scid":"7e37e4dcc6682da8","dcid":"36ce104eee50101c"},"raw":{"length":1251,"payload_length":1224},"frames":[{"frame_type":"stream","stream_id":40,"offset":40,"fin":true,"raw":{"payload_length":400}}]},"first":{"foo":"Bar","hello":123},"second":{"baz":[1,2,3,4]}}
653{"time":0.0,"name":"quic:packet_sent","data":{"header":{"packet_type":"handshake","packet_number":0,"version":"1","scil":8,"dcil":8,"scid":"7e37e4dcc6682da8","dcid":"36ce104eee50101c"},"raw":{"length":1251,"payload_length":1224},"frames":[{"frame_type":"stream","stream_id":1,"offset":0,"fin":true,"raw":{"payload_length":100}}]}}
654"#;
655
656        let written_string = std::str::from_utf8(w.as_ref().get_ref()).unwrap();
657
658        pretty_assertions::assert_eq!(log_string, written_string);
659    }
660
661    #[test]
662    fn elapsed_millis_precision() {
663        let dur = std::time::Duration::from_nanos(1_234_567);
664        assert_eq!(
665            duration_to_millis(dur, &EventTimePrecision::MilliSeconds),
666            1.0
667        );
668        assert_eq!(
669            duration_to_millis(dur, &EventTimePrecision::MicroSeconds),
670            1.234000
671        );
672        assert_eq!(
673            duration_to_millis(dur, &EventTimePrecision::NanoSeconds),
674            1.234567
675        );
676    }
677
678    #[test]
679    fn elapsed_millis_zero_duration_all_precisions() {
680        let dur = std::time::Duration::from_secs(0);
681        assert_eq!(
682            duration_to_millis(dur, &EventTimePrecision::MilliSeconds),
683            0.0
684        );
685        assert_eq!(
686            duration_to_millis(dur, &EventTimePrecision::MicroSeconds),
687            0.0
688        );
689        assert_eq!(
690            duration_to_millis(dur, &EventTimePrecision::NanoSeconds),
691            0.0
692        );
693    }
694}
qlog/streamer.rs

qlog/
streamer.rs
