Add tracing_chrome under "tracing" feature

Cargo.toml

@@ -27,6 +27,7 @@ chrono = { version = "0.4.38", default-features = false }
 chrono-tz = "0.10"
 directories = "6"
 bitflags = "2.6"
+serde_json = { version = "1.0", optional = true }
 
 # Copied from `compiler/rustc/Cargo.toml`.
 # But only for some targets, it fails for others. Rustc configures this in its CI, but we can't
@@ -64,9 +65,12 @@ harness = false
 
 [features]
 default = ["stack-cache"]
+# When adding a new feature that is relevant for some tests,
+# make sure to add it to the FEATURES variable in `ci/ci.sh`.
 genmc = []
 stack-cache = []
 stack-cache-consistency-check = ["stack-cache"]
+tracing = ["serde_json"]
 
 [lints.rust.unexpected_cfgs]
 level = "warn"

ci/ci.sh

@@ -28,16 +28,17 @@ begingroup "Building Miri"
 export RUSTFLAGS="-D warnings"
 export CARGO_INCREMENTAL=0
 export CARGO_EXTRA_FLAGS="--locked"
+# We enable all features (except tracing) to make sure the Stacked Borrows consistency check runs.
+export FEATURES="--features=genmc,stack-cache,stack-cache-consistency-check"
 
 # Determine configuration for installed build (used by test-cargo-miri and `./miri bench`).
+# $FEATURES is not passed here as "stack-cache-consistency-check" makes things quite slow.
 echo "Installing release version of Miri"
 time ./miri install
 
 # Prepare debug build for direct `./miri` invocations.
-# We enable all features to make sure the Stacked Borrows consistency check runs.
 echo "Building debug version of Miri"
-export CARGO_EXTRA_FLAGS="$CARGO_EXTRA_FLAGS --all-features"
-time ./miri build # the build that all the `./miri test` below will use
+time ./miri build "$FEATURES" # the build that all the `./miri test` below will use
 
 endgroup
 
@@ -61,9 +62,9 @@ function run_tests {
 
   ## ui test suite
   if [ -n "${GC_STRESS-}" ]; then
-    time MIRIFLAGS="${MIRIFLAGS-} -Zmiri-provenance-gc=1" ./miri test $TARGET_FLAG
+    time MIRIFLAGS="${MIRIFLAGS-} -Zmiri-provenance-gc=1" ./miri test "$FEATURES" $TARGET_FLAG
   else
-    time ./miri test $TARGET_FLAG
+    time ./miri test "$FEATURES" $TARGET_FLAG
   fi
 
   ## advanced tests
@@ -74,20 +75,20 @@ function run_tests {
     # them. Also error locations change so we don't run the failing tests.
     # We explicitly enable debug-assertions here, they are disabled by -O but we have tests
     # which exist to check that we panic on debug assertion failures.
-    time MIRIFLAGS="${MIRIFLAGS-} -O -Zmir-opt-level=4 -Cdebug-assertions=yes" MIRI_SKIP_UI_CHECKS=1 ./miri test $TARGET_FLAG tests/{pass,panic}
+    time MIRIFLAGS="${MIRIFLAGS-} -O -Zmir-opt-level=4 -Cdebug-assertions=yes" MIRI_SKIP_UI_CHECKS=1 ./miri test "$FEATURES" $TARGET_FLAG tests/{pass,panic}
   fi
   if [ -n "${MANY_SEEDS-}" ]; then
     # Run many-seeds tests. (Also tests `./miri run`.)
     time for FILE in tests/many-seeds/*.rs; do
-      ./miri run "-Zmiri-many-seeds=0..$MANY_SEEDS" $TARGET_FLAG "$FILE"
+      ./miri run "$FEATURES" $TARGET_FLAG "-Zmiri-many-seeds=0..$MANY_SEEDS" "$FILE"
     done
   fi
   if [ -n "${TEST_BENCH-}" ]; then
     # Check that the benchmarks build and run, but only once.
     time HYPERFINE="hyperfine -w0 -r1 --show-output" ./miri bench $TARGET_FLAG --no-install
   fi
   # Smoke-test `./miri run --dep`.
-  ./miri run $TARGET_FLAG --dep tests/pass-dep/getrandom.rs
+  ./miri run "$FEATURES" $TARGET_FLAG --dep tests/pass-dep/getrandom.rs
 
   ## test-cargo-miri
   # On Windows, there is always "python", not "python3" or "python2".
@@ -125,7 +126,7 @@ function run_tests_minimal {
     exit 1
   fi
 
-  time ./miri test $TARGET_FLAG "$@"
+  time ./miri test "$FEATURES" $TARGET_FLAG "$@"
 
   # Ensure that a small smoke test of cargo-miri works.
   time cargo miri run --manifest-path test-cargo-miri/no-std-smoke/Cargo.toml $TARGET_FLAG

rustfmt.toml

@@ -8,3 +8,8 @@ imports_granularity = "Module"
 force_multiline_blocks = true
 match_arm_blocks = false
 match_arm_leading_pipes = "Preserve"
+
+ignore = [
+    # This file is copy-pasted from the tracing_chrome crate and should remain like the original.
+    "src/bin/trace/tracing_chrome.rs"
+]

src/bin/miri.rs

@@ -10,6 +10,7 @@
 
 // Some "regular" crates we want to share with rustc
 extern crate tracing;
+extern crate tracing_subscriber;
 
 // The rustc crates we need
 extern crate rustc_abi;
@@ -24,14 +25,17 @@ extern crate rustc_middle;
 extern crate rustc_session;
 extern crate rustc_span;
 
-use std::env::{self, VarError};
+mod trace;
+
+use std::env;
 use std::num::NonZero;
 use std::ops::Range;
 use std::path::PathBuf;
+use std::process::ExitCode;
 use std::rc::Rc;
 use std::str::FromStr;
 use std::sync::atomic::{AtomicI32, AtomicU32, Ordering};
-use std::sync::{Arc, Once};
+use std::sync::{Arc, Mutex};
 
 use miri::{
     BacktraceStyle, BorrowTrackerMethod, GenmcConfig, GenmcCtx, MiriConfig, MiriEntryFnType,
@@ -52,17 +56,21 @@ use rustc_middle::query::LocalCrate;
 use rustc_middle::traits::{ObligationCause, ObligationCauseCode};
 use rustc_middle::ty::{self, Ty, TyCtxt};
 use rustc_middle::util::Providers;
+use rustc_session::EarlyDiagCtxt;
 use rustc_session::config::{CrateType, ErrorOutputType, OptLevel};
 use rustc_session::search_paths::PathKind;
-use rustc_session::{CtfeBacktrace, EarlyDiagCtxt};
 use rustc_span::def_id::DefId;
 use tracing::debug;
 
+use crate::trace::logger_setup::{TracingGuard, init_early_loggers, init_late_loggers};
+
 struct MiriCompilerCalls {
     miri_config: Option<MiriConfig>,
     many_seeds: Option<ManySeedsConfig>,
     /// Settings for using GenMC with Miri.
     genmc_config: Option<GenmcConfig>,
+    /// Kept here to be dropped before calling [std::process::exit].
+    tracing_guard: Option<TracingGuard>,
 }
 
 struct ManySeedsConfig {
@@ -75,8 +83,9 @@ impl MiriCompilerCalls {
         miri_config: MiriConfig,
         many_seeds: Option<ManySeedsConfig>,
         genmc_config: Option<GenmcConfig>,
+        tracing_guard: Option<TracingGuard>,
     ) -> Self {
-        Self { miri_config: Some(miri_config), many_seeds, genmc_config }
+        Self { miri_config: Some(miri_config), many_seeds, genmc_config, tracing_guard }
     }
 }
 
@@ -156,7 +165,11 @@ impl rustc_driver::Callbacks for MiriCompilerCalls {
         }
 
         let early_dcx = EarlyDiagCtxt::new(tcx.sess.opts.error_format);
-        init_late_loggers(&early_dcx, tcx);
+        let tracing_guard = init_late_loggers(&early_dcx, tcx);
+        if self.tracing_guard.is_none() {
+            // Either tracing_guard or self.tracing_guard are None, due to LOGGER_INITED.call_once().
+            self.tracing_guard = tracing_guard;
+        }
         if !tcx.crate_types().contains(&CrateType::Executable) {
             tcx.dcx().fatal("miri only makes sense on bin crates");
         }
@@ -196,6 +209,7 @@ impl rustc_driver::Callbacks for MiriCompilerCalls {
             assert!(config.seed.is_none());
             let exit_code = sync::IntoDynSyncSend(AtomicI32::new(rustc_driver::EXIT_SUCCESS));
             let num_failed = sync::IntoDynSyncSend(AtomicU32::new(0));
+            let tracing_guard = sync::IntoDynSyncSend(Mutex::new(self.tracing_guard.take()));
             sync::par_for_each_in(many_seeds.seeds.clone(), |seed| {
                 let mut config = config.clone();
                 config.seed = Some((*seed).into());
@@ -211,6 +225,10 @@ impl rustc_driver::Callbacks for MiriCompilerCalls {
                 if return_code != rustc_driver::EXIT_SUCCESS {
                     eprintln!("FAILING SEED: {seed}");
                     if !many_seeds.keep_going {
+                        // Drop the tracing guard before exiting, so tracing calls are flushed correctly.
+                        if let Ok(mut lock) = tracing_guard.try_lock() {
+                            std::mem::drop((*lock).take());
+                        }
                         // `abort_if_errors` would actually not stop, since `par_for_each` waits for the
                         // rest of the to finish, so we just exit immediately.
                         std::process::exit(return_code);
@@ -223,6 +241,8 @@ impl rustc_driver::Callbacks for MiriCompilerCalls {
             if num_failed > 0 {
                 eprintln!("{num_failed}/{total} SEEDS FAILED", total = many_seeds.seeds.count());
             }
+            // Drop the tracing guard before exiting, so tracing calls are flushed correctly.
+            std::mem::drop(tracing_guard);
             std::process::exit(exit_code.0.into_inner());
         } else {
             let return_code = miri::eval_entry(tcx, entry_def_id, entry_type, &config, None)
@@ -232,6 +252,9 @@ impl rustc_driver::Callbacks for MiriCompilerCalls {
                     tcx.dcx().abort_if_errors();
                     rustc_driver::EXIT_FAILURE
                 });
+
+            // Drop the tracing guard before exiting, so tracing calls are flushed correctly.
+            std::mem::drop(self.tracing_guard.take());
             std::process::exit(return_code);
         }
 
@@ -336,74 +359,19 @@ macro_rules! show_error {
     ($($tt:tt)*) => { show_error(&format_args!($($tt)*)) };
 }
 
-fn rustc_logger_config() -> rustc_log::LoggerConfig {
-    // Start with the usual env vars.
-    let mut cfg = rustc_log::LoggerConfig::from_env("RUSTC_LOG");
-
-    // Overwrite if MIRI_LOG is set.
-    if let Ok(var) = env::var("MIRI_LOG") {
-        // MIRI_LOG serves as default for RUSTC_LOG, if that is not set.
-        if matches!(cfg.filter, Err(VarError::NotPresent)) {
-            // 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 `RUSTC_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_const_eval::interpret=debug`.
-            if tracing::Level::from_str(&var).is_ok() {
-                cfg.filter = Ok(format!(
-                    "rustc_middle::mir::interpret={var},rustc_const_eval::interpret={var},miri={var}"
-                ));
-            } else {
-                cfg.filter = Ok(var);
-            }
-        }
-    }
-
-    cfg
-}
-
-/// The global logger can only be set once per process, so track
-/// whether that already happened.
-static LOGGER_INITED: Once = Once::new();
-
-fn init_early_loggers(early_dcx: &EarlyDiagCtxt) {
-    // 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` starts interpreting.
-    if env::var_os("RUSTC_LOG").is_some() {
-        LOGGER_INITED.call_once(|| {
-            rustc_driver::init_logger(early_dcx, rustc_logger_config());
-        });
-    }
-}
-
-fn init_late_loggers(early_dcx: &EarlyDiagCtxt, tcx: TyCtxt<'_>) {
-    // If the logger is not yet initialized, initialize it.
-    LOGGER_INITED.call_once(|| {
-        rustc_driver::init_logger(early_dcx, rustc_logger_config());
-    });
-
-    // If `MIRI_BACKTRACE` is set and `RUSTC_CTFE_BACKTRACE` is not, set `RUSTC_CTFE_BACKTRACE`.
-    // Do this late, so we ideally only apply this to Miri's errors.
-    if let Some(val) = env::var_os("MIRI_BACKTRACE") {
-        let ctfe_backtrace = match &*val.to_string_lossy() {
-            "immediate" => CtfeBacktrace::Immediate,
-            "0" => CtfeBacktrace::Disabled,
-            _ => CtfeBacktrace::Capture,
-        };
-        *tcx.sess.ctfe_backtrace.borrow_mut() = ctfe_backtrace;
-    }
-}
-
 /// Execute a compiler with the given CLI arguments and callbacks.
-fn run_compiler_and_exit(
+/// Does not call [std::process::exit] directly, but rather returns an [ExitCode],
+/// to allow the tracing guard to be dropped before exiting.
+#[must_use]
+fn run_compiler_return_exit_code(
     args: &[String],
     callbacks: &mut (dyn rustc_driver::Callbacks + Send),
-) -> ! {
-    // Invoke compiler, and handle return code.
-    let exit_code =
-        rustc_driver::catch_with_exit_code(move || rustc_driver::run_compiler(args, callbacks));
-    std::process::exit(exit_code)
+) -> ExitCode {
+    // Invoke compiler, catch any unwinding panics and handle return code.
+    match rustc_driver::catch_fatal_errors(move || rustc_driver::run_compiler(args, callbacks)) {
+        Ok(()) => ExitCode::SUCCESS,
+        _ => ExitCode::FAILURE,
+    }
 }
 
 /// Parses a comma separated list of `T` from the given string:
@@ -471,7 +439,7 @@ fn jemalloc_magic() {
     }
 }
 
-fn main() {
+fn main() -> ExitCode {
     #[cfg(any(target_os = "linux", target_os = "macos"))]
     jemalloc_magic();
 
@@ -515,15 +483,12 @@ fn main() {
         }
 
         // We cannot use `rustc_driver::main` as we want it to use `args` as the CLI arguments.
-        run_compiler_and_exit(&args, &mut MiriBeRustCompilerCalls { target_crate })
+        return run_compiler_return_exit_code(&args, &mut MiriBeRustCompilerCalls { target_crate });
     }
 
     // Add an ICE bug report hook.
     rustc_driver::install_ice_hook("https://github.com/rust-lang/miri/issues/new", |_| ());
 
-    // Init loggers the Miri way.
-    init_early_loggers(&early_dcx);
-
     // Parse our arguments and split them across `rustc` and `miri`.
     let mut many_seeds: Option<Range<u32>> = None;
     let mut many_seeds_keep_going = false;
@@ -793,6 +758,11 @@ fn main() {
         );
     };
 
+    // Init loggers the Miri way. Do so after arguments have been parsed, so no tracing file is
+    // created if argument parsing fails, and also so that we don't have to worry about dropping
+    // the guard before calling std::process::exit() in show_error!().
+    let tracing_guard = init_early_loggers(&early_dcx);
+
     debug!("rustc arguments: {:?}", rustc_args);
     debug!("crate arguments: {:?}", miri_config.args);
     #[cfg(target_os = "linux")]
@@ -805,8 +775,8 @@ fn main() {
         // are async-signal-safe, as is accessing atomics
         let _ = unsafe { miri::init_sv() };
     }
-    run_compiler_and_exit(
+    run_compiler_return_exit_code(
         &rustc_args,
-        &mut MiriCompilerCalls::new(miri_config, many_seeds, genmc_config),
+        &mut MiriCompilerCalls::new(miri_config, many_seeds, genmc_config, tracing_guard),
     )
 }