log: Introduce liblog, the old std::logging

This commit moves all logging out of the standard library into an external
crate. This crate is the new crate which is responsible for all logging macros
and logging implementation. A few reasons for this change are:

* The crate map has always been a bit of a code smell among rust programs. It
  has difficulty being loaded on almost all platforms, and it's used almost
  exclusively for logging and only logging. Removing the crate map is one of the
  end goals of this movement.

* The compiler has a fair bit of special support for logging. It has the
  __log_level() expression as well as generating a global word per module
  specifying the log level. This is unfairly favoring the built-in logging
  system, and is much better done purely in libraries instead of the compiler
  itself.

* Initialization of logging is much easier to do if there is no reliance on a
  magical crate map being available to set module log levels.

* If the logging library can be written outside of the standard library, there's
  no reason that it shouldn't be. It's likely that we're not going to build the
  highest quality logging library of all time, so third-party libraries should
  be able to provide just as high-quality logging systems as the default one
  provided in the rust distribution.

With a migration such as this, the change does not come for free. There are some
subtle changes in the behavior of liblog vs the previous logging macros:

* The core change of this migration is that there is no longer a physical
  log-level per module. This concept is still emulated (it is quite useful), but
  there is now only a global log level, not a local one. This global log level
  is a reflection of the maximum of all log levels specified. The previously
  generated logging code looked like:

    if specified_level <= __module_log_level() {
        println!(...)
    }

  The newly generated code looks like:

    if specified_level <= ::log::LOG_LEVEL {
        if ::log::module_enabled(module_path!()) {
            println!(...)
        }
    }

  Notably, the first layer of checking is still intended to be "super fast" in
  that it's just a load of a global word and a compare. The second layer of
  checking is executed to determine if the current module does indeed have
  logging turned on.

  This means that if any module has a debug log level turned on, all modules
  with debug log levels get a little bit slower (they all do more expensive
  dynamic checks to determine if they're turned on or not).

  Semantically, this migration brings no change in this respect, but
  runtime-wise, this will have a perf impact on some code.

* A `RUST_LOG=::help` directive will no longer print out a list of all modules
  that can be logged. This is because the crate map will no longer specify the
  log levels of all modules, so the list of modules is not known. Additionally,
  warnings can no longer be provided if a malformed logging directive was
  supplied.

The new "hello world" for logging looks like:

    #[phase(syntax, link)]
    extern crate log;

    fn main() {
        debug!("Hello, world!");
    }

Author: alexcrichton

mk/crates.mk

@@ -51,7 +51,7 @@
 
 TARGET_CRATES := std green rustuv native flate arena glob term semver \
                  uuid serialize sync getopts collections num test time rand \
-		 workcache url
+		 workcache url log
 HOST_CRATES := syntax rustc rustdoc fourcc hexfloat
 CRATES := $(TARGET_CRATES) $(HOST_CRATES)
 TOOLS := compiletest rustdoc rustc
@@ -60,15 +60,15 @@ DEPS_std := native:rustrt native:compiler-rt native:backtrace
 DEPS_green := std rand native:context_switch
 DEPS_rustuv := std native:uv native:uv_support
 DEPS_native := std
-DEPS_syntax := std term serialize collections
+DEPS_syntax := std term serialize collections log
 DEPS_rustc := syntax native:rustllvm flate arena serialize sync getopts \
-              collections time
+              collections time log
 DEPS_rustdoc := rustc native:sundown serialize sync getopts collections \
                 test time
 DEPS_flate := std native:miniz
 DEPS_arena := std collections
 DEPS_glob := std
-DEPS_serialize := std collections
+DEPS_serialize := std collections log
 DEPS_term := std collections
 DEPS_semver := std
 DEPS_uuid := std serialize rand
@@ -83,6 +83,7 @@ DEPS_time := std serialize
 DEPS_rand := std
 DEPS_url := std collections
 DEPS_workcache := std serialize collections std
+DEPS_log := std sync
 
 TOOL_DEPS_compiletest := test green rustuv getopts
 TOOL_DEPS_rustdoc := rustdoc native

src/compiletest/compiletest.rs

@@ -9,13 +9,16 @@
 // except according to those terms.
 
 #[crate_type = "bin"];
+#[feature(phase)];
 
 #[allow(non_camel_case_types)];
 #[deny(warnings)];
 #[allow(deprecated_owned_vector)];
 
 extern crate test;
 extern crate getopts;
+#[phase(link, syntax)]
+extern crate log;
 
 use std::os;
 use std::io;

src/doc/rust.md

@@ -1055,7 +1055,7 @@ output slot type would normally be. For example:
 
 ~~~~
 fn my_err(s: &str) -> ! {
-    info!("{}", s);
+    println!("{}", s);
     fail!();
 }
 ~~~~
@@ -3885,6 +3885,9 @@ Rust provides several macros to log information. Here's a simple Rust program
 that demonstrates all four of them:
 
 ~~~~
+#[feature(phase)];
+#[phase(syntax, link)] extern crate log;
+
 fn main() {
     error!("This is an error log")
     warn!("This is a warn log")

src/doc/tutorial.md

@@ -796,7 +796,7 @@ unit, `()`, as the empty tuple if you like).
 ~~~~
 let mytup: (int, int, f64) = (10, 20, 30.0);
 match mytup {
-  (a, b, c) => info!("{}", a + b + (c as int))
+  (a, b, c) => println!("{}", a + b + (c as int))
 }
 ~~~~
 
@@ -813,7 +813,7 @@ For example:
 struct MyTup(int, int, f64);
 let mytup: MyTup = MyTup(10, 20, 30.0);
 match mytup {
-  MyTup(a, b, c) => info!("{}", a + b + (c as int))
+  MyTup(a, b, c) => println!("{}", a + b + (c as int))
 }
 ~~~~
 
@@ -1794,7 +1794,7 @@ use std::task::spawn;
 
 // proc is the closure which will be spawned.
 spawn(proc() {
-    debug!("I'm a new task")
+    println!("I'm a new task")
 });
 ~~~~
 

src/libcollections/lib.rs

@@ -20,7 +20,7 @@
       html_favicon_url = "http://www.rust-lang.org/favicon.ico",
       html_root_url = "http://static.rust-lang.org/doc/master")];
 
-#[feature(macro_rules, managed_boxes, default_type_params)];
+#[feature(macro_rules, managed_boxes, default_type_params, phase)];
 
 // NOTE remove the following two attributes after the next snapshot.
 #[allow(unrecognized_lint)];
@@ -30,6 +30,7 @@
 extern crate rand;
 
 #[cfg(test)] extern crate test;
+#[cfg(test)] #[phase(syntax, link)] extern crate log;
 
 pub use bitv::Bitv;
 pub use btree::BTree;

src/libflate/lib.rs

@@ -18,9 +18,11 @@ Simple compression
 #[crate_type = "rlib"];
 #[crate_type = "dylib"];
 #[license = "MIT/ASL2"];
-#[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://static.rust-lang.org/doc/master")];
+#[feature(phase)];
+
+#[cfg(test)] #[phase(syntax, link)] extern crate log;
 
 use std::libc::{c_void, size_t, c_int};
 use std::libc;

src/libgetopts/lib.rs

@@ -86,7 +86,9 @@
 #[allow(missing_doc)];
 #[allow(deprecated_owned_vector)];
 
-#[feature(globs)];
+#[feature(globs, phase)];
+
+#[cfg(test)] #[phase(syntax, link)] extern crate log;
 
 use std::cmp::Eq;
 use std::result::{Err, Ok};

src/libgreen/lib.rs

@@ -172,10 +172,11 @@
       html_root_url = "http://static.rust-lang.org/doc/master")];
 
 // NB this does *not* include globs, please keep it that way.
-#[feature(macro_rules)];
+#[feature(macro_rules, phase)];
 #[allow(visible_private_types)];
 #[allow(deprecated_owned_vector)];
 
+#[cfg(test)] #[phase(syntax, link)] extern crate log;
 extern crate rand;
 
 use std::mem::replace;

src/libgreen/task.rs

@@ -178,14 +178,13 @@ impl GreenTask {
                      f: proc()) -> ~GreenTask {
         let TaskOpts {
             notify_chan, name, stack_size,
-            stderr, stdout, logger,
+            stderr, stdout,
         } = opts;
 
         let mut green = GreenTask::new(pool, stack_size, f);
         {
             let task = green.task.get_mut_ref();
             task.name = name;
-            task.logger = logger;
             task.stderr = stderr;
             task.stdout = stdout;
             match notify_chan {

src/liblog/directive.rs

@@ -0,0 +1,134 @@
+// 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 <LICENSE-APACHE or
+// http://www.apache.org/licenses/LICENSE-2.0> or the MIT license
+// <LICENSE-MIT or http://opensource.org/licenses/MIT>, at your
+// option. This file may not be copied, modified, or distributed
+// except according to those terms.
+
+use std::cmp;
+use std::vec_ng::Vec;
+
+#[deriving(Show, Clone)]
+pub struct LogDirective {
+    name: Option<~str>,
+    level: u32,
+}
+
+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<u32> {
+    from_str::<u32>(level).or_else(|| {
+        let pos = LOG_LEVEL_NAMES.iter().position(|&name| name == 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")
+/// 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<LogDirective> {
+    let mut dirs = Vec::new();
+    for s in spec.split(',') {
+        if s.len() == 0 { continue }
+        let mut parts = s.split('=');
+        let (log_level, name) = match (parts.next(), parts.next(), 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(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_owned()),
+            level: log_level,
+        });
+    }
+    return dirs;
+}
+
+#[cfg(test)]
+mod tests {
+    use super::parse_logging_spec;
+
+    #[test]
+    fn parse_logging_spec_valid() {
+        let dirs = parse_logging_spec("crate1::mod1=1,crate1::mod2,crate2=4");
+        let dirs = dirs.as_slice();
+        assert_eq!(dirs.len(), 3);
+        assert_eq!(dirs[0].name, Some(~"crate1::mod1"));
+        assert_eq!(dirs[0].level, 1);
+
+        assert_eq!(dirs[1].name, Some(~"crate1::mod2"));
+        assert_eq!(dirs[1].level, ::MAX_LOG_LEVEL);
+
+        assert_eq!(dirs[2].name, Some(~"crate2"));
+        assert_eq!(dirs[2].level, 4);
+    }
+
+    #[test]
+    fn parse_logging_spec_invalid_crate() {
+        // test parse_logging_spec with multiple = in specification
+        let dirs = parse_logging_spec("crate1::mod1=1=2,crate2=4");
+        let dirs = dirs.as_slice();
+        assert_eq!(dirs.len(), 1);
+        assert_eq!(dirs[0].name, Some(~"crate2"));
+        assert_eq!(dirs[0].level, 4);
+    }
+
+    #[test]
+    fn parse_logging_spec_invalid_log_level() {
+        // test parse_logging_spec with 'noNumber' as log level
+        let dirs = parse_logging_spec("crate1::mod1=noNumber,crate2=4");
+        let dirs = dirs.as_slice();
+        assert_eq!(dirs.len(), 1);
+        assert_eq!(dirs[0].name, Some(~"crate2"));
+        assert_eq!(dirs[0].level, 4);
+    }
+
+    #[test]
+    fn parse_logging_spec_string_log_level() {
+        // test parse_logging_spec with 'warn' as log level
+        let dirs = parse_logging_spec("crate1::mod1=wrong,crate2=warn");
+        let dirs = dirs.as_slice();
+        assert_eq!(dirs.len(), 1);
+        assert_eq!(dirs[0].name, Some(~"crate2"));
+        assert_eq!(dirs[0].level, ::WARN);
+    }
+
+    #[test]
+    fn parse_logging_spec_global() {
+        // test parse_logging_spec with no crate
+        let dirs = parse_logging_spec("warn,crate2=4");
+        let dirs = dirs.as_slice();
+        assert_eq!(dirs.len(), 2);
+        assert_eq!(dirs[0].name, None);
+        assert_eq!(dirs[0].level, 2);
+        assert_eq!(dirs[1].name, Some(~"crate2"));
+        assert_eq!(dirs[1].level, 4);
+    }
+}