From d1430cd5cc3dc1b4fb9354f713381c6b63a1d7ca Mon Sep 17 00:00:00 2001 From: Wiktor Sikora Date: Sat, 5 Mar 2022 10:42:53 +0100 Subject: [PATCH 1/9] option to disable prefix of user-defined span fields --- tracing-journald/src/lib.rs | 32 ++++++++--- tracing-journald/tests/journal.rs | 91 ++++++++++++++++++++++++++++++- 2 files changed, 112 insertions(+), 11 deletions(-) diff --git a/tracing-journald/src/lib.rs b/tracing-journald/src/lib.rs index ef005ee47d..5b50a6424e 100644 --- a/tracing-journald/src/lib.rs +++ b/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, + span_field_prefix: Option, 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) -> 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); struct SpanVisitor<'a> { buf: &'a mut Vec, 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'_'); } } diff --git a/tracing-journald/tests/journal.rs b/tracing-journald/tests/journal.rs index 4094661a9c..dd073696c5 100644 --- a/tracing-journald/tests/journal.rs +++ 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 { } 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), Binary(Vec), } @@ -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> 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"]); + }); +} From 6a4f99cb3a08056f15c1851e3259906a6ab6a40e Mon Sep 17 00:00:00 2001 From: Wiktor Sikora Date: Wed, 9 Mar 2022 14:26:03 +0100 Subject: [PATCH 2/9] Apply suggestions from code review Co-authored-by: Eliza Weisman --- tracing-journald/src/lib.rs | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/tracing-journald/src/lib.rs b/tracing-journald/src/lib.rs index 5b50a6424e..580a42b508 100644 --- a/tracing-journald/src/lib.rs +++ b/tracing-journald/src/lib.rs @@ -74,7 +74,10 @@ 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. Prefixing user-defined span fields may be disabled. +/// that number. The prefix for user-defined span fields may be changed or disabled using the +/// [`with_span_field_prefix`] method. +/// +/// [`with_span_field_prefix`]: Subscriber::with_span_field_prefix /// /// User-defined fields other than the event `message` field have a prefix applied by default to /// prevent collision with standard fields. @@ -132,7 +135,9 @@ impl Subscriber { } /// Sets the prefix to apply to names of user-defined span fields. - /// Defaults to `Some("S")`. + /// + /// By default, this is `Some("S")`. Setting the span field prefix to + /// `None` will disable the prefix. pub fn with_span_field_prefix(mut self, x: Option) -> Self { self.span_field_prefix = x; self From cd3fac274f6acaff1eb220db8d9599774e6d7429 Mon Sep 17 00:00:00 2001 From: Wiktor Sikora Date: Wed, 9 Mar 2022 15:24:38 +0100 Subject: [PATCH 3/9] applied review suggestions, rustfmt --- tracing-journald/src/lib.rs | 13 +++++++++---- tracing-journald/tests/journal.rs | 12 +++++++----- 2 files changed, 16 insertions(+), 9 deletions(-) diff --git a/tracing-journald/src/lib.rs b/tracing-journald/src/lib.rs index 580a42b508..cfb2a70b55 100644 --- a/tracing-journald/src/lib.rs +++ b/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. The prefix for user-defined span fields may be changed or disabled using the +/// that number. The prefix for user-defined span fields may be changed or disabled using the /// [`with_span_field_prefix`] method. /// /// [`with_span_field_prefix`]: Subscriber::with_span_field_prefix @@ -138,6 +138,9 @@ impl Subscriber { /// /// 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 `_` 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) -> Self { self.span_field_prefix = x; self @@ -301,9 +304,11 @@ 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 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'_'); } } diff --git a/tracing-journald/tests/journal.rs b/tracing-journald/tests/journal.rs index dd073696c5..e1c45f247f 100644 --- a/tracing-journald/tests/journal.rs +++ b/tracing-journald/tests/journal.rs @@ -46,7 +46,7 @@ impl PartialEq<&str> for Field { match self { Field::Text(s) => s == other, Field::Binary(_) => false, - Field::Array(_) => false + Field::Array(_) => false, } } } @@ -56,7 +56,7 @@ impl PartialEq<[u8]> for Field { match self { Field::Text(s) => s.as_bytes() == other, Field::Binary(data) => data == other, - Field::Array(_) => false + Field::Array(_) => false, } } } @@ -66,7 +66,7 @@ impl PartialEq> for Field { match self { Field::Text(_) => false, Field::Binary(_) => false, - Field::Array(data) => data == other + Field::Array(data) => data == other, } } } @@ -228,7 +228,8 @@ fn span_metadata() { #[test] fn no_span_field_prefix() { - let sub = Subscriber::new().unwrap() + let sub = Subscriber::new() + .unwrap() .with_field_prefix(None) .with_span_field_prefix(None); with_journald_subscriber(sub, || { @@ -251,7 +252,8 @@ fn no_span_field_prefix() { #[test] fn spans_field_collision() { - let sub = Subscriber::new().unwrap() + let sub = Subscriber::new() + .unwrap() .with_field_prefix(None) .with_span_field_prefix(None); with_journald_subscriber(sub, || { From 3b8682fe20ab122eaa404b8583656da216765753 Mon Sep 17 00:00:00 2001 From: Wiktor Sikora Date: Sun, 13 Mar 2022 18:41:45 +0100 Subject: [PATCH 4/9] removed span fields prefix, additional tests --- tracing-journald/src/lib.rs | 57 +++---------------- tracing-journald/tests/journal.rs | 91 ++++++++++++++++++++----------- 2 files changed, 67 insertions(+), 81 deletions(-) diff --git a/tracing-journald/src/lib.rs b/tracing-journald/src/lib.rs index cfb2a70b55..4eb114a053 100644 --- a/tracing-journald/src/lib.rs +++ b/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, - span_field_prefix: Option, 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 `_` 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) -> 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,17 +214,13 @@ 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)); @@ -250,14 +228,11 @@ where fn on_record(&self, id: &Id, values: &Record, ctx: Context) { 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::().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); struct SpanVisitor<'a> { buf: &'a mut Vec, - 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, meta: &Metadata, span: Option) { - if span.is_none() { +fn put_metadata(buf: &mut Vec, meta: &Metadata, span: bool) { + if !span { put_field_wellformed( buf, "PRIORITY", @@ -383,20 +351,11 @@ fn put_metadata(buf: &mut Vec, meta: &Metadata, span: Option) { }, ); } - 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(); } diff --git a/tracing-journald/tests/journal.rs b/tracing-journald/tests/journal.rs index e1c45f247f..5631e45777 100644 --- a/tracing-journald/tests/journal.rs +++ b/tracing-journald/tests/journal.rs @@ -40,6 +40,23 @@ enum Field { Binary(Vec), } +impl Field { + pub fn as_array(&self) -> Option<&Vec> { + 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"]); }); } From e03049f7194a705fcb896da0a11bbfb703fc9ff1 Mon Sep 17 00:00:00 2001 From: Wiktor Sikora Date: Sun, 13 Mar 2022 19:46:29 +0100 Subject: [PATCH 5/9] applied review suggestions, rustfmt --- tracing-journald/src/lib.rs | 41 ++++++++++++++++++++----------- tracing-journald/tests/journal.rs | 21 +++++++++++----- 2 files changed, 41 insertions(+), 21 deletions(-) diff --git a/tracing-journald/src/lib.rs b/tracing-journald/src/lib.rs index 4eb114a053..9402f27143 100644 --- a/tracing-journald/src/lib.rs +++ b/tracing-journald/src/lib.rs @@ -216,7 +216,7 @@ where writeln!(buf, "SPAN_NAME").unwrap(); put_value(&mut buf, span.name().as_bytes()); - put_metadata(&mut buf, span.metadata(), true); + put_metadata(&mut buf, span.metadata(), Some("SPAN_")); attrs.record(&mut SpanVisitor { buf: &mut buf, @@ -251,7 +251,8 @@ where } // Record event fields - put_metadata(&mut buf, event.metadata(), false); + put_priority(&mut buf, event.metadata()); + put_metadata(&mut buf, event.metadata(), None); put_field_length_encoded(&mut buf, "SYSLOG_IDENTIFIER", |buf| { write!(buf, "{}", self.syslog_identifier).unwrap() }); @@ -337,25 +338,35 @@ impl Visit for EventVisitor<'_> { } } -fn put_metadata(buf: &mut Vec, meta: &Metadata, span: bool) { - if !span { - put_field_wellformed( - buf, - "PRIORITY", - match *meta.level() { - Level::ERROR => b"3", - Level::WARN => b"4", - Level::INFO => b"5", - Level::DEBUG => b"6", - Level::TRACE => b"7", - }, - ); +fn put_priority(buf: &mut Vec, meta: &Metadata) { + put_field_wellformed( + buf, + "PRIORITY", + match *meta.level() { + Level::ERROR => b"3", + Level::WARN => b"4", + Level::INFO => b"5", + Level::DEBUG => b"6", + Level::TRACE => b"7", + }, + ); +} + +fn put_metadata(buf: &mut Vec, meta: &Metadata, prefix: Option<&str>) { + if let Some(prefix) = prefix { + write!(buf, "{}", prefix).unwrap(); } put_field_wellformed(buf, "TARGET", meta.target().as_bytes()); if let Some(file) = meta.file() { + if let Some(prefix) = prefix { + write!(buf, "{}", prefix).unwrap(); + } put_field_wellformed(buf, "CODE_FILE", file.as_bytes()); } if let Some(line) = meta.line() { + if let Some(prefix) = prefix { + write!(buf, "{}", prefix).unwrap(); + } // Text format is safe as a line number can't possibly contain anything funny writeln!(buf, "CODE_LINE={}", line).unwrap(); } diff --git a/tracing-journald/tests/journal.rs b/tracing-journald/tests/journal.rs index 5631e45777..d9906b434d 100644 --- a/tracing-journald/tests/journal.rs +++ b/tracing-journald/tests/journal.rs @@ -41,7 +41,7 @@ enum Field { } impl Field { - pub fn as_array(&self) -> Option<&Vec> { + pub fn as_array(&self) -> Option<&[String]> { match self { Field::Text(_) => None, Field::Binary(_) => None, @@ -253,7 +253,10 @@ fn span_metadata() { assert_eq!(message["SPAN_NAME"].as_text(), Some("span1")); assert!(message["CODE_FILE"].as_text().is_some()); - assert_eq!(message["CODE_LINE"].as_array().unwrap().len(), 2); + assert!(message["CODE_LINE"].as_text().is_some()); + + assert!(message["SPAN_CODE_FILE"].as_text().is_some()); + assert!(message["SPAN_CODE_LINE"].as_text().is_some()); }); } @@ -276,20 +279,26 @@ fn multiple_spans_metadata() { assert_eq!(message["SPAN_NAME"], vec!["span1", "span2"]); assert!(message["CODE_FILE"].as_text().is_some()); - assert_eq!(message["CODE_LINE"].as_array().unwrap().len(), 3); + assert!(message["CODE_LINE"].as_text().is_some()); + + assert!(message["SPAN_CODE_FILE"].as_text().is_some()); + assert_eq!(message["SPAN_CODE_LINE"].as_array().unwrap().len(), 2); }); } #[test] fn spans_field_collision() { - let sub = Subscriber::new().unwrap().with_field_prefix(None); - with_journald_subscriber(sub, || { + with_journald(|| { 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", span_field = "foo3", "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"); From 94606c4514ab48dc8162b5f61835e7c81db0d809 Mon Sep 17 00:00:00 2001 From: Wiktor Sikora Date: Sun, 13 Mar 2022 20:26:06 +0100 Subject: [PATCH 6/9] tests fix --- tracing-journald/tests/journal.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tracing-journald/tests/journal.rs b/tracing-journald/tests/journal.rs index d9906b434d..cd7a6af0f0 100644 --- a/tracing-journald/tests/journal.rs +++ b/tracing-journald/tests/journal.rs @@ -281,7 +281,7 @@ fn multiple_spans_metadata() { assert!(message["CODE_FILE"].as_text().is_some()); assert!(message["CODE_LINE"].as_text().is_some()); - assert!(message["SPAN_CODE_FILE"].as_text().is_some()); + assert!(message.contains_key("SPAN_CODE_FILE")); assert_eq!(message["SPAN_CODE_LINE"].as_array().unwrap().len(), 2); }); } From 7f73917f9d0296a20e876eb8ec8d8f0d3b58c49b Mon Sep 17 00:00:00 2001 From: Wiktor Sikora Date: Mon, 14 Mar 2022 08:31:05 +0100 Subject: [PATCH 7/9] warning fix --- tracing-journald/tests/journal.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tracing-journald/tests/journal.rs b/tracing-journald/tests/journal.rs index cd7a6af0f0..94d91c4547 100644 --- a/tracing-journald/tests/journal.rs +++ b/tracing-journald/tests/journal.rs @@ -52,7 +52,7 @@ impl Field { match self { Field::Text(v) => Some(v.as_str()), Field::Binary(_) => None, - Field::Array(v) => None, + Field::Array(_) => None, } } } From 8de8a4ec4a587fb9809fa316d24c17c652cd422e Mon Sep 17 00:00:00 2001 From: Wiktor Sikora Date: Mon, 14 Mar 2022 18:43:13 +0100 Subject: [PATCH 8/9] Apply suggestions from code review Co-authored-by: Eliza Weisman --- tracing-journald/src/lib.rs | 3 ++- tracing-journald/tests/journal.rs | 1 + 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/tracing-journald/src/lib.rs b/tracing-journald/src/lib.rs index 9402f27143..a8d88a6e4b 100644 --- a/tracing-journald/src/lib.rs +++ b/tracing-journald/src/lib.rs @@ -73,7 +73,8 @@ mod socket; /// The standard journald `CODE_LINE` and `CODE_FILE` fields are automatically emitted. A `TARGET` /// field is emitted containing the event's target. /// -/// For events recorded inside spans additional `SPAN_NAME` field is emitted. +/// For events recorded inside spans, an additional `SPAN_NAME` field is emitted with the name of +/// each of the event's parent spans. /// /// User-defined fields other than the event `message` field have a prefix applied by default to /// prevent collision with standard fields. diff --git a/tracing-journald/tests/journal.rs b/tracing-journald/tests/journal.rs index 94d91c4547..46bde23b49 100644 --- a/tracing-journald/tests/journal.rs +++ b/tracing-journald/tests/journal.rs @@ -48,6 +48,7 @@ impl Field { Field::Array(v) => Some(v), } } + pub fn as_text(&self) -> Option<&str> { match self { Field::Text(v) => Some(v.as_str()), From c80691717f86dbc118ea1c4481d68f30a0c49db0 Mon Sep 17 00:00:00 2001 From: Wiktor Sikora Date: Tue, 15 Mar 2022 09:24:14 +0100 Subject: [PATCH 9/9] applied review suggestions --- tracing-journald/tests/journal.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/tracing-journald/tests/journal.rs b/tracing-journald/tests/journal.rs index 46bde23b49..dadb37aac3 100644 --- a/tracing-journald/tests/journal.rs +++ b/tracing-journald/tests/journal.rs @@ -41,15 +41,15 @@ enum Field { } impl Field { - pub fn as_array(&self) -> Option<&[String]> { + fn as_array(&self) -> Option<&[String]> { match self { Field::Text(_) => None, Field::Binary(_) => None, Field::Array(v) => Some(v), } } - - pub fn as_text(&self) -> Option<&str> { + + fn as_text(&self) -> Option<&str> { match self { Field::Text(v) => Some(v.as_str()), Field::Binary(_) => None,