From b3a175f730aff58ae41254254bbcd55d81ed9d47 Mon Sep 17 00:00:00 2001 From: Oliver Schneider Date: Tue, 31 May 2016 16:39:52 +0200 Subject: [PATCH 1/9] add dependencies and run cargo update --- Cargo.lock | 108 ++++++++++++++++++++++++++++++++++++++++++++++++++++- Cargo.toml | 3 ++ 2 files changed, 109 insertions(+), 2 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 4827e7fd8a..c5518b1238 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -3,7 +3,18 @@ name = "miri" version = "0.1.0" dependencies = [ "byteorder 0.4.2 (registry+https://github.com/rust-lang/crates.io-index)", - "compiletest_rs 0.1.1 (registry+https://github.com/rust-lang/crates.io-index)", + "compiletest_rs 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)", + "env_logger 0.3.3 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.3.6 (registry+https://github.com/rust-lang/crates.io-index)", + "log_settings 0.1.1 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "aho-corasick" +version = "0.5.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "memchr 0.1.11 (registry+https://github.com/rust-lang/crates.io-index)", ] [[package]] @@ -13,14 +24,107 @@ source = "registry+https://github.com/rust-lang/crates.io-index" [[package]] name = "compiletest_rs" -version = "0.1.1" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "log 0.3.6 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "env_logger" +version = "0.3.3" source = "registry+https://github.com/rust-lang/crates.io-index" dependencies = [ "log 0.3.6 (registry+https://github.com/rust-lang/crates.io-index)", + "regex 0.1.71 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "kernel32-sys" +version = "0.2.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "winapi 0.2.7 (registry+https://github.com/rust-lang/crates.io-index)", + "winapi-build 0.1.1 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "lazy_static" +version = "0.2.1" +source = "registry+https://github.com/rust-lang/crates.io-index" + +[[package]] +name = "libc" +version = "0.2.11" +source = "registry+https://github.com/rust-lang/crates.io-index" + [[package]] name = "log" version = "0.3.6" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "log_settings" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "lazy_static 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "memchr" +version = "0.1.11" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "libc 0.2.11 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "regex" +version = "0.1.71" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "aho-corasick 0.5.2 (registry+https://github.com/rust-lang/crates.io-index)", + "memchr 0.1.11 (registry+https://github.com/rust-lang/crates.io-index)", + "regex-syntax 0.3.3 (registry+https://github.com/rust-lang/crates.io-index)", + "thread_local 0.2.6 (registry+https://github.com/rust-lang/crates.io-index)", + "utf8-ranges 0.1.3 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "regex-syntax" +version = "0.3.3" +source = "registry+https://github.com/rust-lang/crates.io-index" + +[[package]] +name = "thread-id" +version = "2.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "kernel32-sys 0.2.2 (registry+https://github.com/rust-lang/crates.io-index)", + "libc 0.2.11 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "thread_local" +version = "0.2.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "thread-id 2.0.0 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "utf8-ranges" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" + +[[package]] +name = "winapi" +version = "0.2.7" +source = "registry+https://github.com/rust-lang/crates.io-index" + +[[package]] +name = "winapi-build" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" + diff --git a/Cargo.toml b/Cargo.toml index 66bbc729e1..5a8211230f 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -16,6 +16,9 @@ test = false [dependencies] byteorder = "0.4.2" +env_logger = "0.3.3" +log = "0.3.6" +log_settings = "0.1.1" [dev-dependencies] compiletest_rs = "0.1.1" From 4f3f2020edbce8d9bcb618d11f8f7fc5eb8dff76 Mon Sep 17 00:00:00 2001 From: Oliver Schneider Date: Mon, 30 May 2016 18:09:52 +0200 Subject: [PATCH 2/9] 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 49d49650ea..13025cc668 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 bd8a5012b2..0f9cc89919 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 623ed14be7..80d89c164a 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; From 49dfd82fd363a6379af9a6c453e2217e58a0fc6d Mon Sep 17 00:00:00 2001 From: Oliver Schneider Date: Tue, 31 May 2016 16:41:26 +0200 Subject: [PATCH 3/9] fallout because compiletest tried to use rustc's log crate --- tests/run-fail/inception.rs | 32 +++++++++++++++++++++++++------- 1 file changed, 25 insertions(+), 7 deletions(-) diff --git a/tests/run-fail/inception.rs b/tests/run-fail/inception.rs index 25eb72aa04..f0fb4113f1 100644 --- a/tests/run-fail/inception.rs +++ b/tests/run-fail/inception.rs @@ -9,14 +9,32 @@ fn run_miri(file: &str, sysroot: &str) -> Output { let libpath = libpath.to_str().unwrap(); let libpath2 = path.join("target").join("debug").join("deps"); let libpath2 = libpath2.to_str().unwrap(); + let mut args = vec![ + "run".to_string(), "--".to_string(), + "--sysroot".to_string(), sysroot.to_string(), + "-L".to_string(), libpath.to_string(), + "-L".to_string(), libpath2.to_string(), + file.to_string() + ]; + for file in std::fs::read_dir("target/debug/deps").unwrap() { + let file = file.unwrap(); + if file.file_type().unwrap().is_file() { + let path = file.path(); + if let Some(ext) = path.extension() { + if ext == "rlib" { + let name = path.file_stem().unwrap().to_str().unwrap(); + if let Some(dash) = name.rfind('-') { + if name.starts_with("lib") { + args.push("--extern".to_string()); + args.push(format!("{}={}", &name[3..dash], path.to_str().unwrap())); + } + } + } + } + } + } Command::new("cargo") - .args(&[ - "run", "--", - "--sysroot", sysroot, - "-L", libpath, - "-L", libpath2, - file - ]) + .args(&args) .output() .unwrap_or_else(|e| panic!("failed to execute process: {}", e)) } From f1e4ef6c6f90240903b6e40ad92a51593b0ba39f Mon Sep 17 00:00:00 2001 From: Oliver Schneider Date: Tue, 31 May 2016 16:51:30 +0200 Subject: [PATCH 4/9] re-introduce the module name to the logs and show vertical bars --- src/bin/miri.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/bin/miri.rs b/src/bin/miri.rs index 13025cc668..dfb325642e 100644 --- a/src/bin/miri.rs +++ b/src/bin/miri.rs @@ -44,9 +44,9 @@ fn init_logger() { let format = |record: &log::LogRecord| { // prepend spaces to indent the final string let indentation = log_settings::settings().indentation; - let spaces = " "; + let spaces = " | | | | | | | | "; let indentation = &spaces[..std::cmp::min(indentation, spaces.len())]; - format!("{} -{} {}", record.level(), indentation, record.args()) + format!("{}:{}|{} {}", record.level(), record.location().module_path(), indentation, record.args()) }; let mut builder = env_logger::LogBuilder::new(); From f9a54161354821daef7ba2798460a1b93ab0f766 Mon Sep 17 00:00:00 2001 From: Oliver Schneider Date: Wed, 1 Jun 2016 17:32:57 +0200 Subject: [PATCH 5/9] use MIRI_LOG instead of RUST_LOG, because rustc's output is very verbose --- src/bin/miri.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/bin/miri.rs b/src/bin/miri.rs index dfb325642e..8039cd18f8 100644 --- a/src/bin/miri.rs +++ b/src/bin/miri.rs @@ -52,8 +52,8 @@ fn init_logger() { 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()); + if std::env::var("MIRI_LOG").is_ok() { + builder.parse(&std::env::var("MIRI_LOG").unwrap()); } builder.init().unwrap(); From b7df4fdc75f208ced6d8ebec6d8f44f0bd5a6102 Mon Sep 17 00:00:00 2001 From: Oliver Schneider Date: Wed, 1 Jun 2016 17:58:50 +0200 Subject: [PATCH 6/9] use a number for the maximum indentation instead of relying on str::len() --- src/bin/miri.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/bin/miri.rs b/src/bin/miri.rs index 8039cd18f8..85e4f63486 100644 --- a/src/bin/miri.rs +++ b/src/bin/miri.rs @@ -44,8 +44,8 @@ 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())]; + let spaces = " | | | | | | | | |"; + let indentation = &spaces[..std::cmp::min(indentation, 44)]; format!("{}:{}|{} {}", record.level(), record.location().module_path(), indentation, record.args()) }; From c62cce3116803a448991037d1adc9043a77c31d0 Mon Sep 17 00:00:00 2001 From: Oliver Schneider Date: Wed, 1 Jun 2016 18:18:01 +0200 Subject: [PATCH 7/9] wraparound when reaching indentation lvl 40 --- src/bin/miri.rs | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/src/bin/miri.rs b/src/bin/miri.rs index 85e4f63486..33fb8393a7 100644 --- a/src/bin/miri.rs +++ b/src/bin/miri.rs @@ -44,9 +44,11 @@ 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, 44)]; - format!("{}:{}|{} {}", record.level(), record.location().module_path(), indentation, record.args()) + let spaces = " "; + let depth = indentation / spaces.len(); + let indentation = indentation % spaces.len(); + let indentation = &spaces[..indentation]; + format!("{}:{}{:2}{} {}", record.level(), record.location().module_path(), depth, indentation, record.args()) }; let mut builder = env_logger::LogBuilder::new(); From af41c54301ef2abee639f0a8b355ba5a8c0ba258 Mon Sep 17 00:00:00 2001 From: Oliver Schneider Date: Wed, 1 Jun 2016 18:33:29 +0200 Subject: [PATCH 8/9] use format! compile time magics for indentation --- src/bin/miri.rs | 15 ++++++++++----- 1 file changed, 10 insertions(+), 5 deletions(-) diff --git a/src/bin/miri.rs b/src/bin/miri.rs index 33fb8393a7..df1763ae53 100644 --- a/src/bin/miri.rs +++ b/src/bin/miri.rs @@ -41,14 +41,19 @@ fn main() { #[miri_run] fn init_logger() { + const NSPACES: usize = 40; let format = |record: &log::LogRecord| { // prepend spaces to indent the final string let indentation = log_settings::settings().indentation; - let spaces = " "; - let depth = indentation / spaces.len(); - let indentation = indentation % spaces.len(); - let indentation = &spaces[..indentation]; - format!("{}:{}{:2}{} {}", record.level(), record.location().module_path(), depth, indentation, record.args()) + let depth = indentation / NSPACES; + let indentation = indentation % NSPACES; + format!("{lvl}:{module}{depth:2}{indent: Date: Wed, 1 Jun 2016 18:42:57 +0200 Subject: [PATCH 9/9] remove intermediate vars --- src/bin/miri.rs | 8 +++----- 1 file changed, 3 insertions(+), 5 deletions(-) diff --git a/src/bin/miri.rs b/src/bin/miri.rs index df1763ae53..34a8c1b2be 100644 --- a/src/bin/miri.rs +++ b/src/bin/miri.rs @@ -45,13 +45,11 @@ fn init_logger() { let format = |record: &log::LogRecord| { // prepend spaces to indent the final string let indentation = log_settings::settings().indentation; - let depth = indentation / NSPACES; - let indentation = indentation % NSPACES; - format!("{lvl}:{module}{depth:2}{indent: