add the log crate + env_logger to be able to choose the log granularity at runtime

Author: oli-obk

src/bin/miri.rs

@@ -5,6 +5,9 @@ extern crate getopts;
 extern crate miri;
 extern crate rustc;
 extern crate rustc_driver;
+extern crate env_logger;
+extern crate log_settings;
+extern crate log;
 
 use miri::interpreter;
 use rustc::session::Session;
@@ -31,6 +34,27 @@ impl<'a> CompilerCalls<'a> for MiriCompilerCalls {
 
 #[miri_run]
 fn main() {
+    init_logger();
     let args: Vec<String> = std::env::args().collect();
     rustc_driver::run_compiler(&args, &mut MiriCompilerCalls);
 }
+
+#[miri_run]
+fn init_logger() {
+    let format = |record: &log::LogRecord| {
+        // prepend spaces to indent the final string
+        let indentation = log_settings::settings().indentation;
+        let spaces = "                                  ";
+        let indentation = &spaces[..std::cmp::min(indentation, spaces.len())];
+        format!("{} -{} {}", record.level(), indentation, record.args())
+    };
+
+    let mut builder = env_logger::LogBuilder::new();
+    builder.format(format).filter(None, log::LogLevelFilter::Info);
+
+    if std::env::var("RUST_LOG").is_ok() {
+        builder.parse(&std::env::var("RUST_LOG").unwrap());
+    }
+
+    builder.init().unwrap();
+}

src/interpreter.rs

@@ -20,17 +20,6 @@ use error::{EvalError, EvalResult};
 use memory::{Memory, Pointer};
 use primval::{self, PrimVal};
 
-const TRACE_EXECUTION: bool = true;
-static mut INDENTATION: usize = 0;
-
-fn log<F>(extra_indent: usize, f: F) where F: FnOnce() {
-    let indent = unsafe { INDENTATION } + extra_indent;
-    if !TRACE_EXECUTION { return; }
-    for _ in 0..indent { print!("    "); }
-    f();
-    println!("");
-}
-
 struct GlobalEvalContext<'a, 'tcx: 'a> {
     /// The results of the type checker, from rustc.
     tcx: TyCtxt<'a, 'tcx, 'tcx>,
@@ -182,19 +171,19 @@ impl<'a, 'b, 'mir, 'tcx> FnEvalContext<'a, 'b, 'mir, 'tcx> {
             let mut current_block = self.frame().next_block;
 
             loop {
-                log(0, || print!("// {:?}", current_block));
+                trace!("// {:?}", current_block);
                 let current_mir = self.mir().clone(); // Cloning a reference.
                 let block_data = current_mir.basic_block_data(current_block);
 
                 for stmt in &block_data.statements {
-                    log(0, || print!("{:?}", stmt));
+                    trace!("{:?}", stmt);
                     let mir::StatementKind::Assign(ref lvalue, ref rvalue) = stmt.kind;
                     let result = self.eval_assignment(lvalue, rvalue);
                     self.maybe_report(stmt.span, result)?;
                 }
 
                 let terminator = block_data.terminator();
-                log(0, || print!("{:?}", terminator.kind));
+                trace!("{:?}", terminator.kind);
 
                 let result = self.eval_terminator(terminator);
                 match self.maybe_report(terminator.span, result)? {
@@ -246,9 +235,7 @@ impl<'a, 'b, 'mir, 'tcx> FnEvalContext<'a, 'b, 'mir, 'tcx> {
         let num_args = mir.arg_decls.len();
         let num_vars = mir.var_decls.len();
 
-        unsafe {
-            INDENTATION += 1;
-        }
+        ::log_settings::settings().indentation += 1;
 
         self.stack.push(Frame {
             mir: mir.clone(),
@@ -261,9 +248,7 @@ impl<'a, 'b, 'mir, 'tcx> FnEvalContext<'a, 'b, 'mir, 'tcx> {
     }
 
     fn pop_stack_frame(&mut self) {
-        unsafe {
-            INDENTATION -= 1;
-        }
+        ::log_settings::settings().indentation -= 1;
         let _frame = self.stack.pop().expect("tried to pop a stack frame, but there were none");
         // TODO(solson): Deallocate local variables.
         self.substs_stack.pop();
@@ -427,10 +412,10 @@ impl<'a, 'b, 'mir, 'tcx> FnEvalContext<'a, 'b, 'mir, 'tcx> {
 
     fn drop(&mut self, ptr: Pointer, ty: Ty<'tcx>) -> EvalResult<()> {
         if !self.type_needs_drop(ty) {
-            log(1, || print!("no need to drop {:?}", ty));
+            debug!("no need to drop {:?}", ty);
             return Ok(());
         }
-        log(1, || print!("need to drop {:?}", ty));
+        trace!("-need to drop {:?}", ty);
 
         // TODO(solson): Call user-defined Drop::drop impls.
 
@@ -439,7 +424,7 @@ impl<'a, 'b, 'mir, 'tcx> FnEvalContext<'a, 'b, 'mir, 'tcx> {
                 match self.memory.read_ptr(ptr) {
                     Ok(contents_ptr) => {
                         self.drop(contents_ptr, contents_ty)?;
-                        log(1, || print!("deallocating box"));
+                        trace!("-deallocating box");
                         self.memory.deallocate(contents_ptr)?;
                     }
                     Err(EvalError::ReadBytesAsPointer) => {
@@ -1429,36 +1414,29 @@ pub fn interpret_start_points<'a, 'tcx>(
     tcx: TyCtxt<'a, 'tcx, 'tcx>,
     mir_map: &MirMap<'tcx>,
 ) {
+    let initial_indentation = ::log_settings::settings().indentation;
     for (&id, mir) in &mir_map.map {
         for attr in tcx.map.attrs(id) {
             use syntax::attr::AttrMetaMethods;
             if attr.check_name("miri_run") {
                 let item = tcx.map.expect_item(id);
 
-                unsafe {
-                    INDENTATION = 0;
-                }
+                ::log_settings::settings().indentation = initial_indentation;
 
-                if TRACE_EXECUTION {
-                    println!("Interpreting: {}", item.name);
-                }
+                debug!("Interpreting: {}", item.name);
 
                 let mut gecx = GlobalEvalContext::new(tcx, mir_map);
                 let mut fecx = FnEvalContext::new(&mut gecx);
                 match fecx.call_nested(mir) {
-                    Ok(Some(return_ptr)) => if TRACE_EXECUTION {
+                    Ok(Some(return_ptr)) => if log_enabled!(::log::LogLevel::Debug) {
                         fecx.memory.dump(return_ptr.alloc_id);
                     },
-                    Ok(None) => println!("(diverging function returned)"),
+                    Ok(None) => warn!("diverging function returned"),
                     Err(_e) => {
                         // TODO(solson): Detect whether the error was already reported or not.
                         // tcx.sess.err(&e.to_string());
                     }
                 }
-
-                if TRACE_EXECUTION {
-                    println!("");
-                }
             }
         }
     }

src/lib.rs

@@ -12,6 +12,8 @@
 #[macro_use] extern crate rustc;
 extern crate rustc_mir;
 extern crate syntax;
+#[macro_use] extern crate log;
+extern crate log_settings;
 
 // From crates.io.
 extern crate byteorder;