qlog: add ex_data to Event

This change allows additional JSON fields to be contained in qlog events
without needing to change the core definitions.

qlog/src/events/mod.rs

@@ -35,6 +35,10 @@ use connectivity::ConnectivityEventType;
 use serde::Deserialize;
 use serde::Serialize;
 
+use std::collections::BTreeMap;
+
+pub type ExData = BTreeMap<String, serde_json::Value>;
+
 #[derive(Serialize, Deserialize, Clone, Copy, PartialEq, Eq, Debug, Default)]
 #[serde(untagged)]
 pub enum EventType {
@@ -87,6 +91,9 @@ pub struct Event {
     #[serde(flatten)]
     pub data: EventData,
 
+    #[serde(flatten)]
+    pub ex_data: ExData,
+
     pub protocol_type: Option<String>,
     pub group_id: Option<String>,
 
@@ -103,6 +110,21 @@ impl Event {
         Event {
             time,
             data,
+            ex_data: Default::default(),
+            protocol_type: Default::default(),
+            group_id: Default::default(),
+            time_format: Default::default(),
+            ty,
+        }
+    }
+
+    /// Returns a new `Event` object with the provided time and data.
+    pub fn with_time_ex(time: f32, data: EventData, ex_data: ExData) -> Self {
+        let ty = EventType::from(&data);
+        Event {
+            time,
+            data,
+            ex_data,
             protocol_type: Default::default(),
             group_id: Default::default(),
             time_format: Default::default(),
@@ -126,6 +148,7 @@ impl PartialEq for Event {
     fn eq(&self, other: &Event) -> bool {
         self.time == other.time &&
             self.data == other.data &&
+            self.ex_data == other.ex_data &&
             self.protocol_type == other.protocol_type &&
             self.group_id == other.group_id &&
             self.time_format == other.time_format

qlog/src/streamer.rs

@@ -28,6 +28,7 @@ use crate::events::EventData;
 use crate::events::EventImportance;
 use crate::events::EventType;
 use crate::events::Eventable;
+use crate::events::ExData;
 
 /// A helper object specialized for streaming JSON-serialized qlog to a
 /// [`Write`] trait.
@@ -178,6 +179,16 @@ impl QlogStreamer {
         self.add_event_data_with_instant(event_data, now)
     }
 
+    /// Writes an [Event] based on the provided [EventData] to a JSON-SEQ record
+    /// at time [std::time::Instant::now()].
+    pub fn add_event_data_ex_now(
+        &mut self, event_data: EventData, ex_data: ExData,
+    ) -> Result<()> {
+        let now = std::time::Instant::now();
+
+        self.add_event_data_ex_with_instant(event_data, ex_data, now)
+    }
+
     /// Writes an [Event] based on the provided [EventData] and
     /// [std::time::Instant] to a JSON-SEQ record.
     pub fn add_event_data_with_instant(
@@ -204,6 +215,33 @@ impl QlogStreamer {
         self.add_event(event)
     }
 
+    /// Writes an [Event] based on the provided [EventData] and
+    /// [std::time::Instant] to a JSON-SEQ record.
+    pub fn add_event_data_ex_with_instant(
+        &mut self, event_data: EventData, ex_data: ExData,
+        now: std::time::Instant,
+    ) -> Result<()> {
+        if self.state != StreamerState::Ready {
+            return Err(Error::InvalidState);
+        }
+
+        let ty = EventType::from(&event_data);
+        if !EventImportance::from(ty).is_contained_in(&self.log_level) {
+            return Err(Error::Done);
+        }
+
+        let dur = if cfg!(test) {
+            std::time::Duration::from_secs(0)
+        } else {
+            now.duration_since(self.start_time)
+        };
+
+        let rel_time = dur.as_secs_f32() * 1000.0;
+        let event = Event::with_time_ex(rel_time, event_data, ex_data);
+
+        self.add_event(event)
+    }
+
     /// Writes a JSON-SEQ-serialized [Event] using the provided [Event].
     pub fn add_event<E: Serialize + Eventable>(
         &mut self, event: E,
@@ -243,6 +281,9 @@ impl Drop for QlogStreamer {
 
 #[cfg(test)]
 mod tests {
+    use std::collections::BTreeMap;
+    use std::collections::HashMap;
+
     use super::*;
     use crate::events::quic;
     use crate::events::quic::QuicFrame;
@@ -426,4 +467,99 @@ mod tests {
 
         assert_eq!(log_string, written_string);
     }
+
+    #[test]
+    fn stream_data_ex() {
+        let v: Vec<u8> = Vec::new();
+        let buff = std::io::Cursor::new(v);
+        let writer = Box::new(buff);
+
+        let trace = make_trace_seq();
+        let pkt_hdr = make_pkt_hdr(quic::PacketType::Handshake);
+        let raw = Some(RawInfo {
+            length: Some(1251),
+            payload_length: Some(1224),
+            data: None,
+        });
+
+        let frame1 = QuicFrame::Stream {
+            stream_id: 40,
+            offset: 40,
+            length: 400,
+            fin: Some(true),
+            raw: None,
+        };
+
+        let event_data1 = EventData::PacketSent(quic::PacketSent {
+            header: pkt_hdr.clone(),
+            frames: Some(smallvec![frame1]),
+            is_coalesced: None,
+            retry_token: None,
+            stateless_reset_token: None,
+            supported_versions: None,
+            raw: raw.clone(),
+            datagram_id: None,
+            send_at_time: None,
+            trigger: None,
+        });
+        let j1 = json!({"foo": "Bar", "hello": 123});
+        let j2 = json!({"baz": [1,2,3,4]});
+        let mut ex_data = BTreeMap::new();
+        ex_data.insert("first".to_string(), j1);
+        ex_data.insert("second".to_string(), j2);
+
+        let ev1 = Event::with_time_ex(0.0, event_data1, ex_data);
+
+        let frame2 = QuicFrame::Stream {
+            stream_id: 1,
+            offset: 0,
+            length: 100,
+            fin: Some(true),
+            raw: None,
+        };
+
+        let event_data2 = EventData::PacketSent(quic::PacketSent {
+            header: pkt_hdr.clone(),
+            frames: Some(smallvec![frame2]),
+            is_coalesced: None,
+            retry_token: None,
+            stateless_reset_token: None,
+            supported_versions: None,
+            raw: raw.clone(),
+            datagram_id: None,
+            send_at_time: None,
+            trigger: None,
+        });
+
+        let ev2 = Event::with_time(0.0, event_data2);
+
+        let mut s = streamer::QlogStreamer::new(
+            "version".to_string(),
+            Some("title".to_string()),
+            Some("description".to_string()),
+            None,
+            std::time::Instant::now(),
+            trace,
+            EventImportance::Base,
+            writer,
+        );
+
+        assert!(matches!(s.start_log(), Ok(())));
+        assert!(matches!(s.add_event(ev1), Ok(())));
+        assert!(matches!(s.add_event(ev2), Ok(())));
+        assert!(matches!(s.finish_log(), Ok(())));
+
+        let r = s.writer();
+        #[allow(clippy::borrowed_box)]
+        let w: &Box<std::io::Cursor<Vec<u8>>> = unsafe { std::mem::transmute(r) };
+
+        let log_string = r#"{"qlog_version":"version","qlog_format":"JSON-SEQ","title":"title","description":"description","trace":{"vantage_point":{"type":"server"},"title":"Quiche qlog trace","description":"Quiche qlog trace description","configuration":{"time_offset":0.0}}}
+{"time":0.0,"name":"transport: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,"length":400,"fin":true}]},"first":{"foo":"Bar","hello":123},"second":{"baz":[1,2,3,4]}}
+{"time":0.0,"name":"transport: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,"length":100,"fin":true}]}}
+"#;
+
+        let written_string = std::str::from_utf8(w.as_ref().get_ref()).unwrap();
+
+        assert_eq!(log_string, written_string);
+    }
 }