subscriber: add Pretty formatter (backports #1067) (#1080)

This backports PR #1067 to v0.1.x. Since this has already been approved
on master, I'm just going to go ahead and merge it when CI passes.

## Motivation

Currently, the `tracing_subscriber::fmt` module contains only
single-line event formatters. Some users have requested a
human-readable, pretty-printing event formatter optimized for
aesthetics.

## Solution

This branch adds a new `Pretty` formatter which uses an _excessively_
pretty output format. It's neither compact, single-line oriented, nor
easily machine-readable, but it looks _quite_ nice, in my opinion. This
is well suited for local development or potentially for user-facing logs
in a CLI application.

Additionally, I tried to improve the docs for the different formatters
currently provided, including example output. Check out [the Netlify
preview][1]!

[1]: https://deploy-preview-1067--tracing-rs.netlify.app/tracing_subscriber/fmt/index.html#formatters

Signed-off-by: Eliza Weisman <[email protected]>

Author: hawkw

examples/examples/fmt-json.rs

@@ -0,0 +1,21 @@
+#![deny(rust_2018_idioms)]
+#[path = "fmt/yak_shave.rs"]
+mod yak_shave;
+
+fn main() {
+    tracing_subscriber::fmt()
+        .json()
+        .with_max_level(tracing::Level::TRACE)
+        .with_current_span(false)
+        .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"
+    );
+}

examples/examples/fmt-pretty.rs

@@ -0,0 +1,23 @@
+#![deny(rust_2018_idioms)]
+#[path = "fmt/yak_shave.rs"]
+mod yak_shave;
+
+fn main() {
+    tracing_subscriber::fmt()
+        .pretty()
+        .with_thread_names(true)
+        // 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"
+    );
+}

examples/examples/fmt.rs

@@ -1,23 +1,20 @@
 #![deny(rust_2018_idioms)]
-use tracing::{info, Level};
-
 #[path = "fmt/yak_shave.rs"]
 mod yak_shave;
 
 fn main() {
     tracing_subscriber::fmt()
-        // all spans/events with a level higher than DEBUG (e.g, info, warn, etc.)
-        // will be written to stdout.
-        .with_max_level(Level::DEBUG)
-        // sets this to be the default, global subscriber for this application.
+        // 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.
-    info!(number_of_yaks, "preparing to shave yaks");
+    tracing::info!(number_of_yaks, "preparing to shave yaks");
 
     let number_shaved = yak_shave::shave_all(number_of_yaks);
-    info!(
+    tracing::info!(
         all_yaks_shaved = number_shaved == number_of_yaks,
         "yak shaving completed."
     );

examples/examples/fmt/yak_shave.rs

@@ -1,55 +1,55 @@
 use std::{error::Error, io};
-use tracing::{debug, error, info, span, warn, Level};
+use tracing::{debug, error, info, span, trace, warn, Level};
 
 // the `#[tracing::instrument]` attribute creates and enters a span
 // every time the instrumented function is called. The span is named after the
 // the function or method. Paramaters passed to the function are recorded as fields.
 #[tracing::instrument]
 pub fn shave(yak: usize) -> Result<(), Box<dyn Error + 'static>> {
-    // this creates an event at the DEBUG log level with two fields:
+    // this creates an event at the TRACE log level with two fields:
     // - `excitement`, with the key "excitement" and the value "yay!"
     // - `message`, with the key "message" and the value "hello! I'm gonna shave a yak."
     //
     // unlike other fields, `message`'s shorthand initialization is just the string itself.
-    debug!(excitement = "yay!", "hello! I'm gonna shave a yak.");
+    trace!(excitement = "yay!", "hello! I'm gonna shave a yak");
     if yak == 3 {
-        warn!("could not locate yak!");
+        warn!("could not locate yak");
         // note that this is intended to demonstrate `tracing`'s features, not idiomatic
         // error handling! in a library or application, you should consider returning
         // a dedicated `YakError`. libraries like snafu or thiserror make this easy.
-        return Err(io::Error::new(io::ErrorKind::Other, "shaving yak failed!").into());
+        return Err(io::Error::new(io::ErrorKind::Other, "missing yak").into());
     } else {
-        debug!("yak shaved successfully");
+        trace!("yak shaved successfully");
     }
     Ok(())
 }
 
 pub fn shave_all(yaks: usize) -> usize {
-    // Constructs a new span named "shaving_yaks" at the TRACE level,
+    // Constructs a new span named "shaving_yaks" at the INFO level,
     // and a field whose key is "yaks". This is equivalent to writing:
     //
-    // let span = span!(Level::TRACE, "shaving_yaks", yaks = yaks);
+    // let span = span!(Level::INFO, "shaving_yaks", yaks = yaks);
     //
     // local variables (`yaks`) can be used as field values
     // without an assignment, similar to struct initializers.
-    let span = span!(Level::TRACE, "shaving_yaks", yaks);
+    let span = span!(Level::INFO, "shaving_yaks", yaks);
     let _enter = span.enter();
 
     info!("shaving yaks");
 
     let mut yaks_shaved = 0;
     for yak in 1..=yaks {
         let res = shave(yak);
-        debug!(yak, shaved = res.is_ok());
+        debug!(target: "yak_events", yak, shaved = res.is_ok());
 
         if let Err(ref error) = res {
             // Like spans, events can also use the field initialization shorthand.
             // In this instance, `yak` is the field being initalized.
-            error!(yak, error = error.as_ref(), "failed to shave yak!");
+            error!(yak, error = error.as_ref(), "failed to shave yak");
         } else {
             yaks_shaved += 1;
         }
-        debug!(yaks_shaved);
+        trace!(yaks_shaved);
     }
 
     yaks_shaved

tracing-subscriber/src/fmt/fmt_layer.rs

@@ -367,6 +367,19 @@ where
         }
     }
 
+    /// Sets the layer being built to use an [excessively pretty, human-readable formatter](crate::fmt::format::Pretty).
+    #[cfg(feature = "ansi")]
+    #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
+    pub fn pretty(self) -> Layer<S, format::Pretty, format::Format<format::Pretty, T>, W> {
+        Layer {
+            fmt_event: self.fmt_event.pretty(),
+            fmt_fields: format::Pretty::default(),
+            fmt_span: self.fmt_span,
+            make_writer: self.make_writer,
+            _inner: self._inner,
+        }
+    }
+
     /// Sets the layer being built to use a [JSON formatter](../fmt/format/struct.Json.html).
     ///
     /// The full format includes fields from all entered spans.

tracing-subscriber/src/fmt/format/mod.rs

@@ -24,12 +24,18 @@ use ansi_term::{Colour, Style};
 
 #[cfg(feature = "json")]
 mod json;
-
-use fmt::{Debug, Display};
 #[cfg(feature = "json")]
 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
 pub use json::*;
 
+#[cfg(feature = "ansi")]
+mod pretty;
+#[cfg(feature = "ansi")]
+#[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
+pub use pretty::*;
+
+use fmt::{Debug, Display};
+
 /// A type that can format a tracing `Event` for a `fmt::Write`.
 ///
 /// `FormatEvent` is primarily used in the context of [`fmt::Subscriber`] or [`fmt::Layer`]. Each time an event is
@@ -214,6 +220,25 @@ impl<F, T> Format<F, T> {
         }
     }
 
+    /// Use an excessively pretty, human-readable output format.
+    ///
+    /// See [`Pretty`].
+    ///
+    /// Note that this requires the "ansi" feature to be enabled.
+    #[cfg(feature = "ansi")]
+    #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
+    pub fn pretty(self) -> Format<Pretty, T> {
+        Format {
+            format: Pretty::default(),
+            timer: self.timer,
+            ansi: self.ansi,
+            display_target: self.display_target,
+            display_level: self.display_level,
+            display_thread_id: self.display_thread_id,
+            display_thread_name: self.display_thread_name,
+        }
+    }
+
     /// Use the full JSON format.
     ///
     /// The full format includes fields from all entered spans.
@@ -521,6 +546,7 @@ where
 }
 
 // === impl FormatFields ===
+
 impl<'writer, M> FormatFields<'writer> for M
 where
     M: MakeOutput<&'writer mut dyn fmt::Write, fmt::Result>,
@@ -622,10 +648,7 @@ impl<'a> field::Visit for DefaultVisitor<'a> {
 
     fn record_error(&mut self, field: &Field, value: &(dyn std::error::Error + 'static)) {
         if let Some(source) = value.source() {
-            self.record_debug(
-                field,
-                &format_args!("{} {}.source={}", value, field, source),
-            )
+            self.record_debug(field, &format_args!("{}, {}: {}", value, field, source))
         } else {
             self.record_debug(field, &format_args!("{}", value))
         }