1
//! Support for using `tor-error` with the `tracing` crate.
2

            
3
use crate::ErrorKind;
4
use std::sync::atomic::{AtomicU8, Ordering};
5

            
6
#[doc(hidden)]
7
pub use static_assertions;
8
#[doc(hidden)]
9
pub use tracing::{Level, event};
10

            
11
use paste::paste;
12

            
13
/// Runtime policy for handling protocol warnings.
14
#[derive(Copy, Clone, Debug, Eq, PartialEq)]
15
#[repr(u8)]
16
#[non_exhaustive]
17
pub enum ProtocolWarningMode {
18
    /// Do not promote protocol-violation reports based on runtime policy.
19
    Off = 0,
20
    /// Promote protocol-violation reports to warning level.
21
    Warn = 1,
22
}
23

            
24
impl ProtocolWarningMode {
25
    /// Convert an integer (raw bytes) to a protocol-warning mode (enum).
26
10184
    fn from_raw(raw: u8) -> Option<Self> {
27
10184
        match raw {
28
10176
            0 => Some(Self::Off),
29
6
            1 => Some(Self::Warn),
30
2
            _ => None,
31
        }
32
10184
    }
33
}
34

            
35
/// Global runtime state for protocol-warning behavior.
36
static PROTOCOL_WARNING_MODE: AtomicU8 = AtomicU8::new(ProtocolWarningMode::Off as u8);
37

            
38
/// Set runtime policy for protocol-warning log handling.
39
3178
pub fn set_protocol_warning_mode(mode: ProtocolWarningMode) {
40
3178
    PROTOCOL_WARNING_MODE.store(mode as u8, Ordering::Relaxed);
41
3178
}
42

            
43
/// Return current runtime policy for protocol-warning log handling.
44
10184
pub fn protocol_warning_mode() -> ProtocolWarningMode {
45
10184
    let raw = PROTOCOL_WARNING_MODE.load(Ordering::Relaxed);
46
10184
    ProtocolWarningMode::from_raw(raw).unwrap_or(ProtocolWarningMode::Off)
47
10184
}
48

            
49
/// Return true if the given [`ErrorKind`] is eligible for promotion to `WARN` by
50
/// [`event_report!`] and related macros.
51
///
52
/// This is true if [`ErrorKind::is_always_a_warning`] returns true, or if
53
/// `kind` is [`ErrorKind::TorProtocolViolation`] and the runtime
54
/// protocol-warning mode is set to [`ProtocolWarningMode::Warn`].
55
#[doc(hidden)]
56
#[inline]
57
336
pub fn __should_promote_to_warn(kind: ErrorKind) -> bool {
58
336
    kind.is_always_a_warning()
59
334
        || (protocol_warning_mode() == ProtocolWarningMode::Warn
60
4
            && kind == ErrorKind::TorProtocolViolation)
61
336
}
62

            
63
impl ErrorKind {
64
    /// Return true if this [`ErrorKind`] should always be logged as
65
    /// a warning (or more severe).
66
14932
    pub fn is_always_a_warning(&self) -> bool {
67
14932
        matches!(self, ErrorKind::Internal | ErrorKind::BadApiUsage)
68
14932
    }
69
}
70

            
71
/// Log a [`Report`](crate::Report) of a provided error at a given level, or a
72
/// higher level if appropriate.
73
///
74
/// If [`ErrorKind::is_always_a_warning`] returns true for the error's kind, or
75
/// if the runtime protocol-warning policy is active and the error's kind is
76
/// [`ErrorKind::TorProtocolViolation`], we log it at `WARN` when the requested
77
/// level is lower than `WARN`.
78
///
79
/// # Examples
80
///
81
/// ```
82
/// # // this is what implements HasKind in this crate.
83
/// # fn demo(err: &futures::task::SpawnError) {
84
/// # let num = 7;
85
/// use tor_error::event_report;
86
/// use tracing::Level;
87
///
88
/// event_report!(Level::DEBUG, err, "Couldn't chew gum while walking");
89
///
90
/// event_report!(Level::TRACE, err, attempt = %num, "Ephemeral error");
91
/// # }
92
/// ```
93
///
94
/// # Limitations
95
///
96
/// This macro does not support the full range of syntaxes supported by
97
/// [`tracing::event!`].
98
//
99
// NOTE: We need this fancy conditional here because tracing::event! insists on
100
// getting a const expression for its `Level`.  So we can do
101
// `if cond {debug!(..)} else {warn!(..)}`,
102
// but we can't do
103
// `event!(if cond {DEBUG} else {WARN}, ..)`.
104
#[macro_export]
105
macro_rules! event_report {
106
    ($level:expr, $err:expr) => {
107
        $crate::event_report!($level, $err,)
108
    };
109

            
110
    ($level:expr, $err:expr, $($arg:tt)*) => {
111
        {
112
            use $crate::{tracing as tr, HasKind as _, };
113
            let err = $err;
114
            let kind = err.kind();
115
            if tr::Level::WARN < $level && tr::__should_promote_to_warn(kind) {
116
                $crate::event_report!(@raw tr::Level::WARN, err, $($arg)*);
117
            } else {
118
                $crate::event_report!(@raw $level, err, $($arg)*);
119
            }
120
        }
121
    };
122

            
123
    (@raw $level:expr, $err:expr) => {
124
        $crate::event_report!(@raw $level, $err,)
125
    };
126

            
127
    (@raw $level:expr, $err:expr, $($arg:tt)*) => {
128
        {
129
            use $crate::tracing as tr;
130
            use ::std::ops::Deref as _;
131

            
132
            tr::event!(
133
                $level,
134
                // some types like `anyhow::Error` can deref to a `dyn Error`, and we cast as
135
                // `&dyn Error` so that it is handled as an error type by a tracing field
136
                // visitor (see `Visit::record_error()` from `tracing-core`)
137
                error = ((&($err)).deref() as &dyn std::error::Error),
138
                $($arg)*
139
            )
140
        }
141
    }
142
}
143

            
144
/// Define a macro `$level_report`
145
///
146
/// The title line for the doc comment will be
147
/// ``$title_1 `LEVEL` $title_2``
148
///
149
/// A standard body, containing a set of examples, will be provided.
150
///
151
/// You must pass a dollar sign for `D`, because there is no dollar escaping mechanism
152
/// for macro_rules macros in stable Rust (!)
153
macro_rules! define_report_macros { {
154
    # $title_1:tt
155
    LEVEL
156
    # $title_2:tt
157

            
158
    $D:tt
159
    $( [$($flag:tt)*] $level:ident )*
160
} => { $( paste!{
161
    # $title_1
162
    #[doc = concat!("`", stringify!( [< $level:upper >] ), "`")]
163
    # $title_2
164
    ///
165
    /// # Examples:
166
    ///
167
    /// ```
168
    /// # fn demo(err: &futures::task::SpawnError) {
169
    /// # let msg = ();
170
    #[doc = concat!("use tor_error::", stringify!($level), "_report;")]
171
    #[doc = concat!(stringify!($level), "_report!",
172
                    r#"(err, "Cheese exhausted (ephemeral)");"#)]
173
    #[doc = concat!(stringify!($level), "_report!",
174
                    r#"(err, "Unable to parse message {:?}", msg);"#)]
175
    /// # }
176
    /// ```
177
    #[macro_export]
178
    macro_rules! [< $level _report >] {
179
        ( $D err:expr ) => {
180
            // would be nice to do a `$D crate::[< $level _report >]!($D err,)` here,
181
            // but apparently this isn't allowed:
182
            // https://github.com/rust-lang/rust/pull/52234
183
            $D crate::event_report!($($flag)*
184
                                    $D crate::tracing::Level::[< $level:upper >],
185
                                    $D err)
186
        };
187

            
188
        ( $D err:expr, $D ($D rest:tt)* ) => {
189
            $D crate::event_report!($($flag)*
190
                                    $D crate::tracing::Level::[< $level:upper >],
191
                                    $D err, $D ($D rest)*)
192
        }
193
    }
194
} )* } }
195

            
196
define_report_macros! {
197
    /// Log a report for `err` at level
198
    LEVEL
199
    /// (or higher if it is a bug).
200

            
201
    $ [] trace
202
      [] debug
203
      [] info
204
}
205

            
206
define_report_macros! {
207
    /// Log a report for `err` at level
208
    LEVEL
209
    ///
210
    $ [@raw] warn
211
      [@raw] error
212
}
213

            
214
#[cfg(test)]
215
mod test {
216
    // @@ begin test lint list maintained by maint/add_warning @@
217
    #![allow(clippy::bool_assert_comparison)]
218
    #![allow(clippy::clone_on_copy)]
219
    #![allow(clippy::dbg_macro)]
220
    #![allow(clippy::mixed_attributes_style)]
221
    #![allow(clippy::print_stderr)]
222
    #![allow(clippy::print_stdout)]
223
    #![allow(clippy::single_char_pattern)]
224
    #![allow(clippy::unwrap_used)]
225
    #![allow(clippy::unchecked_time_subtraction)]
226
    #![allow(clippy::useless_vec)]
227
    #![allow(clippy::needless_pass_by_value)]
228
    //! <!-- @@ end test lint list maintained by maint/add_warning @@ -->
229

            
230
    use crate::internal;
231
    use crate::report::ErrorReport;
232
    use std::sync::Mutex;
233
    use thiserror::Error;
234
    use tracing_test::traced_test;
235

            
236
    static PROTOCOL_MODE_TEST_LOCK: Mutex<()> = Mutex::new(());
237

            
238
    #[test]
239
    fn protocol_warning_mode_roundtrip_and_fallback() {
240
        let _lock = PROTOCOL_MODE_TEST_LOCK.lock().expect("poisoned mutex");
241

            
242
        struct RestoreMode(super::ProtocolWarningMode);
243

            
244
        impl Drop for RestoreMode {
245
            fn drop(&mut self) {
246
                super::set_protocol_warning_mode(self.0);
247
            }
248
        }
249

            
250
        let original = super::protocol_warning_mode();
251
        let _restore = RestoreMode(original);
252

            
253
        super::set_protocol_warning_mode(super::ProtocolWarningMode::Off);
254
        assert_eq!(
255
            super::protocol_warning_mode(),
256
            super::ProtocolWarningMode::Off
257
        );
258

            
259
        super::set_protocol_warning_mode(super::ProtocolWarningMode::Warn);
260
        assert_eq!(
261
            super::protocol_warning_mode(),
262
            super::ProtocolWarningMode::Warn
263
        );
264

            
265
        super::PROTOCOL_WARNING_MODE.store(u8::MAX, std::sync::atomic::Ordering::Relaxed);
266
        assert_eq!(
267
            super::protocol_warning_mode(),
268
            super::ProtocolWarningMode::Off
269
        );
270
    }
271

            
272
    #[derive(Debug)]
273
    struct KindError(super::ErrorKind);
274

            
275
    impl std::fmt::Display for KindError {
276
        fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
277
            write!(f, "kind error")
278
        }
279
    }
280

            
281
    impl std::error::Error for KindError {}
282

            
283
    impl crate::HasKind for KindError {
284
        fn kind(&self) -> super::ErrorKind {
285
            self.0
286
        }
287
    }
288

            
289
    #[test]
290
    #[traced_test]
291
    #[allow(clippy::cognitive_complexity)]
292
    fn event_report_protocol_warning_policy() {
293
        let _lock = PROTOCOL_MODE_TEST_LOCK.lock().expect("poisoned mutex");
294

            
295
        struct RestoreMode(super::ProtocolWarningMode);
296

            
297
        impl Drop for RestoreMode {
298
            fn drop(&mut self) {
299
                super::set_protocol_warning_mode(self.0);
300
            }
301
        }
302

            
303
        let original = super::protocol_warning_mode();
304
        let _restore = RestoreMode(original);
305

            
306
        let msg_off = "torproto-off-debug";
307
        super::set_protocol_warning_mode(super::ProtocolWarningMode::Off);
308
        let err = KindError(super::ErrorKind::TorProtocolViolation);
309
        debug_report!(err, "{msg_off}");
310

            
311
        let msg_warn = "torproto-warn-promoted";
312
        super::set_protocol_warning_mode(super::ProtocolWarningMode::Warn);
313
        let err = KindError(super::ErrorKind::TorProtocolViolation);
314
        debug_report!(err, "{msg_warn}");
315

            
316
        let msg_internal = "internal-always-warn";
317
        super::set_protocol_warning_mode(super::ProtocolWarningMode::Off);
318
        let err = KindError(super::ErrorKind::Internal);
319
        debug_report!(err, "{msg_internal}");
320

            
321
        let msg_other = "other-kind-stays-debug";
322
        super::set_protocol_warning_mode(super::ProtocolWarningMode::Warn);
323
        let err = KindError(super::ErrorKind::TorDirectoryUnusable);
324
        debug_report!(err, "{msg_other}");
325

            
326
        logs_assert(|lines: &[&str]| {
327
            let level_for = |needle: &str| {
328
                lines
329
                    .iter()
330
                    .find(|line| line.contains(needle))
331
                    .ok_or_else(|| format!("missing log line containing '{needle}'"))
332
                    .and_then(|line| {
333
                        line.split_whitespace()
334
                            .find(|tok| {
335
                                matches!(*tok, "TRACE" | "DEBUG" | "INFO" | "WARN" | "ERROR")
336
                            })
337
                            .ok_or_else(|| format!("could not parse level from line: {line}"))
338
                    })
339
            };
340

            
341
            let msg_off_level = level_for(msg_off)?;
342
            if msg_off_level != "DEBUG" {
343
                return Err(format!(
344
                    "expected DEBUG for '{msg_off}', got {msg_off_level}"
345
                ));
346
            }
347

            
348
            let msg_warn_level = level_for(msg_warn)?;
349
            if msg_warn_level != "WARN" {
350
                return Err(format!(
351
                    "expected WARN for '{msg_warn}', got {msg_warn_level}"
352
                ));
353
            }
354

            
355
            let msg_internal_level = level_for(msg_internal)?;
356
            if msg_internal_level != "WARN" {
357
                return Err(format!(
358
                    "expected WARN for '{msg_internal}', got {msg_internal_level}"
359
                ));
360
            }
361

            
362
            let msg_other_level = level_for(msg_other)?;
363
            if msg_other_level != "DEBUG" {
364
                return Err(format!(
365
                    "expected DEBUG for '{msg_other}', got {msg_other_level}"
366
                ));
367
            }
368

            
369
            Ok(())
370
        });
371
    }
372

            
373
    #[derive(Error, Debug)]
374
    #[error("my error")]
375
    struct MyError;
376

            
377
    #[test]
378
    #[traced_test]
379
    // i really don't think that this test is too complicated
380
    #[allow(clippy::cognitive_complexity)]
381
    fn warn_report() {
382
        let me = MyError;
383
        let _ = me.report();
384
        warn_report!(me, "reporting unwrapped");
385

            
386
        let ae = anyhow::Error::from(me).context("context");
387
        let _ = ae.report();
388
        warn_report!(ae, "reporting anyhow");
389

            
390
        let ie = internal!("Foo was not initialized");
391
        let _ = ie.report();
392
        warn_report!(ie);
393
    }
394
}