diff --git a/README.md b/README.md index 0e88c8138a51..a905c2aeffb7 100644 --- a/README.md +++ b/README.md @@ -114,7 +114,7 @@ Several `-Z` flags are relevant for miri: Since the heart of Miri (the main interpreter engine) lives in rustc, working on Miri will often require using a locally built rustc. This includes getting a -trace of the execution, as distributed rustc has `trace!` disabled. +trace of the execution, as distributed rustc has `debug!` and `trace!` disabled. The first-time setup for a local rustc looks as follows: ``` @@ -130,14 +130,28 @@ rustup override set custom ``` The `build` step can take 30 minutes and more. -Now you can `cargo build` Miri, and you can `cargo test --tests`. (`--tests` -is needed to skip doctests because we have not built rustdoc for your custom -toolchain.) You can also set `RUST_LOG=rustc_mir::interpret=trace` as -environment variable to get a step-by-step trace. +Now you can `cargo build` Miri, and you can `cargo test` it. But the key point +is, you can now run Miri with a trace of all execution steps: + +```sh +MIRI_LOG=debug cargo run tests/run-pass/vecs.rs +``` + +Setting `MIRI_LOG` like this will configure logging for miri itself as well as +the `rustc::mir::interpret` and `rustc_mir::interpret` modules in rustc. You +can also do more targeted configuration, e.g. to debug the stacked borrows +implementation: + +```sh +MIRI_LOG=miri::stacked_borrows=trace,rustc_mir::interpret=debug cargo run tests/run-pass/vecs.rs +``` + +In addition, you can set `MIRI_BACKTRACE=1` to get a backtrace of where an +evaluation error was originally created. If you changed something in rustc and want to re-build, run ``` -./x.py build src/rustc --keep-stage 0 +./x.py --keep-stage 0 build src/rustc ``` This avoids rebuilding the entire stage 0, which can save a lot of time. diff --git a/src/bin/miri.rs b/src/bin/miri.rs index d4494a838852..bacea04c9768 100644 --- a/src/bin/miri.rs +++ b/src/bin/miri.rs @@ -12,6 +12,10 @@ extern crate log_settings; extern crate syntax; extern crate log; +use std::path::PathBuf; +use std::str::FromStr; +use std::env; + use rustc::session::Session; use rustc_metadata::cstore::CStore; use rustc_driver::{Compilation, CompilerCalls, RustcDefaultCalls}; @@ -21,7 +25,6 @@ use rustc::hir::{self, itemlikevisit}; use rustc::ty::TyCtxt; use rustc_codegen_utils::codegen_backend::CodegenBackend; use syntax::ast; -use std::path::PathBuf; struct MiriCompilerCalls { default: Box, @@ -105,6 +108,7 @@ fn after_analysis<'a, 'tcx>( state: &mut CompileState<'a, 'tcx>, validate: bool, ) { + init_late_loggers(); state.session.abort_if_errors(); let tcx = state.tcx.unwrap(); @@ -148,42 +152,39 @@ fn after_analysis<'a, 'tcx>( } } -fn init_logger() { - let format = |formatter: &mut env_logger::fmt::Formatter, record: &log::Record| { - use std::io::Write; - if record.level() == log::Level::Trace { - // prepend frame number - let indentation = log_settings::settings().indentation; - writeln!( - formatter, - "{indentation}:{lvl}:{module}: {text}", - lvl = record.level(), - module = record.module_path().unwrap_or(""), - indentation = indentation, - text = record.args(), - ) - } else { - writeln!( - formatter, - "{lvl}:{module}: {text}", - lvl = record.level(), - module = record.module_path().unwrap_or(""), - text = record.args(), - ) - } - }; - - let mut builder = env_logger::Builder::new(); - builder.format(format).filter( - None, - log::LevelFilter::Info, - ); - - if std::env::var("MIRI_LOG").is_ok() { - builder.parse(&std::env::var("MIRI_LOG").unwrap()); +fn init_early_loggers() { + // Notice that our `extern crate log` is NOT the same as rustc's! So we have to initialize + // them both. We always initialize miri early. + let env = env_logger::Env::new().filter("MIRI_LOG").write_style("MIRI_LOG_STYLE"); + env_logger::init_from_env(env); + // We only initialize rustc if the env var is set (so the user asked for it). + // If it is not set, we avoid initializing now so that we can initialize + // later with our custom settings, and NOT log anything for what happens before + // miri gets started. + if env::var("RUST_LOG").is_ok() { + rustc_driver::init_rustc_env_logger(); } +} - builder.init(); +fn init_late_loggers() { + // Initializing loggers right before we start evaluation. We overwrite the RUST_LOG + // env var if it is not set, control it based on MIRI_LOG. + if let Ok(var) = env::var("MIRI_LOG") { + if env::var("RUST_LOG").is_err() { + // We try to be a bit clever here: If MIRI_LOG is just a single level + // used for everything, we only apply it to the parts of rustc that are + // CTFE-related. Otherwise, we use it verbatim for RUST_LOG. + // This way, if you set `MIRI_LOG=trace`, you get only the right parts of + // rustc traced, but you can also do `MIRI_LOG=miri=trace,rustc_mir::interpret=debug`. + if log::Level::from_str(&var).is_ok() { + env::set_var("RUST_LOG", + &format!("rustc::mir::interpret={0},rustc_mir::interpret={0}", var)); + } else { + env::set_var("RUST_LOG", &var); + } + rustc_driver::init_rustc_env_logger(); + } + } } fn find_sysroot() -> String { @@ -208,8 +209,7 @@ fn find_sysroot() -> String { } fn main() { - rustc_driver::init_rustc_env_logger(); - init_logger(); + init_early_loggers(); let mut args: Vec = std::env::args().collect(); let sysroot_flag = String::from("--sysroot"); diff --git a/src/lib.rs b/src/lib.rs index 9f4eb00877e4..650998c3e16c 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -6,15 +6,16 @@ extern crate log; // From rustc. +extern crate syntax; #[macro_use] extern crate rustc; extern crate rustc_data_structures; extern crate rustc_mir; extern crate rustc_target; -extern crate syntax; use std::collections::HashMap; use std::borrow::Cow; +use std::env; use rustc::ty::{self, Ty, TyCtxt, query::TyCtxtAt}; use rustc::ty::layout::{TyLayout, LayoutOf, Size}; @@ -157,11 +158,21 @@ pub fn eval_main<'a, 'tcx: 'a>( ) { let mut ecx = create_ecx(tcx, main_id, validate).expect("Couldn't create ecx"); + // If MIRI_BACKTRACE is set and RUST_CTFE_BACKTRACE is not, set RUST_CTFE_BACKTRACE. + // Do this late, so we really only apply this to miri's errors. + if let Ok(var) = env::var("MIRI_BACKTRACE") { + if env::var("RUST_CTFE_BACKTRACE") == Err(env::VarError::NotPresent) { + env::set_var("RUST_CTFE_BACKTRACE", &var); + } + } + + // Run! The main execution. let res: EvalResult = (|| { ecx.run()?; ecx.run_tls_dtors() })(); + // Process the result. match res { Ok(()) => { let leaks = ecx.memory().leak_report(); @@ -173,7 +184,8 @@ pub fn eval_main<'a, 'tcx: 'a>( tcx.sess.err("the evaluated program leaked memory"); } } - Err(e) => { + Err(mut e) => { + e.print_backtrace(); if let Some(frame) = ecx.stack().last() { let block = &frame.mir.basic_blocks()[frame.block]; let span = if frame.stmt < block.statements.len() { @@ -195,7 +207,6 @@ pub fn eval_main<'a, 'tcx: 'a>( ecx.tcx.sess.err(&e.to_string()); } - /* Nice try, but with MIRI_BACKTRACE this shows 100s of backtraces. for (i, frame) in ecx.stack().iter().enumerate() { trace!("-------------------"); trace!("Frame {}", i); @@ -205,7 +216,7 @@ pub fn eval_main<'a, 'tcx: 'a>( trace!(" local {}: {:?}", i, local); } } - }*/ + } } } }