Rust: Custom Logger with time-stamp, file name and line number

Rust language has a built-in support for logging.  The default logger logs the log level, module name and log message which are not sufficient for troubleshooting. Fortunately,  Rust log crate does allow overriding with a custom logger.

I wanted to log the current time-stamp,  module name, function name and line number and posted a question on Reddit on how do log these information. Based on the answers, Rust does have support for module, line and file name but no support for function name. 

To implement the Custom Logger, I looked at the default logger implementation in  lib.rs in log crate and realized that LogRecord does support file-name and line number but while logging, it does not use it.

 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,  
      _ => {}  
    }  
    // 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 DefaultLogger { handle: io::stderr() } as Box<Logger + Send>  
    });  
    logger.log(&LogRecord {  
      level: LogLevel(level),  
      args: args,  
      file: loc.file,  
      module_path: loc.module_path,  
      line: loc.line,  
    });  
    set_logger(logger);  
  }  

To support the logging of function name, there is a pending RFC/Pull Request, hope that gets implemented before Rust 1.0.

For time being, let manage without function name and implement our custom logger.

 #![feature(phase)]  
 #[phase(plugin, link)]extern crate log;  
 #[phase(plugin, link)]extern crate time;  
 /// import  
 use log::{Logger,LogRecord,LogLevel,LogLocation, set_logger};  
 use std::io::{ LineBufferedWriter, stdio, stderr} ;  
 /// Custom Logger  
 struct CustomLogger {  
    handle: LineBufferedWriter<stdio::StdWriter>,  
  }  
 /// Implements Logger trait for Custom Logger which support logging timestamp, file name and line number  
 /// in addition to log level, module path and message.  
 impl Logger for CustomLogger {  
    fn log(&mut self, record: &LogRecord) {  
      match writeln!(&mut self.handle,  
             "{}:{}:{}:{}:{} {}",  
             time::strftime("%Y-%m-%d %H:%M:%S %Z", &time::now()).unwrap(),  
             record.level,  
             record.module_path,  
             record.file,  
             record.line,  
             record.args) {  
        Err(e) => panic!("failed to log: {}", e),  
        Ok(()) => {}  
      }  
    }  
  }  
 ///main   
 fn main() {  
       log::set_logger(box CustomLogger { handle: stderr() } );  
   debug!("Debug message");  
   warn!("Warn message");  
   error!("Error message");  
 }  

Here is output:

 RUST_LOG=debug ./target/custom-logger  
 2014-12-17 09:23:48 :DEBUG:custom-logger:/projects/rust/custom-logger/src/main.rs:32 Debug message  
 2014-12-17 09:23:48 :WARN:custom-logger:/projects/rust/custom-logger/src/main.rs:33 Warn message  
 2014-12-17 09:23:48 :ERROR:custom-logger:/projects/rust/custom-logger/src/main.rs:34 Error message  

NOTE:  I notice it doesn't print the timezone and leave an empty space.

Once I figure out the timezone issue and logging function name , it will look like below which is much better than file with being repeated.

RUST_LOG=debug ./target/custom-logger  
 2014-12-17 09:23:48 EST:DEBUG:custom-logger::main::32 Debug message  
 2014-12-17 09:23:48 EST:WARN:custom-logger::main:33 Warn message  
 2014-12-17 09:23:48 EST:ERROR:custom-logger::main:34 Error message