Auto merge of rust-lang#2272 - RalfJung:progress, r=RalfJung

add -Zmiri-report-progress to regularly print a stacktrace of what we are executing

Fixes rust-lang/miri#910

The stacktrace is printed every N basic blocks. I picked the default (1 million) to take a few seconds on my machine, but it can be adjusted by the user.

Author: bors

README.md

@@ -292,6 +292,10 @@ environment variable. We first document the most relevant and most commonly used
 * `-Zmiri-preemption-rate` configures the probability that at the end of a basic block, the active
   thread will be preempted. The default is `0.01` (i.e., 1%). Setting this to `0` disables
   preemption.
+* `-Zmiri-report-progress` makes Miri print the current stacktrace every now and then, so you can
+  tell what it is doing when a program just keeps running. You can customize how frequently the
+  report is printed via `-Zmiri-report-progress=<blocks>`, which prints the report every N basic
+  blocks.
 * `-Zmiri-seed=<hex>` configures the seed of the RNG that Miri uses to resolve non-determinism. This
   RNG is used to pick base addresses for allocations, to determine preemption and failure of
   `compare_exchange_weak`, and to control store buffering for weak memory emulation. When isolation

src/bin/miri.rs

@@ -468,6 +468,15 @@ fn main() {
                     ),
             };
             miri_config.preemption_rate = rate;
+        } else if arg == "-Zmiri-report-progress" {
+            // This makes it take a few seconds between progress reports on my laptop.
+            miri_config.report_progress = Some(1_000_000);
+        } else if let Some(param) = arg.strip_prefix("-Zmiri-report-progress=") {
+            let interval = match param.parse::<u32>() {
+                Ok(i) => i,
+                Err(err) => panic!("-Zmiri-report-progress requires a `u32`: {}", err),
+            };
+            miri_config.report_progress = Some(interval);
         } else if let Some(param) = arg.strip_prefix("-Zmiri-measureme=") {
             miri_config.measureme_out = Some(param.to_string());
         } else if let Some(param) = arg.strip_prefix("-Zmiri-backtrace=") {

src/diagnostics.rs

@@ -68,6 +68,7 @@ pub enum NonHaltingDiagnostic {
     CreatedAlloc(AllocId),
     FreedAlloc(AllocId),
     RejectedIsolatedOp(String),
+    ProgressReport,
 }
 
 /// Level of Miri specific diagnostics
@@ -465,6 +466,8 @@ pub trait EvalContextExt<'mir, 'tcx: 'mir>: crate::MiriEvalContextExt<'mir, 'tcx
                     FreedAlloc(AllocId(id)) => format!("freed allocation with id {id}"),
                     RejectedIsolatedOp(ref op) =>
                         format!("{op} was made to return an error due to isolation"),
+                    ProgressReport =>
+                        format!("progress report: current operation being executed is here"),
                 };
 
                 let (title, diag_level) = match e {

src/eval.rs

@@ -124,6 +124,8 @@ pub struct MiriConfig {
     pub mute_stdout_stderr: bool,
     /// The probability of the active thread being preempted at the end of each basic block.
     pub preemption_rate: f64,
+    /// Report the current instruction being executed every N basic blocks.
+    pub report_progress: Option<u32>,
 }
 
 impl Default for MiriConfig {
@@ -154,6 +156,7 @@ impl Default for MiriConfig {
             provenance_mode: ProvenanceMode::Legacy,
             mute_stdout_stderr: false,
             preemption_rate: 0.01, // 1%
+            report_progress: None,
         }
     }
 }

src/machine.rs

@@ -333,6 +333,11 @@ pub struct Evaluator<'mir, 'tcx> {
 
     /// The probability of the active thread being preempted at the end of each basic block.
     pub(crate) preemption_rate: f64,
+
+    /// If `Some`, we will report the current stack every N basic blocks.
+    pub(crate) report_progress: Option<u32>,
+    /// The number of blocks that passed since the last progress report.
+    pub(crate) since_progress_report: u32,
 }
 
 impl<'mir, 'tcx> Evaluator<'mir, 'tcx> {
@@ -390,6 +395,8 @@ impl<'mir, 'tcx> Evaluator<'mir, 'tcx> {
             mute_stdout_stderr: config.mute_stdout_stderr,
             weak_memory: config.weak_memory_emulation,
             preemption_rate: config.preemption_rate,
+            report_progress: config.report_progress,
+            since_progress_report: 0,
         }
     }
 
@@ -862,6 +869,16 @@ impl<'mir, 'tcx> Machine<'mir, 'tcx> for Evaluator<'mir, 'tcx> {
     }
 
     fn before_terminator(ecx: &mut InterpCx<'mir, 'tcx, Self>) -> InterpResult<'tcx> {
+        // Possibly report our progress.
+        if let Some(report_progress) = ecx.machine.report_progress {
+            if ecx.machine.since_progress_report >= report_progress {
+                register_diagnostic(NonHaltingDiagnostic::ProgressReport);
+                ecx.machine.since_progress_report = 0;
+            }
+            // Cannot overflow, since it is strictly less than `report_progress`.
+            ecx.machine.since_progress_report += 1;
+        }
+        // These are our preemption points.
         ecx.maybe_preempt_active_thread();
         Ok(())
     }

test-cargo-miri/build.rs

@@ -16,7 +16,7 @@ fn main() {
     not_in_miri();
     // Cargo calls `miri --print=cfg` to populate the `CARGO_CFG_*` env vars.
     // Make sure that the "miri" flag is set.
-    assert!(env::var_os("CARGO_CFG_MIRI").is_some());
+    assert!(env::var_os("CARGO_CFG_MIRI").is_some(), "cargo failed to tell us about `--cfg miri`");
     println!("cargo:rerun-if-changed=build.rs");
     println!("cargo:rerun-if-env-changed=MIRITESTVAR");
     println!("cargo:rustc-env=MIRITESTVAR=testval");