journald: remove span field prefixes; add separate fields for span data

tracing-journald/src/lib.rs

@@ -74,7 +74,7 @@ mod socket;
 /// The standard journald `CODE_LINE` and `CODE_FILE` fields are automatically emitted. A `TARGET`
 /// field is emitted containing the event's target. Enclosing spans are numbered counting up from
 /// the root, and their fields and metadata are included in fields prefixed by `Sn_` where `n` is
-/// that number.
+/// that number. Prefixing user-defined span fields may be disabled.
 ///
 /// User-defined fields other than the event `message` field have a prefix applied by default to
 /// prevent collision with standard fields.
@@ -84,6 +84,7 @@ pub struct Subscriber {
     #[cfg(unix)]
     socket: UnixDatagram,
     field_prefix: Option<String>,
+    span_field_prefix: Option<String>,
     syslog_identifier: String,
 }
 
@@ -102,6 +103,7 @@ impl Subscriber {
             let sub = Self {
                 socket,
                 field_prefix: Some("F".into()),
+                span_field_prefix: Some("S".into()),
                 syslog_identifier: std::env::current_exe()
                     .ok()
                     .as_ref()
@@ -129,6 +131,13 @@ impl Subscriber {
         self
     }
 
+    /// Sets the prefix to apply to names of user-defined span fields.
+    /// Defaults to `Some("S")`.
+    pub fn with_span_field_prefix(mut self, x: Option<String>) -> Self {
+        self.span_field_prefix = x;
+        self
+    }
+
     /// Sets the syslog identifier for this logger.
     ///
     /// The syslog identifier comes from the classic syslog interface (`openlog()`
@@ -224,7 +233,8 @@ where
         attrs.record(&mut SpanVisitor {
             buf: &mut buf,
             depth,
-            prefix: self.field_prefix.as_ref().map(|x| &x[..]),
+            field_prefix: self.field_prefix.as_deref(),
+            span_field_prefix: self.span_field_prefix.as_deref(),
         });
 
         span.extensions_mut().insert(SpanFields(buf));
@@ -238,7 +248,8 @@ where
         values.record(&mut SpanVisitor {
             buf,
             depth,
-            prefix: self.field_prefix.as_ref().map(|x| &x[..]),
+            field_prefix: self.field_prefix.as_deref(),
+            span_field_prefix: self.span_field_prefix.as_deref(),
         });
     }
 
@@ -264,7 +275,7 @@ where
 
         event.record(&mut EventVisitor::new(
             &mut buf,
-            self.field_prefix.as_ref().map(|x| &x[..]),
+            self.field_prefix.as_deref(),
         ));
 
         // At this point we can't handle the error anymore so just ignore it.
@@ -277,16 +288,19 @@ struct SpanFields(Vec<u8>);
 struct SpanVisitor<'a> {
     buf: &'a mut Vec<u8>,
     depth: usize,
-    prefix: Option<&'a str>,
+    field_prefix: Option<&'a str>,
+    span_field_prefix: Option<&'a str>,
 }
 
 impl SpanVisitor<'_> {
     fn put_span_prefix(&mut self) {
-        write!(self.buf, "S{}", self.depth).unwrap();
-        if let Some(prefix) = self.prefix {
-            self.buf.extend_from_slice(prefix.as_bytes());
+        if let Some(span_prefix) = self.span_field_prefix {
+            write!(self.buf, "{}{}", span_prefix, self.depth).unwrap();
+            if let Some(prefix) = self.field_prefix {
+                self.buf.extend_from_slice(prefix.as_bytes());
+            }
+            self.buf.push(b'_');
         }
-        self.buf.push(b'_');
     }
 }
 

tracing-journald/tests/journal.rs

@@ -5,7 +5,7 @@ use std::process::Command;
 use std::time::Duration;
 
 use serde::Deserialize;
-use tracing::{debug, error, info, warn};
+use tracing::{debug, error, info, info_span, warn};
 use tracing_journald::Subscriber;
 use tracing_subscriber::subscribe::CollectExt;
 use tracing_subscriber::Registry;
@@ -16,9 +16,13 @@ fn journalctl_version() -> std::io::Result<String> {
 }
 
 fn with_journald(f: impl FnOnce()) {
+    with_journald_subscriber(Subscriber::new().unwrap().with_field_prefix(None), f)
+}
+
+fn with_journald_subscriber(subscriber: Subscriber, f: impl FnOnce()) {
     match journalctl_version() {
         Ok(_) => {
-            let sub = Registry::default().with(Subscriber::new().unwrap().with_field_prefix(None));
+            let sub = Registry::default().with(subscriber);
             tracing::collect::with_default(sub, f);
         }
         Err(error) => eprintln!(
@@ -32,6 +36,7 @@ fn with_journald(f: impl FnOnce()) {
 #[serde(untagged)]
 enum Field {
     Text(String),
+    Array(Vec<String>),
     Binary(Vec<u8>),
 }
 
@@ -41,6 +46,7 @@ impl PartialEq<&str> for Field {
         match self {
             Field::Text(s) => s == other,
             Field::Binary(_) => false,
+            Field::Array(_) => false
         }
     }
 }
@@ -50,6 +56,17 @@ impl PartialEq<[u8]> for Field {
         match self {
             Field::Text(s) => s.as_bytes() == other,
             Field::Binary(data) => data == other,
+            Field::Array(_) => false
+        }
+    }
+}
+
+impl PartialEq<Vec<&str>> for Field {
+    fn eq(&self, other: &Vec<&str>) -> bool {
+        match self {
+            Field::Text(_) => false,
+            Field::Binary(_) => false,
+            Field::Array(data) => data == other
         }
     }
 }
@@ -182,3 +199,73 @@ fn large_message() {
         assert_eq!(message["PRIORITY"], "6");
     });
 }
+
+#[test]
+fn span_metadata() {
+    with_journald(|| {
+        let s1 = info_span!("span1", span_field1 = "foo1");
+        let _g1 = s1.enter();
+        let s2 = info_span!("span2", span_field1 = "foo2");
+        let _g2 = s2.enter();
+
+        info!(test.name = "span_metadata", "Hello World");
+
+        let message = retry_read_one_line_from_journal("span_metadata");
+        assert_eq!(message["MESSAGE"], "Hello World");
+        assert_eq!(message["PRIORITY"], "5");
+
+        assert_eq!(message["S0_SPAN_FIELD1"], "foo1");
+        assert_eq!(message["S0_NAME"], "span1");
+        assert!(message.contains_key("S0_CODE_FILE"));
+        assert!(message.contains_key("S0_CODE_LINE"));
+
+        assert_eq!(message["S1_SPAN_FIELD1"], "foo2");
+        assert_eq!(message["S1_NAME"], "span2");
+        assert!(message.contains_key("S1_CODE_FILE"));
+        assert!(message.contains_key("S1_CODE_LINE"));
+    });
+}
+
+#[test]
+fn no_span_field_prefix() {
+    let sub = Subscriber::new().unwrap()
+        .with_field_prefix(None)
+        .with_span_field_prefix(None);
+    with_journald_subscriber(sub, || {
+        let s1 = info_span!("span1", span_field = "foo");
+        let _guard = s1.enter();
+        info!(test.name = "no_span_prefix", "Hello World");
+
+        let message = retry_read_one_line_from_journal("no_span_prefix");
+        assert_eq!(message["MESSAGE"], "Hello World");
+        assert_eq!(message["PRIORITY"], "5");
+
+        // standard fields still prefixed
+        assert_eq!(message["S0_NAME"], "span1");
+        assert!(message.contains_key("S0_CODE_FILE"));
+        assert!(message.contains_key("S0_CODE_LINE"));
+
+        assert_eq!(message["SPAN_FIELD"], "foo");
+    });
+}
+
+#[test]
+fn spans_field_collision() {
+    let sub = Subscriber::new().unwrap()
+        .with_field_prefix(None)
+        .with_span_field_prefix(None);
+    with_journald_subscriber(sub, || {
+        let s1 = info_span!("span1", span_field = "foo1");
+        let _g1 = s1.enter();
+        let s2 = info_span!("span2", span_field = "foo2");
+        let _g2 = s2.enter();
+
+        info!(test.name = "spans_field_collision", "Hello World");
+
+        let message = retry_read_one_line_from_journal("spans_field_collision");
+        assert_eq!(message["MESSAGE"], "Hello World");
+        assert_eq!(message["S0_NAME"], "span1");
+
+        assert_eq!(message["SPAN_FIELD"], vec!["foo1", "foo2"]);
+    });
+}