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

tracing-journald/src/lib.rs

@@ -37,6 +37,7 @@
     html_favicon_url = "https://raw.githubusercontent.com/tokio-rs/tracing/master/assets/favicon.ico",
     issue_tracker_base_url = "https://github.com/tokio-rs/tracing/issues/"
 )]
+
 #[cfg(unix)]
 use std::os::unix::net::UnixDatagram;
 use std::{fmt, io, io::Write};
@@ -69,15 +70,10 @@ mod socket;
 /// - `DEBUG` => Informational (6)
 /// - `TRACE` => Debug (7)
 ///
-/// Note that the naming scheme differs slightly for the latter half.
-///
 /// 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. The prefix for user-defined span fields may be changed or  disabled using the
-/// [`with_span_field_prefix`] method.
+/// field is emitted containing the event's target.
 ///
-/// [`with_span_field_prefix`]: Subscriber::with_span_field_prefix
+/// For events recorded inside spans additional `SPAN_NAME` field is emitted.
 ///
 /// User-defined fields other than the event `message` field have a prefix applied by default to
 /// prevent collision with standard fields.
@@ -87,7 +83,6 @@ pub struct Subscriber {
     #[cfg(unix)]
     socket: UnixDatagram,
     field_prefix: Option<String>,
-    span_field_prefix: Option<String>,
     syslog_identifier: String,
 }
 
@@ -106,7 +101,6 @@ 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()
@@ -134,18 +128,6 @@ impl Subscriber {
         self
     }
 
-    /// Sets the prefix to apply to names of user-defined span fields.
-    ///
-    /// By default, this is `Some("S")`. Setting the span field prefix to
-    /// `None` will disable the prefix.
-    /// When set to `Some` prefix will be build as `<span_field_prefix><SPAN_DEPTH>_` e.g. `S0_`.
-    /// NOTE: Span field prefix should satisfy requirements of journald field names.
-    /// Setting this for example to empty string `Some("")` may cause unexpected behaviour.
-    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()`
@@ -232,32 +214,25 @@ where
         let span = ctx.span(id).expect("unknown span");
         let mut buf = Vec::with_capacity(256);
 
-        let depth = span.scope().skip(1).count();
-
-        writeln!(buf, "S{}_NAME", depth).unwrap();
+        writeln!(buf, "SPAN_NAME").unwrap();
         put_value(&mut buf, span.name().as_bytes());
-        put_metadata(&mut buf, span.metadata(), Some(depth));
+        put_metadata(&mut buf, span.metadata(), true);
 
         attrs.record(&mut SpanVisitor {
             buf: &mut buf,
-            depth,
             field_prefix: self.field_prefix.as_deref(),
-            span_field_prefix: self.span_field_prefix.as_deref(),
         });
 
         span.extensions_mut().insert(SpanFields(buf));
     }
 
     fn on_record(&self, id: &Id, values: &Record, ctx: Context<C>) {
         let span = ctx.span(id).expect("unknown span");
-        let depth = span.scope().skip(1).count();
         let mut exts = span.extensions_mut();
         let buf = &mut exts.get_mut::<SpanFields>().expect("missing fields").0;
         values.record(&mut SpanVisitor {
             buf,
-            depth,
             field_prefix: self.field_prefix.as_deref(),
-            span_field_prefix: self.span_field_prefix.as_deref(),
         });
     }
 
@@ -276,7 +251,7 @@ where
         }
 
         // Record event fields
-        put_metadata(&mut buf, event.metadata(), None);
+        put_metadata(&mut buf, event.metadata(), false);
         put_field_length_encoded(&mut buf, "SYSLOG_IDENTIFIER", |buf| {
             write!(buf, "{}", self.syslog_identifier).unwrap()
         });
@@ -295,20 +270,13 @@ struct SpanFields(Vec<u8>);
 
 struct SpanVisitor<'a> {
     buf: &'a mut Vec<u8>,
-    depth: usize,
     field_prefix: Option<&'a str>,
-    span_field_prefix: Option<&'a str>,
 }
 
 impl SpanVisitor<'_> {
     fn put_span_prefix(&mut self) {
-        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());
-        }
-        if self.span_field_prefix.is_some() || self.field_prefix.is_some() {
             self.buf.push(b'_');
         }
     }
@@ -369,8 +337,8 @@ impl Visit for EventVisitor<'_> {
     }
 }
 
-fn put_metadata(buf: &mut Vec<u8>, meta: &Metadata, span: Option<usize>) {
-    if span.is_none() {
+fn put_metadata(buf: &mut Vec<u8>, meta: &Metadata, span: bool) {
+    if !span {
         put_field_wellformed(
             buf,
             "PRIORITY",
@@ -383,20 +351,11 @@ fn put_metadata(buf: &mut Vec<u8>, meta: &Metadata, span: Option<usize>) {
             },
         );
     }
-    if let Some(n) = span {
-        write!(buf, "S{}_", n).unwrap();
-    }
     put_field_wellformed(buf, "TARGET", meta.target().as_bytes());
     if let Some(file) = meta.file() {
-        if let Some(n) = span {
-            write!(buf, "S{}_", n).unwrap();
-        }
         put_field_wellformed(buf, "CODE_FILE", file.as_bytes());
     }
     if let Some(line) = meta.line() {
-        if let Some(n) = span {
-            write!(buf, "S{}_", n).unwrap();
-        }
         // Text format is safe as a line number can't possibly contain anything funny
         writeln!(buf, "CODE_LINE={}", line).unwrap();
     }

tracing-journald/tests/journal.rs

@@ -40,6 +40,23 @@ enum Field {
     Binary(Vec<u8>),
 }
 
+impl Field {
+    pub fn as_array(&self) -> Option<&Vec<String>> {
+        match self {
+            Field::Text(_) => None,
+            Field::Binary(_) => None,
+            Field::Array(v) => Some(v),
+        }
+    }
+    pub fn as_text(&self) -> Option<&str> {
+        match self {
+            Field::Text(v) => Some(v.as_str()),
+            Field::Binary(_) => None,
+            Field::Array(v) => None,
+        }
+    }
+}
+
 // Convenience impls to compare fields against strings and bytes with assert_eq!
 impl PartialEq<&str> for Field {
     fn eq(&self, other: &&str) -> bool {
@@ -200,74 +217,84 @@ fn large_message() {
     });
 }
 
+#[test]
+fn simple_metadata() {
+    let sub = Subscriber::new()
+        .unwrap()
+        .with_field_prefix(None)
+        .with_syslog_identifier("test_ident".to_string());
+    with_journald_subscriber(sub, || {
+        info!(test.name = "simple_metadata", "Hello World");
+
+        let message = retry_read_one_line_from_journal("simple_metadata");
+        assert_eq!(message["MESSAGE"], "Hello World");
+        assert_eq!(message["PRIORITY"], "5");
+        assert_eq!(message["TARGET"], "journal");
+        assert_eq!(message["SYSLOG_IDENTIFIER"], "test_ident");
+        assert!(message["CODE_FILE"].as_text().is_some());
+        assert!(message["CODE_LINE"].as_text().is_some());
+    });
+}
+
 #[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["TARGET"], "journal");
 
-        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["SPAN_FIELD1"].as_text(), Some("foo1"));
+        assert_eq!(message["SPAN_NAME"].as_text(), Some("span1"));
 
-        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"));
+        assert!(message["CODE_FILE"].as_text().is_some());
+        assert_eq!(message["CODE_LINE"].as_array().unwrap().len(), 2);
     });
 }
 
 #[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");
+fn multiple_spans_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();
 
-        let message = retry_read_one_line_from_journal("no_span_prefix");
+        info!(test.name = "multiple_spans_metadata", "Hello World");
+
+        let message = retry_read_one_line_from_journal("multiple_spans_metadata");
         assert_eq!(message["MESSAGE"], "Hello World");
         assert_eq!(message["PRIORITY"], "5");
+        assert_eq!(message["TARGET"], "journal");
 
-        // 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_FIELD1"], vec!["foo1", "foo2"]);
+        assert_eq!(message["SPAN_NAME"], vec!["span1", "span2"]);
 
-        assert_eq!(message["SPAN_FIELD"], "foo");
+        assert!(message["CODE_FILE"].as_text().is_some());
+        assert_eq!(message["CODE_LINE"].as_array().unwrap().len(), 3);
     });
 }
 
 #[test]
 fn spans_field_collision() {
-    let sub = Subscriber::new()
-        .unwrap()
-        .with_field_prefix(None)
-        .with_span_field_prefix(None);
+    let sub = Subscriber::new().unwrap().with_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");
+        info!(test.name = "spans_field_collision", span_field = "foo3", "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_NAME"], vec!["span1", "span2"]);
 
-        assert_eq!(message["SPAN_FIELD"], vec!["foo1", "foo2"]);
+        assert_eq!(message["SPAN_FIELD"], vec!["foo1", "foo2", "foo3"]);
     });
 }