From 0973f2536600168624094eb5eb2176f4da7e6bb3 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Sat, 24 Oct 2020 13:45:39 -0700 Subject: [PATCH] make the compact formatter not be useless Signed-off-by: Eliza Weisman --- examples/examples/fmt-compact.rs | 22 ++ tracing-subscriber/src/fmt/format/mod.rs | 268 ++++++++++------------- tracing-subscriber/src/fmt/mod.rs | 26 +++ 3 files changed, 162 insertions(+), 154 deletions(-) create mode 100644 examples/examples/fmt-compact.rs diff --git a/examples/examples/fmt-compact.rs b/examples/examples/fmt-compact.rs new file mode 100644 index 0000000000..a4899ce379 --- /dev/null +++ b/examples/examples/fmt-compact.rs @@ -0,0 +1,22 @@ +#![deny(rust_2018_idioms)] +#[path = "fmt/yak_shave.rs"] +mod yak_shave; + +fn main() { + tracing_subscriber::fmt() + .compact() + // enable everything + .with_max_level(tracing::Level::TRACE) + // sets this to be the default, global collector for this application. + .init(); + + let number_of_yaks = 3; + // this creates a new event, outside of any spans. + tracing::info!(number_of_yaks, "preparing to shave yaks"); + + let number_shaved = yak_shave::shave_all(number_of_yaks); + tracing::info!( + all_yaks_shaved = number_shaved == number_of_yaks, + "yak shaving completed" + ); +} diff --git a/tracing-subscriber/src/fmt/format/mod.rs b/tracing-subscriber/src/fmt/format/mod.rs index ee0335e61e..e052461c3e 100644 --- a/tracing-subscriber/src/fmt/format/mod.rs +++ b/tracing-subscriber/src/fmt/format/mod.rs @@ -10,6 +10,7 @@ use crate::{ use std::{ fmt::{self, Write}, iter, + marker::PhantomData, }; use tracing_core::{ field::{self, Field, Visit}, @@ -213,7 +214,7 @@ impl Format { format: Compact, timer: self.timer, ansi: self.ansi, - display_target: self.display_target, + display_target: false, display_level: self.display_level, display_thread_id: self.display_thread_id, display_thread_name: self.display_thread_name, @@ -347,6 +348,27 @@ impl Format { ..self } } + + fn format_level(&self, level: &Level, writer: &mut dyn fmt::Write) -> fmt::Result + where + F: LevelNames, + { + if self.display_level { + let fmt_level = { + #[cfg(feature = "ansi")] + { + F::format_level(level, self.ansi) + } + #[cfg(not(feature = "ansi"))] + { + F::format_level(level) + } + }; + return write!(writer, "{} ", fmt_level); + } + + Ok(()) + } } #[cfg(feature = "json")] @@ -413,19 +435,7 @@ where #[cfg(not(feature = "ansi"))] time::write(&self.timer, writer)?; - if self.display_level { - let fmt_level = { - #[cfg(feature = "ansi")] - { - FmtLevel::new(meta.level(), self.ansi) - } - #[cfg(not(feature = "ansi"))] - { - FmtLevel::new(meta.level()) - } - }; - write!(writer, "{} ", fmt_level)?; - } + self.format_level(meta.level(), writer)?; if self.display_thread_name { let current_thread = std::thread::current(); @@ -488,19 +498,7 @@ where #[cfg(not(feature = "ansi"))] time::write(&self.timer, writer)?; - if self.display_level { - let fmt_level = { - #[cfg(feature = "ansi")] - { - FmtLevel::new(meta.level(), self.ansi) - } - #[cfg(not(feature = "ansi"))] - { - FmtLevel::new(meta.level()) - } - }; - write!(writer, "{} ", fmt_level)?; - } + self.format_level(meta.level(), writer)?; if self.display_thread_name { let current_thread = std::thread::current(); @@ -520,27 +518,46 @@ where write!(writer, "{:0>2?} ", std::thread::current().id())?; } - let fmt_ctx = { - #[cfg(feature = "ansi")] - { - FmtCtx::new(&ctx, event.parent(), self.ansi) - } - #[cfg(not(feature = "ansi"))] - { - FmtCtx::new(&ctx, event.parent()) - } - }; - write!(writer, "{}", fmt_ctx)?; if self.display_target { - write!(writer, "{}:", meta.target())?; + let target = meta.target(); + #[cfg(feature = "ansi")] + let target = if self.ansi { + Style::new().bold().paint(target) + } else { + Style::new().paint(target) + }; + + write!(writer, "{}:", target)?; } + ctx.format_fields(writer, event)?; - let span = ctx.ctx.current_span(); - if let Some(id) = span.id() { - if let Some(span) = ctx.ctx.metadata(id) { - write!(writer, "{}", span.fields()).unwrap_or(()); + + let span = event + .parent() + .and_then(|id| ctx.ctx.span(&id)) + .or_else(|| ctx.ctx.lookup_current()); + + let scope = span.into_iter().flat_map(|span| { + let parents = span.parents(); + iter::once(span).chain(parents) + }); + #[cfg(feature = "ansi")] + let dimmed = if self.ansi { + Style::new().dimmed() + } else { + Style::new() + }; + for span in scope { + let exts = span.extensions(); + if let Some(fields) = exts.get::>() { + if !fields.is_empty() { + #[cfg(feature = "ansi")] + let fields = dimmed.paint(fields.as_str()); + write!(writer, " {}", fields)?; + } } } + writeln!(writer) } } @@ -693,74 +710,6 @@ impl<'a> fmt::Debug for DefaultVisitor<'a> { } } -struct FmtCtx<'a, S, N> { - ctx: &'a FmtContext<'a, S, N>, - span: Option<&'a span::Id>, - #[cfg(feature = "ansi")] - ansi: bool, -} - -impl<'a, S, N: 'a> FmtCtx<'a, S, N> -where - S: Collect + for<'lookup> LookupSpan<'lookup>, - N: for<'writer> FormatFields<'writer> + 'static, -{ - #[cfg(feature = "ansi")] - pub(crate) fn new( - ctx: &'a FmtContext<'_, S, N>, - span: Option<&'a span::Id>, - ansi: bool, - ) -> Self { - Self { ctx, ansi, span } - } - - #[cfg(not(feature = "ansi"))] - pub(crate) fn new(ctx: &'a FmtContext<'_, S, N>, span: Option<&'a span::Id>) -> Self { - Self { ctx, span } - } - - fn bold(&self) -> Style { - #[cfg(feature = "ansi")] - { - if self.ansi { - return Style::new().bold(); - } - } - - Style::new() - } -} - -impl<'a, S, N: 'a> fmt::Display for FmtCtx<'a, S, N> -where - S: Collect + for<'lookup> LookupSpan<'lookup>, - N: for<'writer> FormatFields<'writer> + 'static, -{ - fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { - let bold = self.bold(); - let mut seen = false; - - let span = self - .span - .and_then(|id| self.ctx.ctx.span(&id)) - .or_else(|| self.ctx.ctx.lookup_current()); - - let scope = span - .into_iter() - .flat_map(|span| span.from_root().chain(iter::once(span))); - - for span in scope { - seen = true; - write!(f, "{}:", bold.paint(span.metadata().name()))?; - } - - if seen { - f.write_char(' ')?; - } - Ok(()) - } -} - struct FullCtx<'a, S, N> where S: Collect + for<'lookup> LookupSpan<'lookup>, @@ -898,62 +847,73 @@ impl<'a> fmt::Display for FmtThreadName<'a> { } } -struct FmtLevel<'a> { - level: &'a Level, - #[cfg(feature = "ansi")] - ansi: bool, -} +trait LevelNames { + const TRACE_STR: &'static str; + const DEBUG_STR: &'static str; + const INFO_STR: &'static str; + const WARN_STR: &'static str; + const ERROR_STR: &'static str; -impl<'a> FmtLevel<'a> { #[cfg(feature = "ansi")] - pub(crate) fn new(level: &'a Level, ansi: bool) -> Self { - Self { level, ansi } + fn format_level<'a>(level: &'a Level, ansi: bool) -> FmtLevel<'a, Self> { + FmtLevel { + level, + ansi, + _f: PhantomData, + } } #[cfg(not(feature = "ansi"))] - pub(crate) fn new(level: &'a Level) -> Self { - Self { level } + fn format_level<'a>(level: &'a Level) -> FmtLevel<'a, Self> { + FmtLevel { + level, + ansi, + _f: PhantomData, + } } } -const TRACE_STR: &str = "TRACE"; -const DEBUG_STR: &str = "DEBUG"; -const INFO_STR: &str = " INFO"; -const WARN_STR: &str = " WARN"; -const ERROR_STR: &str = "ERROR"; +impl LevelNames for Full { + const TRACE_STR: &'static str = "TRACE"; + const DEBUG_STR: &'static str = "DEBUG"; + const INFO_STR: &'static str = " INFO"; + const WARN_STR: &'static str = " WARN"; + const ERROR_STR: &'static str = "ERROR"; +} +impl LevelNames for Compact { + const TRACE_STR: &'static str = "T"; + const DEBUG_STR: &'static str = "D"; + const INFO_STR: &'static str = "I"; + const WARN_STR: &'static str = "W"; + const ERROR_STR: &'static str = "!"; +} -#[cfg(not(feature = "ansi"))] -impl<'a> fmt::Display for FmtLevel<'a> { - fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { - match *self.level { - Level::TRACE => f.pad(TRACE_STR), - Level::DEBUG => f.pad(DEBUG_STR), - Level::INFO => f.pad(INFO_STR), - Level::WARN => f.pad(WARN_STR), - Level::ERROR => f.pad(ERROR_STR), - } - } +struct FmtLevel<'a, F: ?Sized> { + level: &'a Level, + #[cfg(feature = "ansi")] + ansi: bool, + _f: PhantomData, } -#[cfg(feature = "ansi")] -impl<'a> fmt::Display for FmtLevel<'a> { +impl<'a, F: LevelNames> fmt::Display for FmtLevel<'a, F> { fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + #[cfg(feature = "ansi")] if self.ansi { - match *self.level { - Level::TRACE => write!(f, "{}", Colour::Purple.paint(TRACE_STR)), - Level::DEBUG => write!(f, "{}", Colour::Blue.paint(DEBUG_STR)), - Level::INFO => write!(f, "{}", Colour::Green.paint(INFO_STR)), - Level::WARN => write!(f, "{}", Colour::Yellow.paint(WARN_STR)), - Level::ERROR => write!(f, "{}", Colour::Red.paint(ERROR_STR)), - } - } else { - match *self.level { - Level::TRACE => f.pad(TRACE_STR), - Level::DEBUG => f.pad(DEBUG_STR), - Level::INFO => f.pad(INFO_STR), - Level::WARN => f.pad(WARN_STR), - Level::ERROR => f.pad(ERROR_STR), - } + return match *self.level { + Level::TRACE => write!(f, "{}", Colour::Purple.paint(F::TRACE_STR)), + Level::DEBUG => write!(f, "{}", Colour::Blue.paint(F::DEBUG_STR)), + Level::INFO => write!(f, "{}", Colour::Green.paint(F::INFO_STR)), + Level::WARN => write!(f, "{}", Colour::Yellow.paint(F::WARN_STR)), + Level::ERROR => write!(f, "{}", Colour::Red.paint(F::ERROR_STR)), + }; + } + + match *self.level { + Level::TRACE => f.pad(F::TRACE_STR), + Level::DEBUG => f.pad(F::DEBUG_STR), + Level::INFO => f.pad(F::INFO_STR), + Level::WARN => f.pad(F::WARN_STR), + Level::ERROR => f.pad(F::ERROR_STR), } } } diff --git a/tracing-subscriber/src/fmt/mod.rs b/tracing-subscriber/src/fmt/mod.rs index cdb8531e0d..0934ffdba6 100644 --- a/tracing-subscriber/src/fmt/mod.rs +++ b/tracing-subscriber/src/fmt/mod.rs @@ -91,6 +91,32 @@ //! Oct 24 12:55:47.815 INFO fmt: yak shaving completed all_yaks_shaved=false //! //! +//! * [`format::Compact`]: A variant of the default formatter, optimized for +//! short line lengths. Fields from the current span context are appended to +//! the fields of the formatted event, and span names are not shown; the +//! verbosity level is abbreviated to a single character. +//! +//! For example: +//! 
    Finished dev [unoptimized + debuginfo] target(s) in 1.51s
+//!        Running `target/debug/examples/fmt-compact`
+//!   Oct 24 13:40:45.682 I preparing to shave yaks number_of_yaks=3
+//!   Oct 24 13:40:45.682 I shaving yaks yaks=3
+//!   Oct 24 13:40:45.683 T hello! I'm gonna shave a yak excitement="yay!" yak=1 yaks=3
+//!   Oct 24 13:40:45.683 T yak shaved successfully yak=1 yaks=3
+//!   Oct 24 13:40:45.683 D yak=1 shaved=true yaks=3
+//!   Oct 24 13:40:45.683 T yaks_shaved=1 yaks=3
+//!   Oct 24 13:40:45.683 T hello! I'm gonna shave a yak excitement="yay!" yak=2 yaks=3
+//!   Oct 24 13:40:45.683 T yak shaved successfully yak=2 yaks=3
+//!   Oct 24 13:40:45.683 D yak=2 shaved=true yaks=3
+//!   Oct 24 13:40:45.683 T yaks_shaved=2 yaks=3
+//!   Oct 24 13:40:45.683 T hello! I'm gonna shave a yak excitement="yay!" yak=3 yaks=3
+//!   Oct 24 13:40:45.683 W could not locate yak yak=3 yaks=3
+//!   Oct 24 13:40:45.683 D yak=3 shaved=false yaks=3
+//!   Oct 24 13:40:45.683 ! failed to shave yak yak=3 error=missing yak yaks=3
+//!   Oct 24 13:40:45.683 T yaks_shaved=2 yaks=3
+//!   Oct 24 13:40:45.683 I yak shaving completed all_yaks_shaved=false
+//!
+//! //! * [`format::Pretty`]: Emits excessively pretty, multi-line logs, optimized //! for human readability. This is primarily intended to be used in local //! development and debugging, or for command-line applications, where