From 7e9da8d30eb07093c09fd90276aeca4a469a0432 Mon Sep 17 00:00:00 2001 From: Aaron Hill Date: Sat, 8 May 2021 12:20:51 -0400 Subject: [PATCH 1/6] Add `measureme` integration for profiling the interpreted program This PR uses the `measureme` crate to profile the call stack of the program being interpreted by Miri. This is accomplished by starting a measureme 'event' when we enter a function call, and ending the event when we exit the call. The `measureme` tooling can be used to produce a call stack from the generated profile data. Limitations: * We currently record every single entry/exit. This might generate very large profile outputs for programs with a large number of function calls. In follow-up work, we might want to explore sampling (e.g. only recording every N function calls). * This does not integrate very well with Miri's concurrency support. Each event we record starts when we push a frame, and ends when we pop a frame. As a result, switching between virtual threads will cause events from different threads to be interleaved. Additionally, the recorded for a particular frame will include all of the work Miri does before that frame completes, including executing another thread. The `measureme` integration is off by default, and must be enabled via `-Zmiri-measureme=` --- Cargo.lock | 87 ++++++++++++++++++++++++++++++++++++++++++++++ Cargo.toml | 1 + README.md | 4 +++ src/bin/miri.rs | 4 +++ src/eval.rs | 6 +++- src/machine.rs | 50 +++++++++++++++++++++----- src/shims/panic.rs | 1 - 7 files changed, 143 insertions(+), 10 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 69cc1966a6..3ae2700321 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -167,6 +167,15 @@ version = "2.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" +[[package]] +name = "instant" +version = "0.1.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "61124eeebbd69b8190558df225adf7e4caafce0d743919e5d6b19652314ec5ec" +dependencies = [ + "cfg-if", +] + [[package]] name = "itoa" version = "0.4.7" @@ -185,6 +194,15 @@ version = "0.2.92" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "56d855069fafbb9b344c0f962150cd2c1187975cb1c22c1522c240d8c4986714" +[[package]] +name = "lock_api" +version = "0.4.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5a3c91c24eae6777794bb1997ad98bbb87daf92890acab859f7eaa4320333176" +dependencies = [ + "scopeguard", +] + [[package]] name = "log" version = "0.4.14" @@ -194,12 +212,34 @@ dependencies = [ "cfg-if", ] +[[package]] +name = "measureme" +version = "9.1.1" +source = "git+https://github.com/rust-lang/measureme?rev=501d6a3c192beee5e633a6c5f79130bedfdadcb5#501d6a3c192beee5e633a6c5f79130bedfdadcb5" +dependencies = [ + "log", + "memmap2", + "parking_lot", + "perf-event-open-sys", + "rustc-hash", + "smallvec", +] + [[package]] name = "memchr" version = "2.3.4" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "0ee1c47aaa256ecabcaea351eae4a9b01ef39ed810004e298d2511ed284b1525" +[[package]] +name = "memmap2" +version = "0.2.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "397d1a6d6d0563c0f5462bbdae662cf6c784edf5e828e40c7257f85d82bf56dd" +dependencies = [ + "libc", +] + [[package]] name = "miow" version = "0.3.7" @@ -220,6 +260,7 @@ dependencies = [ "hex", "libc", "log", + "measureme", "rand", "rustc-workspace-hack", "rustc_version", @@ -237,6 +278,40 @@ dependencies = [ "libc", ] +[[package]] +name = "parking_lot" +version = "0.11.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6d7744ac029df22dca6284efe4e898991d28e3085c706c972bcd7da4a27a15eb" +dependencies = [ + "instant", + "lock_api", + "parking_lot_core", +] + +[[package]] +name = "parking_lot_core" +version = "0.8.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fa7a782938e745763fe6907fc6ba86946d72f49fe7e21de074e08128a99fb018" +dependencies = [ + "cfg-if", + "instant", + "libc", + "redox_syscall", + "smallvec", + "winapi", +] + +[[package]] +name = "perf-event-open-sys" +version = "1.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ce9bedf5da2c234fdf2391ede2b90fabf585355f33100689bc364a3ea558561a" +dependencies = [ + "libc", +] + [[package]] name = "pest" version = "2.1.3" @@ -355,6 +430,12 @@ dependencies = [ "winapi", ] +[[package]] +name = "rustc-hash" +version = "1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "08d43f7aa6b08d49f382cde6a7982047c3426db949b1424bc4b7ec9ae12c6ce2" + [[package]] name = "rustc-workspace-hack" version = "1.0.0" @@ -394,6 +475,12 @@ version = "1.0.5" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "71d301d4193d031abdd79ff7e3dd721168a9572ef3fe51a1517aba235bd8f86e" +[[package]] +name = "scopeguard" +version = "1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d29ab0c6d3fc0ee92fe66e2d99f700eab17a8d57d1c1d3b748380fb20baa78cd" + [[package]] name = "semver" version = "0.11.0" diff --git a/Cargo.toml b/Cargo.toml index ab7d88e669..fd212e4304 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -18,6 +18,7 @@ test = false # we have no unit tests doctest = false # and no doc tests [dependencies] +measureme = { git = "https://github.com/rust-lang/measureme", rev = "501d6a3c192beee5e633a6c5f79130bedfdadcb5" } getrandom = { version = "0.2", features = ["std"] } env_logger = "0.8" log = "0.4" diff --git a/README.md b/README.md index 469263115d..87f6b87c66 100644 --- a/README.md +++ b/README.md @@ -258,6 +258,10 @@ environment variable: this pointer. Note that it is not currently guaranteed that code that works with `-Zmiri-track-raw-pointers` also works without `-Zmiri-track-raw-pointers`, but for the vast majority of code, this will be the case. +* `-Zmiri-measureme=` enables `measureme` profiling for the interpreted program. + This can be used to find which parts of your program are executing slowly under Miri. + The profile is written out to a file with the prefix ``, and can be processed + using the tools in the repository https://github.com/rust-lang/measureme Some native rustc `-Z` flags are also very relevant for Miri: diff --git a/src/bin/miri.rs b/src/bin/miri.rs index 4a1ea3a542..47cde5c353 100644 --- a/src/bin/miri.rs +++ b/src/bin/miri.rs @@ -318,6 +318,10 @@ fn main() { }; miri_config.cmpxchg_weak_failure_rate = rate; } + arg if arg.starts_with("-Zmiri-measureme=") => { + let measureme_out = arg.strip_prefix("-Zmiri-measureme=").unwrap(); + miri_config.measureme_out = Some(measureme_out.to_string()); + } _ => { // Forward to rustc. rustc_args.push(arg); diff --git a/src/eval.rs b/src/eval.rs index 1e46015f87..a5268b58a2 100644 --- a/src/eval.rs +++ b/src/eval.rs @@ -54,6 +54,9 @@ pub struct MiriConfig { /// Rate of spurious failures for compare_exchange_weak atomic operations, /// between 0.0 and 1.0, defaulting to 0.8 (80% chance of failure). pub cmpxchg_weak_failure_rate: f64, + /// If `Some`, enable the `measureme` profiler, writing results to the specified + /// directory. + pub measureme_out: Option, } impl Default for MiriConfig { @@ -73,6 +76,7 @@ impl Default for MiriConfig { track_raw: false, data_race_detector: true, cmpxchg_weak_failure_rate: 0.8, + measureme_out: None, } } } @@ -92,7 +96,7 @@ pub fn create_ecx<'mir, 'tcx: 'mir>( tcx, rustc_span::source_map::DUMMY_SP, param_env, - Evaluator::new(config.communicate, config.validate, layout_cx), + Evaluator::new(&config, layout_cx), MemoryExtra::new(&config), ); // Complete initialization. diff --git a/src/machine.rs b/src/machine.rs index 467696e839..77c606a83f 100644 --- a/src/machine.rs +++ b/src/machine.rs @@ -10,6 +10,8 @@ use std::time::Instant; use log::trace; use rand::rngs::StdRng; use rand::SeedableRng; +use std::collections::hash_map::Entry; +use measureme::{Profiler, StringId, EventId, DetachedTiming}; use rustc_data_structures::fx::FxHashMap; use rustc_middle::{ @@ -34,7 +36,6 @@ pub const STACK_SIZE: u64 = 16 * PAGE_SIZE; // whatever pub const NUM_CPUS: u64 = 1; /// Extra data stored with each stack frame -#[derive(Debug)] pub struct FrameData<'tcx> { /// Extra data for Stacked Borrows. pub call_id: stacked_borrows::CallId, @@ -43,6 +44,8 @@ pub struct FrameData<'tcx> { /// called by `try`). When this frame is popped during unwinding a panic, /// we stop unwinding, use the `CatchUnwindData` to handle catching. pub catch_unwind: Option>, + + pub timing: Option, } /// Extra memory kinds @@ -270,16 +273,21 @@ pub struct Evaluator<'mir, 'tcx> { /// Allocations that are considered roots of static memory (that may leak). pub(crate) static_roots: Vec, + + profiler: Option, + string_cache: FxHashMap, } impl<'mir, 'tcx> Evaluator<'mir, 'tcx> { pub(crate) fn new( - communicate: bool, - validate: bool, + config: &MiriConfig, layout_cx: LayoutCx<'tcx, TyCtxt<'tcx>>, ) -> Self { let layouts = PrimitiveLayouts::new(layout_cx).expect("Couldn't get layouts of primitive types"); + let profiler = config.measureme_out.as_ref().map(|out| { + Profiler::new(out).expect("Couldn't create `measureme` profiler") + }); Evaluator { // `env_vars` could be initialized properly here if `Memory` were available before // calling this method. @@ -288,14 +296,16 @@ impl<'mir, 'tcx> Evaluator<'mir, 'tcx> { argv: None, cmd_line: None, tls: TlsData::default(), - communicate, - validate, + communicate: config.communicate, + validate: config.validate, file_handler: Default::default(), dir_handler: Default::default(), time_anchor: Instant::now(), layouts, threads: ThreadManager::default(), static_roots: Vec::new(), + profiler, + string_cache: Default::default(), } } } @@ -601,7 +611,26 @@ impl<'mir, 'tcx> Machine<'mir, 'tcx> for Evaluator<'mir, 'tcx> { let call_id = stacked_borrows.map_or(NonZeroU64::new(1).unwrap(), |stacked_borrows| { stacked_borrows.borrow_mut().new_call() }); - let extra = FrameData { call_id, catch_unwind: None }; + let timing = if let Some(profiler) = ecx.machine.profiler.as_ref() { + let fn_name = frame.instance.to_string(); + let entry = ecx.machine.string_cache.entry(fn_name.clone()); + let name = match entry { + Entry::Occupied(e) => *e.get(), + Entry::Vacant(e) => { + *e.insert(profiler.alloc_string(&*fn_name)) + } + }; + + Some(profiler.start_recording_interval_event_detached( + name, + EventId::from_label(name), + 0 + )) + } else { + None + }; + + let extra = FrameData { call_id, catch_unwind: None, timing }; Ok(frame.with_extra(extra)) } @@ -625,10 +654,15 @@ impl<'mir, 'tcx> Machine<'mir, 'tcx> for Evaluator<'mir, 'tcx> { #[inline(always)] fn after_stack_pop( ecx: &mut InterpCx<'mir, 'tcx, Self>, - frame: Frame<'mir, 'tcx, Tag, FrameData<'tcx>>, + mut frame: Frame<'mir, 'tcx, Tag, FrameData<'tcx>>, unwinding: bool, ) -> InterpResult<'tcx, StackPopJump> { - ecx.handle_stack_pop(frame.extra, unwinding) + let timing = frame.extra.timing.take(); + let res = ecx.handle_stack_pop(frame.extra, unwinding); + if let Some(profiler) = ecx.machine.profiler.as_ref() { + profiler.finish_recording_interval_event(timing.unwrap()); + } + res } #[inline(always)] diff --git a/src/shims/panic.rs b/src/shims/panic.rs index b1da7f340f..6b08ee8e18 100644 --- a/src/shims/panic.rs +++ b/src/shims/panic.rs @@ -119,7 +119,6 @@ pub trait EvalContextExt<'mir, 'tcx: 'mir>: crate::MiriEvalContextExt<'mir, 'tcx ) -> InterpResult<'tcx, StackPopJump> { let this = self.eval_context_mut(); - trace!("handle_stack_pop(extra = {:?}, unwinding = {})", extra, unwinding); if let Some(stacked_borrows) = &this.memory.extra.stacked_borrows { stacked_borrows.borrow_mut().end_call(extra.call_id); } From 2166eaed90a9f94e5078bd470b5cd8cbdccc7543 Mon Sep 17 00:00:00 2001 From: Aaron Hill Date: Sat, 8 May 2021 13:17:58 -0400 Subject: [PATCH 2/6] Use active thread id --- src/machine.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/machine.rs b/src/machine.rs index 77c606a83f..7a26a609bb 100644 --- a/src/machine.rs +++ b/src/machine.rs @@ -624,7 +624,7 @@ impl<'mir, 'tcx> Machine<'mir, 'tcx> for Evaluator<'mir, 'tcx> { Some(profiler.start_recording_interval_event_detached( name, EventId::from_label(name), - 0 + ecx.get_active_thread().to_u32() )) } else { None From 16f469280ee8dfea1ca4f24a272f44865896006e Mon Sep 17 00:00:00 2001 From: Aaron Hill Date: Sat, 29 May 2021 17:09:46 -0500 Subject: [PATCH 3/6] Address review comments --- Cargo.lock | 5 +++-- Cargo.toml | 2 +- README.md | 8 ++++---- src/eval.rs | 4 ++-- src/machine.rs | 33 +++++++++++++++++++-------------- 5 files changed, 29 insertions(+), 23 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 3ae2700321..e728dc07b9 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -214,8 +214,9 @@ dependencies = [ [[package]] name = "measureme" -version = "9.1.1" -source = "git+https://github.com/rust-lang/measureme?rev=501d6a3c192beee5e633a6c5f79130bedfdadcb5#501d6a3c192beee5e633a6c5f79130bedfdadcb5" +version = "9.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "78f7a41bc6f856a2cf0e95094ad5121f82500e2d9a0f3c0171d98f6566d8117d" dependencies = [ "log", "memmap2", diff --git a/Cargo.toml b/Cargo.toml index fd212e4304..7ee96f7e99 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -18,7 +18,6 @@ test = false # we have no unit tests doctest = false # and no doc tests [dependencies] -measureme = { git = "https://github.com/rust-lang/measureme", rev = "501d6a3c192beee5e633a6c5f79130bedfdadcb5" } getrandom = { version = "0.2", features = ["std"] } env_logger = "0.8" log = "0.4" @@ -31,6 +30,7 @@ smallvec = "1.4.2" # See the `src/tools/rustc-workspace-hack/README.md` file in `rust-lang/rust` # for more information. rustc-workspace-hack = "1.0.0" +measureme = "9.1.2" # Enable some feature flags that dev-dependencies need but dependencies # do not. This makes `./miri install` after `./miri build` faster. diff --git a/README.md b/README.md index 87f6b87c66..b214ab6d09 100644 --- a/README.md +++ b/README.md @@ -222,6 +222,10 @@ environment variable: times to exclude several variables. On Windows, the `TERM` environment variable is excluded by default. * `-Zmiri-ignore-leaks` disables the memory leak checker. +* `-Zmiri-measureme=` enables `measureme` profiling for the interpreted program. + This can be used to find which parts of your program are executing slowly under Miri. + The profile is written out to a file with the prefix ``, and can be processed + using the tools in the repository https://github.com/rust-lang/measureme. * `-Zmiri-seed=` configures the seed of the RNG that Miri uses to resolve non-determinism. This RNG is used to pick base addresses for allocations. When isolation is enabled (the default), this is also used to emulate system @@ -258,10 +262,6 @@ environment variable: this pointer. Note that it is not currently guaranteed that code that works with `-Zmiri-track-raw-pointers` also works without `-Zmiri-track-raw-pointers`, but for the vast majority of code, this will be the case. -* `-Zmiri-measureme=` enables `measureme` profiling for the interpreted program. - This can be used to find which parts of your program are executing slowly under Miri. - The profile is written out to a file with the prefix ``, and can be processed - using the tools in the repository https://github.com/rust-lang/measureme Some native rustc `-Z` flags are also very relevant for Miri: diff --git a/src/eval.rs b/src/eval.rs index a5268b58a2..52e554f57d 100644 --- a/src/eval.rs +++ b/src/eval.rs @@ -54,8 +54,8 @@ pub struct MiriConfig { /// Rate of spurious failures for compare_exchange_weak atomic operations, /// between 0.0 and 1.0, defaulting to 0.8 (80% chance of failure). pub cmpxchg_weak_failure_rate: f64, - /// If `Some`, enable the `measureme` profiler, writing results to the specified - /// directory. + /// If `Some`, enable the `measureme` profiler, writing results to a file + /// with the specified prefix. pub measureme_out: Option, } diff --git a/src/machine.rs b/src/machine.rs index 7a26a609bb..4ed2fba43c 100644 --- a/src/machine.rs +++ b/src/machine.rs @@ -10,7 +10,6 @@ use std::time::Instant; use log::trace; use rand::rngs::StdRng; use rand::SeedableRng; -use std::collections::hash_map::Entry; use measureme::{Profiler, StringId, EventId, DetachedTiming}; use rustc_data_structures::fx::FxHashMap; @@ -45,6 +44,9 @@ pub struct FrameData<'tcx> { /// we stop unwinding, use the `CatchUnwindData` to handle catching. pub catch_unwind: Option>, + /// If `measureme` profiling is enabled, holds timing information + /// for the start of this frame. When we finish executing this frame, + /// we use this to register a completed event with `measureme`. pub timing: Option, } @@ -274,7 +276,11 @@ pub struct Evaluator<'mir, 'tcx> { /// Allocations that are considered roots of static memory (that may leak). pub(crate) static_roots: Vec, + /// The `measureme` profiler used to record timing information about + /// the emulated program. profiler: Option, + /// Used with `profiler` to cache the `StringId`s for event names + /// uesd with `measureme`. string_cache: FxHashMap, } @@ -607,29 +613,28 @@ impl<'mir, 'tcx> Machine<'mir, 'tcx> for Evaluator<'mir, 'tcx> { ecx: &mut InterpCx<'mir, 'tcx, Self>, frame: Frame<'mir, 'tcx, Tag>, ) -> InterpResult<'tcx, Frame<'mir, 'tcx, Tag, FrameData<'tcx>>> { - let stacked_borrows = ecx.memory.extra.stacked_borrows.as_ref(); - let call_id = stacked_borrows.map_or(NonZeroU64::new(1).unwrap(), |stacked_borrows| { - stacked_borrows.borrow_mut().new_call() - }); + // Start recording our event before doing anything else let timing = if let Some(profiler) = ecx.machine.profiler.as_ref() { let fn_name = frame.instance.to_string(); let entry = ecx.machine.string_cache.entry(fn_name.clone()); - let name = match entry { - Entry::Occupied(e) => *e.get(), - Entry::Vacant(e) => { - *e.insert(profiler.alloc_string(&*fn_name)) - } - }; + let name = entry.or_insert_with(|| { + profiler.alloc_string(&*fn_name) + }); Some(profiler.start_recording_interval_event_detached( - name, - EventId::from_label(name), - ecx.get_active_thread().to_u32() + *name, + EventId::from_label(*name), + ecx.get_active_thread().to_u32(), )) } else { None }; + let stacked_borrows = ecx.memory.extra.stacked_borrows.as_ref(); + let call_id = stacked_borrows.map_or(NonZeroU64::new(1).unwrap(), |stacked_borrows| { + stacked_borrows.borrow_mut().new_call() + }); + let extra = FrameData { call_id, catch_unwind: None, timing }; Ok(frame.with_extra(extra)) } From 20f1b2a969f6d61f5f8bf4d7877d30c66e22e70f Mon Sep 17 00:00:00 2001 From: Aaron Hill Date: Sat, 29 May 2021 17:16:12 -0500 Subject: [PATCH 4/6] Run fmt --- src/machine.rs | 18 +++++++----------- 1 file changed, 7 insertions(+), 11 deletions(-) diff --git a/src/machine.rs b/src/machine.rs index 4ed2fba43c..1a01ece6c9 100644 --- a/src/machine.rs +++ b/src/machine.rs @@ -8,9 +8,9 @@ use std::num::NonZeroU64; use std::time::Instant; use log::trace; +use measureme::{DetachedTiming, EventId, Profiler, StringId}; use rand::rngs::StdRng; use rand::SeedableRng; -use measureme::{Profiler, StringId, EventId, DetachedTiming}; use rustc_data_structures::fx::FxHashMap; use rustc_middle::{ @@ -285,15 +285,13 @@ pub struct Evaluator<'mir, 'tcx> { } impl<'mir, 'tcx> Evaluator<'mir, 'tcx> { - pub(crate) fn new( - config: &MiriConfig, - layout_cx: LayoutCx<'tcx, TyCtxt<'tcx>>, - ) -> Self { + pub(crate) fn new(config: &MiriConfig, layout_cx: LayoutCx<'tcx, TyCtxt<'tcx>>) -> Self { let layouts = PrimitiveLayouts::new(layout_cx).expect("Couldn't get layouts of primitive types"); - let profiler = config.measureme_out.as_ref().map(|out| { - Profiler::new(out).expect("Couldn't create `measureme` profiler") - }); + let profiler = config + .measureme_out + .as_ref() + .map(|out| Profiler::new(out).expect("Couldn't create `measureme` profiler")); Evaluator { // `env_vars` could be initialized properly here if `Memory` were available before // calling this method. @@ -617,9 +615,7 @@ impl<'mir, 'tcx> Machine<'mir, 'tcx> for Evaluator<'mir, 'tcx> { let timing = if let Some(profiler) = ecx.machine.profiler.as_ref() { let fn_name = frame.instance.to_string(); let entry = ecx.machine.string_cache.entry(fn_name.clone()); - let name = entry.or_insert_with(|| { - profiler.alloc_string(&*fn_name) - }); + let name = entry.or_insert_with(|| profiler.alloc_string(&*fn_name)); Some(profiler.start_recording_interval_event_detached( *name, From 0317e5bfd60246c224071303f0ffa6a12a2096ab Mon Sep 17 00:00:00 2001 From: Aaron Hill Date: Sun, 30 May 2021 10:04:57 -0500 Subject: [PATCH 5/6] Address more review comments --- src/machine.rs | 25 ++++++++++++++++--------- src/shims/panic.rs | 1 + 2 files changed, 17 insertions(+), 9 deletions(-) diff --git a/src/machine.rs b/src/machine.rs index 1a01ece6c9..ed633b5e17 100644 --- a/src/machine.rs +++ b/src/machine.rs @@ -8,7 +8,6 @@ use std::num::NonZeroU64; use std::time::Instant; use log::trace; -use measureme::{DetachedTiming, EventId, Profiler, StringId}; use rand::rngs::StdRng; use rand::SeedableRng; @@ -47,7 +46,16 @@ pub struct FrameData<'tcx> { /// If `measureme` profiling is enabled, holds timing information /// for the start of this frame. When we finish executing this frame, /// we use this to register a completed event with `measureme`. - pub timing: Option, + pub timing: Option, +} + +impl<'tcx> std::fmt::Debug for FrameData<'tcx> { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + f.debug_struct("FrameData") + .field("call_id", &self.call_id) + .field("catch_unwind", &self.catch_unwind) + .finish() + } } /// Extra memory kinds @@ -278,20 +286,19 @@ pub struct Evaluator<'mir, 'tcx> { /// The `measureme` profiler used to record timing information about /// the emulated program. - profiler: Option, + profiler: Option, /// Used with `profiler` to cache the `StringId`s for event names /// uesd with `measureme`. - string_cache: FxHashMap, + string_cache: FxHashMap, } impl<'mir, 'tcx> Evaluator<'mir, 'tcx> { pub(crate) fn new(config: &MiriConfig, layout_cx: LayoutCx<'tcx, TyCtxt<'tcx>>) -> Self { let layouts = PrimitiveLayouts::new(layout_cx).expect("Couldn't get layouts of primitive types"); - let profiler = config - .measureme_out - .as_ref() - .map(|out| Profiler::new(out).expect("Couldn't create `measureme` profiler")); + let profiler = config.measureme_out.as_ref().map(|out| { + measureme::Profiler::new(out).expect("Couldn't create `measureme` profiler") + }); Evaluator { // `env_vars` could be initialized properly here if `Memory` were available before // calling this method. @@ -619,7 +626,7 @@ impl<'mir, 'tcx> Machine<'mir, 'tcx> for Evaluator<'mir, 'tcx> { Some(profiler.start_recording_interval_event_detached( *name, - EventId::from_label(*name), + measureme::EventId::from_label(*name), ecx.get_active_thread().to_u32(), )) } else { diff --git a/src/shims/panic.rs b/src/shims/panic.rs index 6b08ee8e18..b1da7f340f 100644 --- a/src/shims/panic.rs +++ b/src/shims/panic.rs @@ -119,6 +119,7 @@ pub trait EvalContextExt<'mir, 'tcx: 'mir>: crate::MiriEvalContextExt<'mir, 'tcx ) -> InterpResult<'tcx, StackPopJump> { let this = self.eval_context_mut(); + trace!("handle_stack_pop(extra = {:?}, unwinding = {})", extra, unwinding); if let Some(stacked_borrows) = &this.memory.extra.stacked_borrows { stacked_borrows.borrow_mut().end_call(extra.call_id); } From c89a5d62ee4100018d8422ebdcddb47ed6290fcd Mon Sep 17 00:00:00 2001 From: Ralf Jung Date: Sun, 30 May 2021 17:13:49 +0200 Subject: [PATCH 6/6] add comment to debug impl --- src/machine.rs | 1 + 1 file changed, 1 insertion(+) diff --git a/src/machine.rs b/src/machine.rs index ed633b5e17..4f643e7f50 100644 --- a/src/machine.rs +++ b/src/machine.rs @@ -51,6 +51,7 @@ pub struct FrameData<'tcx> { impl<'tcx> std::fmt::Debug for FrameData<'tcx> { fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + // Omitting `timing`, it does not support `Debug`. f.debug_struct("FrameData") .field("call_id", &self.call_id) .field("catch_unwind", &self.catch_unwind)