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
15256
    fn from_raw(raw: u8) -> Option<Self> {
27
15256
        match raw {
28
15248
            0 => Some(Self::Off),
29
6
            1 => Some(Self::Warn),
30
2
            _ => None,
31
        }
32
15256
    }
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
3316
pub fn set_protocol_warning_mode(mode: ProtocolWarningMode) {
40
3316
    PROTOCOL_WARNING_MODE.store(mode as u8, Ordering::Relaxed);
41
3316
}
42

            
43
/// Return current runtime policy for protocol-warning log handling.
44
15256
pub fn protocol_warning_mode() -> ProtocolWarningMode {
45
15256
    let raw = PROTOCOL_WARNING_MODE.load(Ordering::Relaxed);
46
15256
    ProtocolWarningMode::from_raw(raw).unwrap_or(ProtocolWarningMode::Off)
47
15256
}
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
516
pub fn __should_promote_to_warn(kind: ErrorKind) -> bool {
58
516
    kind.is_always_a_warning()
59
514
        || (protocol_warning_mode() == ProtocolWarningMode::Warn
60
4
            && kind == ErrorKind::TorProtocolViolation)
61
516
}
62

            
63
impl ErrorKind {
64
    /// Return true if this [`ErrorKind`] should always be logged as
65
    /// a warning (or more severe).
66
23122
    pub fn is_always_a_warning(&self) -> bool {
67
23122
        matches!(self, ErrorKind::Internal | ErrorKind::BadApiUsage)
68
23122
    }
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
    #![allow(clippy::string_slice)] // See arti#2571
229
    //! <!-- @@ end test lint list maintained by maint/add_warning @@ -->
230

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

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

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

            
243
        struct RestoreMode(super::ProtocolWarningMode);
244

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

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

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

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

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

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

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

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

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

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

            
296
        struct RestoreMode(super::ProtocolWarningMode);
297

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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