diff --git a/examples/README.md b/examples/README.md index d415bd76..96c1ac8a 100644 --- a/examples/README.md +++ b/examples/README.md @@ -26,6 +26,8 @@ This directory contains a collection of examples that demonstrate the use of the events. + `fmt-multiple-writers.rs`: demonstrates how `fmt::Layer` can write to multiple destinations (in this instance, stdout and a file) simultaneously. + + `fmt-source-locations.rs`: demonstrates displaying source code locations + with `fmt::Layer`. + `subscriber-filter`: Demonstrates the `tracing-subscriber::filter` module, which provides a layer which adds configurable filtering to a subscriber implementation. diff --git a/examples/examples/fmt-source-locations.rs b/examples/examples/fmt-source-locations.rs new file mode 100644 index 00000000..799ebb17 --- /dev/null +++ b/examples/examples/fmt-source-locations.rs @@ -0,0 +1,29 @@ +//! Demonstrates displaying events' source code locations with the `fmt` +//! subscriber. +#![deny(rust_2018_idioms)] +#[path = "fmt/yak_shave.rs"] +mod yak_shave; + +fn main() { + tracing_subscriber::fmt() + // enable everything + .with_max_level(tracing::Level::TRACE) + // display source code file paths + .with_file(true) + // display source code line numbers + .with_line_number(true) + // disable targets + .with_target(false) + // 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/fmt_layer.rs b/tracing-subscriber/src/fmt/fmt_layer.rs index 50eed20d..c2708e28 100644 --- a/tracing-subscriber/src/fmt/fmt_layer.rs +++ b/tracing-subscriber/src/fmt/fmt_layer.rs @@ -299,6 +299,30 @@ where ..self } } + /// Sets whether or not an event's [source code file path][file] is + /// displayed. + /// + /// [file]: tracing_core::Metadata::file + pub fn with_file(self, display_filename: bool) -> Layer, W> { + Layer { + fmt_event: self.fmt_event.with_file(display_filename), + ..self + } + } + + /// Sets whether or not an event's [source code line number][line] is + /// displayed. + /// + /// [line]: tracing_core::Metadata::line + pub fn with_line_number( + self, + display_line_number: bool, + ) -> Layer, W> { + Layer { + fmt_event: self.fmt_event.with_line_number(display_line_number), + ..self + } + } /// Sets whether or not an event's level is displayed. pub fn with_level(self, display_level: bool) -> Layer, W> { diff --git a/tracing-subscriber/src/fmt/format/json.rs b/tracing-subscriber/src/fmt/format/json.rs index cc86f03c..5eac440a 100644 --- a/tracing-subscriber/src/fmt/format/json.rs +++ b/tracing-subscriber/src/fmt/format/json.rs @@ -243,6 +243,18 @@ where serializer.serialize_entry("target", meta.target())?; } + if self.display_filename { + if let Some(filename) = meta.file() { + serializer.serialize_entry("filename", filename)?; + } + } + + if self.display_line_number { + if let Some(line_number) = meta.line() { + serializer.serialize_entry("line_number", &line_number)?; + } + } + if self.format.display_current_span { if let Some(ref span) = current_span { serializer @@ -488,6 +500,7 @@ mod test { use tracing::{self, subscriber::with_default}; use std::fmt; + use std::path::Path; struct MockTime; impl FormatTime for MockTime { @@ -515,6 +528,50 @@ mod test { }); } + #[test] + fn json_filename() { + let current_path = Path::new("tracing-subscriber") + .join("src") + .join("fmt") + .join("format") + .join("json.rs") + .to_str() + .expect("path must be valid unicode") + // escape windows backslashes + .replace('\\', "\\\\"); + let expected = + &format!("{}{}{}", + "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":42,\"name\":\"json_span\",\"number\":3},\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3}],\"target\":\"tracing_subscriber::fmt::format::json::test\",\"filename\":\"", + current_path, + "\",\"fields\":{\"message\":\"some json test\"}}\n"); + let subscriber = subscriber() + .flatten_event(false) + .with_current_span(true) + .with_file(true) + .with_span_list(true); + test_json(expected, subscriber, || { + let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3); + let _guard = span.enter(); + tracing::info!("some json test"); + }); + } + + #[test] + fn json_line_number() { + let expected = + "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":42,\"name\":\"json_span\",\"number\":3},\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3}],\"target\":\"tracing_subscriber::fmt::format::json::test\",\"line_number\":42,\"fields\":{\"message\":\"some json test\"}}\n"; + let subscriber = subscriber() + .flatten_event(false) + .with_current_span(true) + .with_line_number(true) + .with_span_list(true); + test_json_with_line_number(expected, subscriber, || { + let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3); + let _guard = span.enter(); + tracing::info!("some json test"); + }); + } + #[test] fn json_flattened_event() { let expected = @@ -747,4 +804,34 @@ mod test { serde_json::from_str(actual).unwrap() ); } + + fn test_json_with_line_number( + expected: &str, + builder: crate::fmt::SubscriberBuilder>, + producer: impl FnOnce() -> T, + ) { + let make_writer = MockMakeWriter::default(); + let subscriber = builder + .with_writer(make_writer.clone()) + .with_timer(MockTime) + .finish(); + + with_default(subscriber, producer); + + let buf = make_writer.buf(); + let actual = std::str::from_utf8(&buf[..]).unwrap(); + let mut expected = + serde_json::from_str::>(expected) + .unwrap(); + let expect_line_number = expected.remove("line_number").is_some(); + let mut actual: std::collections::HashMap<&str, serde_json::Value> = + serde_json::from_str(actual).unwrap(); + let line_number = actual.remove("line_number"); + if expect_line_number { + assert_eq!(line_number.map(|x| x.is_number()), Some(true)); + } else { + assert!(line_number.is_none()); + } + assert_eq!(actual, expected); + } } diff --git a/tracing-subscriber/src/fmt/format/mod.rs b/tracing-subscriber/src/fmt/format/mod.rs index 38485f3c..a3a1bded 100644 --- a/tracing-subscriber/src/fmt/format/mod.rs +++ b/tracing-subscriber/src/fmt/format/mod.rs @@ -325,6 +325,8 @@ pub struct Format { pub(crate) display_level: bool, pub(crate) display_thread_id: bool, pub(crate) display_thread_name: bool, + pub(crate) display_filename: bool, + pub(crate) display_line_number: bool, } // === impl Writer === @@ -501,6 +503,8 @@ impl Default for Format { display_level: true, display_thread_id: false, display_thread_name: false, + display_filename: false, + display_line_number: false, } } } @@ -519,6 +523,8 @@ impl Format { display_level: self.display_level, display_thread_id: self.display_thread_id, display_thread_name: self.display_thread_name, + display_filename: self.display_filename, + display_line_number: self.display_line_number, } } @@ -556,6 +562,8 @@ impl Format { display_level: self.display_level, display_thread_id: self.display_thread_id, display_thread_name: self.display_thread_name, + display_filename: true, + display_line_number: true, } } @@ -587,6 +595,8 @@ impl Format { display_level: self.display_level, display_thread_id: self.display_thread_id, display_thread_name: self.display_thread_name, + display_filename: self.display_filename, + display_line_number: self.display_line_number, } } @@ -614,6 +624,8 @@ impl Format { display_level: self.display_level, display_thread_id: self.display_thread_id, display_thread_name: self.display_thread_name, + display_filename: self.display_filename, + display_line_number: self.display_line_number, } } @@ -628,6 +640,8 @@ impl Format { display_level: self.display_level, display_thread_id: self.display_thread_id, display_thread_name: self.display_thread_name, + display_filename: self.display_filename, + display_line_number: self.display_line_number, } } @@ -677,6 +691,38 @@ impl Format { } } + /// Sets whether or not an event's [source code file path][file] is + /// displayed. + /// + /// [file]: tracing_core::Metadata::file + pub fn with_file(self, display_filename: bool) -> Format { + Format { + display_filename, + ..self + } + } + + /// Sets whether or not an event's [source code line number][line] is + /// displayed. + /// + /// [line]: tracing_core::Metadata::line + pub fn with_line_number(self, display_line_number: bool) -> Format { + Format { + display_line_number, + ..self + } + } + + /// Sets whether or not the source code location from which an event + /// originated is displayed. + /// + /// This is equivalent to calling [`Format::with_file`] and + /// [`Format::with_line_number`] with the same value. + pub fn with_source_location(self, display_location: bool) -> Self { + self.with_line_number(display_location) + .with_file(display_location) + } + #[inline] fn format_timestamp(&self, writer: &mut Writer<'_>) -> fmt::Result where @@ -852,6 +898,34 @@ where )?; } + let line_number = if self.display_line_number { + meta.line() + } else { + None + }; + + if self.display_filename { + if let Some(filename) = meta.file() { + write!( + writer, + "{}{}{}", + dimmed.paint(filename), + dimmed.paint(":"), + if line_number.is_some() { "" } else { " " } + )?; + } + } + + if let Some(line_number) = line_number { + write!( + writer, + "{}{}:{} ", + dimmed.prefix(), + line_number, + dimmed.suffix() + )?; + } + ctx.format_fields(writer.by_ref(), event)?; writeln!(writer) } @@ -930,18 +1004,45 @@ where }; write!(writer, "{}", fmt_ctx)?; + let bold = writer.bold(); + let dimmed = writer.dimmed(); + + let mut needs_space = false; if self.display_target { - write!( - writer, - "{}{} ", - writer.bold().paint(meta.target()), - writer.dimmed().paint(":") - )?; + write!(writer, "{}{}", bold.paint(meta.target()), dimmed.paint(":"))?; + needs_space = true; + } + + if self.display_filename { + if let Some(filename) = meta.file() { + if self.display_target { + writer.write_char(' ')?; + } + write!(writer, "{}{}", bold.paint(filename), dimmed.paint(":"))?; + needs_space = true; + } + } + + if self.display_line_number { + if let Some(line_number) = meta.line() { + write!( + writer, + "{}{}{}{}", + bold.prefix(), + line_number, + bold.suffix(), + dimmed.paint(":") + )?; + needs_space = true; + } + } + + if needs_space { + writer.write_char(' ')?; } ctx.format_fields(writer.by_ref(), event)?; - let dimmed = writer.dimmed(); for span in ctx .event_scope() .into_iter() @@ -1213,6 +1314,14 @@ impl Style { fn paint(&self, d: impl fmt::Display) -> impl fmt::Display { d } + + fn prefix(&self) -> impl fmt::Display { + "" + } + + fn suffix(&self) -> impl fmt::Display { + "" + } } struct FmtThreadName<'a> { @@ -1540,9 +1649,9 @@ pub(super) mod test { }; use super::*; - use std::fmt; use regex::Regex; + use std::{fmt, path::Path}; pub(crate) struct MockTime; impl FormatTime for MockTime { @@ -1612,6 +1721,99 @@ pub(super) mod test { run_test(subscriber, make_writer, expected); } + #[test] + fn with_line_number_and_file_name() { + let make_writer = MockMakeWriter::default(); + let subscriber = crate::fmt::Subscriber::builder() + .with_writer(make_writer.clone()) + .with_file(true) + .with_line_number(true) + .with_level(false) + .with_ansi(false) + .with_timer(MockTime); + + let expected = Regex::new(&format!( + "^fake time tracing_subscriber::fmt::format::test: {}:[0-9]+: hello\n$", + current_path() + // if we're on Windows, the path might contain backslashes, which + // have to be escpaed before compiling the regex. + .replace('\\', "\\\\") + )) + .unwrap(); + let _default = set_default(&subscriber.into()); + tracing::info!("hello"); + let res = make_writer.get_string(); + assert!(expected.is_match(&res)); + } + + #[test] + fn with_line_number() { + let make_writer = MockMakeWriter::default(); + let subscriber = crate::fmt::Subscriber::builder() + .with_writer(make_writer.clone()) + .with_line_number(true) + .with_level(false) + .with_ansi(false) + .with_timer(MockTime); + + let expected = + Regex::new("^fake time tracing_subscriber::fmt::format::test: [0-9]+: hello\n$") + .unwrap(); + let _default = set_default(&subscriber.into()); + tracing::info!("hello"); + let res = make_writer.get_string(); + assert!(expected.is_match(&res)); + } + + #[test] + fn with_filename() { + let make_writer = MockMakeWriter::default(); + let subscriber = crate::fmt::Subscriber::builder() + .with_writer(make_writer.clone()) + .with_file(true) + .with_level(false) + .with_ansi(false) + .with_timer(MockTime); + let expected = &format!( + "fake time tracing_subscriber::fmt::format::test: {}: hello\n", + current_path(), + ); + assert_info_hello(subscriber, make_writer, expected); + } + + #[test] + fn with_thread_ids() { + let make_writer = MockMakeWriter::default(); + let subscriber = crate::fmt::Subscriber::builder() + .with_writer(make_writer.clone()) + .with_thread_ids(true) + .with_ansi(false) + .with_timer(MockTime); + let expected = + "fake time INFO ThreadId(NUMERIC) tracing_subscriber::fmt::format::test: hello\n"; + + assert_info_hello_ignore_numeric(subscriber, make_writer, expected); + } + + #[test] + fn pretty_default() { + let make_writer = MockMakeWriter::default(); + let subscriber = crate::fmt::Subscriber::builder() + .pretty() + .with_writer(make_writer.clone()) + .with_ansi(false) + .with_timer(MockTime); + let expected = format!( + r#" fake time INFO tracing_subscriber::fmt::format::test: hello + at {}:NUMERIC + +"#, + file!() + ); + + assert_info_hello_ignore_numeric(subscriber, make_writer, &expected) + } + fn assert_info_hello(subscriber: impl Into, buf: MockMakeWriter, expected: &str) { let _default = set_default(&subscriber.into()); tracing::info!("hello"); @@ -1645,14 +1847,14 @@ pub(super) mod test { T: Send + Sync + 'static, { let make_writer = MockMakeWriter::default(); - let collector = builder + let subscriber = builder .with_writer(make_writer.clone()) .with_level(false) .with_ansi(false) .with_timer(MockTime) .finish(); - with_default(collector, || { + with_default(subscriber, || { let span1 = tracing::info_span!("span1", span = 1); let span2 = tracing::info_span!(parent: &span1, "span2", span = 2); tracing::info!(parent: &span2, "hello"); @@ -1869,4 +2071,16 @@ pub(super) mod test { assert!(!f.contains(FmtSpan::EXIT)); assert!(f.contains(FmtSpan::CLOSE)); } + + /// Returns the test's module path. + fn current_path() -> String { + Path::new("tracing-subscriber") + .join("src") + .join("fmt") + .join("format") + .join("mod.rs") + .to_str() + .expect("path must not contain invalid unicode") + .to_owned() + } } diff --git a/tracing-subscriber/src/fmt/format/pretty.rs b/tracing-subscriber/src/fmt/format/pretty.rs index d78cf888..d1c8ba95 100644 --- a/tracing-subscriber/src/fmt/format/pretty.rs +++ b/tracing-subscriber/src/fmt/format/pretty.rs @@ -76,6 +76,10 @@ impl Pretty { /// Sets whether the event's source code location is displayed. /// /// This defaults to `true`. + #[deprecated( + since = "0.3.6", + note = "all formatters now support configurable source locations. Use `Format::with_source_location` instead." + )] pub fn with_source_location(self, display_location: bool) -> Self { Self { display_location, @@ -84,17 +88,6 @@ impl Pretty { } } -impl Format { - /// Sets whether or not the source code location from which an event - /// originated is displayed. - /// - /// This defaults to `true`. - pub fn with_source_location(mut self, display_location: bool) -> Self { - self.format = self.format.with_source_location(display_location); - self - } -} - impl FormatEvent for Format where C: Subscriber + for<'a> LookupSpan<'a>, @@ -147,12 +140,37 @@ where }; write!( writer, - "{}{}{}: ", + "{}{}{}:", target_style.prefix(), meta.target(), target_style.infix(style) )?; } + let line_number = if self.display_line_number { + meta.line() + } else { + None + }; + + // If the file name is disabled, format the line number right after the + // target. Otherwise, if we also display the file, it'll go on a + // separate line. + if let (Some(line_number), false, true) = ( + line_number, + self.display_filename, + self.format.display_location, + ) { + write!( + writer, + "{}{}{}:", + style.prefix(), + line_number, + style.infix(style) + )?; + } + + writer.write_char(' ')?; + let mut v = PrettyVisitor::new(writer.by_ref(), true).with_style(style); event.record(&mut v); v.finish()?; @@ -164,20 +182,21 @@ where Style::new() }; let thread = self.display_thread_name || self.display_thread_id; - if let (true, Some(file), Some(line)) = - (self.format.display_location, meta.file(), meta.line()) - { - write!( - writer, - " {} {}:{}{}", - dimmed.paint("at"), - file, - line, - dimmed.paint(if thread { " " } else { "\n" }) - )?; + + if let (Some(file), true, true) = ( + meta.file(), + self.format.display_location, + self.display_filename, + ) { + write!(writer, " {} {}", dimmed.paint("at"), file,)?; + + if let Some(line) = line_number { + write!(writer, ":{}", line)?; + } + writer.write_char(if thread { ' ' } else { '\n' })?; } else if thread { write!(writer, " ")?; - } + }; if thread { write!(writer, "{} ", dimmed.paint("on"))?; diff --git a/tracing-subscriber/src/fmt/mod.rs b/tracing-subscriber/src/fmt/mod.rs index 5eca6527..09a67a0b 100644 --- a/tracing-subscriber/src/fmt/mod.rs +++ b/tracing-subscriber/src/fmt/mod.rs @@ -734,6 +734,34 @@ where } } + /// Sets whether or not an event's [source code file path][file] is + /// displayed. + /// + /// [file]: tracing_core::Metadata::file + pub fn with_file( + self, + display_filename: bool, + ) -> SubscriberBuilder, F, W> { + SubscriberBuilder { + inner: self.inner.with_file(display_filename), + ..self + } + } + + /// Sets whether or not an event's [source code line number][line] is + /// displayed. + /// + /// [line]: tracing_core::Metadata::line + pub fn with_line_number( + self, + display_line_number: bool, + ) -> SubscriberBuilder, F, W> { + SubscriberBuilder { + inner: self.inner.with_line_number(display_line_number), + ..self + } + } + /// Sets whether or not an event's level is displayed. pub fn with_level( self,