From 42a353eaf46528b99917dd8dc141cc93c791f7eb Mon Sep 17 00:00:00 2001 From: Steven Fackler Date: Sat, 24 Jan 2015 22:44:46 -0800 Subject: [PATCH 1/5] Rewrite liblog into a logging facade See issue #3 for background. Closes #3 Closes #7 Closes #11 --- Cargo.toml | 5 +- README.md | 14 +- src/directive.rs | 199 ---------- src/lib.rs | 936 +++++++++++++++++++++++++++-------------------- src/macros.rs | 260 ++++++------- 5 files changed, 650 insertions(+), 764 deletions(-) delete mode 100644 src/directive.rs diff --git a/Cargo.toml b/Cargo.toml index 318f6ba23..c73fa05ef 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -9,8 +9,5 @@ repository = "https://github.com/rust-lang/log" documentation = "http://doc.rust-lang.org/log" homepage = "https://github.com/rust-lang/log" description = """ -Logging macros and infrastructure for Rust +A lightweight logging facade for Rust """ - -[dependencies] -regex = "0.1" diff --git a/README.md b/README.md index f2599573b..d315533ef 100644 --- a/README.md +++ b/README.md @@ -1,23 +1,33 @@ log === -A Rust library for application logging via debug/info/warn/error macros +A Rust library providing a lightweight logging *facade*. [![Build Status](https://travis-ci.org/rust-lang/log.svg?branch=master)](https://travis-ci.org/rust-lang/log) [Documentation](http://doc.rust-lang.org/log) +A logging facade provides a single logging API that abstracts over the actual +logging implementation. Libraries can use the logging API provided by this +crate, and the consumer of those libraries can choose the logging +implementation that is most suitable for its use case. + +Libraries should simply depend on the `log` crate, using the various logging +macros as they like. Applications should choose a logging implementation that +will process all logging messages. + ## Usage Add this to your `Cargo.toml`: ```toml [dependencies] -log = "0.1.0" +log = "0.2" ``` and this to your crate root: ```rust +#[macro_use] extern crate log; ``` diff --git a/src/directive.rs b/src/directive.rs deleted file mode 100644 index 813450301..000000000 --- a/src/directive.rs +++ /dev/null @@ -1,199 +0,0 @@ -// Copyright 2014 The Rust Project Developers. See the COPYRIGHT -// file at the top-level directory of this distribution and at -// http://rust-lang.org/COPYRIGHT. -// -// Licensed under the Apache License, Version 2.0 or the MIT license -// , at your -// option. This file may not be copied, modified, or distributed -// except according to those terms. - -use regex::Regex; -use std::ascii::AsciiExt; -use std::cmp; - -#[derive(Show, Clone)] -pub struct LogDirective { - pub name: Option, - pub level: u32, -} - -pub static LOG_LEVEL_NAMES: [&'static str; 4] = ["ERROR", "WARN", "INFO", - "DEBUG"]; - -/// Parse an individual log level that is either a number or a symbolic log level -fn parse_log_level(level: &str) -> Option { - level.parse::().or_else(|| { - let pos = LOG_LEVEL_NAMES.iter().position(|&name| name.eq_ignore_ascii_case(level)); - pos.map(|p| p as u32 + 1) - }).map(|p| cmp::min(p, ::MAX_LOG_LEVEL)) -} - -/// Parse a logging specification string (e.g: "crate1,crate2::mod3,crate3::x=1/foo") -/// and return a vector with log directives. -/// -/// Valid log levels are 0-255, with the most likely ones being 1-4 (defined in -/// std::). Also supports string log levels of error, warn, info, and debug -pub fn parse_logging_spec(spec: &str) -> (Vec, Option) { - let mut dirs = Vec::new(); - - let mut parts = spec.split('/'); - let mods = parts.next(); - let filter = parts.next(); - if parts.next().is_some() { - println!("warning: invalid logging spec '{}', \ - ignoring it (too many '/'s)", spec); - return (dirs, None); - } - mods.map(|m| { for s in m.split(',') { - if s.len() == 0 { continue } - let mut parts = s.split('='); - let (log_level, name) = match (parts.next(), parts.next().map(|s| s.trim()), parts.next()) { - (Some(part0), None, None) => { - // if the single argument is a log-level string or number, - // treat that as a global fallback - match parse_log_level(part0) { - Some(num) => (num, None), - None => (::MAX_LOG_LEVEL, Some(part0)), - } - } - (Some(part0), Some(""), None) => (::MAX_LOG_LEVEL, Some(part0)), - (Some(part0), Some(part1), None) => { - match parse_log_level(part1) { - Some(num) => (num, Some(part0)), - _ => { - println!("warning: invalid logging spec '{}', \ - ignoring it", part1); - continue - } - } - }, - _ => { - println!("warning: invalid logging spec '{}', \ - ignoring it", s); - continue - } - }; - dirs.push(LogDirective { - name: name.map(|s| s.to_string()), - level: log_level, - }); - }}); - - let filter = filter.map_or(None, |filter| { - match Regex::new(filter) { - Ok(re) => Some(re), - Err(e) => { - println!("warning: invalid regex filter - {}", e); - None - } - } - }); - - return (dirs, filter); -} - -#[cfg(test)] -mod tests { - use super::parse_logging_spec; - - #[test] - fn parse_logging_spec_valid() { - let (dirs, filter) = parse_logging_spec("crate1::mod1=1,crate1::mod2,crate2=4"); - assert_eq!(dirs.len(), 3); - assert_eq!(dirs[0].name, Some("crate1::mod1".to_string())); - assert_eq!(dirs[0].level, 1); - - assert_eq!(dirs[1].name, Some("crate1::mod2".to_string())); - assert_eq!(dirs[1].level, ::MAX_LOG_LEVEL); - - assert_eq!(dirs[2].name, Some("crate2".to_string())); - assert_eq!(dirs[2].level, 4); - assert!(filter.is_none()); - } - - #[test] - fn parse_logging_spec_invalid_crate() { - // test parse_logging_spec with multiple = in specification - let (dirs, filter) = parse_logging_spec("crate1::mod1=1=2,crate2=4"); - assert_eq!(dirs.len(), 1); - assert_eq!(dirs[0].name, Some("crate2".to_string())); - assert_eq!(dirs[0].level, 4); - assert!(filter.is_none()); - } - - #[test] - fn parse_logging_spec_invalid_log_level() { - // test parse_logging_spec with 'noNumber' as log level - let (dirs, filter) = parse_logging_spec("crate1::mod1=noNumber,crate2=4"); - assert_eq!(dirs.len(), 1); - assert_eq!(dirs[0].name, Some("crate2".to_string())); - assert_eq!(dirs[0].level, 4); - assert!(filter.is_none()); - } - - #[test] - fn parse_logging_spec_string_log_level() { - // test parse_logging_spec with 'warn' as log level - let (dirs, filter) = parse_logging_spec("crate1::mod1=wrong,crate2=warn"); - assert_eq!(dirs.len(), 1); - assert_eq!(dirs[0].name, Some("crate2".to_string())); - assert_eq!(dirs[0].level, ::WARN); - assert!(filter.is_none()); - } - - #[test] - fn parse_logging_spec_empty_log_level() { - // test parse_logging_spec with '' as log level - let (dirs, filter) = parse_logging_spec("crate1::mod1=wrong,crate2="); - assert_eq!(dirs.len(), 1); - assert_eq!(dirs[0].name, Some("crate2".to_string())); - assert_eq!(dirs[0].level, ::MAX_LOG_LEVEL); - assert!(filter.is_none()); - } - - #[test] - fn parse_logging_spec_global() { - // test parse_logging_spec with no crate - let (dirs, filter) = parse_logging_spec("warn,crate2=4"); - assert_eq!(dirs.len(), 2); - assert_eq!(dirs[0].name, None); - assert_eq!(dirs[0].level, 2); - assert_eq!(dirs[1].name, Some("crate2".to_string())); - assert_eq!(dirs[1].level, 4); - assert!(filter.is_none()); - } - - #[test] - fn parse_logging_spec_valid_filter() { - let (dirs, filter) = parse_logging_spec("crate1::mod1=1,crate1::mod2,crate2=4/abc"); - assert_eq!(dirs.len(), 3); - assert_eq!(dirs[0].name, Some("crate1::mod1".to_string())); - assert_eq!(dirs[0].level, 1); - - assert_eq!(dirs[1].name, Some("crate1::mod2".to_string())); - assert_eq!(dirs[1].level, ::MAX_LOG_LEVEL); - - assert_eq!(dirs[2].name, Some("crate2".to_string())); - assert_eq!(dirs[2].level, 4); - assert!(filter.is_some() && filter.unwrap().to_string() == "abc"); - } - - #[test] - fn parse_logging_spec_invalid_crate_filter() { - let (dirs, filter) = parse_logging_spec("crate1::mod1=1=2,crate2=4/a.c"); - assert_eq!(dirs.len(), 1); - assert_eq!(dirs[0].name, Some("crate2".to_string())); - assert_eq!(dirs[0].level, 4); - assert!(filter.is_some() && filter.unwrap().to_string() == "a.c"); - } - - #[test] - fn parse_logging_spec_empty_with_filter() { - let (dirs, filter) = parse_logging_spec("crate1/a*c"); - assert_eq!(dirs.len(), 1); - assert_eq!(dirs[0].name, Some("crate1".to_string())); - assert_eq!(dirs[0].level, ::MAX_LOG_LEVEL); - assert!(filter.is_some() && filter.unwrap().to_string() == "a*c"); - } -} diff --git a/src/lib.rs b/src/lib.rs index 1b5392b49..6ad77ffda 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -1,506 +1,632 @@ -// Copyright 2014 The Rust Project Developers. See the COPYRIGHT -// file at the top-level directory of this distribution and at -// http://rust-lang.org/COPYRIGHT. -// -// Licensed under the Apache License, Version 2.0 or the MIT license -// , at your -// option. This file may not be copied, modified, or distributed -// except according to those terms. - -//! Utilities for program-wide and customizable logging -//! -//! ## Example -//! -//! ``` -//! #[macro_use] extern crate log; -//! -//! fn main() { -//! debug!("this is a debug {}", "message"); -//! error!("this is printed by default"); -//! -//! if log_enabled!(log::INFO) { -//! let x = 3i * 4i; // expensive computation -//! info!("the answer was: {}", x); +//! A lightweight logging facade. +//! +//! A logging facade provides a single logging API that abstracts over the +//! actual logging implementation. Libraries can use the logging API provided +//! by this crate, and the consumer of those libraries can choose the logging +//! framework that is most suitable for its use case. +//! +//! If no logging implementation is selected, the facade falls back to a "noop" +//! implementation that ignores all log messages. The overhead in this case +//! is very small - just an integer load, comparison and jump. +//! +//! # Use +//! +//! ## In libraries +//! +//! Libraries should link only to the `log` crate, and use the provided +//! macros to log whatever information will be useful to downstream consumers. +//! +//! ### Examples +//! +//! ```rust +//! # #![allow(unstable)] +//! #[macro_use] +//! extern crate log; +//! +//! # pub struct Yak(String); +//! # impl Yak { fn shave(&self, _: u32) {} } +//! # fn find_a_razor() -> Result { Ok(1) } +//! pub fn shave_the_yak(yak: &Yak) { +//! trace!("Commencing yak shaving"); +//! +//! loop { +//! match find_a_razor() { +//! Ok(razor) => { +//! info!("Razor located: {}", razor); +//! yak.shave(razor); +//! break; +//! } +//! Err(err) => { +//! warn!("Unable to locate a razor: {}, retrying", err); +//! } +//! } //! } //! } +//! # fn main() {} //! ``` //! -//! Assumes the binary is `main`: -//! -//! ```{.bash} -//! $ RUST_LOG=error ./main -//! ERROR:main: this is printed by default -//! ``` -//! -//! ```{.bash} -//! $ RUST_LOG=info ./main -//! ERROR:main: this is printed by default -//! INFO:main: the answer was: 12 -//! ``` -//! -//! ```{.bash} -//! $ RUST_LOG=debug ./main -//! DEBUG:main: this is a debug message -//! ERROR:main: this is printed by default -//! INFO:main: the answer was: 12 -//! ``` -//! -//! You can also set the log level on a per module basis: -//! -//! ```{.bash} -//! $ RUST_LOG=main=info ./main -//! ERROR:main: this is printed by default -//! INFO:main: the answer was: 12 -//! ``` -//! -//! And enable all logging: -//! -//! ```{.bash} -//! $ RUST_LOG=main ./main -//! DEBUG:main: this is a debug message -//! ERROR:main: this is printed by default -//! INFO:main: the answer was: 12 -//! ``` -//! +//! ## In executables //! -//! ## Logging Macros +//! Executables should chose a logging framework and initialize it early in the +//! runtime of the program. Logging frameworks will typically include a +//! function to do this. Any log messages generated before the framework is +//! initialized will be ignored. //! -//! There are five macros that the logging subsystem uses: +//! The executable itself may use the `log` crate to log as well. //! -//! * `log!(level, ...)` - the generic logging macro, takes a level as a u32 and any -//! related `format!` arguments -//! * `debug!(...)` - a macro hard-wired to the log level of `DEBUG` -//! * `info!(...)` - a macro hard-wired to the log level of `INFO` -//! * `warn!(...)` - a macro hard-wired to the log level of `WARN` -//! * `error!(...)` - a macro hard-wired to the log level of `ERROR` +//! ### Warning //! -//! All of these macros use the same style of syntax as the `format!` syntax -//! extension. Details about the syntax can be found in the documentation of -//! `std::fmt` along with the Rust tutorial/manual. +//! The logging system may only be initialized once. //! -//! If you want to check at runtime if a given logging level is enabled (e.g. if the -//! information you would want to log is expensive to produce), you can use the -//! following macro: +//! ### Examples //! -//! * `log_enabled!(level)` - returns true if logging of the given level is enabled +//! ```rust,ignore +//! #[macro_use] +//! extern crate log; +//! extern crate my_logger; //! -//! ## Enabling logging +//! fn main() { +//! my_logger::init(); //! -//! Log levels are controlled on a per-module basis, and by default all logging is -//! disabled except for `error!` (a log level of 1). Logging is controlled via the -//! `RUST_LOG` environment variable. The value of this environment variable is a -//! comma-separated list of logging directives. A logging directive is of the form: +//! info!("starting up"); //! -//! ```text -//! path::to::module=log_level +//! // ... +//! } //! ``` //! -//! The path to the module is rooted in the name of the crate it was compiled for, -//! so if your program is contained in a file `hello.rs`, for example, to turn on -//! logging for this file you would use a value of `RUST_LOG=hello`. -//! Furthermore, this path is a prefix-search, so all modules nested in the -//! specified module will also have logging enabled. +//! # Logger implementations //! -//! The actual `log_level` is optional to specify. If omitted, all logging will be -//! enabled. If specified, the it must be either a numeric in the range of 1-255, or -//! it must be one of the strings `debug`, `error`, `info`, or `warn`. If a numeric -//! is specified, then all logging less than or equal to that numeral is enabled. -//! For example, if logging level 3 is active, error, warn, and info logs will be -//! printed, but debug will be omitted. +//! Loggers implement the `Log` trait. Here's a very basic example that simply +//! logs all messages at the `Error`, `Warn` or `Info` levels to stdout: //! -//! As the log level for a module is optional, the module to enable logging for is -//! also optional. If only a `log_level` is provided, then the global log level for -//! all modules is set to this value. +//! ```rust +//! extern crate log; //! -//! Some examples of valid values of `RUST_LOG` are: +//! use log::{LogRecord, LogLevel}; //! -//! * `hello` turns on all logging for the 'hello' module -//! * `info` turns on all info logging -//! * `hello=debug` turns on debug logging for 'hello' -//! * `hello=3` turns on info logging for 'hello' -//! * `hello,std::option` turns on hello, and std's option logging -//! * `error,hello=warn` turn on global error logging and also warn for hello +//! struct SimpleLogger; //! -//! ## Filtering results -//! -//! A RUST_LOG directive may include a regex filter. The syntax is to append `/` -//! followed by a regex. Each message is checked against the regex, and is only -//! logged if it matches. Note that the matching is done after formatting the log -//! string but before adding any logging meta-data. There is a single filter for all -//! modules. -//! -//! Some examples: -//! -//! * `hello/foo` turns on all logging for the 'hello' module where the log message -//! includes 'foo'. -//! * `info/f.o` turns on all info logging where the log message includes 'foo', -//! 'f1o', 'fao', etc. -//! * `hello=debug/foo*foo` turns on debug logging for 'hello' where the log -//! message includes 'foofoo' or 'fofoo' or 'fooooooofoo', etc. -//! * `error,hello=warn/[0-9] scopes` turn on global error logging and also warn for -//! hello. In both cases the log message must include a single digit number -//! followed by 'scopes' +//! impl log::Log for SimpleLogger { +//! fn enabled(&self, level: LogLevel, _module: &str) -> bool { +//! level <= LogLevel::Info +//! } //! -//! ## Performance and Side Effects +//! fn log(&self, record: &LogRecord) { +//! if self.enabled(record.level, record.location.module_path) { +//! println!("{} - {}", record.level, record.args); +//! } +//! } +//! } //! -//! Each of these macros will expand to code similar to: +//! # fn main() {} +//! ``` //! -//! ```rust,ignore -//! if log_level <= my_module_log_level() { -//! ::log::log(log_level, format!(...)); +//! Loggers are installed by calling the `set_logger` function. It takes a +//! closure which is provided a `MaxLogLevel` token and returns a `Log` trait +//! object. The `MaxLogLevel` token controls the global maximum log level. The +//! logging facade uses this as an optimization to improve performance of log +//! messages at levels that are disabled. In the case of our example logger, +//! we'll want to set the maximum log level to `Info`, since we ignore any +//! `Debug` or `Trace` level log messages. A logging framework should provide a +//! function that wraps a call to `set_logger`, handling initialization of the +//! logger: +//! +//! ```rust +//! # extern crate log; +//! # use log::{LogLevel, LogLevelFilter, SetLoggerError}; +//! # struct SimpleLogger; +//! # impl log::Log for SimpleLogger { +//! # fn enabled(&self, _: LogLevel, _: &str) -> bool { false } +//! # fn log(&self, _: &log::LogRecord) {} +//! # } +//! # fn main() {} +//! pub fn init() -> Result<(), SetLoggerError> { +//! log::set_logger(|max_log_level| { +//! max_log_level.set(LogLevelFilter::Info); +//! Box::new(SimpleLogger) +//! }) //! } //! ``` -//! -//! What this means is that each of these macros are very cheap at runtime if -//! they're turned off (just a load and an integer comparison). This also means that -//! if logging is disabled, none of the components of the log will be executed. - #![doc(html_logo_url = "http://www.rust-lang.org/logos/rust-logo-128x128-blk-v2.png", html_favicon_url = "http://www.rust-lang.org/favicon.ico", html_root_url = "http://doc.rust-lang.org/log/")] -#![deny(missing_docs)] -#![cfg_attr(test, deny(warnings))] +#![warn(missing_docs)] #![allow(unstable)] -extern crate regex; - -use std::cell::RefCell; +use std::ascii::AsciiExt; +use std::cmp; use std::fmt; -use std::io::LineBufferedWriter; -use std::io; use std::mem; -use std::os; +use std::ops::Deref; use std::rt; -use std::slice; -use std::sync::{Once, ONCE_INIT}; +use std::str::FromStr; +use std::sync::atomic::{AtomicUsize, ATOMIC_USIZE_INIT, Ordering}; +mod macros; -use regex::Regex; +// The setup here is a bit weird to make at_exit work. +// +// There are four different states that we care about: the logger's +// uninitialized, the logger's initializing (set_logger's been called but +// LOGGER hasn't actually been set yet), the logger's active, or the logger's +// shutting down inside of at_exit. +// +// The LOGGER static is normally a Box> with some special possible +// values as well. The uninitialized and initializing states are represented by +// the values 0 and 1 respectively. The shutting down state is also represented +// by 1. Any other value is a valid pointer to the logger. +// +// The at_exit routine needs to make sure that no threads are actively logging +// when it deallocates the logger. The number of actively logging threads is +// tracked in the REFCOUNT static. The routine first sets LOGGER back to 1. +// All logging calls past that point will immediatly return without accessing +// the logger. At that point, the at_exit routine just waits for the refcount +// to reach 0 before deallocating the logger. Note that the refcount does not +// necessarily monotonically decrease at this point, as new log calls still +// increment and decrement it, but the interval in between is small enough that +// the wait is really just for the active log calls to finish. +static LOGGER: AtomicUsize = ATOMIC_USIZE_INIT; +static REFCOUNT: AtomicUsize = ATOMIC_USIZE_INIT; + +const UNINITIALIZED: usize = 0; +const INITIALIZING: usize = 1; + +static MAX_LOG_LEVEL_FILTER: AtomicUsize = ATOMIC_USIZE_INIT; + +static LOG_LEVEL_NAMES: [&'static str; 6] = ["OFF", "ERROR", "WARN", "INFO", "DEBUG", "TRACE"]; + +/// An enum representing the available verbosity levels of the logging framework +/// +/// A `LogLevel` may be compared directly to a `LogLevelFilter`. +#[repr(usize)] +#[derive(Copy, Eq, Debug)] +pub enum LogLevel { + /// The "error" level. + /// + /// Designates very serious errors. + Error, + /// The "warn" level. + /// + /// Designates hazardous situations. + Warn, + /// The "info" level. + /// + /// Designates useful information. + Info, + /// The "debug" level. + /// + /// Designates lower priority information. + Debug, + /// The "trace" level. + /// + /// Designates very low priority, often extremely verbose, information. + Trace, +} -use directive::LOG_LEVEL_NAMES; +impl Clone for LogLevel { + #[inline] + fn clone(&self) -> LogLevel { + *self + } +} -#[macro_use] -pub mod macros; -mod directive; +impl PartialEq for LogLevel { + #[inline] + fn eq(&self, other: &LogLevel) -> bool { + *self as usize == *other as usize + } +} -/// Maximum logging level of a module that can be specified. Common logging -/// levels are found in the DEBUG/INFO/WARN/ERROR constants. -pub const MAX_LOG_LEVEL: u32 = 255; +impl PartialEq for LogLevel { + #[inline] + fn eq(&self, other: &LogLevelFilter) -> bool { + (*self as usize) + 1 == *other as usize + } +} -/// The default logging level of a crate if no other is specified. -const DEFAULT_LOG_LEVEL: u32 = 1; +impl PartialOrd for LogLevel { + #[inline] + fn partial_cmp(&self, other: &LogLevel) -> Option { + Some(self.cmp(other)) + } +} -/// An unsafe constant that is the maximum logging level of any module -/// specified. This is the first line of defense to determining whether a -/// logging statement should be run. -static mut LOG_LEVEL: u32 = MAX_LOG_LEVEL; +impl PartialOrd for LogLevel { + #[inline] + fn partial_cmp(&self, other: &LogLevelFilter) -> Option { + Some(((*self as usize) + 1).cmp(&(*other as usize))) + } +} -static mut DIRECTIVES: *const Vec = - 0 as *const Vec; +impl Ord for LogLevel { + #[inline] + fn cmp(&self, other: &LogLevel) -> cmp::Ordering { + (*self as usize).cmp(&(*other as usize)) + } +} -/// Optional regex filter. -static mut FILTER: *const Regex = 0 as *const _; +impl FromStr for LogLevel { + fn from_str(level: &str) -> Option { + LOG_LEVEL_NAMES.iter() + .position(|&name| name.eq_ignore_ascii_case(level)) + .into_iter() + .filter(|&idx| idx != 0) + .map(|idx| unsafe { mem::transmute(idx - 1) }) + .next() + } +} -/// Debug log level -pub const DEBUG: u32 = 4; -/// Info log level -pub const INFO: u32 = 3; -/// Warn log level -pub const WARN: u32 = 2; -/// Error log level -pub const ERROR: u32 = 1; +impl fmt::Display for LogLevel { + fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result { + write!(fmt, "{}", LOG_LEVEL_NAMES[(*self as usize) + 1]) + } +} -thread_local!(static LOCAL_LOGGER: RefCell>> = { - RefCell::new(None) -}); +impl LogLevel { + /// Returns the most verbose logging level. + #[inline] + pub fn max() -> LogLevel { + LogLevel::Trace + } -/// A trait used to represent an interface to a task-local logger. Each task -/// can have its own custom logger which can respond to logging messages -/// however it likes. -pub trait Logger { - /// Logs a single message described by the `record`. - fn log(&mut self, record: &LogRecord); + /// Converts the `LogLevel` to the equivalent `LogLevelFilter`. + #[inline] + pub fn to_log_level_filter(&self) -> LogLevelFilter { + unsafe { mem::transmute((*self as usize) + 1) } + } } -struct DefaultLogger { - handle: LineBufferedWriter, +/// An enum representing the available verbosity level filters of the logging +/// framework. +/// +/// A `LogLevelFilter` may be compared directly to a `LogLevel`. +#[repr(usize)] +#[derive(Copy, Eq, Debug)] +pub enum LogLevelFilter { + /// A level lower than all log levels. + Off, + /// Corresponds to the `Error` log level. + Error, + /// Corresponds to the `Warn` log level. + Warn, + /// Corresponds to the `Trace` log level. + Info, + /// Corresponds to the `Debug` log level. + Debug, + /// Corresponds to the `Trace` log level. + Trace, } -/// Wraps the log level with fmt implementations. -#[derive(PartialEq, PartialOrd, Show)] -pub struct LogLevel(pub u32); - -impl Copy for LogLevel {} +// Deriving generates terrible impls of these traits -impl fmt::Display for LogLevel { - fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result { - let LogLevel(level) = *self; - match LOG_LEVEL_NAMES.get(level as usize - 1) { - Some(name) => name.fmt(fmt), - None => level.fmt(fmt) - } +impl Clone for LogLevelFilter { + #[inline] + fn clone(&self) -> LogLevelFilter { + *self } } -impl Logger for DefaultLogger { - fn log(&mut self, record: &LogRecord) { - match writeln!(&mut self.handle, - "{}:{}: {}", - record.level, - record.module_path, - record.args) { - Err(e) => panic!("failed to log: {}", e), - Ok(()) => {} - } +impl PartialEq for LogLevelFilter { + #[inline] + fn eq(&self, other: &LogLevelFilter) -> bool { + *self as usize == *other as usize } } -impl Drop for DefaultLogger { - fn drop(&mut self) { - // FIXME(#12628): is panicking the right thing to do? - match self.handle.flush() { - Err(e) => panic!("failed to flush a logger: {}", e), - Ok(()) => {} - } +impl PartialEq for LogLevelFilter { + #[inline] + fn eq(&self, other: &LogLevel) -> bool { + other.eq(self) } } -/// This function is called directly by the compiler when using the logging -/// macros. This function does not take into account whether the log level -/// specified is active or not, it will always log something if this method is -/// called. -/// -/// It is not recommended to call this function directly, rather it should be -/// invoked through the logging family of macros. -#[doc(hidden)] -pub fn log(level: u32, loc: &'static LogLocation, args: fmt::Arguments) { - // Test the literal string from args against the current filter, if there - // is one. - match unsafe { FILTER.as_ref() } { - Some(filter) if !filter.is_match(args.to_string().as_slice()) => return, - _ => {} +impl PartialOrd for LogLevelFilter { + #[inline] + fn partial_cmp(&self, other: &LogLevelFilter) -> Option { + Some(self.cmp(other)) } +} - // Completely remove the local logger from TLS in case anyone attempts to - // frob the slot while we're doing the logging. This will destroy any logger - // set during logging. - let mut logger = LOCAL_LOGGER.with(|s| { - s.borrow_mut().take() - }).unwrap_or_else(|| { - Box::new(DefaultLogger { handle: io::stderr() }) as Box - }); - logger.log(&LogRecord { - level: LogLevel(level), - args: args, - file: loc.file, - module_path: loc.module_path, - line: loc.line, - }); - set_logger(logger); +impl PartialOrd for LogLevelFilter { + #[inline] + fn partial_cmp(&self, other: &LogLevel) -> Option { + other.partial_cmp(self).map(|x| x.reverse()) + } } -/// Getter for the global log level. This is a function so that it can be called -/// safely -#[doc(hidden)] -#[inline(always)] -pub fn log_level() -> u32 { unsafe { LOG_LEVEL } } +impl Ord for LogLevelFilter { + #[inline] + fn cmp(&self, other: &LogLevelFilter) -> cmp::Ordering { + (*self as usize).cmp(&(*other as usize)) + } +} -/// Replaces the task-local logger with the specified logger, returning the old -/// logger. -pub fn set_logger(logger: Box) -> Option> { - let mut l = Some(logger); - LOCAL_LOGGER.with(|slot| { - mem::replace(&mut *slot.borrow_mut(), l.take()) - }) +impl FromStr for LogLevelFilter { + fn from_str(level: &str) -> Option { + LOG_LEVEL_NAMES.iter() + .position(|&name| name.eq_ignore_ascii_case(level)) + .map(|p| unsafe { mem::transmute(p) }) + } } -/// A LogRecord is created by the logging macros, and passed as the only -/// argument to Loggers. -#[derive(Show)] -pub struct LogRecord<'a> { +impl fmt::Display for LogLevelFilter { + fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result { + write!(fmt, "{}", LOG_LEVEL_NAMES[*self as usize]) + } +} - /// The module path of where the LogRecord originated. - pub module_path: &'a str, +impl LogLevelFilter { + /// Returns the most verbose logging level filter. + #[inline] + pub fn max() -> LogLevelFilter { + LogLevelFilter::Trace + } - /// The LogLevel of this record. - pub level: LogLevel, + /// Converts `self` to the equivalent `LogLevel`. + /// + /// Returns `None` if `self` is `LogLevel::Off`. + #[inline] + pub fn to_log_level(&self) -> Option { + match *self { + LogLevelFilter::Off => None, + v => unsafe { Some(mem::transmute((v as usize) - 1)) } + } + } +} - /// The arguments from the log line. +/// The "payload" of a log message. +pub struct LogRecord<'a> { + /// The message body. pub args: fmt::Arguments<'a>, + /// The location of the log directive. + pub location: &'static LogLocation, + /// The verbosity level of the message. + pub level: LogLevel, +} - /// The file of where the LogRecord originated. - pub file: &'a str, - - /// The line number of where the LogRecord originated. - pub line: usize, +/// A trait encapsulating the operations required of a logger +pub trait Log: Sync+Send { + /// Determines if a log message sent at the specified level from the + /// specified module would be logged. + /// + /// This is used by the `log_enabled!` macro to allow callers to avoid + /// expensive computation of log message arguments if the message would be + /// discarded anyway. + fn enabled(&self, level: LogLevel, module: &str) -> bool; + + /// Logs the `LogRecord`. + /// + /// Note that `enabled` is *not* necessarily called before this method. + /// Implementations of `log` should perform all necessary filtering + /// internally. + fn log(&self, record: &LogRecord); } -#[doc(hidden)] +/// The location of a log message. +#[derive(Copy, Clone, Debug)] pub struct LogLocation { + /// The module path of the message. pub module_path: &'static str, + /// The source file containing the message. pub file: &'static str, + /// The line containing the message. pub line: usize, } -impl Copy for LogLocation {} - -/// Tests whether a given module's name is enabled for a particular level of -/// logging. This is the second layer of defense about determining whether a -/// module's log statement should be emitted or not. -#[doc(hidden)] -pub fn mod_enabled(level: u32, module: &str) -> bool { - static INIT: Once = ONCE_INIT; - INIT.call_once(init); - - // It's possible for many threads are in this function, only one of them - // will perform the global initialization, but all of them will need to check - // again to whether they should really be here or not. Hence, despite this - // check being expanded manually in the logging macro, this function checks - // the log level again. - if level > unsafe { LOG_LEVEL } { return false } - - // This assertion should never get tripped unless we're in an at_exit - // handler after logging has been torn down and a logging attempt was made. - assert!(unsafe { !DIRECTIVES.is_null() }); - - enabled(level, module, unsafe { (*DIRECTIVES).iter() }) -} - -fn enabled(level: u32, - module: &str, - iter: slice::Iter) - -> bool { - // Search for the longest match, the vector is assumed to be pre-sorted. - for directive in iter.rev() { - match directive.name { - Some(ref name) if !module.starts_with(name.as_slice()) => {}, - Some(..) | None => { - return level <= directive.level - } - } +/// A token providing read and write access to the global maximum log level +/// filter. +/// +/// The maximum log level is used as an optimization to avoid evaluating log +/// messages that will be ignored by the logger. Any message with a level +/// higher than the maximum log level filter will be ignored. A logger should +/// make sure to keep the maximum log level filter in sync with its current +/// configuration. +#[allow(missing_copy_implementations)] +pub struct MaxLogLevelFilter(()); + +impl fmt::Debug for MaxLogLevelFilter { + fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result { + write!(fmt, "MaxLogLevelFilter") } - level <= DEFAULT_LOG_LEVEL } -/// Initialize logging for the current process. +impl MaxLogLevelFilter { + /// Gets the current maximum log level filter. + pub fn get(&self) -> LogLevelFilter { + max_log_level() + } + + /// Sets the maximum log level. + pub fn set(&self, level: LogLevelFilter) { + MAX_LOG_LEVEL_FILTER.store(level as usize, Ordering::Relaxed) + } +} + +/// Returns the current maximum log level. /// -/// This is not threadsafe at all, so initialization is performed through a -/// `Once` primitive (and this function is called from that primitive). -fn init() { - let (mut directives, filter) = match os::getenv("RUST_LOG") { - Some(spec) => directive::parse_logging_spec(spec.as_slice()), - None => (Vec::new(), None), - }; - - // Sort the provided directives by length of their name, this allows a - // little more efficient lookup at runtime. - directives.sort_by(|a, b| { - let alen = a.name.as_ref().map(|a| a.len()).unwrap_or(0); - let blen = b.name.as_ref().map(|b| b.len()).unwrap_or(0); - alen.cmp(&blen) - }); +/// The `log!`, `error!`, `warn!`, `info!`, `debug!`, and `trace!` macros check +/// this value and discard any message logged at a higher level. The maximum +/// log level is set by the `MaxLogLevel` token passed to loggers. +#[inline(always)] +pub fn max_log_level() -> LogLevelFilter { + unsafe { mem::transmute(MAX_LOG_LEVEL_FILTER.load(Ordering::Relaxed)) } +} - let max_level = { - let max = directives.iter().max_by(|d| d.level); - max.map(|d| d.level).unwrap_or(DEFAULT_LOG_LEVEL) - }; +/// Sets the global logger. +/// +/// The `make_logger` closure is passed a `MaxLogLevel` object, which the +/// logger should use to keep the global maximum log level in sync with the +/// highest log level that the logger will not ignore. +/// +/// This function may only be called once in the lifetime of a program. Any log +/// events that occur before the call to `set_logger` completes will be +/// ignored. +/// +/// This function does not typically need to be called manually. Logger +/// implementations should provide an initialization method that calls +/// `set_logger` internally. +pub fn set_logger(make_logger: M) -> Result<(), SetLoggerError> + where M: FnOnce(MaxLogLevelFilter) -> Box { + if LOGGER.compare_and_swap(UNINITIALIZED, INITIALIZING, Ordering::Relaxed) != UNINITIALIZED { + return Err(SetLoggerError); + } - unsafe { - LOG_LEVEL = max_level; + let logger = Box::new(make_logger(MaxLogLevelFilter(()))); + let logger = unsafe { mem::transmute::>, usize>(logger) }; + LOGGER.store(logger, Ordering::Release); + rt::at_exit(|| { + // Set to INITIALIZING to prevent re-initialization after + let logger = LOGGER.swap(INITIALIZING, Ordering::Acquire); - assert!(FILTER.is_null()); - match filter { - Some(f) => FILTER = mem::transmute(Box::new(f)), - None => {} + while REFCOUNT.load(Ordering::Relaxed) != 0 { + // FIXME add a sleep here when it doesn't involve timers } - assert!(DIRECTIVES.is_null()); - DIRECTIVES = mem::transmute(Box::new(directives)); - - // Schedule the cleanup for the globals for when the runtime exits. - rt::at_exit(|| { - assert!(!DIRECTIVES.is_null()); - let _directives: Box> = - mem::transmute(DIRECTIVES); - DIRECTIVES = 0 as *const Vec; - - if !FILTER.is_null() { - let _filter: Box = mem::transmute(FILTER); - FILTER = 0 as *const _; - } - }); - } + unsafe { mem::transmute::>>(logger); } + }); + + Ok(()) } -#[cfg(test)] -mod tests { - use super::enabled; - use directive::LogDirective; - - #[test] - fn match_full_path() { - let dirs = [ - LogDirective { - name: Some("crate2".to_string()), - level: 3 - }, - LogDirective { - name: Some("crate1::mod1".to_string()), - level: 2 - } - ]; - assert!(enabled(2, "crate1::mod1", dirs.iter())); - assert!(!enabled(3, "crate1::mod1", dirs.iter())); - assert!(enabled(3, "crate2", dirs.iter())); - assert!(!enabled(4, "crate2", dirs.iter())); +/// The type returned by `set_logger` if `set_logger` has already been called. +#[allow(missing_copy_implementations)] +#[derive(Debug)] +pub struct SetLoggerError; + +impl fmt::Display for SetLoggerError { + fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result { + write!(fmt, "Attempted to set a logger after the logging system was already initialized") } +} - #[test] - fn no_match() { - let dirs = [ - LogDirective { name: Some("crate2".to_string()), level: 3 }, - LogDirective { name: Some("crate1::mod1".to_string()), level: 2 } - ]; - assert!(!enabled(2, "crate3", dirs.iter())); +struct LoggerGuard(usize); + +impl Drop for LoggerGuard { + fn drop(&mut self) { + REFCOUNT.fetch_sub(1, Ordering::Relaxed); } +} + +impl Deref for LoggerGuard { + type Target = Box; - #[test] - fn match_beginning() { - let dirs = [ - LogDirective { name: Some("crate2".to_string()), level: 3 }, - LogDirective { name: Some("crate1::mod1".to_string()), level: 2 } - ]; - assert!(enabled(3, "crate2::mod1", dirs.iter())); + fn deref(&self) -> &Box { + unsafe { mem::transmute(self.0) } } +} - #[test] - fn match_beginning_longest_match() { - let dirs = [ - LogDirective { name: Some("crate2".to_string()), level: 3 }, - LogDirective { name: Some("crate2::mod".to_string()), level: 4 }, - LogDirective { name: Some("crate1::mod1".to_string()), level: 2 } - ]; - assert!(enabled(4, "crate2::mod1", dirs.iter())); - assert!(!enabled(4, "crate2", dirs.iter())); +fn logger() -> Option { + REFCOUNT.fetch_add(1, Ordering::Relaxed); + let logger = LOGGER.load(Ordering::Acquire); + if logger == UNINITIALIZED || logger == INITIALIZING { + REFCOUNT.fetch_sub(1, Ordering::Relaxed); + None + } else { + Some(LoggerGuard(logger)) } +} - #[test] - fn match_default() { - let dirs = [ - LogDirective { name: None, level: 3 }, - LogDirective { name: Some("crate1::mod1".to_string()), level: 2 } - ]; - assert!(enabled(2, "crate1::mod1", dirs.iter())); - assert!(enabled(3, "crate2::mod2", dirs.iter())); +/// Determines if the current logger will ignore a log message at the specified +/// level from the specified module. +/// +/// This should not typically be called directly. The `log_enabled!` macro +/// should be used instead. +pub fn enabled(level: LogLevel, module: &str) -> bool { + if let Some(logger) = logger() { + logger.enabled(level, module) + } else { + false } +} - #[test] - fn zero_level() { - let dirs = [ - LogDirective { name: None, level: 3 }, - LogDirective { name: Some("crate1::mod1".to_string()), level: 0 } - ]; - assert!(!enabled(1, "crate1::mod1", dirs.iter())); - assert!(enabled(3, "crate2::mod2", dirs.iter())); +/// Logs a message. +/// +/// This should not typically be called directly. The `log!`, `error!`, +/// `warn!`, `info!`, `debug!`, and `trace!` macros should be used instead. +pub fn log(level: LogLevel, loc: &'static LogLocation, args: fmt::Arguments) { + if let Some(logger) = logger() { + logger.log(&LogRecord { + args: args, + location: loc, + level: level, + }) } } + +#[cfg(test)] +mod tests { + use super::{LogLevel, LogLevelFilter}; + + #[test] + fn test_loglevelfilter_from_str() { + let tests = [ + ("off", Some(LogLevelFilter::Off)), + ("error", Some(LogLevelFilter::Error)), + ("warn", Some(LogLevelFilter::Warn)), + ("info", Some(LogLevelFilter::Info)), + ("debug", Some(LogLevelFilter::Debug)), + ("trace", Some(LogLevelFilter::Trace)), + ("OFF", Some(LogLevelFilter::Off)), + ("ERROR", Some(LogLevelFilter::Error)), + ("WARN", Some(LogLevelFilter::Warn)), + ("INFO", Some(LogLevelFilter::Info)), + ("DEBUG", Some(LogLevelFilter::Debug)), + ("TRACE", Some(LogLevelFilter::Trace)), + ]; + for &(s, ref expected) in tests.iter() { + assert_eq!(expected, &s.parse()); + } + } + + #[test] + fn test_loglevel_from_str() { + let tests = [ + ("OFF", None), + ("error", Some(LogLevel::Error)), + ("warn", Some(LogLevel::Warn)), + ("info", Some(LogLevel::Info)), + ("debug", Some(LogLevel::Debug)), + ("trace", Some(LogLevel::Trace)), + ("ERROR", Some(LogLevel::Error)), + ("WARN", Some(LogLevel::Warn)), + ("INFO", Some(LogLevel::Info)), + ("DEBUG", Some(LogLevel::Debug)), + ("TRACE", Some(LogLevel::Trace)), + ]; + for &(s, ref expected) in tests.iter() { + assert_eq!(expected, &s.parse()); + } + } + + #[test] + fn test_loglevel_show() { + assert_eq!("INFO", LogLevel::Info.to_string()); + assert_eq!("ERROR", LogLevel::Error.to_string()); + } + + #[test] + fn test_cross_cmp() { + assert!(LogLevel::Debug > LogLevelFilter::Error); + assert!(LogLevelFilter::Warn < LogLevel::Trace); + assert!(LogLevelFilter::Off < LogLevel::Error); + } + + #[test] + fn test_cross_eq() { + assert!(LogLevel::Error == LogLevelFilter::Error); + assert!(LogLevelFilter::Off != LogLevel::Error); + assert!(LogLevel::Trace == LogLevelFilter::Trace); + } + + #[test] + fn test_to_log_level() { + assert_eq!(Some(LogLevel::Error), LogLevelFilter::Error.to_log_level()); + assert_eq!(None, LogLevelFilter::Off.to_log_level()); + assert_eq!(Some(LogLevel::Debug), LogLevelFilter::Debug.to_log_level()); + } + + #[test] + fn test_to_log_level_filter() { + assert_eq!(LogLevelFilter::Error, LogLevel::Error.to_log_level_filter()); + assert_eq!(LogLevelFilter::Trace, LogLevel::Trace.to_log_level_filter()); + } +} diff --git a/src/macros.rs b/src/macros.rs index c36d3e027..2adf76f58 100644 --- a/src/macros.rs +++ b/src/macros.rs @@ -1,199 +1,151 @@ -// Copyright 2014 The Rust Project Developers. See the COPYRIGHT -// file at the top-level directory of this distribution and at -// http://rust-lang.org/COPYRIGHT. -// -// Licensed under the Apache License, Version 2.0 or the MIT license -// , at your -// option. This file may not be copied, modified, or distributed -// except according to those terms. - -//! Logging macros - -/// The standard logging macro -/// -/// This macro will generically log over a provided level (of type u32) with a -/// format!-based argument list. See documentation in `std::fmt` for details on -/// how to use the syntax. -/// -/// # Example -/// -/// ``` -/// #[macro_use] extern crate log; -/// -/// fn main() { -/// log!(log::WARN, "this is a warning {}", "message"); -/// log!(log::DEBUG, "this is a debug message"); -/// log!(6, "this is a custom logging level: {level}", level=6u); -/// } -/// ``` -/// -/// Assumes the binary is `main`: -/// -/// ```{.bash} -/// $ RUST_LOG=warn ./main -/// WARN:main: this is a warning message -/// ``` +/// The standard logging macro. /// -/// ```{.bash} -/// $ RUST_LOG=debug ./main -/// DEBUG:main: this is a debug message -/// WARN:main: this is a warning message -/// ``` -/// -/// ```{.bash} -/// $ RUST_LOG=6 ./main -/// DEBUG:main: this is a debug message -/// WARN:main: this is a warning message -/// 6:main: this is a custom logging level: 6 -/// ``` +/// This macro will generically log with the specified `LogLevel` and `format!` +/// based argument list. #[macro_export] macro_rules! log { ($lvl:expr, $($arg:tt)+) => ({ - static LOC: ::log::LogLocation = ::log::LogLocation { + static LOC: $crate::LogLocation = $crate::LogLocation { line: line!(), file: file!(), module_path: module_path!(), }; let lvl = $lvl; - if log_enabled!(lvl) { - ::log::log(lvl, &LOC, format_args!($($arg)+)); + if lvl <= $crate::max_log_level() { + $crate::log(lvl, &LOC, format_args!($($arg)+)) } }) } -/// A convenience macro for logging at the error log level. -/// -/// # Example -/// -/// ``` -/// #[macro_use] extern crate log; -/// -/// fn main() { -/// let error = 3u; -/// error!("the build has failed with error code: {}", error); -/// } -/// ``` -/// -/// Assumes the binary is `main`: -/// -/// ```{.bash} -/// $ RUST_LOG=error ./main -/// ERROR:main: the build has failed with error code: 3 -/// ``` +/// Logs a message at the error level. /// +/// Logging through this macro is disabled if the `log_level = "off"` cfg is +/// present. #[macro_export] macro_rules! error { - ($($arg:tt)*) => (log!(::log::ERROR, $($arg)*)) + ($($arg:tt)*) => ( + match () { + #[cfg(not(any(log_level = "off")))] + () => log!($crate::LogLevel::Error, $($arg)*), + #[cfg(any(log_level = "off"))] + () => {} + } + ) } -/// A convenience macro for logging at the warning log level. -/// -/// # Example -/// -/// ``` -/// #[macro_use] extern crate log; -/// -/// fn main() { -/// let code = 3u; -/// warn!("you may like to know that a process exited with: {}", code); -/// } -/// ``` -/// -/// Assumes the binary is `main`: +/// Logs a message at the warn level. /// -/// ```{.bash} -/// $ RUST_LOG=warn ./main -/// WARN:main: you may like to know that a process exited with: 3 -/// ``` +/// Logging through this macro is disabled if any of the following cfgs are +/// present: `log_level = "off"` or `log_level = "error"`. #[macro_export] macro_rules! warn { - ($($arg:tt)*) => (log!(::log::WARN, $($arg)*)) + ($($arg:tt)*) => ( + match () { + #[cfg(not(any(log_level = "off", + log_level = "error")))] + () => log!($crate::LogLevel::Warn, $($arg)*), + #[cfg(any(log_level = "off", + log_level = "error"))] + () => {} + } + ) } -/// A convenience macro for logging at the info log level. -/// -/// # Example -/// -/// ``` -/// #[macro_use] extern crate log; -/// -/// fn main() { -/// let ret = 3i; -/// info!("this function is about to return: {}", ret); -/// } -/// ``` +/// Logs a message at the info level. /// -/// Assumes the binary is `main`: -/// -/// ```{.bash} -/// $ RUST_LOG=info ./main -/// INFO:main: this function is about to return: 3 -/// ``` +/// Logging through this macro is disabled if any of the following cfgs are +/// present: `log_level = "off"`, `log_level = "error"`, or +/// `log_level = "warn"`. #[macro_export] macro_rules! info { - ($($arg:tt)*) => (log!(::log::INFO, $($arg)*)) + ($($arg:tt)*) => ( + match () { + #[cfg(not(any(log_level = "off", + log_level = "error", + log_level = "warn")))] + () => log!($crate::LogLevel::Info, $($arg)*), + #[cfg(any(log_level = "off", + log_level = "error", + log_level = "warn"))] + () => {} + } + ) } -/// A convenience macro for logging at the debug log level. This macro can also -/// be omitted at compile time by passing `--cfg ndebug` to the compiler. If -/// this option is not passed, then debug statements will be compiled. -/// -/// # Example -/// -/// ``` -/// #[macro_use] extern crate log; -/// -/// fn main() { -/// debug!("x = {x}, y = {y}", x=10i, y=20i); -/// } -/// ``` -/// -/// Assumes the binary is `main`: +/// Logs a message at the debug level. /// -/// ```{.bash} -/// $ RUST_LOG=debug ./main -/// DEBUG:main: x = 10, y = 20 -/// ``` +/// Logging through this macro is disabled if any of the following cfgs are +/// present: `log_level = "off"`, `log_level = "error"`, `log_level = "warn"`, +/// or `log_level = "info"`. #[macro_export] macro_rules! debug { - ($($arg:tt)*) => (if cfg!(not(ndebug)) { log!(::log::DEBUG, $($arg)*) }) + ($($arg:tt)*) => ( + match () { + #[cfg(not(any(log_level = "off", + log_level = "error", + log_level = "warn", + log_level = "info")))] + () => log!($crate::LogLevel::Debug, $($arg)*), + #[cfg(any(log_level = "off", + log_level = "error", + log_level = "warn", + log_level = "info"))] + () => {} + + } + ) } -/// A macro to test whether a log level is enabled for the current module. -/// -/// # Example -/// -/// ``` -/// #[macro_use] extern crate log; +/// Logs a message at the trace level. /// -/// struct Point { x: int, y: int } -/// fn some_expensive_computation() -> Point { Point { x: 1, y: 2 } } +/// Logging through this macro is disabled if any of the following cfgs are +/// present: `log_level = "off"`, `log_level = "error"`, `log_level = "warn"`, +/// `log_level = "info"`, or `log_level = "debug"`. +#[macro_export] +macro_rules! trace { + ($($arg:tt)*) => ( + match () { + #[cfg(not(any(log_level = "off", + log_level = "error", + log_level = "warn", + log_level = "info", + log_level = "debug")))] + () => log!($crate::LogLevel::Trace, $($arg)*), + #[cfg(any(log_level = "off", + log_level = "error", + log_level = "warn", + log_level = "info", + log_level = "debug"))] + () => {} + } + ) +} + +/// Determines if a message logged at the specified level in that module will +/// be logged. /// -/// fn main() { -/// if log_enabled!(log::DEBUG) { -/// let x = some_expensive_computation(); -/// debug!("x.x = {}, x.y = {}", x.x, x.y); -/// } -/// } -/// ``` +/// This can be used to avoid expensive computation of log message arguments if +/// the message would be ignored anyway. /// -/// Assumes the binary is `main`: +/// # Examples /// -/// ```{.bash} -/// $ RUST_LOG=error ./main -/// ``` +/// ```rust +/// # #[macro_use] +/// # extern crate log; +/// use log::LogLevel::Debug; /// -/// ```{.bash} -/// $ RUST_LOG=debug ./main -/// DEBUG:main: x.x = 1, x.y = 2 +/// # fn foo() { +/// if log_enabled!(Debug) { +/// debug!("expensive debug data: {}", expensive_call()); +/// } +/// # } +/// # fn expensive_call() -> u32 { 0 } +/// # fn main() {} /// ``` #[macro_export] macro_rules! log_enabled { ($lvl:expr) => ({ let lvl = $lvl; - (lvl != ::log::DEBUG || cfg!(not(ndebug))) && - lvl <= ::log::log_level() && - ::log::mod_enabled(lvl, module_path!()) + lvl <= $crate::max_log_level() && $crate::enabled(lvl, module_path!()) }) } From 28ce2f8b963e602da385c4c9698306ad1b1c8ae9 Mon Sep 17 00:00:00 2001 From: Steven Fackler Date: Mon, 26 Jan 2015 23:08:37 -0800 Subject: [PATCH 2/5] Update for @alexcrichton's comments --- src/lib.rs | 99 ++++++++++++++++++++++++++++++++++++--------------- src/macros.rs | 74 ++++++++++++++------------------------ 2 files changed, 97 insertions(+), 76 deletions(-) diff --git a/src/lib.rs b/src/lib.rs index 6ad77ffda..ec4d2f38b 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -92,8 +92,8 @@ //! } //! //! fn log(&self, record: &LogRecord) { -//! if self.enabled(record.level, record.location.module_path) { -//! println!("{} - {}", record.level, record.args); +//! if self.enabled(record.level(), record.location().module_path) { +//! println!("{} - {}", record.level(), record.args()); //! } //! } //! } @@ -183,7 +183,7 @@ pub enum LogLevel { /// The "error" level. /// /// Designates very serious errors. - Error, + Error = 1, // This way these line up with the discriminants for LogLevelFilter below /// The "warn" level. /// /// Designates hazardous situations. @@ -219,7 +219,7 @@ impl PartialEq for LogLevel { impl PartialEq for LogLevel { #[inline] fn eq(&self, other: &LogLevelFilter) -> bool { - (*self as usize) + 1 == *other as usize + *self as usize == *other as usize } } @@ -233,7 +233,7 @@ impl PartialOrd for LogLevel { impl PartialOrd for LogLevel { #[inline] fn partial_cmp(&self, other: &LogLevelFilter) -> Option { - Some(((*self as usize) + 1).cmp(&(*other as usize))) + Some((*self as usize).cmp(&(*other as usize))) } } @@ -250,18 +250,29 @@ impl FromStr for LogLevel { .position(|&name| name.eq_ignore_ascii_case(level)) .into_iter() .filter(|&idx| idx != 0) - .map(|idx| unsafe { mem::transmute(idx - 1) }) + .map(|idx| LogLevel::from_usize(idx).unwrap()) .next() } } impl fmt::Display for LogLevel { fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result { - write!(fmt, "{}", LOG_LEVEL_NAMES[(*self as usize) + 1]) + write!(fmt, "{}", LOG_LEVEL_NAMES[*self as usize]) } } impl LogLevel { + fn from_usize(u: usize) -> Option { + match u { + 1 => Some(LogLevel::Error), + 2 => Some(LogLevel::Warn), + 3 => Some(LogLevel::Info), + 4 => Some(LogLevel::Debug), + 5 => Some(LogLevel::Trace), + _ => None + } + } + /// Returns the most verbose logging level. #[inline] pub fn max() -> LogLevel { @@ -271,7 +282,7 @@ impl LogLevel { /// Converts the `LogLevel` to the equivalent `LogLevelFilter`. #[inline] pub fn to_log_level_filter(&self) -> LogLevelFilter { - unsafe { mem::transmute((*self as usize) + 1) } + LogLevelFilter::from_usize(*self as usize).unwrap() } } @@ -344,7 +355,7 @@ impl FromStr for LogLevelFilter { fn from_str(level: &str) -> Option { LOG_LEVEL_NAMES.iter() .position(|&name| name.eq_ignore_ascii_case(level)) - .map(|p| unsafe { mem::transmute(p) }) + .map(|p| LogLevelFilter::from_usize(p).unwrap()) } } @@ -355,6 +366,17 @@ impl fmt::Display for LogLevelFilter { } impl LogLevelFilter { + fn from_usize(u: usize) -> Option { + match u { + 0 => Some(LogLevelFilter::Off), + 1 => Some(LogLevelFilter::Error), + 2 => Some(LogLevelFilter::Warn), + 3 => Some(LogLevelFilter::Info), + 4 => Some(LogLevelFilter::Debug), + 5 => Some(LogLevelFilter::Trace), + _ => None + } + } /// Returns the most verbose logging level filter. #[inline] pub fn max() -> LogLevelFilter { @@ -366,21 +388,32 @@ impl LogLevelFilter { /// Returns `None` if `self` is `LogLevel::Off`. #[inline] pub fn to_log_level(&self) -> Option { - match *self { - LogLevelFilter::Off => None, - v => unsafe { Some(mem::transmute((v as usize) - 1)) } - } + LogLevel::from_usize(*self as usize) } } /// The "payload" of a log message. pub struct LogRecord<'a> { + args: fmt::Arguments<'a>, + location: &'a LogLocation, + level: LogLevel, +} + +impl<'a> LogRecord<'a> { /// The message body. - pub args: fmt::Arguments<'a>, + pub fn args(&self) -> &fmt::Arguments<'a> { + &self.args + } + /// The location of the log directive. - pub location: &'static LogLocation, + pub fn location(&self) -> &LogLocation { + self.location + } + /// The verbosity level of the message. - pub level: LogLevel, + pub fn level(&self) -> LogLevel { + self.level + } } /// A trait encapsulating the operations required of a logger @@ -437,7 +470,7 @@ impl MaxLogLevelFilter { /// Sets the maximum log level. pub fn set(&self, level: LogLevelFilter) { - MAX_LOG_LEVEL_FILTER.store(level as usize, Ordering::Relaxed) + MAX_LOG_LEVEL_FILTER.store(level as usize, Ordering::SeqCst) } } @@ -466,18 +499,18 @@ pub fn max_log_level() -> LogLevelFilter { /// `set_logger` internally. pub fn set_logger(make_logger: M) -> Result<(), SetLoggerError> where M: FnOnce(MaxLogLevelFilter) -> Box { - if LOGGER.compare_and_swap(UNINITIALIZED, INITIALIZING, Ordering::Relaxed) != UNINITIALIZED { - return Err(SetLoggerError); + if LOGGER.compare_and_swap(UNINITIALIZED, INITIALIZING, Ordering::SeqCst) != UNINITIALIZED { + return Err(SetLoggerError(())); } let logger = Box::new(make_logger(MaxLogLevelFilter(()))); let logger = unsafe { mem::transmute::>, usize>(logger) }; - LOGGER.store(logger, Ordering::Release); + LOGGER.store(logger, Ordering::SeqCst); rt::at_exit(|| { // Set to INITIALIZING to prevent re-initialization after - let logger = LOGGER.swap(INITIALIZING, Ordering::Acquire); + let logger = LOGGER.swap(INITIALIZING, Ordering::SeqCst); - while REFCOUNT.load(Ordering::Relaxed) != 0 { + while REFCOUNT.load(Ordering::SeqCst) != 0 { // FIXME add a sleep here when it doesn't involve timers } @@ -490,11 +523,11 @@ pub fn set_logger(make_logger: M) -> Result<(), SetLoggerError> /// The type returned by `set_logger` if `set_logger` has already been called. #[allow(missing_copy_implementations)] #[derive(Debug)] -pub struct SetLoggerError; +pub struct SetLoggerError(()); impl fmt::Display for SetLoggerError { fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result { - write!(fmt, "Attempted to set a logger after the logging system was already initialized") + write!(fmt, "attempted to set a logger after the logging system was already initialized") } } @@ -502,7 +535,7 @@ struct LoggerGuard(usize); impl Drop for LoggerGuard { fn drop(&mut self) { - REFCOUNT.fetch_sub(1, Ordering::Relaxed); + REFCOUNT.fetch_sub(1, Ordering::SeqCst); } } @@ -515,10 +548,10 @@ impl Deref for LoggerGuard { } fn logger() -> Option { - REFCOUNT.fetch_add(1, Ordering::Relaxed); - let logger = LOGGER.load(Ordering::Acquire); + REFCOUNT.fetch_add(1, Ordering::SeqCst); + let logger = LOGGER.load(Ordering::SeqCst); if logger == UNINITIALIZED || logger == INITIALIZING { - REFCOUNT.fetch_sub(1, Ordering::Relaxed); + REFCOUNT.fetch_sub(1, Ordering::SeqCst); None } else { Some(LoggerGuard(logger)) @@ -542,7 +575,7 @@ pub fn enabled(level: LogLevel, module: &str) -> bool { /// /// This should not typically be called directly. The `log!`, `error!`, /// `warn!`, `info!`, `debug!`, and `trace!` macros should be used instead. -pub fn log(level: LogLevel, loc: &'static LogLocation, args: fmt::Arguments) { +pub fn log(level: LogLevel, loc: &LogLocation, args: fmt::Arguments) { if let Some(logger) = logger() { logger.log(&LogRecord { args: args, @@ -571,6 +604,7 @@ mod tests { ("INFO", Some(LogLevelFilter::Info)), ("DEBUG", Some(LogLevelFilter::Debug)), ("TRACE", Some(LogLevelFilter::Trace)), + ("asdf", None), ]; for &(s, ref expected) in tests.iter() { assert_eq!(expected, &s.parse()); @@ -591,6 +625,7 @@ mod tests { ("INFO", Some(LogLevel::Info)), ("DEBUG", Some(LogLevel::Debug)), ("TRACE", Some(LogLevel::Trace)), + ("asdf", None), ]; for &(s, ref expected) in tests.iter() { assert_eq!(expected, &s.parse()); @@ -603,6 +638,12 @@ mod tests { assert_eq!("ERROR", LogLevel::Error.to_string()); } + #[test] + fn test_loglevelfilter_show() { + assert_eq!("OFF", LogLevelFilter::Off.to_string()); + assert_eq!("ERROR", LogLevelFilter::Error.to_string()); + } + #[test] fn test_cross_cmp() { assert!(LogLevel::Debug > LogLevelFilter::Error); diff --git a/src/macros.rs b/src/macros.rs index 2adf76f58..e4f7543de 100644 --- a/src/macros.rs +++ b/src/macros.rs @@ -24,11 +24,8 @@ macro_rules! log { #[macro_export] macro_rules! error { ($($arg:tt)*) => ( - match () { - #[cfg(not(any(log_level = "off")))] - () => log!($crate::LogLevel::Error, $($arg)*), - #[cfg(any(log_level = "off"))] - () => {} + if !cfg!(any(log_level = "off")) { + log!($crate::LogLevel::Error, $($arg)*); } ) } @@ -40,13 +37,9 @@ macro_rules! error { #[macro_export] macro_rules! warn { ($($arg:tt)*) => ( - match () { - #[cfg(not(any(log_level = "off", - log_level = "error")))] - () => log!($crate::LogLevel::Warn, $($arg)*), - #[cfg(any(log_level = "off", - log_level = "error"))] - () => {} + if !cfg!(any(log_level = "off", + log_level = "error")) { + log!($crate::LogLevel::Warn, $($arg)*); } ) } @@ -59,15 +52,10 @@ macro_rules! warn { #[macro_export] macro_rules! info { ($($arg:tt)*) => ( - match () { - #[cfg(not(any(log_level = "off", - log_level = "error", - log_level = "warn")))] - () => log!($crate::LogLevel::Info, $($arg)*), - #[cfg(any(log_level = "off", - log_level = "error", - log_level = "warn"))] - () => {} + if !cfg!(any(log_level = "off", + log_level = "error", + log_level = "warn")) { + log!($crate::LogLevel::Info, $($arg)*); } ) } @@ -80,18 +68,11 @@ macro_rules! info { #[macro_export] macro_rules! debug { ($($arg:tt)*) => ( - match () { - #[cfg(not(any(log_level = "off", - log_level = "error", - log_level = "warn", - log_level = "info")))] - () => log!($crate::LogLevel::Debug, $($arg)*), - #[cfg(any(log_level = "off", - log_level = "error", - log_level = "warn", - log_level = "info"))] - () => {} - + if !cfg!(any(log_level = "off", + log_level = "error", + log_level = "warn", + log_level = "info")) { + log!($crate::LogLevel::Debug, $($arg)*); } ) } @@ -104,19 +85,12 @@ macro_rules! debug { #[macro_export] macro_rules! trace { ($($arg:tt)*) => ( - match () { - #[cfg(not(any(log_level = "off", - log_level = "error", - log_level = "warn", - log_level = "info", - log_level = "debug")))] - () => log!($crate::LogLevel::Trace, $($arg)*), - #[cfg(any(log_level = "off", - log_level = "error", - log_level = "warn", - log_level = "info", - log_level = "debug"))] - () => {} + if !cfg!(any(log_level = "off", + log_level = "error", + log_level = "warn", + log_level = "info", + log_level = "debug")) { + log!($crate::LogLevel::Debug, $($arg)*); } ) } @@ -146,6 +120,12 @@ macro_rules! trace { macro_rules! log_enabled { ($lvl:expr) => ({ let lvl = $lvl; - lvl <= $crate::max_log_level() && $crate::enabled(lvl, module_path!()) + !cfg!(log_level = "off") && + (lvl <= $crate::LogLevel::Error || !cfg!(log_level = "error")) && + (lvl <= $crate::LogLevel::Warn || !cfg!(log_level = "warn")) && + (lvl <= $crate::LogLevel::Debug || !cfg!(log_level = "debug")) && + (lvl <= $crate::LogLevel::Info || !cfg!(log_level = "info")) && + lvl <= $crate::max_log_level() && + $crate::enabled(lvl, module_path!()) }) } From abf0c0aafd0b0eb4fc9f67c822c8279c979e6880 Mon Sep 17 00:00:00 2001 From: Steven Fackler Date: Mon, 26 Jan 2015 23:25:43 -0800 Subject: [PATCH 3/5] Add env_logger --- .gitignore | 4 +- env/Cargo.toml | 11 ++ env/src/lib.rs | 338 +++++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 351 insertions(+), 2 deletions(-) create mode 100644 env/Cargo.toml create mode 100644 env/src/lib.rs diff --git a/.gitignore b/.gitignore index 4fffb2f89..2c96eb1b6 100644 --- a/.gitignore +++ b/.gitignore @@ -1,2 +1,2 @@ -/target -/Cargo.lock +target/ +Cargo.lock diff --git a/env/Cargo.toml b/env/Cargo.toml new file mode 100644 index 000000000..03e9a4fda --- /dev/null +++ b/env/Cargo.toml @@ -0,0 +1,11 @@ +[package] +name = "env_logger" +version = "0.0.1" +authors = ["The Rust Project Developers"] + +[dependencies.log] +version = "0.1" +path = ".." + +[dependencies] +regex = "0.1" diff --git a/env/src/lib.rs b/env/src/lib.rs new file mode 100644 index 000000000..33654da9d --- /dev/null +++ b/env/src/lib.rs @@ -0,0 +1,338 @@ +// Copyright 2014-2015 The Rust Project Developers. See the COPYRIGHT +// file at the top-level directory of this distribution and at +// http://rust-lang.org/COPYRIGHT. +// +// Licensed under the Apache License, Version 2.0 or the MIT license +// , at your +// option. This file may not be copied, modified, or distributed +// except according to those terms. +#![allow(unstable)] +extern crate regex; +extern crate log; + +use regex::Regex; +use std::io::{self, LineBufferedWriter}; +use std::io::stdio::StdWriter; +use std::sync::Mutex; +use std::os; + +use log::{Log, LogLevel, LogLevelFilter, LogRecord, SetLoggerError}; + +struct Logger { + directives: Vec, + filter: Option, + out: Mutex>, +} + +impl Log for Logger { + fn enabled(&self, level: LogLevel, module: &str) -> bool { + // Search for the longest match, the vector is assumed to be pre-sorted. + for directive in self.directives.iter().rev() { + match directive.name { + Some(ref name) if !module.starts_with(&**name) => {}, + Some(..) | None => { + return level <= directive.level + } + } + } + false + } + + fn log(&self, record: &LogRecord) { + if !self.enabled(record.level(), record.location().module_path) { + return; + } + + if let Some(filter) = self.filter.as_ref() { + if filter.is_match(&*record.args().to_string()) { + return; + } + } + + let _ = writeln!(&mut *self.out.lock().unwrap(), + "{}:{}: {}", + record.level(), + record.location().module_path, + record.args()); + } +} + +struct LogDirective { + name: Option, + level: LogLevelFilter, +} + +pub fn init() -> Result<(), SetLoggerError> { + log::set_logger(|max_level| { + let (mut directives, filter) = match os::getenv("RUST_LOG") { + Some(spec) => parse_logging_spec(spec.as_slice()), + None => (Vec::new(), None), + }; + + // Sort the provided directives by length of their name, this allows a + // little more efficient lookup at runtime. + directives.sort_by(|a, b| { + let alen = a.name.as_ref().map(|a| a.len()).unwrap_or(0); + let blen = b.name.as_ref().map(|b| b.len()).unwrap_or(0); + alen.cmp(&blen) + }); + + let level = { + let max = directives.iter().max_by(|d| d.level); + max.map(|d| d.level).unwrap_or(LogLevelFilter::max()) + }; + max_level.set(level); + + Box::new(Logger { + directives: directives, + filter: filter, + out: Mutex::new(io::stderr()), + }) + }) +} + +/// Parse a logging specification string (e.g: "crate1,crate2::mod3,crate3::x=error/foo") +/// and return a vector with log directives. +fn parse_logging_spec(spec: &str) -> (Vec, Option) { + let mut dirs = Vec::new(); + + let mut parts = spec.split('/'); + let mods = parts.next(); + let filter = parts.next(); + if parts.next().is_some() { + println!("warning: invalid logging spec '{}', \ + ignoring it (too many '/'s)", spec); + return (dirs, None); + } + mods.map(|m| { for s in m.split(',') { + if s.len() == 0 { continue } + let mut parts = s.split('='); + let (log_level, name) = match (parts.next(), parts.next().map(|s| s.trim()), parts.next()) { + (Some(part0), None, None) => { + // if the single argument is a log-level string or number, + // treat that as a global fallback + match part0.parse() { + Some(num) => (num, None), + None => (LogLevelFilter::max(), Some(part0)), + } + } + (Some(part0), Some(""), None) => (LogLevelFilter::max(), Some(part0)), + (Some(part0), Some(part1), None) => { + match part1.parse() { + Some(num) => (num, Some(part0)), + _ => { + println!("warning: invalid logging spec '{}', \ + ignoring it", part1); + continue + } + } + }, + _ => { + println!("warning: invalid logging spec '{}', \ + ignoring it", s); + continue + } + }; + dirs.push(LogDirective { + name: name.map(|s| s.to_string()), + level: log_level, + }); + }}); + + let filter = filter.map_or(None, |filter| { + match Regex::new(filter) { + Ok(re) => Some(re), + Err(e) => { + println!("warning: invalid regex filter - {}", e); + None + } + } + }); + + return (dirs, filter); +} + +#[cfg(test)] +mod tests { + use std::io; + use std::sync::Mutex; + use log::{Log, LogLevel, LogLevelFilter}; + + use super::{Logger, LogDirective, parse_logging_spec}; + + fn make_logger(dirs: Vec) -> Logger { + Logger { + directives: dirs, + filter: None, + out: Mutex::new(io::stderr()) + } + } + + #[test] + fn match_full_path() { + let logger = make_logger(vec![ + LogDirective { + name: Some("crate2".to_string()), + level: LogLevelFilter::Info + }, + LogDirective { + name: Some("crate1::mod1".to_string()), + level: LogLevelFilter::Warn + } + ]); + assert!(logger.enabled(LogLevel::Warn, "crate1::mod1")); + assert!(!logger.enabled(LogLevel::Info, "crate1::mod1")); + assert!(logger.enabled(LogLevel::Info, "crate2")); + assert!(!logger.enabled(LogLevel::Debug, "crate2")); + } + + #[test] + fn no_match() { + let logger = make_logger(vec![ + LogDirective { name: Some("crate2".to_string()), level: LogLevelFilter::Info }, + LogDirective { name: Some("crate1::mod1".to_string()), level: LogLevelFilter::Warn } + ]); + assert!(!logger.enabled(LogLevel::Warn, "crate3")); + } + + #[test] + fn match_beginning() { + let logger = make_logger(vec![ + LogDirective { name: Some("crate2".to_string()), level: LogLevelFilter::Info }, + LogDirective { name: Some("crate1::mod1".to_string()), level: LogLevelFilter::Warn } + ]); + assert!(logger.enabled(LogLevel::Info, "crate2::mod1")); + } + + #[test] + fn match_beginning_longest_match() { + let logger = make_logger(vec![ + LogDirective { name: Some("crate2".to_string()), level: LogLevelFilter::Info }, + LogDirective { name: Some("crate2::mod".to_string()), level: LogLevelFilter::Debug }, + LogDirective { name: Some("crate1::mod1".to_string()), level: LogLevelFilter::Warn } + ]); + assert!(logger.enabled(LogLevel::Debug, "crate2::mod1")); + assert!(!logger.enabled(LogLevel::Debug, "crate2")); + } + + #[test] + fn match_default() { + let logger = make_logger(vec![ + LogDirective { name: None, level: LogLevelFilter::Info }, + LogDirective { name: Some("crate1::mod1".to_string()), level: LogLevelFilter::Warn } + ]); + assert!(logger.enabled(LogLevel::Warn, "crate1::mod1")); + assert!(logger.enabled(LogLevel::Info, "crate2::mod2")); + } + + #[test] + fn zero_level() { + let logger = make_logger(vec![ + LogDirective { name: None, level: LogLevelFilter::Info }, + LogDirective { name: Some("crate1::mod1".to_string()), level: LogLevelFilter::Off } + ]); + assert!(!logger.enabled(LogLevel::Error, "crate1::mod1")); + assert!(logger.enabled(LogLevel::Info, "crate2::mod2")); + } + + #[test] + fn parse_logging_spec_valid() { + let (dirs, filter) = parse_logging_spec("crate1::mod1=error,crate1::mod2,crate2=debug"); + assert_eq!(dirs.len(), 3); + assert_eq!(dirs[0].name, Some("crate1::mod1".to_string())); + assert_eq!(dirs[0].level, LogLevelFilter::Error); + + assert_eq!(dirs[1].name, Some("crate1::mod2".to_string())); + assert_eq!(dirs[1].level, LogLevelFilter::max()); + + assert_eq!(dirs[2].name, Some("crate2".to_string())); + assert_eq!(dirs[2].level, LogLevelFilter::Debug); + assert!(filter.is_none()); + } + + #[test] + fn parse_logging_spec_invalid_crate() { + // test parse_logging_spec with multiple = in specification + let (dirs, filter) = parse_logging_spec("crate1::mod1=warn=info,crate2=debug"); + assert_eq!(dirs.len(), 1); + assert_eq!(dirs[0].name, Some("crate2".to_string())); + assert_eq!(dirs[0].level, LogLevelFilter::Debug); + assert!(filter.is_none()); + } + + #[test] + fn parse_logging_spec_invalid_log_level() { + // test parse_logging_spec with 'noNumber' as log level + let (dirs, filter) = parse_logging_spec("crate1::mod1=noNumber,crate2=debug"); + assert_eq!(dirs.len(), 1); + assert_eq!(dirs[0].name, Some("crate2".to_string())); + assert_eq!(dirs[0].level, LogLevelFilter::Debug); + assert!(filter.is_none()); + } + + #[test] + fn parse_logging_spec_string_log_level() { + // test parse_logging_spec with 'warn' as log level + let (dirs, filter) = parse_logging_spec("crate1::mod1=wrong,crate2=warn"); + assert_eq!(dirs.len(), 1); + assert_eq!(dirs[0].name, Some("crate2".to_string())); + assert_eq!(dirs[0].level, LogLevelFilter::Warn); + assert!(filter.is_none()); + } + + #[test] + fn parse_logging_spec_empty_log_level() { + // test parse_logging_spec with '' as log level + let (dirs, filter) = parse_logging_spec("crate1::mod1=wrong,crate2="); + assert_eq!(dirs.len(), 1); + assert_eq!(dirs[0].name, Some("crate2".to_string())); + assert_eq!(dirs[0].level, LogLevelFilter::max()); + assert!(filter.is_none()); + } + + #[test] + fn parse_logging_spec_global() { + // test parse_logging_spec with no crate + let (dirs, filter) = parse_logging_spec("warn,crate2=debug"); + assert_eq!(dirs.len(), 2); + assert_eq!(dirs[0].name, None); + assert_eq!(dirs[0].level, LogLevelFilter::Warn); + assert_eq!(dirs[1].name, Some("crate2".to_string())); + assert_eq!(dirs[1].level, LogLevelFilter::Debug); + assert!(filter.is_none()); + } + + #[test] + fn parse_logging_spec_valid_filter() { + let (dirs, filter) = parse_logging_spec("crate1::mod1=error,crate1::mod2,crate2=debug/abc"); + assert_eq!(dirs.len(), 3); + assert_eq!(dirs[0].name, Some("crate1::mod1".to_string())); + assert_eq!(dirs[0].level, LogLevelFilter::Error); + + assert_eq!(dirs[1].name, Some("crate1::mod2".to_string())); + assert_eq!(dirs[1].level, LogLevelFilter::max()); + + assert_eq!(dirs[2].name, Some("crate2".to_string())); + assert_eq!(dirs[2].level, LogLevelFilter::Debug); + assert!(filter.is_some() && filter.unwrap().to_string() == "abc"); + } + + #[test] + fn parse_logging_spec_invalid_crate_filter() { + let (dirs, filter) = parse_logging_spec("crate1::mod1=error=warn,crate2=debug/a.c"); + assert_eq!(dirs.len(), 1); + assert_eq!(dirs[0].name, Some("crate2".to_string())); + assert_eq!(dirs[0].level, LogLevelFilter::Debug); + assert!(filter.is_some() && filter.unwrap().to_string() == "a.c"); + } + + #[test] + fn parse_logging_spec_empty_with_filter() { + let (dirs, filter) = parse_logging_spec("crate1/a*c"); + assert_eq!(dirs.len(), 1); + assert_eq!(dirs[0].name, Some("crate1".to_string())); + assert_eq!(dirs[0].level, LogLevelFilter::max()); + assert!(filter.is_some() && filter.unwrap().to_string() == "a*c"); + } +} From 3cb3bff11be9f58bbc1ba56e532dda5d842ca62c Mon Sep 17 00:00:00 2001 From: Steven Fackler Date: Mon, 26 Jan 2015 23:51:42 -0800 Subject: [PATCH 4/5] Add some documentation + copyright notices --- env/src/lib.rs | 122 +++++++++++++++++++++++++++++++++++++++++++++++++ src/lib.rs | 9 ++++ src/macros.rs | 9 ++++ 3 files changed, 140 insertions(+) diff --git a/env/src/lib.rs b/env/src/lib.rs index 33654da9d..04a6b238f 100644 --- a/env/src/lib.rs +++ b/env/src/lib.rs @@ -7,6 +7,123 @@ // , at your // option. This file may not be copied, modified, or distributed // except according to those terms. +//! A logger configured via an environment variable. +//! +//! ## Example +//! +//! ``` +//! #[macro_use] extern crate log; +//! extern crate env_logger; +//! +//! use log::LogLevel; +//! +//! fn main() { +//! env_logger::init().unwrap(); +//! +//! debug!("this is a debug {}", "message"); +//! error!("this is printed by default"); +//! +//! if log_enabled!(LogLevel::Info) { +//! let x = 3i * 4i; // expensive computation +//! info!("the answer was: {}", x); +//! } +//! } +//! ``` +//! +//! Assumes the binary is `main`: +//! +//! ```{.bash} +//! $ RUST_LOG=error ./main +//! ERROR:main: this is printed by default +//! ``` +//! +//! ```{.bash} +//! $ RUST_LOG=info ./main +//! ERROR:main: this is printed by default +//! INFO:main: the answer was: 12 +//! ``` +//! +//! ```{.bash} +//! $ RUST_LOG=debug ./main +//! DEBUG:main: this is a debug message +//! ERROR:main: this is printed by default +//! INFO:main: the answer was: 12 +//! ``` +//! +//! You can also set the log level on a per module basis: +//! +//! ```{.bash} +//! $ RUST_LOG=main=info ./main +//! ERROR:main: this is printed by default +//! INFO:main: the answer was: 12 +//! ``` +//! +//! And enable all logging: +//! +//! ```{.bash} +//! $ RUST_LOG=main ./main +//! DEBUG:main: this is a debug message +//! ERROR:main: this is printed by default +//! INFO:main: the answer was: 12 +//! ``` +//! +//! See the documentation for the log crate for more information about its API. +//! +//! ## Enabling logging +//! +//! Log levels are controlled on a per-module basis, and by default all logging is +//! disabled except for `error!`. Logging is controlled via the `RUST_LOG` +//! environment variable. The value of this environment variable is a +//! comma-separated list of logging directives. A logging directive is of the form: +//! +//! ```text +//! path::to::module=log_level +//! ``` +//! +//! The path to the module is rooted in the name of the crate it was compiled for, +//! so if your program is contained in a file `hello.rs`, for example, to turn on +//! logging for this file you would use a value of `RUST_LOG=hello`. +//! Furthermore, this path is a prefix-search, so all modules nested in the +//! specified module will also have logging enabled. +//! +//! The actual `log_level` is optional to specify. If omitted, all logging will be +//! enabled. If specified, it must be one of the strings `debug`, `error`, `info`, +//! `warn`, or `trace`. +//! +//! As the log level for a module is optional, the module to enable logging for is +//! also optional. If only a `log_level` is provided, then the global log level for +//! all modules is set to this value. +//! +//! Some examples of valid values of `RUST_LOG` are: +//! +//! * `hello` turns on all logging for the 'hello' module +//! * `info` turns on all info logging +//! * `hello=debug` turns on debug logging for 'hello' +//! * `hello,std::option` turns on hello, and std's option logging +//! * `error,hello=warn` turn on global error logging and also warn for hello +//! +//! ## Filtering results +//! +//! A RUST_LOG directive may include a regex filter. The syntax is to append `/` +//! followed by a regex. Each message is checked against the regex, and is only +//! logged if it matches. Note that the matching is done after formatting the log +//! string but before adding any logging meta-data. There is a single filter for all +//! modules. +//! +//! Some examples: +//! +//! * `hello/foo` turns on all logging for the 'hello' module where the log message +//! includes 'foo'. +//! * `info/f.o` turns on all info logging where the log message includes 'foo', +//! 'f1o', 'fao', etc. +//! * `hello=debug/foo*foo` turns on debug logging for 'hello' where the log +//! message includes 'foofoo' or 'fofoo' or 'fooooooofoo', etc. +//! * `error,hello=warn/[0-9] scopes` turn on global error logging and also warn for +//! hello. In both cases the log message must include a single digit number +//! followed by 'scopes'. +#![doc(html_logo_url = "http://www.rust-lang.org/logos/rust-logo-128x128-blk-v2.png", + html_favicon_url = "http://www.rust-lang.org/favicon.ico", + html_root_url = "http://doc.rust-lang.org/log/")] #![allow(unstable)] extern crate regex; extern crate log; @@ -63,6 +180,11 @@ struct LogDirective { level: LogLevelFilter, } +/// Initializes the global logger with an env logger. +/// +/// This should be called early in the execution of a Rust program, and the +/// global logger may only be initialized once. Future initialization attempts +/// will return an error. pub fn init() -> Result<(), SetLoggerError> { log::set_logger(|max_level| { let (mut directives, filter) = match os::getenv("RUST_LOG") { diff --git a/src/lib.rs b/src/lib.rs index ec4d2f38b..f454d843c 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -1,3 +1,12 @@ +// Copyright 2015 The Rust Project Developers. See the COPYRIGHT +// file at the top-level directory of this distribution and at +// http://rust-lang.org/COPYRIGHT. +// +// Licensed under the Apache License, Version 2.0 or the MIT license +// , at your +// option. This file may not be copied, modified, or distributed +// except according to those terms. //! A lightweight logging facade. //! //! A logging facade provides a single logging API that abstracts over the diff --git a/src/macros.rs b/src/macros.rs index e4f7543de..eb225130c 100644 --- a/src/macros.rs +++ b/src/macros.rs @@ -1,3 +1,12 @@ +// Copyright 2014-2015 The Rust Project Developers. See the COPYRIGHT +// file at the top-level directory of this distribution and at +// http://rust-lang.org/COPYRIGHT. +// +// Licensed under the Apache License, Version 2.0 or the MIT license +// , at your +// option. This file may not be copied, modified, or distributed +// except according to those terms. /// The standard logging macro. /// /// This macro will generically log with the specified `LogLevel` and `format!` From 587258c8c3a664cf65eeda61efb1a76dd7f83797 Mon Sep 17 00:00:00 2001 From: Steven Fackler Date: Mon, 26 Jan 2015 23:56:55 -0800 Subject: [PATCH 5/5] Add stuff to README --- README.md | 58 +++++++++++++++++++++++++++++++++++++++++++++++++------ 1 file changed, 52 insertions(+), 6 deletions(-) diff --git a/README.md b/README.md index d315533ef..860ec326a 100644 --- a/README.md +++ b/README.md @@ -12,22 +12,68 @@ logging implementation. Libraries can use the logging API provided by this crate, and the consumer of those libraries can choose the logging implementation that is most suitable for its use case. -Libraries should simply depend on the `log` crate, using the various logging -macros as they like. Applications should choose a logging implementation that -will process all logging messages. - ## Usage -Add this to your `Cargo.toml`: +## In libraries + +Libraries should link only to the `log` crate, and use the provided macros to +log whatever information will be useful to downstream consumers: ```toml [dependencies] log = "0.2" ``` -and this to your crate root: +```rust +#[macro_use] +extern crate log; + +pub fn shave_the_yak(yak: &Yak) { + trace!("Commencing yak shaving"); + + loop { + match find_a_razor() { + Ok(razor) => { + info!("Razor located: {}", razor); + yak.shave(razor); + break; + } + Err(err) => { + warn!("Unable to locate a razor: {}, retrying", err); + } + } + } +} +``` + +## In executables + +Executables should chose a logger implementation and initialize it early in the +runtime of the program. Logger implementations will typically include a +function to do this. Any log messages generated before the logger is +initialized will be ignored. + +The executable itself may use the `log` crate to log as well. + +The `env_logger` crate provides a logger implementation that mirrors the +functionality of the old revision of the `log` crate. + +```toml +[dependencies] +log = "0.2" +env_logger = "0.1" +``` ```rust #[macro_use] extern crate log; +extern crate env_logger; + +fn main() { + env_logger::init().unwrap(); + + info!("starting up"); + + // ... +} ```