src/liblog/lib.rs

   1 // Copyright 2014 The Rust Project Developers. See the COPYRIGHT
   2 // file at the top-level directory of this distribution and at
   3 // http://rust-lang.org/COPYRIGHT.
   4 //
   5 // Licensed under the Apache License, Version 2.0 <LICENSE-APACHE or
   6 // http://www.apache.org/licenses/LICENSE-2.0> or the MIT license
   7 // <LICENSE-MIT or http://opensource.org/licenses/MIT>, at your
   8 // option. This file may not be copied, modified, or distributed
   9 // except according to those terms.
  10
  11 //! Utilities for program-wide and customizable logging
  12 //!
  13 //! ## Example
  14 //!
  15 //! ```
  16 //! #![feature(phase)]
  17 //! #[phase(plugin, link)] extern crate log;
  18 //!
  19 //! fn main() {
  20 //!     debug!("this is a debug {}", "message");
  21 //!     error!("this is printed by default");
  22 //!
  23 //!     if log_enabled!(log::INFO) {
  24 //!         let x = 3i * 4i; // expensive computation
  25 //!         info!("the answer was: {}", x);
  26 //!     }
  27 //! }
  28 //! ```
  29 //!
  30 //! Assumes the binary is `main`:
  31 //!
  32 //! ```{.bash}
  33 //! $ RUST_LOG=error ./main
  34 //! ERROR:main: this is printed by default
  35 //! ```
  36 //!
  37 //! ```{.bash}
  38 //! $ RUST_LOG=info ./main
  39 //! ERROR:main: this is printed by default
  40 //! INFO:main: the answer was: 12
  41 //! ```
  42 //!
  43 //! ```{.bash}
  44 //! $ RUST_LOG=debug ./main
  45 //! DEBUG:main: this is a debug message
  46 //! ERROR:main: this is printed by default
  47 //! INFO:main: the answer was: 12
  48 //! ```
  49 //!
  50 //! You can also set the log level on a per module basis:
  51 //!
  52 //! ```{.bash}
  53 //! $ RUST_LOG=main=info ./main
  54 //! ERROR:main: this is printed by default
  55 //! INFO:main: the answer was: 12
  56 //! ```
  57 //!
  58 //! And enable all logging:
  59 //!
  60 //! ```{.bash}
  61 //! $ RUST_LOG=main ./main
  62 //! DEBUG:main: this is a debug message
  63 //! ERROR:main: this is printed by default
  64 //! INFO:main: the answer was: 12
  65 //! ```
  66 //!
  67 //!
  68 //! ## Logging Macros
  69 //!
  70 //! There are five macros that the logging subsystem uses:
  71 //!
  72 //! * `log!(level, ...)` - the generic logging macro, takes a level as a u32 and any
  73 //!                        related `format!` arguments
  74 //! * `debug!(...)` - a macro hard-wired to the log level of `DEBUG`
  75 //! * `info!(...)` - a macro hard-wired to the log level of `INFO`
  76 //! * `warn!(...)` - a macro hard-wired to the log level of `WARN`
  77 //! * `error!(...)` - a macro hard-wired to the log level of `ERROR`
  78 //!
  79 //! All of these macros use the same style of syntax as the `format!` syntax
  80 //! extension. Details about the syntax can be found in the documentation of
  81 //! `std::fmt` along with the Rust tutorial/manual.
  82 //!
  83 //! If you want to check at runtime if a given logging level is enabled (e.g. if the
  84 //! information you would want to log is expensive to produce), you can use the
  85 //! following macro:
  86 //!
  87 //! * `log_enabled!(level)` - returns true if logging of the given level is enabled
  88 //!
  89 //! ## Enabling logging
  90 //!
  91 //! Log levels are controlled on a per-module basis, and by default all logging is
  92 //! disabled except for `error!` (a log level of 1). Logging is controlled via the
  93 //! `RUST_LOG` environment variable. The value of this environment variable is a
  94 //! comma-separated list of logging directives. A logging directive is of the form:
  95 //!
  96 //! ```text
  97 //! path::to::module=log_level
  98 //! ```
  99 //!
 100 //! The path to the module is rooted in the name of the crate it was compiled for,
 101 //! so if your program is contained in a file `hello.rs`, for example, to turn on
 102 //! logging for this file you would use a value of `RUST_LOG=hello`.
 103 //! Furthermore, this path is a prefix-search, so all modules nested in the
 104 //! specified module will also have logging enabled.
 105 //!
 106 //! The actual `log_level` is optional to specify. If omitted, all logging will be
 107 //! enabled. If specified, the it must be either a numeric in the range of 1-255, or
 108 //! it must be one of the strings `debug`, `error`, `info`, or `warn`. If a numeric
 109 //! is specified, then all logging less than or equal to that numeral is enabled.
 110 //! For example, if logging level 3 is active, error, warn, and info logs will be
 111 //! printed, but debug will be omitted.
 112 //!
 113 //! As the log level for a module is optional, the module to enable logging for is
 114 //! also optional. If only a `log_level` is provided, then the global log level for
 115 //! all modules is set to this value.
 116 //!
 117 //! Some examples of valid values of `RUST_LOG` are:
 118 //!
 119 //! * `hello` turns on all logging for the 'hello' module
 120 //! * `info` turns on all info logging
 121 //! * `hello=debug` turns on debug logging for 'hello'
 122 //! * `hello=3` turns on info logging for 'hello'
 123 //! * `hello,std::option` turns on hello, and std's option logging
 124 //! * `error,hello=warn` turn on global error logging and also warn for hello
 125 //!
 126 //! ## Filtering results
 127 //!
 128 //! A RUST_LOG directive may include a regex filter. The syntax is to append `/`
 129 //! followed by a regex. Each message is checked against the regex, and is only
 130 //! logged if it matches. Note that the matching is done after formatting the log
 131 //! string but before adding any logging meta-data. There is a single filter for all
 132 //! modules.
 133 //!
 134 //! Some examples:
 135 //!
 136 //! * `hello/foo` turns on all logging for the 'hello' module where the log message
 137 //! includes 'foo'.
 138 //! * `info/f.o` turns on all info logging where the log message includes 'foo',
 139 //! 'f1o', 'fao', etc.
 140 //! * `hello=debug/foo*foo` turns on debug logging for 'hello' where the the log
 141 //! message includes 'foofoo' or 'fofoo' or 'fooooooofoo', etc.
 142 //! * `error,hello=warn/[0-9] scopes` turn on global error logging and also warn for
 143 //!  hello. In both cases the log message must include a single digit number
 144 //!  followed by 'scopes'
 145 //!
 146 //! ## Performance and Side Effects
 147 //!
 148 //! Each of these macros will expand to code similar to:
 149 //!
 150 //! ```rust,ignore
 151 //! if log_level <= my_module_log_level() {
 152 //!     ::log::log(log_level, format!(...));
 153 //! }
 154 //! ```
 155 //!
 156 //! What this means is that each of these macros are very cheap at runtime if
 157 //! they're turned off (just a load and an integer comparison). This also means that
 158 //! if logging is disabled, none of the components of the log will be executed.
 159
 160 #![crate_name = "log"]
 161 #![experimental]
 162 #![license = "MIT/ASL2"]
 163 #![crate_type = "rlib"]
 164 #![crate_type = "dylib"]
 165 #![doc(html_logo_url = "http://www.rust-lang.org/logos/rust-logo-128x128-blk-v2.png",
 166        html_favicon_url = "http://www.rust-lang.org/favicon.ico",
 167        html_root_url = "http://doc.rust-lang.org/master/",
 168        html_playground_url = "http://play.rust-lang.org/")]
 169 #![feature(macro_rules)]
 170 #![deny(missing_doc)]
 171
 172 extern crate regex;
 173
 174 use regex::Regex;
 175 use std::fmt;
 176 use std::io::LineBufferedWriter;
 177 use std::io;
 178 use std::mem;
 179 use std::os;
 180 use std::rt;
 181 use std::slice;
 182 use std::sync::{Once, ONCE_INIT};
 183
 184 use directive::LOG_LEVEL_NAMES;
 185
 186 pub mod macros;
 187 mod directive;
 188
 189 /// Maximum logging level of a module that can be specified. Common logging
 190 /// levels are found in the DEBUG/INFO/WARN/ERROR constants.
 191 pub static MAX_LOG_LEVEL: u32 = 255;
 192
 193 /// The default logging level of a crate if no other is specified.
 194 static DEFAULT_LOG_LEVEL: u32 = 1;
 195
 196 /// An unsafe constant that is the maximum logging level of any module
 197 /// specified. This is the first line of defense to determining whether a
 198 /// logging statement should be run.
 199 static mut LOG_LEVEL: u32 = MAX_LOG_LEVEL;
 200
 201 static mut DIRECTIVES: *const Vec<directive::LogDirective> =
 202     0 as *const Vec<directive::LogDirective>;
 203
 204 /// Optional regex filter.
 205 static mut FILTER: *const Regex = 0 as *const _;
 206
 207 /// Debug log level
 208 pub static DEBUG: u32 = 4;
 209 /// Info log level
 210 pub static INFO: u32 = 3;
 211 /// Warn log level
 212 pub static WARN: u32 = 2;
 213 /// Error log level
 214 pub static ERROR: u32 = 1;
 215
 216 local_data_key!(local_logger: Box<Logger + Send>)
 217
 218 /// A trait used to represent an interface to a task-local logger. Each task
 219 /// can have its own custom logger which can respond to logging messages
 220 /// however it likes.
 221 pub trait Logger {
 222     /// Logs a single message described by the `record`.
 223     fn log(&mut self, record: &LogRecord);
 224 }
 225
 226 struct DefaultLogger {
 227     handle: LineBufferedWriter<io::stdio::StdWriter>,
 228 }
 229
 230 /// Wraps the log level with fmt implementations.
 231 #[deriving(PartialEq, PartialOrd)]
 232 pub struct LogLevel(pub u32);
 233
 234 impl fmt::Show for LogLevel {
 235     fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result {
 236         let LogLevel(level) = *self;
 237         match LOG_LEVEL_NAMES.get(level as uint - 1) {
 238             Some(name) => name.fmt(fmt),
 239             None => level.fmt(fmt)
 240         }
 241     }
 242 }
 243
 244 impl fmt::Signed for LogLevel {
 245     fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result {
 246         let LogLevel(level) = *self;
 247         write!(fmt, "{}", level)
 248     }
 249 }
 250
 251 impl Logger for DefaultLogger {
 252     fn log(&mut self, record: &LogRecord) {
 253         match writeln!(&mut self.handle,
 254                        "{}:{}: {}",
 255                        record.level,
 256                        record.module_path,
 257                        record.args) {
 258             Err(e) => fail!("failed to log: {}", e),
 259             Ok(()) => {}
 260         }
 261     }
 262 }
 263
 264 impl Drop for DefaultLogger {
 265     fn drop(&mut self) {
 266         // FIXME(#12628): is failure the right thing to do?
 267         match self.handle.flush() {
 268             Err(e) => fail!("failed to flush a logger: {}", e),
 269             Ok(()) => {}
 270         }
 271     }
 272 }
 273
 274 /// This function is called directly by the compiler when using the logging
 275 /// macros. This function does not take into account whether the log level
 276 /// specified is active or not, it will always log something if this method is
 277 /// called.
 278 ///
 279 /// It is not recommended to call this function directly, rather it should be
 280 /// invoked through the logging family of macros.
 281 #[doc(hidden)]
 282 pub fn log(level: u32, loc: &'static LogLocation, args: &fmt::Arguments) {
 283     // Test the literal string from args against the current filter, if there
 284     // is one.
 285     match unsafe { FILTER.as_ref() } {
 286         Some(filter) if filter.is_match(args.to_string().as_slice()) => return,
 287         _ => {}
 288     }
 289
 290     // Completely remove the local logger from TLS in case anyone attempts to
 291     // frob the slot while we're doing the logging. This will destroy any logger
 292     // set during logging.
 293     let mut logger = local_logger.replace(None).unwrap_or_else(|| {
 294         box DefaultLogger { handle: io::stderr() } as Box<Logger + Send>
 295     });
 296     logger.log(&LogRecord {
 297         level: LogLevel(level),
 298         args: args,
 299         file: loc.file,
 300         module_path: loc.module_path,
 301         line: loc.line,
 302     });
 303     local_logger.replace(Some(logger));
 304 }
 305
 306 /// Getter for the global log level. This is a function so that it can be called
 307 /// safely
 308 #[doc(hidden)]
 309 #[inline(always)]
 310 pub fn log_level() -> u32 { unsafe { LOG_LEVEL } }
 311
 312 /// Replaces the task-local logger with the specified logger, returning the old
 313 /// logger.
 314 pub fn set_logger(logger: Box<Logger + Send>) -> Option<Box<Logger + Send>> {
 315     local_logger.replace(Some(logger))
 316 }
 317
 318 /// A LogRecord is created by the logging macros, and passed as the only
 319 /// argument to Loggers.
 320 #[deriving(Show)]
 321 pub struct LogRecord<'a> {
 322
 323     /// The module path of where the LogRecord originated.
 324     pub module_path: &'a str,
 325
 326     /// The LogLevel of this record.
 327     pub level: LogLevel,
 328
 329     /// The arguments from the log line.
 330     pub args: &'a fmt::Arguments<'a>,
 331
 332     /// The file of where the LogRecord originated.
 333     pub file: &'a str,
 334
 335     /// The line number of where the LogRecord originated.
 336     pub line: uint,
 337 }
 338
 339 #[doc(hidden)]
 340 pub struct LogLocation {
 341     pub module_path: &'static str,
 342     pub file: &'static str,
 343     pub line: uint,
 344 }
 345
 346 /// Tests whether a given module's name is enabled for a particular level of
 347 /// logging. This is the second layer of defense about determining whether a
 348 /// module's log statement should be emitted or not.
 349 #[doc(hidden)]
 350 pub fn mod_enabled(level: u32, module: &str) -> bool {
 351     static mut INIT: Once = ONCE_INIT;
 352     unsafe { INIT.doit(init); }
 353
 354     // It's possible for many threads are in this function, only one of them
 355     // will perform the global initialization, but all of them will need to check
 356     // again to whether they should really be here or not. Hence, despite this
 357     // check being expanded manually in the logging macro, this function checks
 358     // the log level again.
 359     if level > unsafe { LOG_LEVEL } { return false }
 360
 361     // This assertion should never get tripped unless we're in an at_exit
 362     // handler after logging has been torn down and a logging attempt was made.
 363     assert!(unsafe { !DIRECTIVES.is_null() });
 364
 365     enabled(level, module, unsafe { (*DIRECTIVES).iter() })
 366 }
 367
 368 fn enabled(level: u32,
 369            module: &str,
 370            iter: slice::Items<directive::LogDirective>)
 371            -> bool {
 372     // Search for the longest match, the vector is assumed to be pre-sorted.
 373     for directive in iter.rev() {
 374         match directive.name {
 375             Some(ref name) if !module.starts_with(name.as_slice()) => {},
 376             Some(..) | None => {
 377                 return level <= directive.level
 378             }
 379         }
 380     }
 381     level <= DEFAULT_LOG_LEVEL
 382 }
 383
 384 /// Initialize logging for the current process.
 385 ///
 386 /// This is not threadsafe at all, so initialization os performed through a
 387 /// `Once` primitive (and this function is called from that primitive).
 388 fn init() {
 389     let (mut directives, filter) = match os::getenv("RUST_LOG") {
 390         Some(spec) => directive::parse_logging_spec(spec.as_slice()),
 391         None => (Vec::new(), None),
 392     };
 393
 394     // Sort the provided directives by length of their name, this allows a
 395     // little more efficient lookup at runtime.
 396     directives.sort_by(|a, b| {
 397         let alen = a.name.as_ref().map(|a| a.len()).unwrap_or(0);
 398         let blen = b.name.as_ref().map(|b| b.len()).unwrap_or(0);
 399         alen.cmp(&blen)
 400     });
 401
 402     let max_level = {
 403         let max = directives.iter().max_by(|d| d.level);
 404         max.map(|d| d.level).unwrap_or(DEFAULT_LOG_LEVEL)
 405     };
 406
 407     unsafe {
 408         LOG_LEVEL = max_level;
 409
 410         assert!(FILTER.is_null());
 411         match filter {
 412             Some(f) => FILTER = mem::transmute(box f),
 413             None => {}
 414         }
 415
 416         assert!(DIRECTIVES.is_null());
 417         DIRECTIVES = mem::transmute(box directives);
 418
 419         // Schedule the cleanup for the globals for when the runtime exits.
 420         rt::at_exit(proc() {
 421             assert!(!DIRECTIVES.is_null());
 422             let _directives: Box<Vec<directive::LogDirective>> =
 423                 mem::transmute(DIRECTIVES);
 424             DIRECTIVES = 0 as *const Vec<directive::LogDirective>;
 425
 426             if !FILTER.is_null() {
 427                 let _filter: Box<Regex> = mem::transmute(FILTER);
 428                 FILTER = 0 as *const _;
 429             }
 430         });
 431     }
 432 }
 433
 434 #[cfg(test)]
 435 mod tests {
 436     use super::enabled;
 437     use directive::LogDirective;
 438
 439     #[test]
 440     fn match_full_path() {
 441         let dirs = [
 442             LogDirective {
 443                 name: Some("crate2".to_string()),
 444                 level: 3
 445             },
 446             LogDirective {
 447                 name: Some("crate1::mod1".to_string()),
 448                 level: 2
 449             }
 450         ];
 451         assert!(enabled(2, "crate1::mod1", dirs.iter()));
 452         assert!(!enabled(3, "crate1::mod1", dirs.iter()));
 453         assert!(enabled(3, "crate2", dirs.iter()));
 454         assert!(!enabled(4, "crate2", dirs.iter()));
 455     }
 456
 457     #[test]
 458     fn no_match() {
 459         let dirs = [
 460             LogDirective { name: Some("crate2".to_string()), level: 3 },
 461             LogDirective { name: Some("crate1::mod1".to_string()), level: 2 }
 462         ];
 463         assert!(!enabled(2, "crate3", dirs.iter()));
 464     }
 465
 466     #[test]
 467     fn match_beginning() {
 468         let dirs = [
 469             LogDirective { name: Some("crate2".to_string()), level: 3 },
 470             LogDirective { name: Some("crate1::mod1".to_string()), level: 2 }
 471         ];
 472         assert!(enabled(3, "crate2::mod1", dirs.iter()));
 473     }
 474
 475     #[test]
 476     fn match_beginning_longest_match() {
 477         let dirs = [
 478             LogDirective { name: Some("crate2".to_string()), level: 3 },
 479             LogDirective { name: Some("crate2::mod".to_string()), level: 4 },
 480             LogDirective { name: Some("crate1::mod1".to_string()), level: 2 }
 481         ];
 482         assert!(enabled(4, "crate2::mod1", dirs.iter()));
 483         assert!(!enabled(4, "crate2", dirs.iter()));
 484     }
 485
 486     #[test]
 487     fn match_default() {
 488         let dirs = [
 489             LogDirective { name: None, level: 3 },
 490             LogDirective { name: Some("crate1::mod1".to_string()), level: 2 }
 491         ];
 492         assert!(enabled(2, "crate1::mod1", dirs.iter()));
 493         assert!(enabled(3, "crate2::mod2", dirs.iter()));
 494     }
 495
 496     #[test]
 497     fn zero_level() {
 498         let dirs = [
 499             LogDirective { name: None, level: 3 },
 500             LogDirective { name: Some("crate1::mod1".to_string()), level: 0 }
 501         ];
 502         assert!(!enabled(1, "crate1::mod1", dirs.iter()));
 503         assert!(enabled(3, "crate2::mod2", dirs.iter()));
 504     }
 505 }