//! Support for using `tor-error` with the `tracing` crate. use crate::ErrorKind; use std::sync::atomic::{AtomicU8, Ordering}; #[doc(hidden)] pub use static_assertions; #[doc(hidden)] pub use tracing::{Level, event}; use paste::paste; /// Runtime policy for handling protocol warnings. #[derive(Copy, Clone, Debug, Eq, PartialEq)] #[repr(u8)] #[non_exhaustive] pub enum ProtocolWarningMode { /// Do not promote protocol-violation reports based on runtime policy. Off = 0, /// Promote protocol-violation reports to warning level. Warn = 1, } impl ProtocolWarningMode { /// Convert an integer (raw bytes) to a protocol-warning mode (enum). fn from_raw(raw: u8) -> Option { match raw { 0 => Some(Self::Off), 1 => Some(Self::Warn), _ => None, } } } /// Global runtime state for protocol-warning behavior. static PROTOCOL_WARNING_MODE: AtomicU8 = AtomicU8::new(ProtocolWarningMode::Off as u8); /// Set runtime policy for protocol-warning log handling. pub fn set_protocol_warning_mode(mode: ProtocolWarningMode) { PROTOCOL_WARNING_MODE.store(mode as u8, Ordering::Relaxed); } /// Return current runtime policy for protocol-warning log handling. pub fn protocol_warning_mode() -> ProtocolWarningMode { let raw = PROTOCOL_WARNING_MODE.load(Ordering::Relaxed); ProtocolWarningMode::from_raw(raw).unwrap_or(ProtocolWarningMode::Off) } /// Return true if the given [`ErrorKind`] is eligible for promotion to `WARN` by /// [`event_report!`] and related macros. /// /// This is true if [`ErrorKind::is_always_a_warning`] returns true, or if /// `kind` is [`ErrorKind::TorProtocolViolation`] and the runtime /// protocol-warning mode is set to [`ProtocolWarningMode::Warn`]. #[doc(hidden)] #[inline] pub fn __should_promote_to_warn(kind: ErrorKind) -> bool { kind.is_always_a_warning() || (protocol_warning_mode() == ProtocolWarningMode::Warn && kind == ErrorKind::TorProtocolViolation) } impl ErrorKind { /// Return true if this [`ErrorKind`] should always be logged as /// a warning (or more severe). pub fn is_always_a_warning(&self) -> bool { matches!(self, ErrorKind::Internal | ErrorKind::BadApiUsage) } } /// Log a [`Report`](crate::Report) of a provided error at a given level, or a /// higher level if appropriate. /// /// If [`ErrorKind::is_always_a_warning`] returns true for the error's kind, or /// if the runtime protocol-warning policy is active and the error's kind is /// [`ErrorKind::TorProtocolViolation`], we log it at `WARN` when the requested /// level is lower than `WARN`. /// /// # Examples /// /// ``` /// # // this is what implements HasKind in this crate. /// # fn demo(err: &futures::task::SpawnError) { /// # let num = 7; /// use tor_error::event_report; /// use tracing::Level; /// /// event_report!(Level::DEBUG, err, "Couldn't chew gum while walking"); /// /// event_report!(Level::TRACE, err, attempt = %num, "Ephemeral error"); /// # } /// ``` /// /// # Limitations /// /// This macro does not support the full range of syntaxes supported by /// [`tracing::event!`]. // // NOTE: We need this fancy conditional here because tracing::event! insists on // getting a const expression for its `Level`. So we can do // `if cond {debug!(..)} else {warn!(..)}`, // but we can't do // `event!(if cond {DEBUG} else {WARN}, ..)`. #[macro_export] macro_rules! event_report { ($level:expr, $err:expr) => { $crate::event_report!($level, $err,) }; ($level:expr, $err:expr, $($arg:tt)*) => { { use $crate::{tracing as tr, HasKind as _, }; let err = $err; let kind = err.kind(); if tr::Level::WARN < $level && tr::__should_promote_to_warn(kind) { $crate::event_report!(@raw tr::Level::WARN, err, $($arg)*); } else { $crate::event_report!(@raw $level, err, $($arg)*); } } }; (@raw $level:expr, $err:expr) => { $crate::event_report!(@raw $level, $err,) }; (@raw $level:expr, $err:expr, $($arg:tt)*) => { { use $crate::tracing as tr; use ::std::ops::Deref as _; tr::event!( $level, // some types like `anyhow::Error` can deref to a `dyn Error`, and we cast as // `&dyn Error` so that it is handled as an error type by a tracing field // visitor (see `Visit::record_error()` from `tracing-core`) error = ((&($err)).deref() as &dyn std::error::Error), $($arg)* ) } } } /// Define a macro `$level_report` /// /// The title line for the doc comment will be /// ``$title_1 `LEVEL` $title_2`` /// /// A standard body, containing a set of examples, will be provided. /// /// You must pass a dollar sign for `D`, because there is no dollar escaping mechanism /// for macro_rules macros in stable Rust (!) macro_rules! define_report_macros { { # $title_1:tt LEVEL # $title_2:tt $D:tt $( [$($flag:tt)*] $level:ident )* } => { $( paste!{ # $title_1 #[doc = concat!("`", stringify!( [< $level:upper >] ), "`")] # $title_2 /// /// # Examples: /// /// ``` /// # fn demo(err: &futures::task::SpawnError) { /// # let msg = (); #[doc = concat!("use tor_error::", stringify!($level), "_report;")] #[doc = concat!(stringify!($level), "_report!", r#"(err, "Cheese exhausted (ephemeral)");"#)] #[doc = concat!(stringify!($level), "_report!", r#"(err, "Unable to parse message {:?}", msg);"#)] /// # } /// ``` #[macro_export] macro_rules! [< $level _report >] { ( $D err:expr ) => { // would be nice to do a `$D crate::[< $level _report >]!($D err,)` here, // but apparently this isn't allowed: // https://github.com/rust-lang/rust/pull/52234 $D crate::event_report!($($flag)* $D crate::tracing::Level::[< $level:upper >], $D err) }; ( $D err:expr, $D ($D rest:tt)* ) => { $D crate::event_report!($($flag)* $D crate::tracing::Level::[< $level:upper >], $D err, $D ($D rest)*) } } } )* } } define_report_macros! { /// Log a report for `err` at level LEVEL /// (or higher if it is a bug). $ [] trace [] debug [] info } define_report_macros! { /// Log a report for `err` at level LEVEL /// $ [@raw] warn [@raw] error } #[cfg(test)] mod test { // @@ begin test lint list maintained by maint/add_warning @@ #![allow(clippy::bool_assert_comparison)] #![allow(clippy::clone_on_copy)] #![allow(clippy::dbg_macro)] #![allow(clippy::mixed_attributes_style)] #![allow(clippy::print_stderr)] #![allow(clippy::print_stdout)] #![allow(clippy::single_char_pattern)] #![allow(clippy::unwrap_used)] #![allow(clippy::unchecked_time_subtraction)] #![allow(clippy::useless_vec)] #![allow(clippy::needless_pass_by_value)] #![allow(clippy::string_slice)] // See arti#2571 //! use crate::internal; use crate::report::ErrorReport; use std::sync::Mutex; use thiserror::Error; use tracing_test::traced_test; static PROTOCOL_MODE_TEST_LOCK: Mutex<()> = Mutex::new(()); #[test] fn protocol_warning_mode_roundtrip_and_fallback() { let _lock = PROTOCOL_MODE_TEST_LOCK.lock().expect("poisoned mutex"); struct RestoreMode(super::ProtocolWarningMode); impl Drop for RestoreMode { fn drop(&mut self) { super::set_protocol_warning_mode(self.0); } } let original = super::protocol_warning_mode(); let _restore = RestoreMode(original); super::set_protocol_warning_mode(super::ProtocolWarningMode::Off); assert_eq!( super::protocol_warning_mode(), super::ProtocolWarningMode::Off ); super::set_protocol_warning_mode(super::ProtocolWarningMode::Warn); assert_eq!( super::protocol_warning_mode(), super::ProtocolWarningMode::Warn ); super::PROTOCOL_WARNING_MODE.store(u8::MAX, std::sync::atomic::Ordering::Relaxed); assert_eq!( super::protocol_warning_mode(), super::ProtocolWarningMode::Off ); } #[derive(Debug)] struct KindError(super::ErrorKind); impl std::fmt::Display for KindError { fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { write!(f, "kind error") } } impl std::error::Error for KindError {} impl crate::HasKind for KindError { fn kind(&self) -> super::ErrorKind { self.0 } } #[test] #[traced_test] fn event_report_protocol_warning_policy() { let _lock = PROTOCOL_MODE_TEST_LOCK.lock().expect("poisoned mutex"); struct RestoreMode(super::ProtocolWarningMode); impl Drop for RestoreMode { fn drop(&mut self) { super::set_protocol_warning_mode(self.0); } } let original = super::protocol_warning_mode(); let _restore = RestoreMode(original); let msg_off = "torproto-off-debug"; super::set_protocol_warning_mode(super::ProtocolWarningMode::Off); let err = KindError(super::ErrorKind::TorProtocolViolation); debug_report!(err, "{msg_off}"); let msg_warn = "torproto-warn-promoted"; super::set_protocol_warning_mode(super::ProtocolWarningMode::Warn); let err = KindError(super::ErrorKind::TorProtocolViolation); debug_report!(err, "{msg_warn}"); let msg_internal = "internal-always-warn"; super::set_protocol_warning_mode(super::ProtocolWarningMode::Off); let err = KindError(super::ErrorKind::Internal); debug_report!(err, "{msg_internal}"); let msg_other = "other-kind-stays-debug"; super::set_protocol_warning_mode(super::ProtocolWarningMode::Warn); let err = KindError(super::ErrorKind::TorDirectoryUnusable); debug_report!(err, "{msg_other}"); logs_assert(|lines: &[&str]| { let level_for = |needle: &str| { lines .iter() .find(|line| line.contains(needle)) .ok_or_else(|| format!("missing log line containing '{needle}'")) .and_then(|line| { line.split_whitespace() .find(|tok| { matches!(*tok, "TRACE" | "DEBUG" | "INFO" | "WARN" | "ERROR") }) .ok_or_else(|| format!("could not parse level from line: {line}")) }) }; let msg_off_level = level_for(msg_off)?; if msg_off_level != "DEBUG" { return Err(format!( "expected DEBUG for '{msg_off}', got {msg_off_level}" )); } let msg_warn_level = level_for(msg_warn)?; if msg_warn_level != "WARN" { return Err(format!( "expected WARN for '{msg_warn}', got {msg_warn_level}" )); } let msg_internal_level = level_for(msg_internal)?; if msg_internal_level != "WARN" { return Err(format!( "expected WARN for '{msg_internal}', got {msg_internal_level}" )); } let msg_other_level = level_for(msg_other)?; if msg_other_level != "DEBUG" { return Err(format!( "expected DEBUG for '{msg_other}', got {msg_other_level}" )); } Ok(()) }); } #[derive(Error, Debug)] #[error("my error")] struct MyError; #[test] #[traced_test] fn warn_report() { let me = MyError; let _ = me.report(); warn_report!(me, "reporting unwrapped"); let ae = anyhow::Error::from(me).context("context"); let _ = ae.report(); warn_report!(ae, "reporting anyhow"); let ie = internal!("Foo was not initialized"); let _ = ie.report(); warn_report!(ie); } }