From 533e1f105d6c461b072646bdb1cfd76367f3b2ef Mon Sep 17 00:00:00 2001 From: Bryan Garza <1396101+bryangarza@users.noreply.github.com> Date: Sat, 30 Apr 2022 00:41:59 +0000 Subject: [PATCH] subscriber: write format_event errors to Writer, update SubscriberBuilder Update the error-handling logic when calling `format_event` to write the error message to the Writer. Only if that fails do we write to stderr. Define new method `SubscriberBuilder::with_silence_errors(bool)` so that a user may disable this behavior. Enabled by default. Add unit tests for both `silence_errors=true` and `false`. --- tracing-subscriber/src/fmt/fmt_layer.rs | 98 ++++++++++++++++++++++++- tracing-subscriber/src/fmt/mod.rs | 13 ++++ 2 files changed, 108 insertions(+), 3 deletions(-) diff --git a/tracing-subscriber/src/fmt/fmt_layer.rs b/tracing-subscriber/src/fmt/fmt_layer.rs index df546b078f..de626ca8e4 100644 --- a/tracing-subscriber/src/fmt/fmt_layer.rs +++ b/tracing-subscriber/src/fmt/fmt_layer.rs @@ -70,6 +70,7 @@ pub struct Layer< fmt_event: E, fmt_span: format::FmtSpanConfig, is_ansi: bool, + silence_errors: bool, _inner: PhantomData, } @@ -119,6 +120,7 @@ where fmt_span: self.fmt_span, make_writer: self.make_writer, is_ansi: self.is_ansi, + silence_errors: self.silence_errors, _inner: self._inner, } } @@ -148,6 +150,7 @@ where fmt_span: self.fmt_span, make_writer: self.make_writer, is_ansi: self.is_ansi, + silence_errors: self.silence_errors, _inner: self._inner, } } @@ -180,6 +183,7 @@ impl Layer { fmt_event: self.fmt_event, fmt_span: self.fmt_span, is_ansi: self.is_ansi, + silence_errors: self.silence_errors, make_writer, _inner: self._inner, } @@ -263,6 +267,7 @@ impl Layer { fmt_event: self.fmt_event, fmt_span: self.fmt_span, is_ansi: self.is_ansi, + silence_errors: self.silence_errors, make_writer: TestWriter::default(), _inner: self._inner, } @@ -278,6 +283,14 @@ impl Layer { } } + /// Whether to write errors to the Writer, or ignore them. + pub fn with_silence_errors(self, silence_errors: bool) -> Self { + Self { + silence_errors, + ..self + } + } + /// Updates the [`MakeWriter`] by applying a function to the existing [`MakeWriter`]. /// /// This sets the [`MakeWriter`] that the layer being built will use to write events. @@ -306,6 +319,7 @@ impl Layer { fmt_event: self.fmt_event, fmt_span: self.fmt_span, is_ansi: self.is_ansi, + silence_errors: self.silence_errors, make_writer: f(self.make_writer), _inner: self._inner, } @@ -337,6 +351,7 @@ where fmt_span: self.fmt_span, make_writer: self.make_writer, is_ansi: self.is_ansi, + silence_errors: self.silence_errors, _inner: self._inner, } } @@ -349,6 +364,7 @@ where fmt_span: self.fmt_span.without_time(), make_writer: self.make_writer, is_ansi: self.is_ansi, + silence_errors: self.silence_errors, _inner: self._inner, } } @@ -477,6 +493,7 @@ where fmt_span: self.fmt_span, make_writer: self.make_writer, is_ansi: self.is_ansi, + silence_errors: self.silence_errors, _inner: self._inner, } } @@ -491,6 +508,7 @@ where fmt_span: self.fmt_span, make_writer: self.make_writer, is_ansi: self.is_ansi, + silence_errors: self.silence_errors, _inner: self._inner, } } @@ -521,6 +539,7 @@ where make_writer: self.make_writer, // always disable ANSI escapes in JSON mode! is_ansi: false, + silence_errors: self.silence_errors, _inner: self._inner, } } @@ -587,6 +606,7 @@ impl Layer { fmt_span: self.fmt_span, make_writer: self.make_writer, is_ansi: self.is_ansi, + silence_errors: self.silence_errors, _inner: self._inner, } } @@ -617,6 +637,7 @@ impl Layer { fmt_span: self.fmt_span, make_writer: self.make_writer, is_ansi: self.is_ansi, + silence_errors: self.silence_errors, _inner: self._inner, } } @@ -630,6 +651,7 @@ impl Default for Layer { fmt_span: format::FmtSpanConfig::default(), make_writer: io::stdout, is_ansi: cfg!(feature = "ansi"), + silence_errors: false, _inner: PhantomData, } } @@ -749,6 +771,11 @@ where { fields.was_ansi = self.is_ansi; extensions.insert(fields); + } else { + eprintln!( + "[tracing-subscriber] Unable to format the following event, ignoring: {:?}", + attrs + ); } } @@ -895,9 +922,20 @@ where .is_ok() { let mut writer = self.make_writer.make_writer_for(event.metadata()); - let _ = io::Write::write_all(&mut writer, buf.as_bytes()); - } else { - eprintln!("[tracing-subscriber] Unable to format the following event: {:?}", event); + let res = io::Write::write_all(&mut writer, buf.as_bytes()); + if !self.silence_errors { + if let Err(e) = res { + eprintln!("Unable to write an event to the Writer for this Subscriber! Error: {}", e); + } + } + } else if !self.silence_errors { + let err_msg = format!("Unable to format the following event. Name: {}; Fields: {:?}", + event.metadata().name(), event.fields()); + let mut writer = self.make_writer.make_writer_for(event.metadata()); + let res = io::Write::write_all(&mut writer, err_msg.as_bytes()); + if let Err(e) = res { + eprintln!("Unable to write an \"event formatting error\" to the Writer for this Subscriber! Error: {}", e); + } } buf.clear(); @@ -1194,6 +1232,60 @@ mod test { re.replace_all(s.as_str(), "timing").to_string() } + #[test] + fn format_error_print_to_stderr() { + struct AlwaysError; + + impl std::fmt::Debug for AlwaysError { + fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result { + Err(std::fmt::Error) + } + } + + let make_writer = MockMakeWriter::default(); + let subscriber = crate::fmt::Subscriber::builder() + .with_writer(make_writer.clone()) + .with_level(false) + .with_ansi(false) + .with_timer(MockTime) + .finish(); + + with_default(subscriber, || { + tracing::info!(?AlwaysError); + }); + let actual = sanitize_timings(make_writer.get_string()); + + // Only assert the start because the line number and callsite may change. + let expected = "Unable to format the following event. Name: event tracing-subscriber/src/fmt/fmt_layer.rs:"; + assert!(actual.as_str().starts_with(expected)); + } + + #[test] + fn format_error_ignore_if_silence_errors_is_true() { + struct AlwaysError; + + impl std::fmt::Debug for AlwaysError { + fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result { + Err(std::fmt::Error) + } + } + + let make_writer = MockMakeWriter::default(); + let subscriber = crate::fmt::Subscriber::builder() + .with_writer(make_writer.clone()) + .with_level(false) + .with_ansi(false) + .with_timer(MockTime) + .with_silence_errors(true) + .finish(); + + with_default(subscriber, || { + tracing::info!(?AlwaysError); + }); + let actual = sanitize_timings(make_writer.get_string()); + assert_eq!("", actual.as_str()); + } + #[test] fn synthesize_span_none() { let make_writer = MockMakeWriter::default(); diff --git a/tracing-subscriber/src/fmt/mod.rs b/tracing-subscriber/src/fmt/mod.rs index eb2e7a252f..1c6a3d315b 100644 --- a/tracing-subscriber/src/fmt/mod.rs +++ b/tracing-subscriber/src/fmt/mod.rs @@ -615,6 +615,19 @@ where } } + /// Whether to write errors to the Writer, or ignore them. + /// + /// An error in this case refers to errors which may occur within the + /// Subscriber implementation itself, or in code that it depends on. + /// + /// It does not refer to traces set to the level of Error. + pub fn with_silence_errors(self, silence_errors: bool) -> SubscriberBuilder, F, W> { + SubscriberBuilder { + inner: self.inner.with_silence_errors(silence_errors), + ..self + } + } + /// Sets whether or not an event's target is displayed. pub fn with_target( self,