autopush_common/
logging.rs

1use std::io;
2
3use gethostname::gethostname;
4use slog::{self, Drain};
5use slog_mozlog_json::MozLogJson;
6
7use crate::errors::Result;
8
9/// Default number of records slog-async buffers before it begins dropping them.
10///
11/// slog-async's own default of 128 is trivially overrun: the consumer only needs
12/// to stall briefly (scheduling, a slow write) for the buffer to fill, and each
13/// dropped record then produces an ERROR level "channel overflow" report of its
14/// own, converting filtered-out records into unfilterable noise. Sized instead
15/// for seconds of headroom at a high logging rate; ~110 bytes per slot is
16/// allocated up front, so this costs roughly 2MB resident.
17pub const DEFAULT_LOG_CHAN_SIZE: usize = 20_000;
18
19/// Initialize logging.
20///
21/// `chan_size` is the slog-async buffer depth; see [`DEFAULT_LOG_CHAN_SIZE`]. A
22/// value of 0 is treated as the default: crossbeam would otherwise give us a
23/// rendezvous channel, blocking every logging call until the consumer picks the
24/// record up.
25pub fn init_logging(json: bool, chan_size: usize, name: &str, version: &str) -> Result<()> {
26    let chan_size = if chan_size == 0 {
27        DEFAULT_LOG_CHAN_SIZE
28    } else {
29        chan_size
30    };
31    // NOTE: `slog_envlogger` (the RUST_LOG filter) must be the *outermost*
32    // drain, wrapping `slog_async`. Nested inside it instead, every record is
33    // queued to the async channel before anyone checks its level, so RUST_LOG
34    // can't relieve channel pressure and filtered records still cause overflow.
35    let (logger, filter_level) = if json {
36        let hostname = gethostname().to_string_lossy().to_string();
37
38        let drain = MozLogJson::new(io::stdout())
39            .logger_name(format!("{name}-{version}"))
40            .msg_type(format!("{name}:log"))
41            .hostname(hostname)
42            .build()
43            .fuse();
44        let drain = slog_async::Async::new(drain)
45            .chan_size(chan_size)
46            .build()
47            .fuse();
48        let drain = slog_envlogger::new(drain);
49        let filter_level = slog_envlogger::EnvLogger::filter(&drain);
50        (slog::Logger::root(drain, slog_o!()), filter_level)
51    } else {
52        let decorator = slog_term::TermDecorator::new().build();
53        let drain = slog_term::FullFormat::new(decorator).build().fuse();
54        let drain = slog_async::Async::new(drain)
55            .chan_size(chan_size)
56            .build()
57            .fuse();
58        let drain = slog_envlogger::new(drain);
59        let filter_level = slog_envlogger::EnvLogger::filter(&drain);
60        (slog::Logger::root(drain, slog_o!()), filter_level)
61    };
62    // XXX: cancel slog_scope's NoGlobalLoggerSet for now, it's difficult to
63    // prevent it from potentially panicing during tests. reset_logging resets
64    // the global logger during shutdown anyway:
65    // https://github.com/slog-rs/slog/issues/169
66    slog_scope::set_global_logger(logger).cancel_reset();
67    // Register the `log` -> `slog` bridge, then set `log`'s ceiling separately:
68    // `init_with_level` takes a `log::Level`, which can't express "off".
69    slog_stdlog::init_with_level(log::Level::Error).ok();
70    log::set_max_level(log_max_level(filter_level));
71    Ok(())
72}
73
74/// Translate the `RUST_LOG` filter's maximum level into a ceiling for the `log`
75/// crate.
76///
77/// Our own `slog` macros reach the logger directly, so this governs only records
78/// arriving via `log` -- that is, our dependencies. hyper/h2/tonic/tower emit
79/// `tracing` events and, with no `tracing` subscriber installed, those fall
80/// through to `log`; h2 in particular traces per HTTP/2 frame.
81///
82/// `slog_stdlog::init` would set the ceiling to TRACE, admitting all of it.
83/// Deriving the ceiling from the filter's own maximum instead means a record no
84/// directive could ever accept is rejected by `log::max_level()` before it is
85/// built, rather than being constructed and then dropped by the filter. Records
86/// between this ceiling and a narrower per-module directive still reach the
87/// filter, which remains the authority on what is actually logged.
88fn log_max_level(filter: slog::FilterLevel) -> log::LevelFilter {
89    match filter {
90        slog::FilterLevel::Off => log::LevelFilter::Off,
91        // `log` has no Critical; Error is the nearest ceiling that admits it.
92        slog::FilterLevel::Critical | slog::FilterLevel::Error => log::LevelFilter::Error,
93        slog::FilterLevel::Warning => log::LevelFilter::Warn,
94        slog::FilterLevel::Info => log::LevelFilter::Info,
95        slog::FilterLevel::Debug => log::LevelFilter::Debug,
96        slog::FilterLevel::Trace => log::LevelFilter::Trace,
97    }
98}
99
100pub fn reset_logging() {
101    let logger = slog::Logger::root(slog::Discard, o!());
102    slog_scope::set_global_logger(logger).cancel_reset();
103}
104
105/// Initialize logging to `slog_term::TestStdoutWriter` for tests
106///
107/// Note: unfortunately this disables slog's `TermDecorator` (which can't be
108/// captured by cargo test) color output
109pub fn init_test_logging() {
110    let decorator = slog_term::PlainSyncDecorator::new(slog_term::TestStdoutWriter);
111    let drain = std::sync::Mutex::new(slog_term::FullFormat::new(decorator).build()).fuse();
112    let logger = slog::Logger::root(drain, slog::o!());
113    slog_scope::set_global_logger(logger).cancel_reset();
114    slog_stdlog::init().ok();
115}
116
117/// Return parallelism/number of CPU information to log at startup
118pub fn parallelism_banner() -> String {
119    format!(
120        "available_parallelism: {:?} num_cpus: {} num_cpus (phys): {}",
121        std::thread::available_parallelism(),
122        num_cpus::get(),
123        num_cpus::get_physical()
124    )
125}
autopush_common/logging.rs

autopush_common/
logging.rs
