From 4f3f2020edbce8d9bcb618d11f8f7fc5eb8dff76 Mon Sep 17 00:00:00 2001 From: Oliver Schneider Date: Mon, 30 May 2016 18:09:52 +0200 Subject: [PATCH] add the `log` crate + `env_logger` to be able to choose the log granularity at runtime --- src/bin/miri.rs | 24 ++++++++++++++++++++++++ src/interpreter.rs | 40 +++++++++++++++------------------------- src/lib.rs | 2 ++ 3 files changed, 41 insertions(+), 25 deletions(-) diff --git a/src/bin/miri.rs b/src/bin/miri.rs index 49d49650ea5..13025cc668b 100644 --- a/src/bin/miri.rs +++ b/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 = 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(); +} diff --git a/src/interpreter.rs b/src/interpreter.rs index bd8a5012b2e..0f9cc899193 100644 --- a/src/interpreter.rs +++ b/src/interpreter.rs @@ -20,8 +20,6 @@ use error::{EvalError, EvalResult}; use memory::{Memory, Pointer}; use primval::{self, PrimVal}; -const TRACE_EXECUTION: bool = true; - struct GlobalEvalContext<'a, 'tcx: 'a> { /// The results of the type checker, from rustc. tcx: TyCtxt<'a, 'tcx, 'tcx>, @@ -168,32 +166,24 @@ impl<'a, 'b, 'mir, 'tcx> FnEvalContext<'a, 'b, 'mir, 'tcx> { r } - fn log(&self, extra_indent: usize, f: F) where F: FnOnce() { - let indent = self.stack.len() + extra_indent; - if !TRACE_EXECUTION { return; } - for _ in 0..indent { print!(" "); } - f(); - println!(""); - } - fn run(&mut self) -> EvalResult<()> { 'outer: while !self.stack.is_empty() { let mut current_block = self.frame().next_block; loop { - self.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 { - self.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(); - self.log(0, || print!("{:?}", terminator.kind)); + trace!("{:?}", terminator.kind); let result = self.eval_terminator(terminator); match self.maybe_report(terminator.span, result)? { @@ -245,6 +235,8 @@ impl<'a, 'b, 'mir, 'tcx> FnEvalContext<'a, 'b, 'mir, 'tcx> { let num_args = mir.arg_decls.len(); let num_vars = mir.var_decls.len(); + ::log_settings::settings().indentation += 1; + self.stack.push(Frame { mir: mir.clone(), next_block: mir::START_BLOCK, @@ -256,6 +248,7 @@ impl<'a, 'b, 'mir, 'tcx> FnEvalContext<'a, 'b, 'mir, 'tcx> { } fn pop_stack_frame(&mut self) { + ::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(); @@ -419,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) { - self.log(1, || print!("no need to drop {:?}", ty)); + debug!("no need to drop {:?}", ty); return Ok(()); } - self.log(1, || print!("need to drop {:?}", ty)); + trace!("-need to drop {:?}", ty); // TODO(solson): Call user-defined Drop::drop impls. @@ -431,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)?; - self.log(1, || print!("deallocating box")); + trace!("-deallocating box"); self.memory.deallocate(contents_ptr)?; } Err(EvalError::ReadBytesAsPointer) => { @@ -1421,32 +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); - if TRACE_EXECUTION { - println!("Interpreting: {}", item.name); - } + ::log_settings::settings().indentation = initial_indentation; + + 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!(""); - } } } } diff --git a/src/lib.rs b/src/lib.rs index 623ed14be76..80d89c164ac 100644 --- a/src/lib.rs +++ b/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;