Allow a regex filter for RUST_LOG

When specifying RUST_LOG, the programmer may append `/regex` to the end of the spec. All results will then be filtered using that regex.

Author: nrc

mk/crates.mk

@@ -96,7 +96,7 @@ DEPS_test := std getopts serialize rbml term time regex native:rust_test_helpers
 DEPS_time := std serialize
 DEPS_rand := core
 DEPS_url := std
-DEPS_log := std
+DEPS_log := std regex
 DEPS_regex := std
 DEPS_regex_macros = rustc syntax std regex
 DEPS_fmt_macros = std

src/liblog/directive.rs

@@ -8,6 +8,7 @@
 // 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;
 
@@ -28,14 +29,23 @@ fn parse_log_level(level: &str) -> Option<u32> {
     }).map(|p| cmp::min(p, ::MAX_LOG_LEVEL))
 }
 
-/// Parse a logging specification string (e.g: "crate1,crate2::mod3,crate3::x=1")
+/// 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<LogDirective> {
+pub fn parse_logging_spec(spec: &str) -> (Vec<LogDirective>, Option<Regex>) {
     let mut dirs = Vec::new();
-    for s in spec.split(',') {
+
+    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()) {
@@ -68,8 +78,19 @@ pub fn parse_logging_spec(spec: &str) -> Vec<LogDirective> {
             name: name.map(|s| s.to_string()),
             level: log_level,
         });
-    }
-    return dirs;
+    }});
+
+    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)]
@@ -78,7 +99,7 @@ mod tests {
 
     #[test]
     fn parse_logging_spec_valid() {
-        let dirs = parse_logging_spec("crate1::mod1=1,crate1::mod2,crate2=4");
+        let (dirs, filter) = 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".to_string()));
@@ -89,57 +110,99 @@ mod tests {
 
         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 = parse_logging_spec("crate1::mod1=1=2,crate2=4");
+        let (dirs, filter) = 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".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 = parse_logging_spec("crate1::mod1=noNumber,crate2=4");
+        let (dirs, filter) = 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".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 = parse_logging_spec("crate1::mod1=wrong,crate2=warn");
+        let (dirs, filter) = 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".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 = parse_logging_spec("crate1::mod1=wrong,crate2=");
+        let (dirs, filter) = parse_logging_spec("crate1::mod1=wrong,crate2=");
         let dirs = dirs.as_slice();
         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 = parse_logging_spec("warn,crate2=4");
+        let (dirs, filter) = 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".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");
+        let dirs = dirs.as_slice();
+        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().as_slice() == "abc");
+    }
+
+    #[test]
+    fn parse_logging_spec_invalid_crate_filter() {
+        let (dirs, filter) = parse_logging_spec("crate1::mod1=1=2,crate2=4/a.c");
+        let dirs = dirs.as_slice();
+        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().as_slice() == "a.c");
+    }
+
+    #[test]
+    fn parse_logging_spec_empty_with_filter() {
+        let (dirs, filter) = parse_logging_spec("crate1/a*c");
+        let dirs = dirs.as_slice();
+        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().as_slice() == "a*c");
     }
 }

src/liblog/lib.rs

@@ -80,14 +80,32 @@ all modules is set to this value.
 
 Some examples of valid values of `RUST_LOG` are:
 
-```text
-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
-```
+* `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
+
+## 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 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'
 
 ## Performance and Side Effects
 
@@ -117,6 +135,9 @@ if logging is disabled, none of the components of the log will be executed.
 #![feature(macro_rules)]
 #![deny(missing_doc)]
 
+extern crate regex;
+
+use regex::Regex;
 use std::fmt;
 use std::io::LineBufferedWriter;
 use std::io;
@@ -146,6 +167,9 @@ static mut LOG_LEVEL: u32 = MAX_LOG_LEVEL;
 static mut DIRECTIVES: *const Vec<directive::LogDirective> =
     0 as *const Vec<directive::LogDirective>;
 
+/// Optional regex filter.
+static mut FILTER: *const Regex = 0 as *const _;
+
 /// Debug log level
 pub static DEBUG: u32 = 4;
 /// Info log level
@@ -222,6 +246,13 @@ impl Drop for DefaultLogger {
 /// 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.to_option() } {
+        Some(filter) if filter.is_match(args.to_string().as_slice()) => return,
+        _ => {}
+    }
+
     // 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.
@@ -321,9 +352,9 @@ fn enabled(level: u32,
 /// This is not threadsafe at all, so initialization os performed through a
 /// `Once` primitive (and this function is called from that primitive).
 fn init() {
-    let mut directives = match os::getenv("RUST_LOG") {
+    let (mut directives, filter) = match os::getenv("RUST_LOG") {
         Some(spec) => directive::parse_logging_spec(spec.as_slice()),
-        None => Vec::new(),
+        None => (Vec::new(), None),
     };
 
     // Sort the provided directives by length of their name, this allows a
@@ -342,15 +373,26 @@ fn init() {
     unsafe {
         LOG_LEVEL = max_level;
 
+        assert!(FILTER.is_null());
+        match filter {
+            Some(f) => FILTER = mem::transmute(box f),
+            None => {}
+        }
+
         assert!(DIRECTIVES.is_null());
         DIRECTIVES = mem::transmute(box directives);
 
-        // Schedule the cleanup for this global for when the runtime exits.
+        // Schedule the cleanup for the globals for when the runtime exits.
         rt::at_exit(proc() {
             assert!(!DIRECTIVES.is_null());
             let _directives: Box<Vec<directive::LogDirective>> =
                 mem::transmute(DIRECTIVES);
             DIRECTIVES = 0 as *const Vec<directive::LogDirective>;
+
+            if !FILTER.is_null() {
+                let _filter: Box<Regex> = mem::transmute(FILTER);
+                FILTER = 0 as *const _;
+            }
         });
     }
 }