[ tor-browser ].git.dasho

logging.rs (12727B)
      1 /* This Source Code Form is subject to the terms of the Mozilla Public
      2 * License, v. 2.0. If a copy of the MPL was not distributed with this
      3 * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
      4 
      5 //! Gecko-esque logger implementation for the [`log`] crate.
      6 //!
      7 //! The [`log`] crate provides a single logging API that abstracts over the
      8 //! actual logging implementation.  This module uses the logging API
      9 //! to provide a log implementation that shares many aesthetical traits with
     10 //! [Log.sys.mjs] from Gecko.
     11 //!
     12 //! Using the [`error!`], [`warn!`], [`info!`], [`debug!`], and
     13 //! [`trace!`] macros from `log` will output a timestamp field, followed by the
     14 //! log level, and then the message.  The fields are separated by a tab
     15 //! character, making the output suitable for further text processing with
     16 //! `awk(1)`.
     17 //!
     18 //! This module shares the same API as `log`, except it provides additional
     19 //! entry functions [`init`] and [`init_with_level`] and additional log levels
     20 //! `Level::Fatal` and `Level::Config`.  Converting these into the
     21 //! [`log::Level`] is lossy so that `Level::Fatal` becomes `log::Level::Error`
     22 //! and `Level::Config` becomes `log::Level::Debug`.
     23 //!
     24 //! [`log`]: https://docs.rs/log/newest/log/
     25 //! [Log.sys.mjs]: https://searchfox.org/mozilla-central/source/toolkit/modules/Log.sys.mjs
     26 //! [`error!`]: https://docs.rs/log/newest/log/macro.error.html
     27 //! [`warn!`]: https://docs.rs/log/newest/log/macro.warn.html
     28 //! [`info!`]: https://docs.rs/log/newest/log/macro.info.html
     29 //! [`debug!`]: https://docs.rs/log/newest/log/macro.debug.html
     30 //! [`trace!`]: https://docs.rs/log/newest/log/macro.trace.html
     31 //! [`init`]: fn.init.html
     32 //! [`init_with_level`]: fn.init_with_level.html
     33 
     34 use icu_segmenter::GraphemeClusterSegmenter;
     35 use std::fmt;
     36 use std::io;
     37 use std::io::Write;
     38 use std::str;
     39 use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering};
     40 
     41 use mozprofile::preferences::Pref;
     42 
     43 static LOG_TRUNCATE: AtomicBool = AtomicBool::new(true);
     44 static MAX_LOG_LEVEL: AtomicUsize = AtomicUsize::new(0);
     45 
     46 const MAX_STRING_LENGTH: usize = 250;
     47 
     48 const LOGGED_TARGETS: &[&str] = &[
     49    "geckodriver",
     50    "mozdevice",
     51    "mozprofile",
     52    "mozrunner",
     53    "mozversion",
     54    "webdriver",
     55 ];
     56 
     57 /// Logger levels from [Log.sys.mjs].
     58 ///
     59 /// [Log.sys.mjs]: https://searchfox.org/mozilla-central/source/toolkit/modules/Log.sys.mjs
     60 #[repr(usize)]
     61 #[derive(Clone, Copy, Eq, Debug, Hash, PartialEq)]
     62 pub enum Level {
     63    Fatal = 70,
     64    Error = 60,
     65    Warn = 50,
     66    Info = 40,
     67    Config = 30,
     68    Debug = 20,
     69    Trace = 10,
     70 }
     71 
     72 impl From<usize> for Level {
     73    fn from(n: usize) -> Level {
     74        use self::Level::*;
     75        match n {
     76            70 => Fatal,
     77            60 => Error,
     78            50 => Warn,
     79            40 => Info,
     80            30 => Config,
     81            20 => Debug,
     82            10 => Trace,
     83            _ => Info,
     84        }
     85    }
     86 }
     87 
     88 impl fmt::Display for Level {
     89    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
     90        use self::Level::*;
     91        let s = match *self {
     92            Fatal => "FATAL",
     93            Error => "ERROR",
     94            Warn => "WARN",
     95            Info => "INFO",
     96            Config => "CONFIG",
     97            Debug => "DEBUG",
     98            Trace => "TRACE",
     99        };
    100        write!(f, "{}", s)
    101    }
    102 }
    103 
    104 impl str::FromStr for Level {
    105    type Err = ();
    106 
    107    fn from_str(s: &str) -> Result<Level, ()> {
    108        use self::Level::*;
    109        match s.to_lowercase().as_ref() {
    110            "fatal" => Ok(Fatal),
    111            "error" => Ok(Error),
    112            "warn" => Ok(Warn),
    113            "info" => Ok(Info),
    114            "config" => Ok(Config),
    115            "debug" => Ok(Debug),
    116            "trace" => Ok(Trace),
    117            _ => Err(()),
    118        }
    119    }
    120 }
    121 
    122 impl From<Level> for log::Level {
    123    fn from(level: Level) -> log::Level {
    124        use self::Level::*;
    125        match level {
    126            Fatal | Error => log::Level::Error,
    127            Warn => log::Level::Warn,
    128            Info => log::Level::Info,
    129            Config | Debug => log::Level::Debug,
    130            Trace => log::Level::Trace,
    131        }
    132    }
    133 }
    134 
    135 impl From<Level> for Pref {
    136    fn from(level: Level) -> Pref {
    137        use self::Level::*;
    138        Pref::new(match level {
    139            Fatal => "Fatal",
    140            Error => "Error",
    141            Warn => "Warn",
    142            Info => "Info",
    143            Config => "Config",
    144            Debug => "Debug",
    145            Trace => "Trace",
    146        })
    147    }
    148 }
    149 
    150 impl From<log::Level> for Level {
    151    fn from(log_level: log::Level) -> Level {
    152        use log::Level::*;
    153        match log_level {
    154            Error => Level::Error,
    155            Warn => Level::Warn,
    156            Info => Level::Info,
    157            Debug => Level::Debug,
    158            Trace => Level::Trace,
    159        }
    160    }
    161 }
    162 
    163 struct Logger;
    164 
    165 impl log::Log for Logger {
    166    fn enabled(&self, meta: &log::Metadata) -> bool {
    167        LOGGED_TARGETS.iter().any(|&x| meta.target().starts_with(x))
    168            && meta.level() <= log::max_level()
    169    }
    170 
    171    fn log(&self, record: &log::Record) {
    172        if self.enabled(record.metadata()) {
    173            if let Some((s1, s2)) = truncate_message(record.args()) {
    174                println!(
    175                    "{}\t{}\t{}\t{} ... {}",
    176                    format_ts(chrono::Local::now()),
    177                    record.target(),
    178                    record.level(),
    179                    s1,
    180                    s2
    181                );
    182            } else {
    183                println!(
    184                    "{}\t{}\t{}\t{}",
    185                    format_ts(chrono::Local::now()),
    186                    record.target(),
    187                    record.level(),
    188                    record.args()
    189                )
    190            }
    191        }
    192    }
    193 
    194    fn flush(&self) {
    195        io::stdout().flush().unwrap();
    196    }
    197 }
    198 
    199 /// Initialises the logging subsystem with the default log level.
    200 pub fn init(truncate: bool) -> Result<(), log::SetLoggerError> {
    201    init_with_level(Level::Info, truncate)
    202 }
    203 
    204 /// Initialises the logging subsystem.
    205 pub fn init_with_level(level: Level, truncate: bool) -> Result<(), log::SetLoggerError> {
    206    let logger = Logger {};
    207    set_max_level(level);
    208    set_truncate(truncate);
    209    log::set_boxed_logger(Box::new(logger))?;
    210    Ok(())
    211 }
    212 
    213 /// Returns the current maximum log level.
    214 pub fn max_level() -> Level {
    215    MAX_LOG_LEVEL.load(Ordering::Relaxed).into()
    216 }
    217 
    218 /// Sets the global maximum log level.
    219 pub fn set_max_level(level: Level) {
    220    MAX_LOG_LEVEL.store(level as usize, Ordering::SeqCst);
    221 
    222    let slevel: log::Level = level.into();
    223    log::set_max_level(slevel.to_level_filter())
    224 }
    225 
    226 /// Sets the global maximum log level.
    227 pub fn set_truncate(truncate: bool) {
    228    LOG_TRUNCATE.store(truncate, Ordering::SeqCst);
    229 }
    230 
    231 /// Returns the truncation flag.
    232 pub fn truncate() -> bool {
    233    LOG_TRUNCATE.load(Ordering::Relaxed)
    234 }
    235 
    236 /// Produces a 13-digit Unix Epoch timestamp similar to Gecko.
    237 fn format_ts(ts: chrono::DateTime<chrono::Local>) -> String {
    238    format!("{}{:03}", ts.timestamp(), ts.timestamp_subsec_millis())
    239 }
    240 
    241 /// Truncate a log message if it's too long
    242 fn truncate_message(args: &fmt::Arguments) -> Option<(String, String)> {
    243    // Don't truncate the message if requested.
    244    if !truncate() {
    245        return None;
    246    }
    247 
    248    let message = format!("{}", args);
    249    if message.is_empty() || message.len() < MAX_STRING_LENGTH {
    250        return None;
    251    }
    252    let chars = GraphemeClusterSegmenter::new()
    253        .segment_str(&message)
    254        .collect::<Vec<_>>()
    255        .windows(2)
    256        .map(|i| &message[i[0]..i[1]])
    257        .collect::<Vec<&str>>();
    258 
    259    if chars.len() > MAX_STRING_LENGTH {
    260        let middle: usize = MAX_STRING_LENGTH / 2;
    261        let s1 = chars[0..middle].concat();
    262        let s2 = chars[chars.len() - middle..].concat();
    263        Some((s1, s2))
    264    } else {
    265        None
    266    }
    267 }
    268 
    269 #[cfg(test)]
    270 mod tests {
    271    use super::*;
    272 
    273    use std::str::FromStr;
    274    use std::sync::Mutex;
    275 
    276    use mozprofile::preferences::{Pref, PrefValue};
    277 
    278    lazy_static! {
    279        static ref LEVEL_MUTEX: Mutex<()> = Mutex::new(());
    280    }
    281 
    282    #[test]
    283    fn test_level_repr() {
    284        assert_eq!(Level::Fatal as usize, 70);
    285        assert_eq!(Level::Error as usize, 60);
    286        assert_eq!(Level::Warn as usize, 50);
    287        assert_eq!(Level::Info as usize, 40);
    288        assert_eq!(Level::Config as usize, 30);
    289        assert_eq!(Level::Debug as usize, 20);
    290        assert_eq!(Level::Trace as usize, 10);
    291    }
    292 
    293    #[test]
    294    fn test_level_from_log() {
    295        assert_eq!(Level::from(log::Level::Error), Level::Error);
    296        assert_eq!(Level::from(log::Level::Warn), Level::Warn);
    297        assert_eq!(Level::from(log::Level::Info), Level::Info);
    298        assert_eq!(Level::from(log::Level::Debug), Level::Debug);
    299        assert_eq!(Level::from(log::Level::Trace), Level::Trace);
    300    }
    301 
    302    #[test]
    303    fn test_level_into_log() {
    304        assert_eq!(Into::<log::Level>::into(Level::Fatal), log::Level::Error);
    305        assert_eq!(Into::<log::Level>::into(Level::Error), log::Level::Error);
    306        assert_eq!(Into::<log::Level>::into(Level::Warn), log::Level::Warn);
    307        assert_eq!(Into::<log::Level>::into(Level::Info), log::Level::Info);
    308        assert_eq!(Into::<log::Level>::into(Level::Config), log::Level::Debug);
    309        assert_eq!(Into::<log::Level>::into(Level::Debug), log::Level::Debug);
    310        assert_eq!(Into::<log::Level>::into(Level::Trace), log::Level::Trace);
    311    }
    312 
    313    #[test]
    314    fn test_level_into_pref() {
    315        let tests = [
    316            (Level::Fatal, "Fatal"),
    317            (Level::Error, "Error"),
    318            (Level::Warn, "Warn"),
    319            (Level::Info, "Info"),
    320            (Level::Config, "Config"),
    321            (Level::Debug, "Debug"),
    322            (Level::Trace, "Trace"),
    323        ];
    324 
    325        for &(lvl, s) in tests.iter() {
    326            let expected = Pref {
    327                value: PrefValue::String(s.to_string()),
    328                sticky: false,
    329            };
    330            assert_eq!(Into::<Pref>::into(lvl), expected);
    331        }
    332    }
    333 
    334    #[test]
    335    fn test_level_from_str() {
    336        assert_eq!(Level::from_str("fatal"), Ok(Level::Fatal));
    337        assert_eq!(Level::from_str("error"), Ok(Level::Error));
    338        assert_eq!(Level::from_str("warn"), Ok(Level::Warn));
    339        assert_eq!(Level::from_str("info"), Ok(Level::Info));
    340        assert_eq!(Level::from_str("config"), Ok(Level::Config));
    341        assert_eq!(Level::from_str("debug"), Ok(Level::Debug));
    342        assert_eq!(Level::from_str("trace"), Ok(Level::Trace));
    343 
    344        assert_eq!(Level::from_str("INFO"), Ok(Level::Info));
    345 
    346        assert!(Level::from_str("foo").is_err());
    347    }
    348 
    349    #[test]
    350    fn test_level_to_str() {
    351        assert_eq!(Level::Fatal.to_string(), "FATAL");
    352        assert_eq!(Level::Error.to_string(), "ERROR");
    353        assert_eq!(Level::Warn.to_string(), "WARN");
    354        assert_eq!(Level::Info.to_string(), "INFO");
    355        assert_eq!(Level::Config.to_string(), "CONFIG");
    356        assert_eq!(Level::Debug.to_string(), "DEBUG");
    357        assert_eq!(Level::Trace.to_string(), "TRACE");
    358    }
    359 
    360    #[test]
    361    fn test_max_level() {
    362        let _guard = LEVEL_MUTEX.lock();
    363        set_max_level(Level::Info);
    364        assert_eq!(max_level(), Level::Info);
    365    }
    366 
    367    #[test]
    368    fn test_set_max_level() {
    369        let _guard = LEVEL_MUTEX.lock();
    370        set_max_level(Level::Error);
    371        assert_eq!(max_level(), Level::Error);
    372        set_max_level(Level::Fatal);
    373        assert_eq!(max_level(), Level::Fatal);
    374    }
    375 
    376    #[test]
    377    fn test_init_with_level() {
    378        let _guard = LEVEL_MUTEX.lock();
    379        init_with_level(Level::Debug, false).unwrap();
    380        assert_eq!(max_level(), Level::Debug);
    381        assert!(init_with_level(Level::Warn, false).is_err());
    382    }
    383 
    384    #[test]
    385    fn test_format_ts() {
    386        let ts = chrono::Local::now();
    387        let s = format_ts(ts);
    388        assert_eq!(s.len(), 13);
    389    }
    390 
    391    #[test]
    392    fn test_truncate() {
    393        let short_message = (0..MAX_STRING_LENGTH).map(|_| "x").collect::<String>();
    394        // A message up to MAX_STRING_LENGTH is not truncated
    395        assert_eq!(truncate_message(&format_args!("{}", short_message)), None);
    396 
    397        let long_message = (0..MAX_STRING_LENGTH + 1).map(|_| "x").collect::<String>();
    398        let part = (0..MAX_STRING_LENGTH / 2).map(|_| "x").collect::<String>();
    399 
    400        // A message longer than MAX_STRING_LENGTH is not truncated if requested
    401        set_truncate(false);
    402        assert_eq!(truncate_message(&format_args!("{}", long_message)), None);
    403 
    404        // A message longer than MAX_STRING_LENGTH is truncated if requested
    405        set_truncate(true);
    406        assert_eq!(
    407            truncate_message(&format_args!("{}", long_message)),
    408            Some((part.to_owned(), part))
    409        );
    410    }
    411 }
	tor-browser The Tor Browser
	git clone https://git.dasho.dev/tor-browser.git
	Log \| Files \| Refs \| README \| LICENSE