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