Auto merge of #3338 - RalfJung:more-tracking-and-threads, r=RalfJung

print thread name in miri error backtraces; add option to track read/write accesses

This came up while debugging rust-lang/rust#121626. It didn't end up being useful there but still seems like good tools to have around.

Author: bors

src/bin/miri.rs

@@ -534,6 +534,8 @@ fn main() {
                     ),
             };
             miri_config.tracked_alloc_ids.extend(ids);
+        } else if arg == "-Zmiri-track-alloc-accesses" {
+            miri_config.track_alloc_accesses = true;
         } else if let Some(param) = arg.strip_prefix("-Zmiri-compare-exchange-weak-failure-rate=") {
             let rate = match param.parse::<f64>() {
                 Ok(rate) if rate >= 0.0 && rate <= 1.0 => rate,

src/borrow_tracker/mod.rs

@@ -122,13 +122,6 @@ impl VisitProvenance for GlobalStateInner {
 /// We need interior mutable access to the global state.
 pub type GlobalState = RefCell<GlobalStateInner>;
 
-/// Indicates which kind of access is being performed.
-#[derive(Copy, Clone, Hash, PartialEq, Eq, Debug)]
-pub enum AccessKind {
-    Read,
-    Write,
-}
-
 impl fmt::Display for AccessKind {
     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
         match self {

src/borrow_tracker/stacked_borrows/diagnostics.rs

@@ -5,7 +5,7 @@ use rustc_data_structures::fx::FxHashSet;
 use rustc_span::{Span, SpanData};
 use rustc_target::abi::Size;
 
-use crate::borrow_tracker::{AccessKind, GlobalStateInner, ProtectorKind};
+use crate::borrow_tracker::{GlobalStateInner, ProtectorKind};
 use crate::*;
 
 /// Error reporting

src/borrow_tracker/stacked_borrows/mod.rs

@@ -16,7 +16,7 @@ use rustc_target::abi::{Abi, Size};
 
 use crate::borrow_tracker::{
     stacked_borrows::diagnostics::{AllocHistory, DiagnosticCx, DiagnosticCxBuilder},
-    AccessKind, GlobalStateInner, ProtectorKind,
+    GlobalStateInner, ProtectorKind,
 };
 use crate::*;
 

src/borrow_tracker/tree_borrows/diagnostics.rs

@@ -9,7 +9,7 @@ use crate::borrow_tracker::tree_borrows::{
     tree::LocationState,
     unimap::UniIndex,
 };
-use crate::borrow_tracker::{AccessKind, ProtectorKind};
+use crate::borrow_tracker::ProtectorKind;
 use crate::*;
 
 /// Cause of an access: either a real access or one

src/borrow_tracker/tree_borrows/mod.rs

@@ -1,6 +1,6 @@
 use rustc_target::abi::{Abi, Size};
 
-use crate::borrow_tracker::{AccessKind, GlobalState, GlobalStateInner, ProtectorKind};
+use crate::borrow_tracker::{GlobalState, GlobalStateInner, ProtectorKind};
 use rustc_middle::{
     mir::{Mutability, RetagKind},
     ty::{

src/borrow_tracker/tree_borrows/perms.rs

@@ -3,7 +3,7 @@ use std::fmt;
 
 use crate::borrow_tracker::tree_borrows::diagnostics::TransitionError;
 use crate::borrow_tracker::tree_borrows::tree::AccessRelatedness;
-use crate::borrow_tracker::AccessKind;
+use crate::AccessKind;
 
 /// The activation states of a pointer.
 #[derive(Debug, Clone, Copy, PartialEq, Eq, Hash)]

src/borrow_tracker/tree_borrows/tree.rs

@@ -24,7 +24,7 @@ use crate::borrow_tracker::tree_borrows::{
     unimap::{UniEntry, UniIndex, UniKeyMap, UniValMap},
     Permission,
 };
-use crate::borrow_tracker::{AccessKind, GlobalState, ProtectorKind};
+use crate::borrow_tracker::{GlobalState, ProtectorKind};
 use crate::*;
 
 mod tests;

src/concurrency/data_race.rs

@@ -1673,8 +1673,8 @@ impl GlobalState {
         vector: VectorIdx,
     ) -> String {
         let thread = self.vector_info.borrow()[vector];
-        let thread_name = thread_mgr.get_thread_name(thread);
-        format!("thread `{}`", String::from_utf8_lossy(thread_name))
+        let thread_name = thread_mgr.get_thread_display_name(thread);
+        format!("thread `{thread_name}`")
     }
 
     /// Acquire a lock, express that the previous call of

src/concurrency/thread.rs

@@ -160,9 +160,18 @@ pub type StackEmptyCallback<'mir, 'tcx> =
     Box<dyn FnMut(&mut MiriInterpCx<'mir, 'tcx>) -> InterpResult<'tcx, Poll<()>>>;
 
 impl<'mir, 'tcx> Thread<'mir, 'tcx> {
-    /// Get the name of the current thread, or `<unnamed>` if it was not set.
-    fn thread_name(&self) -> &[u8] {
-        if let Some(ref thread_name) = self.thread_name { thread_name } else { b"<unnamed>" }
+    /// Get the name of the current thread if it was set.
+    fn thread_name(&self) -> Option<&[u8]> {
+        self.thread_name.as_deref()
+    }
+
+    /// Get the name of the current thread for display purposes; will include thread ID if not set.
+    fn thread_display_name(&self, id: ThreadId) -> String {
+        if let Some(ref thread_name) = self.thread_name {
+            String::from_utf8_lossy(thread_name).into_owned()
+        } else {
+            format!("unnamed-{}", id.index())
+        }
     }
 
     /// Return the top user-relevant frame, if there is one.
@@ -205,7 +214,7 @@ impl<'mir, 'tcx> std::fmt::Debug for Thread<'mir, 'tcx> {
         write!(
             f,
             "{}({:?}, {:?})",
-            String::from_utf8_lossy(self.thread_name()),
+            String::from_utf8_lossy(self.thread_name().unwrap_or(b"<unnamed>")),
             self.state,
             self.join_status
         )
@@ -572,10 +581,14 @@ impl<'mir, 'tcx: 'mir> ThreadManager<'mir, 'tcx> {
     }
 
     /// Get the name of the given thread.
-    pub fn get_thread_name(&self, thread: ThreadId) -> &[u8] {
+    pub fn get_thread_name(&self, thread: ThreadId) -> Option<&[u8]> {
         self.threads[thread].thread_name()
     }
 
+    pub fn get_thread_display_name(&self, thread: ThreadId) -> String {
+        self.threads[thread].thread_display_name(thread)
+    }
+
     /// Put the thread into the blocked state.
     fn block_thread(&mut self, thread: ThreadId) {
         let state = &mut self.threads[thread].state;
@@ -980,7 +993,7 @@ pub trait EvalContextExt<'mir, 'tcx: 'mir>: crate::MiriInterpCxExt<'mir, 'tcx> {
     }
 
     #[inline]
-    fn get_thread_name<'c>(&'c self, thread: ThreadId) -> &'c [u8]
+    fn get_thread_name<'c>(&'c self, thread: ThreadId) -> Option<&[u8]>
     where
         'mir: 'c,
     {

src/diagnostics.rs

@@ -116,6 +116,7 @@ pub enum NonHaltingDiagnostic {
     CreatedCallId(CallId),
     CreatedAlloc(AllocId, Size, Align, MemoryKind<MiriMemoryKind>),
     FreedAlloc(AllocId),
+    AccessedAlloc(AllocId, AccessKind),
     RejectedIsolatedOp(String),
     ProgressReport {
         block_count: u64, // how many basic blocks have been run so far
@@ -477,7 +478,6 @@ pub fn report_msg<'tcx>(
 
     // Show note and help messages.
     let mut extra_span = false;
-    let notes_len = notes.len();
     for (span_data, note) in notes {
         if let Some(span_data) = span_data {
             err.span_note(span_data.span(), note);
@@ -486,7 +486,6 @@ pub fn report_msg<'tcx>(
             err.note(note);
         }
     }
-    let helps_len = helps.len();
     for (span_data, help) in helps {
         if let Some(span_data) = span_data {
             err.span_help(span_data.span(), help);
@@ -495,12 +494,20 @@ pub fn report_msg<'tcx>(
             err.help(help);
         }
     }
-    if notes_len + helps_len > 0 {
-        // Add visual separator before backtrace.
-        err.note(if extra_span { "BACKTRACE (of the first span):" } else { "BACKTRACE:" });
-    }
 
     // Add backtrace
+    let mut backtrace_title = String::from("BACKTRACE");
+    if extra_span {
+        write!(backtrace_title, " (of the first span)").unwrap();
+    }
+    let thread_name =
+        machine.threads.get_thread_display_name(machine.threads.get_active_thread_id());
+    if thread_name != "main" {
+        // Only print thread name if it is not `main`.
+        write!(backtrace_title, " on thread `{thread_name}`").unwrap();
+    };
+    write!(backtrace_title, ":").unwrap();
+    err.note(backtrace_title);
     for (idx, frame_info) in stacktrace.iter().enumerate() {
         let is_local = machine.is_local(frame_info);
         // No span for non-local frames and the first frame (which is the error site).
@@ -532,6 +539,7 @@ impl<'mir, 'tcx> MiriMachine<'mir, 'tcx> {
             | PoppedPointerTag(..)
             | CreatedCallId(..)
             | CreatedAlloc(..)
+            | AccessedAlloc(..)
             | FreedAlloc(..)
             | ProgressReport { .. }
             | WeakMemoryOutdatedLoad => ("tracking was triggered".to_string(), DiagLevel::Note),
@@ -553,6 +561,8 @@ impl<'mir, 'tcx> MiriMachine<'mir, 'tcx> {
                     size = size.bytes(),
                     align = align.bytes(),
                 ),
+            AccessedAlloc(AllocId(id), access_kind) =>
+                format!("{access_kind} access to allocation with id {id}"),
             FreedAlloc(AllocId(id)) => format!("freed allocation with id {id}"),
             RejectedIsolatedOp(ref op) =>
                 format!("{op} was made to return an error due to isolation"),

src/eval.rs

@@ -112,6 +112,8 @@ pub struct MiriConfig {
     pub tracked_call_ids: FxHashSet<CallId>,
     /// The allocation ids to report about.
     pub tracked_alloc_ids: FxHashSet<AllocId>,
+    /// For the tracked alloc ids, also report read/write accesses.
+    pub track_alloc_accesses: bool,
     /// Determine if data race detection should be enabled
     pub data_race_detector: bool,
     /// Determine if weak memory emulation should be enabled. Requires data race detection to be enabled
@@ -169,6 +171,7 @@ impl Default for MiriConfig {
             tracked_pointer_tags: FxHashSet::default(),
             tracked_call_ids: FxHashSet::default(),
             tracked_alloc_ids: FxHashSet::default(),
+            track_alloc_accesses: false,
             data_race_detector: true,
             weak_memory_emulation: true,
             track_outdated_loads: false,

src/helpers.rs

@@ -22,6 +22,13 @@ use rand::RngCore;
 
 use crate::*;
 
+/// Indicates which kind of access is being performed.
+#[derive(Copy, Clone, Hash, PartialEq, Eq, Debug)]
+pub enum AccessKind {
+    Read,
+    Write,
+}
+
 // This mapping should match `decode_error_kind` in
 // <https://github.com/rust-lang/rust/blob/master/library/std/src/sys/pal/unix/mod.rs>.
 const UNIX_IO_ERROR_TABLE: &[(&str, std::io::ErrorKind)] = {

src/lib.rs

@@ -120,7 +120,7 @@ pub use crate::diagnostics::{
 pub use crate::eval::{
     create_ecx, eval_entry, AlignmentCheck, BacktraceStyle, IsolatedOp, MiriConfig, RejectOpWith,
 };
-pub use crate::helpers::EvalContextExt as _;
+pub use crate::helpers::{AccessKind, EvalContextExt as _};
 pub use crate::intptrcast::{EvalContextExt as _, ProvenanceMode};
 pub use crate::machine::{
     AllocExtra, FrameExtra, MiriInterpCx, MiriInterpCxExt, MiriMachine, MiriMemoryKind,

src/machine.rs

@@ -512,6 +512,8 @@ pub struct MiriMachine<'mir, 'tcx> {
     /// The allocation IDs to report when they are being allocated
     /// (helps for debugging memory leaks and use after free bugs).
     tracked_alloc_ids: FxHashSet<AllocId>,
+    /// For the tracked alloc ids, also report read/write accesses.
+    track_alloc_accesses: bool,
 
     /// Controls whether alignment of memory accesses is being checked.
     pub(crate) check_alignment: AlignmentCheck,
@@ -654,6 +656,7 @@ impl<'mir, 'tcx> MiriMachine<'mir, 'tcx> {
             extern_statics: FxHashMap::default(),
             rng: RefCell::new(rng),
             tracked_alloc_ids: config.tracked_alloc_ids.clone(),
+            track_alloc_accesses: config.track_alloc_accesses,
             check_alignment: config.check_alignment,
             cmpxchg_weak_failure_rate: config.cmpxchg_weak_failure_rate,
             mute_stdout_stderr: config.mute_stdout_stderr,
@@ -793,6 +796,7 @@ impl VisitProvenance for MiriMachine<'_, '_> {
             local_crates: _,
             rng: _,
             tracked_alloc_ids: _,
+            track_alloc_accesses: _,
             check_alignment: _,
             cmpxchg_weak_failure_rate: _,
             mute_stdout_stderr: _,
@@ -1235,6 +1239,10 @@ impl<'mir, 'tcx> Machine<'mir, 'tcx> for MiriMachine<'mir, 'tcx> {
         (alloc_id, prov_extra): (AllocId, Self::ProvenanceExtra),
         range: AllocRange,
     ) -> InterpResult<'tcx> {
+        if machine.track_alloc_accesses && machine.tracked_alloc_ids.contains(&alloc_id) {
+            machine
+                .emit_diagnostic(NonHaltingDiagnostic::AccessedAlloc(alloc_id, AccessKind::Read));
+        }
         if let Some(data_race) = &alloc_extra.data_race {
             data_race.read(alloc_id, range, machine)?;
         }
@@ -1255,6 +1263,10 @@ impl<'mir, 'tcx> Machine<'mir, 'tcx> for MiriMachine<'mir, 'tcx> {
         (alloc_id, prov_extra): (AllocId, Self::ProvenanceExtra),
         range: AllocRange,
     ) -> InterpResult<'tcx> {
+        if machine.track_alloc_accesses && machine.tracked_alloc_ids.contains(&alloc_id) {
+            machine
+                .emit_diagnostic(NonHaltingDiagnostic::AccessedAlloc(alloc_id, AccessKind::Write));
+        }
         if let Some(data_race) = &mut alloc_extra.data_race {
             data_race.write(alloc_id, range, machine)?;
         }

src/shims/unix/thread.rs

@@ -104,7 +104,8 @@ pub trait EvalContextExt<'mir, 'tcx: 'mir>: crate::MiriInterpCxExt<'mir, 'tcx> {
         let name_out = name_out.to_pointer(this)?;
         let len = len.to_target_usize(this)?;
 
-        let name = this.get_thread_name(thread).to_owned();
+        // FIXME: we should use the program name if the thread name is not set
+        let name = this.get_thread_name(thread).unwrap_or(b"<unnamed>").to_owned();
         let (success, _written) = this.write_c_str(&name, name_out, len)?;
 
         Ok(if success { Scalar::from_u32(0) } else { this.eval_libc("ERANGE") })

tests/compiletest.rs

@@ -172,6 +172,8 @@ regexes! {
     r"\.rs:[0-9]+:[0-9]+(: [0-9]+:[0-9]+)?" => ".rs:LL:CC",
     // erase alloc ids
     "alloc[0-9]+"                    => "ALLOC",
+    // erase thread ids
+    r"unnamed-[0-9]+"               => "unnamed-ID",
     // erase borrow tags
     "<[0-9]+>"                       => "<TAG>",
     "<[0-9]+="                       => "<TAG=",

tests/fail-dep/concurrency/libc_pthread_create_too_few_args.stderr

@@ -6,7 +6,7 @@ LL |     panic!()
    |
    = help: this indicates a bug in the program: it performed an invalid operation, and caused Undefined Behavior
    = help: see https://doc.rust-lang.org/nightly/reference/behavior-considered-undefined.html for further information
-   = note: BACKTRACE:
+   = note: BACKTRACE on thread `unnamed-ID`:
    = note: inside `thread_start` at RUSTLIB/core/src/panic.rs:LL:CC
    = note: this error originates in the macro `$crate::panic::panic_2021` which comes from the expansion of the macro `panic` (in Nightly builds, run with -Z macro-backtrace for more info)
 

tests/fail-dep/concurrency/libc_pthread_create_too_many_args.stderr

@@ -6,7 +6,7 @@ LL |     panic!()
    |
    = help: this indicates a bug in the program: it performed an invalid operation, and caused Undefined Behavior
    = help: see https://doc.rust-lang.org/nightly/reference/behavior-considered-undefined.html for further information
-   = note: BACKTRACE:
+   = note: BACKTRACE on thread `unnamed-ID`:
    = note: inside `thread_start` at RUSTLIB/core/src/panic.rs:LL:CC
    = note: this error originates in the macro `$crate::panic::panic_2021` which comes from the expansion of the macro `panic` (in Nightly builds, run with -Z macro-backtrace for more info)
 

tests/fail-dep/concurrency/libc_pthread_join_main.stderr

@@ -6,7 +6,7 @@ LL |             assert_eq!(libc::pthread_join(thread_id, ptr::null_mut()), 0);
    |
    = help: this indicates a bug in the program: it performed an invalid operation, and caused Undefined Behavior
    = help: see https://doc.rust-lang.org/nightly/reference/behavior-considered-undefined.html for further information
-   = note: BACKTRACE:
+   = note: BACKTRACE on thread `unnamed-ID`:
    = note: inside closure at $DIR/libc_pthread_join_main.rs:LL:CC
 
 note: some details are omitted, run with `MIRIFLAGS=-Zmiri-backtrace=full` for a verbose backtrace

tests/fail-dep/concurrency/libc_pthread_join_multiple.stderr

@@ -6,7 +6,7 @@ LL | ...   assert_eq!(libc::pthread_join(native_copy, ptr::null_mut()), 0);
    |
    = help: this indicates a bug in the program: it performed an invalid operation, and caused Undefined Behavior
    = help: see https://doc.rust-lang.org/nightly/reference/behavior-considered-undefined.html for further information
-   = note: BACKTRACE:
+   = note: BACKTRACE on thread `unnamed-ID`:
    = note: inside closure at $DIR/libc_pthread_join_multiple.rs:LL:CC
 
 note: some details are omitted, run with `MIRIFLAGS=-Zmiri-backtrace=full` for a verbose backtrace

tests/fail-dep/concurrency/libc_pthread_join_self.stderr

@@ -6,7 +6,7 @@ LL |             assert_eq!(libc::pthread_join(native, ptr::null_mut()), 0);
    |
    = help: this indicates a bug in the program: it performed an invalid operation, and caused Undefined Behavior
    = help: see https://doc.rust-lang.org/nightly/reference/behavior-considered-undefined.html for further information
-   = note: BACKTRACE:
+   = note: BACKTRACE on thread `unnamed-ID`:
    = note: inside closure at $DIR/libc_pthread_join_self.rs:LL:CC
 
 note: some details are omitted, run with `MIRIFLAGS=-Zmiri-backtrace=full` for a verbose backtrace

tests/fail-dep/concurrency/unwind_top_of_stack.stderr

@@ -14,7 +14,7 @@ LL | | }
    |
    = help: this indicates a bug in the program: it performed an invalid operation, and caused Undefined Behavior
    = help: see https://doc.rust-lang.org/nightly/reference/behavior-considered-undefined.html for further information
-   = note: BACKTRACE:
+   = note: BACKTRACE on thread `unnamed-ID`:
    = note: inside `thread_start` at $DIR/unwind_top_of_stack.rs:LL:CC
 
 error: aborting due to 1 previous error

tests/fail-dep/shims/env-set_var-data-race.stderr

@@ -1,8 +1,8 @@
-error: Undefined Behavior: Data race detected between (1) non-atomic write on thread `main` and (2) non-atomic read on thread `<unnamed>` at ALLOC. (2) just happened here
+error: Undefined Behavior: Data race detected between (1) non-atomic write on thread `main` and (2) non-atomic read on thread `unnamed-ID` at ALLOC. (2) just happened here
   --> $DIR/env-set_var-data-race.rs:LL:CC
    |
 LL |         libc::getenv(b"TZ/0".as_ptr().cast());
-   |         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Data race detected between (1) non-atomic write on thread `main` and (2) non-atomic read on thread `<unnamed>` at ALLOC. (2) just happened here
+   |         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Data race detected between (1) non-atomic write on thread `main` and (2) non-atomic read on thread `unnamed-ID` at ALLOC. (2) just happened here
    |
 help: and (1) occurred earlier here
   --> $DIR/env-set_var-data-race.rs:LL:CC
@@ -11,7 +11,7 @@ LL |     env::set_var("MY_RUST_VAR", "Ferris");
    |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    = help: this indicates a bug in the program: it performed an invalid operation, and caused Undefined Behavior
    = help: see https://doc.rust-lang.org/nightly/reference/behavior-considered-undefined.html for further information
-   = note: BACKTRACE (of the first span):
+   = note: BACKTRACE (of the first span) on thread `unnamed-ID`:
    = note: inside closure at $DIR/env-set_var-data-race.rs:LL:CC
 
 note: some details are omitted, run with `MIRIFLAGS=-Zmiri-backtrace=full` for a verbose backtrace

tests/fail-dep/shims/sync/libc_pthread_mutex_deadlock.stderr

@@ -4,6 +4,7 @@ error: deadlock: the evaluated program deadlocked
 LL |             assert_eq!(libc::pthread_mutex_lock(lock_copy.0.get() as *mut _), 0);
    |                                                                            ^ the evaluated program deadlocked
    |
+   = note: BACKTRACE on thread `unnamed-ID`:
    = note: inside closure at $DIR/libc_pthread_mutex_deadlock.rs:LL:CC
 
 note: some details are omitted, run with `MIRIFLAGS=-Zmiri-backtrace=full` for a verbose backtrace