From f9a3f17fbbf77c826f4a27d5d079846e4879c405 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Wed, 28 Apr 2021 15:15:21 -0700 Subject: [PATCH] tracing: add an example of `tracing` in a panic hook (#1375) It turns out that when using the global dispatcher, emitting tracing events in a panic hook will capture the span in which the program panicked. This is very handy for debugging panics! Thanks a lot to @nate_mara for pointing this out to me on twitter --- I hadn't even thought of it! Since it isn't necessarily immediately obvious that this works, I thought it would be nice to add an example. --- examples/examples/panic_hook.rs | 51 +++++++++++++++++++++++++++++++++ 1 file changed, 51 insertions(+) create mode 100644 examples/examples/panic_hook.rs diff --git a/examples/examples/panic_hook.rs b/examples/examples/panic_hook.rs new file mode 100644 index 00000000..4d24dadd --- /dev/null +++ b/examples/examples/panic_hook.rs @@ -0,0 +1,51 @@ +//! This example demonstrates how `tracing` events can be recorded from within a +//! panic hook, capturing the span context in which the program panicked. + +fn main() { + let subscriber = tracing_subscriber::fmt() + .with_max_level(tracing::Level::TRACE) + .finish(); + + // NOTE: Using `tracing` in a panic hook requires the use of the *global* + // trace dispatcher (`tracing::subscriber::set_global_default`), rather than + // the per-thread scoped dispatcher + // (`tracing::subscriber::with_default`/`set_default`). With the scoped trace + // dispatcher, the subscriber's thread-local context may already have been + // torn down by unwinding by the time the panic handler is reached. + tracing::subscriber::set_global_default(subscriber).unwrap(); + + // Set a panic hook that records the panic as a `tracing` event at the + // `ERROR` verbosity level. + // + // If we are currently in a span when the panic occurred, the logged event + // will include the current span, allowing the context in which the panic + // occurred to be recorded. + std::panic::set_hook(Box::new(|panic| { + // If the panic has a source location, record it as structured fields. + if let Some(location) = panic.location() { + // On nightly Rust, where the `PanicInfo` type also exposes a + // `message()` method returning just the message, we could record + // just the message instead of the entire `fmt::Display` + // implementation, avoiding the duplciated location + tracing::error!( + message = %panic, + panic.file = location.file(), + panic.line = location.line(), + panic.column = location.column(), + ); + } else { + tracing::error!(message = %panic); + } + })); + + for i in 0..10 { + check_number(i); + } +} + +#[tracing::instrument] +fn check_number(x: i32) { + if x % 2 == 0 { + panic!("I don't work with even numbers!"); + } +}