Add support of having arguments on events.

This is implemented by encoding arguments as part of the event_id.

Author: michaelwoerister

analyzeme/src/event.rs

@@ -1,12 +1,16 @@
 use crate::timestamp::Timestamp;
+use memchr::memchr;
 use std::borrow::Cow;
 use std::time::Duration;
 
+const SEPARATOR: u8 = 0x1E;
+const ARG_TAG: u8 = 0x11;
+
 #[derive(Clone, Eq, PartialEq, Hash, Debug)]
 pub struct Event<'a> {
     pub event_kind: Cow<'a, str>,
     pub label: Cow<'a, str>,
-    pub additional_data: &'a [Cow<'a, str>],
+    pub additional_data: Vec<Cow<'a, str>>,
     pub timestamp: Timestamp,
     pub thread_id: u32,
 }
@@ -36,4 +40,144 @@ impl<'a> Event<'a> {
             Timestamp::Instant(_) => None,
         }
     }
+
+    pub(crate) fn parse_event_id(event_id: Cow<'a, str>) -> (Cow<'a, str>, Vec<Cow<'a, str>>) {
+        let event_id = match event_id {
+            Cow::Owned(s) => Cow::Owned(s.into_bytes()),
+            Cow::Borrowed(s) => Cow::Borrowed(s.as_bytes()),
+        };
+
+        let mut parser = Parser::new(event_id);
+
+        let label = match parser.parse_label() {
+            Ok(label) => label,
+            Err(message) => {
+                eprintln!("{}", message);
+                return (Cow::from("<parse error>"), Vec::new());
+            }
+        };
+
+        let mut args = Vec::new();
+
+        while parser.pos != parser.full_text.len() {
+            match parser.parse_arg() {
+                Ok(arg) => args.push(arg),
+                Err(message) => {
+                    eprintln!("{}", message);
+                    break;
+                }
+            }
+        }
+
+        (label, args)
+    }
+}
+
+struct Parser<'a> {
+    full_text: Cow<'a, [u8]>,
+    pos: usize,
+}
+
+impl<'a> Parser<'a> {
+    fn new(full_text: Cow<'a, [u8]>) -> Parser<'a> {
+        Parser { full_text, pos: 0 }
+    }
+
+    fn peek(&self) -> u8 {
+        self.full_text[self.pos]
+    }
+
+    fn parse_label(&mut self) -> Result<Cow<'a, str>, String> {
+        assert!(self.pos == 0);
+        self.parse_separator_terminated_text()
+    }
+
+    fn parse_separator_terminated_text(&mut self) -> Result<Cow<'a, str>, String> {
+        let start = self.pos;
+
+        let end = memchr(SEPARATOR, &self.full_text[start..])
+            .map(|pos| pos + start)
+            .unwrap_or(self.full_text.len());
+
+        if start == end {
+            return self.err("Zero-length <text>");
+        }
+
+        self.pos = end;
+
+        Ok(self.substring(start, end))
+    }
+
+    fn parse_arg(&mut self) -> Result<Cow<'a, str>, String> {
+        if self.peek() != SEPARATOR {
+            return self.err(&format!(
+                "Expected '\\x{:x}' char at start of <argument>",
+                SEPARATOR
+            ));
+        }
+
+        self.pos += 1;
+        let tag = self.peek();
+
+        match tag {
+            ARG_TAG => {
+                self.pos += 1;
+                self.parse_separator_terminated_text()
+            }
+            other => self.err(&format!("Unexpected argument tag '{:x}'", other)),
+        }
+    }
+
+    fn err<T>(&self, message: &str) -> Result<T, String> {
+        Err(format!(
+            r#"Could not parse `event_id`. {} at {} in "{}""#,
+            message,
+            self.pos,
+            std::str::from_utf8(&self.full_text[..]).unwrap()
+        ))
+    }
+
+    fn substring(&self, start: usize, end: usize) -> Cow<'a, str> {
+        match self.full_text {
+            Cow::Owned(ref s) => {
+                let bytes = s[start..end].to_owned();
+                Cow::Owned(String::from_utf8(bytes).unwrap())
+            }
+            Cow::Borrowed(s) => Cow::Borrowed(std::str::from_utf8(&s[start..end]).unwrap()),
+        }
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+    use std::borrow::Cow;
+
+    #[test]
+    fn parse_event_id_no_args() {
+        let (label, args) = Event::parse_event_id(Cow::from("foo"));
+
+        assert_eq!(label, "foo");
+        assert!(args.is_empty());
+    }
+
+    #[test]
+    fn parse_event_id_one_arg() {
+        let (label, args) = Event::parse_event_id(Cow::from("foo\x1e\x11my_arg"));
+
+        assert_eq!(label, "foo");
+        assert_eq!(args, vec![Cow::from("my_arg")]);
+    }
+
+    #[test]
+    fn parse_event_id_n_args() {
+        let (label, args) =
+            Event::parse_event_id(Cow::from("foo\x1e\x11arg1\x1e\x11arg2\x1e\x11arg3"));
+
+        assert_eq!(label, "foo");
+        assert_eq!(
+            args,
+            vec![Cow::from("arg1"), Cow::from("arg2"), Cow::from("arg3")]
+        );
+    }
 }

analyzeme/src/profiling_data.rs

@@ -1,7 +1,7 @@
 use crate::event::Event;
 use crate::lightweight_event::LightweightEvent;
-use crate::StringTable;
 use crate::timestamp::Timestamp;
+use crate::StringTable;
 use measureme::file_header::{
     read_file_header, write_file_header, CURRENT_FILE_FORMAT_VERSION, FILE_HEADER_SIZE,
     FILE_MAGIC_EVENT_STREAM,
@@ -94,10 +94,14 @@ impl ProfilingData {
 
         let timestamp = Timestamp::from_raw_event(&raw_event, self.metadata.start_time);
 
+        let event_id = string_table.get(raw_event.event_id).to_string();
+        // Parse out the label and arguments from the `event_id`.
+        let (label, additional_data) = Event::parse_event_id(event_id);
+
         Event {
             event_kind: string_table.get(raw_event.event_kind).to_string(),
-            label: string_table.get(raw_event.event_id).to_string(),
-            additional_data: &[],
+            label,
+            additional_data,
             timestamp,
             thread_id: raw_event.thread_id,
         }
@@ -319,7 +323,7 @@ mod tests {
         Event {
             event_kind: Cow::from(event_kind),
             label: Cow::from(label),
-            additional_data: &[],
+            additional_data: Vec::new(),
             timestamp: Timestamp::Interval {
                 start: SystemTime::UNIX_EPOCH + Duration::from_nanos(start_nanos),
                 end: SystemTime::UNIX_EPOCH + Duration::from_nanos(end_nanos),
@@ -337,7 +341,7 @@ mod tests {
         Event {
             event_kind: Cow::from(event_kind),
             label: Cow::from(label),
-            additional_data: &[],
+            additional_data: Vec::new(),
             timestamp: Timestamp::Instant(
                 SystemTime::UNIX_EPOCH + Duration::from_nanos(timestamp_nanos),
             ),
@@ -399,7 +403,6 @@ mod tests {
         assert_eq!(events[0].to_event(), full_interval("k1", "id1", 0, 10, 100));
         assert_eq!(events[1].to_event(), full_interval("k2", "id2", 1, 100, 110));
         assert_eq!(events[2].to_event(), full_interval("k3", "id3", 0, 120, 140));
-
     }
 
     #[test]

analyzeme/src/testing_common.rs

@@ -1,6 +1,6 @@
 use crate::timestamp::Timestamp;
 use crate::{Event, ProfilingData};
-use measureme::{Profiler, SerializationSink, StringId};
+use measureme::{EventIdBuilder, Profiler, SerializationSink, StringId};
 use rustc_hash::FxHashMap;
 use std::borrow::Cow;
 use std::default::Default;
@@ -18,6 +18,27 @@ fn mk_filestem(file_name_stem: &str) -> PathBuf {
     path
 }
 
+#[derive(Clone)]
+struct ExpectedEvent {
+    kind: Cow<'static, str>,
+    label: Cow<'static, str>,
+    args: Vec<Cow<'static, str>>,
+}
+
+impl ExpectedEvent {
+    fn new(
+        kind: &'static str,
+        label: &'static str,
+        args: &[&'static str]
+    ) -> ExpectedEvent {
+        ExpectedEvent {
+            kind: Cow::from(kind),
+            label: Cow::from(label),
+            args: args.iter().map(|&x| Cow::from(x)).collect(),
+        }
+    }
+}
+
 // Generate some profiling data. This is the part that would run in rustc.
 fn generate_profiling_data<S: SerializationSink>(
     filestem: &Path,
@@ -28,25 +49,34 @@ fn generate_profiling_data<S: SerializationSink>(
 
     let event_id_virtual = StringId::new_virtual(42);
 
+    let event_id_builder = EventIdBuilder::new(&profiler);
+
     let event_ids = vec![
         (
             profiler.alloc_string("Generic"),
             profiler.alloc_string("SomeGenericActivity"),
         ),
         (profiler.alloc_string("Query"), event_id_virtual),
+        (
+            profiler.alloc_string("QueryWithArg"),
+            event_id_builder.from_label_and_arg(
+                profiler.alloc_string("AQueryWithArg"),
+                profiler.alloc_string("some_arg")
+            ),
+        ),
     ];
 
     // This and event_ids have to match!
-    let mut event_ids_as_str: FxHashMap<_, _> = Default::default();
-    event_ids_as_str.insert(event_ids[0].0, "Generic");
-    event_ids_as_str.insert(event_ids[0].1, "SomeGenericActivity");
-    event_ids_as_str.insert(event_ids[1].0, "Query");
-    event_ids_as_str.insert(event_ids[1].1, "SomeQuery");
+    let expected_events_templates = vec![
+        ExpectedEvent::new("Generic", "SomeGenericActivity", &[]),
+        ExpectedEvent::new("Query", "SomeQuery", &[]),
+        ExpectedEvent::new("QueryWithArg", "AQueryWithArg", &["some_arg"]),
+    ];
 
     let threads: Vec<_> = (0.. num_threads).map(|thread_id| {
         let event_ids = event_ids.clone();
         let profiler = profiler.clone();
-        let event_ids_as_str = event_ids_as_str.clone();
+        let expected_events_templates = expected_events_templates.clone();
 
         std::thread::spawn(move || {
             let mut expected_events = Vec::new();
@@ -60,7 +90,7 @@ fn generate_profiling_data<S: SerializationSink>(
                     thread_id as u32,
                     4,
                     &event_ids[..],
-                    &event_ids_as_str,
+                    &expected_events_templates,
                     &mut expected_events,
                 );
             }
@@ -166,14 +196,16 @@ fn pseudo_invocation<S: SerializationSink>(
     thread_id: u32,
     recursions_left: usize,
     event_ids: &[(StringId, StringId)],
-    event_ids_as_str: &FxHashMap<StringId, &'static str>,
+    expected_events_templates: &[ExpectedEvent],
     expected_events: &mut Vec<Event<'static>>,
 ) {
     if recursions_left == 0 {
         return;
     }
 
-    let (event_kind, event_id) = event_ids[random % event_ids.len()];
+    let random_event_index = random % event_ids.len();
+
+    let (event_kind, event_id) = event_ids[random_event_index];
 
     let _prof_guard = profiler.start_recording_interval_event(event_kind, event_id, thread_id);
 
@@ -183,19 +215,19 @@ fn pseudo_invocation<S: SerializationSink>(
         thread_id,
         recursions_left - 1,
         event_ids,
-        event_ids_as_str,
+        expected_events_templates,
         expected_events,
     );
 
     expected_events.push(Event {
-        event_kind: Cow::from(event_ids_as_str[&event_kind]),
-        label: Cow::from(event_ids_as_str[&event_id]),
-        additional_data: &[],
+        event_kind: expected_events_templates[random_event_index].kind.clone(),
+        label: expected_events_templates[random_event_index].label.clone(),
+        additional_data: expected_events_templates[random_event_index].args.clone(),
+        thread_id,
         // We can't test this anyway:
         timestamp: Timestamp::Interval {
             start: SystemTime::UNIX_EPOCH,
             end: SystemTime::UNIX_EPOCH,
         },
-        thread_id,
     });
 }

measureme/src/event_id.rs

@@ -0,0 +1,40 @@
+use crate::{Profiler, SerializationSink, StringComponent, StringId};
+
+/// Event IDs are strings conforming to the following grammar:
+///
+/// ```ignore
+///   <event_id> = <label> {<argument>}
+///   <label> = <text>
+///   <argument> = '\x1E' '\x11' <text>
+///   <text> = regex([^0x1E]+) // Anything but the separator byte
+///  ```
+///
+/// This means there's always a "label", followed by an optional list of
+/// arguments. Future versions my support other optional suffixes (with a tag
+/// other than '\x11' after the '\x1E' separator), such as a "category".
+
+pub struct EventIdBuilder<'p, S: SerializationSink> {
+    profiler: &'p Profiler<S>,
+}
+
+impl<'p, S: SerializationSink> EventIdBuilder<'p, S> {
+    pub fn new(profiler: &Profiler<S>) -> EventIdBuilder<'_, S> {
+        EventIdBuilder { profiler }
+    }
+
+    pub fn from_label(&self, label: StringId) -> StringId {
+        // Just forward the string ID, i single identifier is a valid event_id
+        label
+    }
+
+    pub fn from_label_and_arg(&self, label: StringId, arg: StringId) -> StringId {
+        self.profiler.alloc_string(&[
+            // Label
+            StringComponent::Ref(label),
+            // Seperator and start tag for arg
+            StringComponent::Value("\x1E\x11"),
+            // Arg string id
+            StringComponent::Ref(arg),
+        ])
+    }
+}

measureme/src/file_header.rs

@@ -6,7 +6,7 @@ use crate::serialization::SerializationSink;
 use byteorder::{ByteOrder, LittleEndian};
 use std::error::Error;
 
-pub const CURRENT_FILE_FORMAT_VERSION: u32 = 4;
+pub const CURRENT_FILE_FORMAT_VERSION: u32 = 5;
 pub const FILE_MAGIC_EVENT_STREAM: &[u8; 4] = b"MMES";
 pub const FILE_MAGIC_STRINGTABLE_DATA: &[u8; 4] = b"MMSD";
 pub const FILE_MAGIC_STRINGTABLE_INDEX: &[u8; 4] = b"MMSI";