Include system boot time in the primary log as metadata

agent/src/log_writer.rs

@@ -32,15 +32,21 @@ impl LogWriter {
         let file = File::create(&config.log_file)
             .await
             .with_context(|| format!("unable to create file `{}`", config.log_file.display()))?;
-        Ok(Self {
+
+        let mut log_writer = Self {
             config: config.clone(),
             file: Some(file),
             offset: 0u64,
             instant: Instant::now(),
             groups: Vec::default(),
             written_events: 0usize,
             pending_events: 0usize,
-        })
+        };
+
+        let metadata = EventGroup::metadata();
+        log_writer.write_event_group(&metadata).await?;
+
+        Ok(log_writer)
     }
 
     pub fn timeout(&self) -> Duration {
@@ -164,18 +170,22 @@ impl LogWriter {
         Ok(())
     }
 
+    async fn write_event_group(&mut self, group: &EventGroup) -> Result<()> {
+        let v = match self.config.format {
+            config::Format::Normal => serde_cbor::ser::to_vec(group)?,
+            config::Format::Packed => serde_cbor::ser::to_vec_packed(group)?,
+            config::Format::Minimal => to_vec_minimal(group)?,
+        };
+        self.write_all(v).await
+    }
+
     pub async fn flush(&mut self) -> Result<()> {
         self.pending_events = 0;
         for group in self.groups.clone() {
             if self.should_rotate_after(self.written_events) {
                 self.rotate().await?;
             }
-            let v = match self.config.format {
-                config::Format::Normal => serde_cbor::ser::to_vec(&group)?,
-                config::Format::Packed => serde_cbor::ser::to_vec_packed(&group)?,
-                config::Format::Minimal => to_vec_minimal(&group)?,
-            };
-            self.write_all(v).await?;
+            self.write_event_group(&group).await?;
             probe!(
                 crypto_auditing_internal_agent,
                 event_group,

agent/tests/coalesce.rs

@@ -120,7 +120,8 @@ fn test_probe_coalesce() {
         .into_iter::<EventGroup>()
         .collect();
     let groups = groups.expect("error deserializing");
-    assert_eq!(groups.len(), 2);
-    assert_eq!(groups[0].events().len(), 4);
-    assert_eq!(groups[1].events().len(), 1);
+    assert_eq!(groups.len(), 3);
+    assert!(groups[0].is_metadata());
+    assert_eq!(groups[1].events().len(), 4);
+    assert_eq!(groups[2].events().len(), 1);
 }

agent/tests/composite.rs

@@ -144,27 +144,28 @@ fn test_probe_composite() {
         .into_iter::<EventGroup>()
         .collect();
     let groups = groups.expect("error deserializing");
-    assert_eq!(groups.len(), 5);
-    assert_eq!(groups[0].events().len(), 1);
-    assert!(matches!(groups[0].events()[0], Event::NewContext { .. }));
+    assert_eq!(groups.len(), 6);
+    assert!(groups[0].is_metadata());
     assert_eq!(groups[1].events().len(), 1);
-    if let Event::Data { key, .. } = &groups[1].events()[0] {
+    assert!(matches!(groups[1].events()[0], Event::NewContext { .. }));
+    assert_eq!(groups[2].events().len(), 1);
+    if let Event::Data { key, .. } = &groups[2].events()[0] {
         assert_eq!(key, "foo");
     } else {
         unreachable!();
     }
-    assert_eq!(groups[2].events().len(), 1);
-    if let Event::Data { key, .. } = &groups[2].events()[0] {
+    assert_eq!(groups[3].events().len(), 1);
+    if let Event::Data { key, .. } = &groups[3].events()[0] {
         assert_eq!(key, "bar");
     } else {
         unreachable!();
     }
-    assert_eq!(groups[3].events().len(), 1);
-    if let Event::Data { key, .. } = &groups[3].events()[0] {
+    assert_eq!(groups[4].events().len(), 1);
+    if let Event::Data { key, .. } = &groups[4].events()[0] {
         assert_eq!(key, "baz");
     } else {
         unreachable!();
     }
-    assert_eq!(groups[4].events().len(), 1);
-    assert!(matches!(groups[4].events()[0], Event::NewContext { .. }));
+    assert_eq!(groups[5].events().len(), 1);
+    assert!(matches!(groups[5].events()[0], Event::NewContext { .. }));
 }

agent/tests/no_coalesce.rs

@@ -142,10 +142,11 @@ fn test_probe_no_coalesce() {
         .into_iter::<EventGroup>()
         .collect();
     let groups = groups.expect("error deserializing");
-    assert_eq!(groups.len(), 5);
-    assert_eq!(groups[0].events().len(), 1);
+    assert_eq!(groups.len(), 6);
+    assert!(groups[0].is_metadata());
     assert_eq!(groups[1].events().len(), 1);
     assert_eq!(groups[2].events().len(), 1);
     assert_eq!(groups[3].events().len(), 1);
     assert_eq!(groups[4].events().len(), 1);
+    assert_eq!(groups[5].events().len(), 1);
 }

crypto-auditing/src/types.rs

@@ -17,6 +17,9 @@ include!(concat!(env!("OUT_DIR"), "/bindings.rs"));
 
 pub type ContextId = [u8; 16];
 
+/// Context ID associated with `EventGroup` representing metadata
+pub const METADATA_CONTEXT_ID: ContextId = [0; 16];
+
 fn only_values<K, V, S>(source: &BTreeMap<K, V>, serializer: S) -> Result<S::Ok, S::Error>
 where
     S: Serializer,
@@ -177,6 +180,15 @@ pub enum Event {
     },
 }
 
+impl Event {
+    pub fn data(&self, needle: &str) -> Option<&EventData> {
+        match self {
+            Self::Data { key, value } if key == needle => Some(value),
+            _ => None,
+        }
+    }
+}
+
 #[serde_as]
 #[derive(Serialize, Deserialize, Clone, Debug)]
 pub struct EventGroup {
@@ -197,6 +209,32 @@ fn format_context_id(pid_tgid: u64, context: i64) -> ContextId {
 }
 
 impl EventGroup {
+    /// Returns a new `EventGroup` with metadata events
+    pub fn metadata() -> Self {
+        let events = vec![
+            Event::Data {
+                key: "version".to_string(),
+                value: EventData::Word(1),
+            },
+            Event::Data {
+                key: "boot_time".to_string(),
+                value: EventData::Word(System::boot_time() as i64),
+            },
+        ];
+
+        Self {
+            context: METADATA_CONTEXT_ID,
+            start: Default::default(),
+            end: Default::default(),
+            events,
+        }
+    }
+
+    /// Returns true if this is a metadata group
+    pub fn is_metadata(&self) -> bool {
+        self.context == METADATA_CONTEXT_ID
+    }
+
     /// Returns the context ID associated with the event group
     pub fn context(&self) -> &ContextId {
         &self.context

docs/logging-format.md

@@ -363,6 +363,16 @@ events in given time window from `start` to `end`.  Timestamps are
 represented as a monotonic duration from the kernel boot time.
 `ContextId` is an encrypted 16-byte context.
 
+The first `EventGroup` may be a virtual metadata group, whose
+`ContextId` is all-zero. This is used for including environmental
+information as event entries. The following events are currently
+defined:
+
+| key         | value type | description                                 |
+|-------------|------------|---------------------------------------------|
+| `version`   | word       | the file format version (should be 1)       |
+| `boot_time` | word       | kernel boot time in seconds from Unix epoch |
+
 ### Drawbacks and alternatives
 
 ### Questions

log-parser/src/query.rs

@@ -2,27 +2,56 @@
 // Copyright (C) 2022-2023 The crypto-auditing developers.
 
 use anyhow::{Context as _, Result};
-use crypto_auditing::types::{ContextTracker, EventGroup};
+use crypto_auditing::types::{ContextTracker, EventData, EventGroup};
 use pager::Pager;
 use serde_cbor::de::Deserializer;
 use std::io::{self, Write};
-use std::time::{Duration, UNIX_EPOCH};
+use std::time::{Duration, SystemTime, UNIX_EPOCH};
 
 mod config;
 
+fn get_boot_time_from_metadata(group: &EventGroup) -> Option<SystemTime> {
+    for event in group.events() {
+        if let Some(data) = event.data("boot_time") {
+            match data {
+                EventData::Word(secs) => {
+                    return Some(UNIX_EPOCH + Duration::from_secs(*secs as u64));
+                }
+                _ => (),
+            }
+        }
+    }
+    None
+}
+
 fn main() -> Result<(), Box<dyn std::error::Error>> {
     let config = config::Config::new()?;
     Pager::new().setup();
 
     let log_file = std::fs::File::open(&config.log_file)
         .with_context(|| format!("unable to read file `{}`", config.log_file.display()))?;
 
-    let mut tracker = ContextTracker::new(
-        config
-            .boot_time
-            .map(|secs| UNIX_EPOCH + Duration::from_secs(secs)),
-    );
-    for group in Deserializer::from_reader(&log_file).into_iter::<EventGroup>() {
+    let mut groups = Deserializer::from_reader(&log_file)
+        .into_iter::<EventGroup>()
+        .peekable();
+
+    // Figure out the system boot time, first from the config, and
+    // then from the metadata group in the log
+    let boot_time = if let Some(secs) = config.boot_time {
+        Some(UNIX_EPOCH + Duration::from_secs(secs))
+    } else if let Some(Ok(group)) = groups.peek()
+        && group.is_metadata()
+    {
+        let boot_time = get_boot_time_from_metadata(&group);
+        // Skip the metadata group
+        groups.next();
+        boot_time
+    } else {
+        None
+    };
+
+    let mut tracker = ContextTracker::new(boot_time);
+    for group in groups {
         tracker.handle_event_group(&group?);
     }
     let root_contexts: Vec<_> = tracker