From d7a2e428160f0d3b1d013ccce0082fc85464fe28 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Mon, 29 Nov 2021 10:51:40 -0800 Subject: [PATCH 1/3] subscriber: fix missing event fields in `Compact` formatter The line of code that prints the event's fields (including its message) was accidentally deleted in 0a16972ba4a5da5b9fd6534b9674d3df88652029, while backporting PR #1696 from `master` (where the `Compact`) formatter implementation is significantly different. This branch puts it back. Fixes #1741 --- tracing-subscriber/src/fmt/format/mod.rs | 20 +++++++++++--------- 1 file changed, 11 insertions(+), 9 deletions(-) diff --git a/tracing-subscriber/src/fmt/format/mod.rs b/tracing-subscriber/src/fmt/format/mod.rs index 2f4ae6f6d6..ea97f0358d 100644 --- a/tracing-subscriber/src/fmt/format/mod.rs +++ b/tracing-subscriber/src/fmt/format/mod.rs @@ -906,15 +906,6 @@ where write!(writer, "{:0>2?} ", std::thread::current().id())?; } - if self.display_target { - write!( - writer, - "{}{}", - writer.bold().paint(meta.target()), - writer.dimmed().paint(":") - )?; - } - let fmt_ctx = { #[cfg(feature = "ansi")] { @@ -927,6 +918,17 @@ where }; write!(writer, "{}", fmt_ctx)?; + if self.display_target { + write!( + writer, + "{}{}", + writer.bold().paint(meta.target()), + writer.dimmed().paint(":") + )?; + } + + ctx.format_fields(writer.by_ref(), event)?; + let dimmed = writer.dimmed(); for span in ctx .event_scope() From 5dc6de01a267a042f5803c2f2b8cfcf9050dac6f Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Mon, 29 Nov 2021 11:18:58 -0800 Subject: [PATCH 2/3] missing whitespace after target Signed-off-by: Eliza Weisman --- tracing-subscriber/src/fmt/format/mod.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tracing-subscriber/src/fmt/format/mod.rs b/tracing-subscriber/src/fmt/format/mod.rs index ea97f0358d..47af71ac4d 100644 --- a/tracing-subscriber/src/fmt/format/mod.rs +++ b/tracing-subscriber/src/fmt/format/mod.rs @@ -921,7 +921,7 @@ where if self.display_target { write!( writer, - "{}{}", + "{}{} ", writer.bold().paint(meta.target()), writer.dimmed().paint(":") )?; From 0c85d9c807342667b65aed5f1f11fd3e9b697414 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Mon, 29 Nov 2021 12:34:32 -0800 Subject: [PATCH 3/3] subscriber: add tests for default formatter Signed-off-by: Eliza Weisman --- tracing-subscriber/src/fmt/format/mod.rs | 218 ++++++++++++++++------- 1 file changed, 154 insertions(+), 64 deletions(-) diff --git a/tracing-subscriber/src/fmt/format/mod.rs b/tracing-subscriber/src/fmt/format/mod.rs index 47af71ac4d..9001e102e0 100644 --- a/tracing-subscriber/src/fmt/format/mod.rs +++ b/tracing-subscriber/src/fmt/format/mod.rs @@ -1527,7 +1527,7 @@ pub(super) mod test { subscriber::with_default, }; - use super::{FmtSpan, TimingDisplay, Writer}; + use super::*; use std::fmt; pub(crate) struct MockTime; @@ -1553,64 +1553,60 @@ pub(super) mod test { run_test(subscriber, make_writer, "hello\n") } - #[cfg(feature = "ansi")] - #[test] - fn with_ansi_true() { - let expected = "\u{1b}[2mfake time\u{1b}[0m \u{1b}[32m INFO\u{1b}[0m \u{1b}[2mtracing_subscriber::fmt::format::test\u{1b}[0m\u{1b}[2m:\u{1b}[0m hello\n"; - test_ansi(true, expected); - } - - #[cfg(feature = "ansi")] - #[test] - fn with_ansi_false() { - let expected = "fake time INFO tracing_subscriber::fmt::format::test: hello\n"; - test_ansi(false, expected); + fn test_ansi( + is_ansi: bool, + expected: &str, + builder: crate::fmt::SubscriberBuilder>, + ) where + Format: FormatEvent, + T: Send + Sync + 'static, + { + let make_writer = MockMakeWriter::default(); + let subscriber = builder + .with_writer(make_writer.clone()) + .with_ansi(is_ansi) + .with_timer(MockTime); + run_test(subscriber, make_writer, expected) } #[cfg(not(feature = "ansi"))] - #[test] - fn without_ansi() { + fn test_without_ansi( + expected: &str, + builder: crate::fmt::SubscriberBuilder>, + ) where + Format: FormatEvent, + T: Send + Sync, + { let make_writer = MockMakeWriter::default(); - let expected = "fake time INFO tracing_subscriber::fmt::format::test: hello\n"; - let subscriber = crate::fmt::Subscriber::builder() - .with_writer(make_writer) - .with_timer(MockTime); - run_test(subscriber, make_writer, expected); + let subscriber = builder.with_writer(make_writer).with_timer(MockTime); + run_test(subscriber, make_writer, expected) } - #[test] - fn without_level() { + fn test_without_level( + expected: &str, + builder: crate::fmt::SubscriberBuilder>, + ) where + Format: FormatEvent, + T: Send + Sync + 'static, + { let make_writer = MockMakeWriter::default(); - let subscriber = crate::fmt::Subscriber::builder() + let subscriber = builder .with_writer(make_writer.clone()) .with_level(false) .with_ansi(false) .with_timer(MockTime); - let expected = "fake time tracing_subscriber::fmt::format::test: hello\n"; - run_test(subscriber, make_writer, expected); } - #[cfg(feature = "ansi")] - fn test_ansi(is_ansi: bool, expected: &str) { - let make_writer = MockMakeWriter::default(); - let subscriber = crate::fmt::Subscriber::builder() - .with_writer(make_writer.clone()) - .with_ansi(is_ansi) - .with_timer(MockTime); - run_test(subscriber, make_writer, expected) - } - - fn run_test(subscriber: impl Into, buf: MockMakeWriter, expected: &str) { - let _default = set_default(&subscriber.into()); - tracing::info!("hello"); - assert_eq!(expected, buf.get_string()) - } - - #[test] - fn overridden_parents() { + fn test_overridden_parents( + expected: &str, + builder: crate::fmt::SubscriberBuilder>, + ) where + Format: FormatEvent, + T: Send + Sync + 'static, + { let make_writer = MockMakeWriter::default(); - let collector = crate::fmt::Subscriber::builder() + let collector = builder .with_writer(make_writer.clone()) .with_level(false) .with_ansi(false) @@ -1618,20 +1614,23 @@ pub(super) mod test { .finish(); with_default(collector, || { - let span1 = tracing::info_span!("span1"); - let span2 = tracing::info_span!(parent: &span1, "span2"); + let span1 = tracing::info_span!("span1", span = 1); + let span2 = tracing::info_span!(parent: &span1, "span2", span = 2); tracing::info!(parent: &span2, "hello"); }); - assert_eq!( - "fake time span1:span2: tracing_subscriber::fmt::format::test: hello\n", - make_writer.get_string() - ); + assert_eq!(expected, make_writer.get_string()); } - #[test] - fn overridden_parents_in_scope() { + fn test_overridden_parents_in_scope( + expected1: &str, + expected2: &str, + builder: crate::fmt::SubscriberBuilder>, + ) where + Format: FormatEvent, + T: Send + Sync + 'static, + { let make_writer = MockMakeWriter::default(); - let subscriber = crate::fmt::Subscriber::builder() + let subscriber = builder .with_writer(make_writer.clone()) .with_level(false) .with_ansi(false) @@ -1639,25 +1638,116 @@ pub(super) mod test { .finish(); with_default(subscriber, || { - let span1 = tracing::info_span!("span1"); - let span2 = tracing::info_span!(parent: &span1, "span2"); - let span3 = tracing::info_span!("span3"); + let span1 = tracing::info_span!("span1", span = 1); + let span2 = tracing::info_span!(parent: &span1, "span2", span = 2); + let span3 = tracing::info_span!("span3", span = 3); let _e3 = span3.enter(); tracing::info!("hello"); - assert_eq!( - "fake time span3: tracing_subscriber::fmt::format::test: hello\n", - make_writer.get_string().as_str() - ); + assert_eq!(expected1, make_writer.get_string().as_str()); tracing::info!(parent: &span2, "hello"); - assert_eq!( - "fake time span1:span2: tracing_subscriber::fmt::format::test: hello\n", - make_writer.get_string().as_str() - ); + assert_eq!(expected2, make_writer.get_string().as_str()); }); } + fn run_test(subscriber: impl Into, buf: MockMakeWriter, expected: &str) { + let _default = set_default(&subscriber.into()); + tracing::info!("hello"); + assert_eq!(expected, buf.get_string()) + } + + mod default { + use super::*; + #[cfg(feature = "ansi")] + #[test] + fn with_ansi_true() { + let expected = "\u{1b}[2mfake time\u{1b}[0m \u{1b}[32m INFO\u{1b}[0m \u{1b}[2mtracing_subscriber::fmt::format::test\u{1b}[0m\u{1b}[2m:\u{1b}[0m hello\n"; + test_ansi(true, expected, crate::fmt::Subscriber::builder()); + } + + #[cfg(feature = "ansi")] + #[test] + fn with_ansi_false() { + let expected = "fake time INFO tracing_subscriber::fmt::format::test: hello\n"; + test_ansi(false, expected, crate::fmt::Subscriber::builder()); + } + + #[cfg(not(feature = "ansi"))] + #[test] + fn without_ansi() { + let expected = "fake time INFO tracing_subscriber::fmt::format::test: hello\n"; + test_without_ansi(expected, crate::fmt::Subscriber::builder()) + } + + #[test] + fn without_level() { + let expected = "fake time tracing_subscriber::fmt::format::test: hello\n"; + test_without_level(expected, crate::fmt::Subscriber::builder()) + } + + #[test] + fn overridden_parents() { + let expected = "fake time span1{span=1}:span2{span=2}: tracing_subscriber::fmt::format::test: hello\n"; + test_overridden_parents(expected, crate::fmt::Subscriber::builder()) + } + + #[test] + fn overridden_parents_in_scope() { + test_overridden_parents_in_scope( + "fake time span3{span=3}: tracing_subscriber::fmt::format::test: hello\n", + "fake time span1{span=1}:span2{span=2}: tracing_subscriber::fmt::format::test: hello\n", + crate::fmt::Subscriber::builder(), + ) + } + } + + mod compact { + use super::*; + + #[cfg(feature = "ansi")] + #[test] + fn with_ansi_true() { + let expected = "\u{1b}[2mfake time\u{1b}[0m \u{1b}[32m INFO\u{1b}[0m \u{1b}[1mtracing_subscriber::fmt::format::test\u{1b}[0m\u{1b}[2m:\u{1b}[0m hello\n"; + test_ansi(true, expected, crate::fmt::Subscriber::builder().compact()) + } + + #[cfg(feature = "ansi")] + #[test] + fn with_ansi_false() { + let expected = "fake time INFO tracing_subscriber::fmt::format::test: hello\n"; + test_ansi(false, expected, crate::fmt::Subscriber::builder().compact()); + } + + #[cfg(not(feature = "ansi"))] + #[test] + fn without_ansi() { + let expected = "fake time INFO tracing_subscriber::fmt::format::test: hello\n"; + test_without_ansi(expected, crate::fmt::Subscriber::builder().compact()) + } + + #[test] + fn without_level() { + let expected = "fake time tracing_subscriber::fmt::format::test: hello\n"; + test_without_level(expected, crate::fmt::Subscriber::builder().compact()); + } + + #[test] + fn overridden_parents() { + let expected = "fake time span1:span2: tracing_subscriber::fmt::format::test: hello span=1 span=2\n"; + test_overridden_parents(expected, crate::fmt::Subscriber::builder().compact()) + } + + #[test] + fn overridden_parents_in_scope() { + test_overridden_parents_in_scope( + "fake time span3: tracing_subscriber::fmt::format::test: hello span=3\n", + "fake time span1:span2: tracing_subscriber::fmt::format::test: hello span=1 span=2\n", + crate::fmt::Subscriber::builder().compact(), + ) + } + } + #[test] fn format_nanos() { fn fmt(t: u64) -> String {