Add support for SpanTrace capture in ICE reports

let me push damnit! we meet again rustfmt enable trace by default checkpoint while figuring out this damn rebase reduce log level to avoid bugs in logging remove accidentally readded fn remove unused deps bless these initially, deal with actual output next add example with spantrace output try to hack around the issue to get nice output with proper spantrace output add helper message for spantrace
rust-lang · Mar 16, 2023 · 8057e62 · 8057e62
1 parent 1203e08
commit 8057e62
Show file tree

Hide file tree

Showing 19 changed files with 90 additions and 23 deletions.
diff --git a/Cargo.lock b/Cargo.lock
@@ -3323,6 +3323,16 @@ version = "0.3.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "61807f77802ff30975e01f4f071c8ba10c022052f98b3294119f3e615d13e5be"
 
+[[package]]
+name = "nu-ansi-term"
+version = "0.46.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84"
+dependencies = [
+ "overload",
+ "winapi",
+]
+
 [[package]]
 name = "num-integer"
 version = "0.1.43"
@@ -3500,6 +3510,12 @@ dependencies = [
  "winapi",
 ]
 
+[[package]]
+name = "overload"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39"
+
 [[package]]
 name = "owo-colors"
 version = "3.5.0"
@@ -4588,6 +4604,7 @@ dependencies = [
  "rustc_ty_utils",
  "serde_json",
  "tracing",
+ "tracing-error",
  "winapi",
 ]
 
@@ -4919,6 +4936,7 @@ dependencies = [
  "rustc_span",
  "tracing",
  "tracing-core",
+ "tracing-error",
  "tracing-subscriber",
  "tracing-tree",
 ]
@@ -5742,9 +5760,9 @@ dependencies = [
 
 [[package]]
 name = "sharded-slab"
-version = "0.1.1"
+version = "0.1.4"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "79c719719ee05df97490f80a45acfc99e5a30ce98a1e4fb67aee422745ae14e3"
+checksum = "900fba806f70c630b0a382d0d825e17a0f19fcd059a2ade1ff237bcddf446b31"
 dependencies = [
  "lazy_static",
 ]
@@ -6387,9 +6405,9 @@ dependencies = [
 
 [[package]]
 name = "tracing-core"
-version = "0.1.28"
+version = "0.1.30"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "7b7358be39f2f274f322d2aaed611acc57f382e8eb1e5b48cb9ae30933495ce7"
+checksum = "24eb03ba0eab1fd845050058ce5e616558e8f8d8fca633e6b163fe25c797213a"
 dependencies = [
  "once_cell",
  "valuable",
@@ -6407,9 +6425,9 @@ dependencies = [
 
 [[package]]
 name = "tracing-log"
-version = "0.1.2"
+version = "0.1.3"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "a6923477a48e41c1951f1999ef8bb5a3023eb723ceadafe78ffb65dc366761e3"
+checksum = "78ddad33d2d10b1ed7eb9d1f518a5674713876e97e5bb9b7345a7984fbb4f922"
 dependencies = [
  "lazy_static",
  "log",
@@ -6418,14 +6436,14 @@ dependencies = [
 
 [[package]]
 name = "tracing-subscriber"
-version = "0.3.3"
+version = "0.3.16"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "245da694cc7fc4729f3f418b304cb57789f1bed2a78c575407ab8a23f53cb4d3"
+checksum = "a6176eae26dd70d0c919749377897b54a9276bd7061339665dd68777926b5a70"
 dependencies = [
- "ansi_term",
- "lazy_static",
  "matchers",
- "parking_lot 0.11.2",
+ "nu-ansi-term",
+ "once_cell",
+ "parking_lot 0.12.1",
  "regex",
  "sharded-slab",
  "smallvec",

diff --git a/compiler/rustc_driver_impl/Cargo.toml b/compiler/rustc_driver_impl/Cargo.toml
@@ -50,6 +50,7 @@ rustc_interface = { path = "../rustc_interface" }
 rustc_ast = { path = "../rustc_ast" }
 rustc_span = { path = "../rustc_span" }
 rustc_hir_analysis = { path = "../rustc_hir_analysis" }
+tracing-error = "0.2.0"
 
 [target.'cfg(unix)'.dependencies]
 libc = "0.2"
@@ -60,5 +61,4 @@ winapi = { version = "0.3", features = ["consoleapi", "debugapi", "processenv"]
 [features]
 llvm = ['rustc_interface/llvm']
 max_level_info = ['rustc_log/max_level_info']
-rustc_use_parallel_compiler = ['rustc_data_structures/rustc_use_parallel_compiler', 'rustc_interface/rustc_use_parallel_compiler',
-    'rustc_middle/rustc_use_parallel_compiler']
+rustc_use_parallel_compiler = ['rustc_data_structures/rustc_use_parallel_compiler', 'rustc_interface/rustc_use_parallel_compiler', 'rustc_middle/rustc_use_parallel_compiler']
diff --git a/compiler/rustc_driver_impl/src/lib.rs b/compiler/rustc_driver_impl/src/lib.rs
@@ -1245,6 +1245,15 @@ pub fn report_ice(info: &panic::PanicInfo<'_>, bug_report_url: &str) {
 
     interface::try_print_query_stack(&handler, num_frames);
 
+    let spantrace = tracing_error::SpanTrace::capture().to_string();
+    if !spantrace.is_empty() {
+        eprintln!("SpanTrace:\n{}", spantrace);
+    } else {
+        eprintln!(
+            "note: run with `RUSTC_ICE_LOG=trace` environment variable to display a SpanTrace"
+        );
+    }
+
     #[cfg(windows)]
     unsafe {
         if env::var("RUSTC_BREAK_ON_ICE").is_ok() {
@@ -1273,14 +1282,14 @@ pub fn install_ice_hook() {
 /// This allows tools to enable rust logging without having to magically match rustc's
 /// tracing crate version.
 pub fn init_rustc_env_logger() {
-    init_env_logger("RUSTC_LOG");
+    init_env_logger("RUSTC_LOG", "RUSTC_ICE_LOG");
 }
 
 /// This allows tools to enable rust logging without having to magically match rustc's
 /// tracing crate version. In contrast to `init_rustc_env_logger` it allows you to choose an env var
 /// other than `RUSTC_LOG`.
-pub fn init_env_logger(env: &str) {
-    if let Err(error) = rustc_log::init_env_logger(env) {
+pub fn init_env_logger(env: &str, ice_env: &str) {
+    if let Err(error) = rustc_log::init_env_logger(env, ice_env) {
         early_error(ErrorOutputType::default(), &error.to_string());
     }
 }

diff --git a/compiler/rustc_log/Cargo.toml b/compiler/rustc_log/Cargo.toml
@@ -5,9 +5,10 @@ edition = "2021"
 
 [dependencies]
 tracing = "0.1.28"
-tracing-subscriber = { version = "0.3.3", default-features = false, features = ["fmt", "env-filter", "smallvec", "parking_lot", "ansi"] }
+tracing-subscriber = { version = "0.3.16", default-features = false, features = ["registry", "fmt", "env-filter", "smallvec", "parking_lot", "ansi"] }
 tracing-tree = "0.2.0"
 tracing-core = "0.1.28"
+tracing-error = "0.2.0"
 
 [dev-dependencies]
 rustc_span = { path = "../rustc_span" }

diff --git a/compiler/rustc_log/src/lib.rs b/compiler/rustc_log/src/lib.rs
@@ -45,20 +45,32 @@
 use std::env::{self, VarError};
 use std::fmt::{self, Display};
 use std::io::{self, IsTerminal};
+use std::str::FromStr;
 use tracing_core::{Event, Subscriber};
 use tracing_subscriber::filter::{Directive, EnvFilter, LevelFilter};
 use tracing_subscriber::fmt::{
     format::{self, FormatEvent, FormatFields},
     FmtContext,
 };
 use tracing_subscriber::layer::SubscriberExt;
+use tracing_subscriber::Layer;
 
-pub fn init_env_logger(env: &str) -> Result<(), Error> {
-    let filter = match env::var(env) {
+/// In contrast to `init_rustc_env_logger` this allows you to choose an env var
+/// other than `RUSTC_LOG`.
+pub fn init_env_logger(env: &str, ice_env: &str) -> Result<(), Error> {
+    let log_filter = match env::var(env) {
         Ok(env) => EnvFilter::new(env),
         _ => EnvFilter::default().add_directive(Directive::from(LevelFilter::WARN)),
     };
 
+    let error_filter = match env::var(ice_env) {
+        Ok(env) => tracing::Level::from_str(&env).unwrap(),
+        _ => tracing::Level::WARN,
+    };
+    let error_filter = tracing_subscriber::filter::filter_fn(move |metadata| {
+        metadata.is_span() && metadata.level() <= &error_filter
+    });
+
     let color_logs = match env::var(String::from(env) + "_COLOR") {
         Ok(value) => match value.as_ref() {
             "always" => true,
@@ -75,7 +87,7 @@ pub fn init_env_logger(env: &str) -> Result<(), Error> {
         Some(v) => &v != "0",
     };
 
-    let layer = tracing_tree::HierarchicalLayer::default()
+    let log_layer = tracing_tree::HierarchicalLayer::default()
         .with_writer(io::stderr)
         .with_indent_lines(true)
         .with_ansi(color_logs)
@@ -84,9 +96,12 @@ pub fn init_env_logger(env: &str) -> Result<(), Error> {
         .with_verbose_entry(verbose_entry_exit)
         .with_indent_amount(2);
     #[cfg(parallel_compiler)]
-    let layer = layer.with_thread_ids(true).with_thread_names(true);
+    let log_layer = log_layer.with_thread_ids(true).with_thread_names(true);
+    let error_layer = tracing_error::ErrorLayer::default();
+    let subscriber = tracing_subscriber::Registry::default()
+        .with(error_layer.with_filter(error_filter))
+        .with(log_layer.with_filter(log_filter));
 
-    let subscriber = tracing_subscriber::Registry::default().with(filter).with(layer);
     match env::var(format!("{env}_BACKTRACE")) {
         Ok(str) => {
             let fmt_layer = tracing_subscriber::fmt::layer()

diff --git a/compiler/rustc_session/src/session.rs b/compiler/rustc_session/src/session.rs
@@ -677,6 +677,7 @@ impl Session {
             || self.opts.unstable_opts.unpretty.is_some()
             || self.opts.output_types.contains_key(&OutputType::Mir)
             || std::env::var_os("RUSTC_LOG").is_some()
+            || std::env::var_os("RUSTC_ICE_LOG").is_some()
         {
             return;
         }

diff --git a/src/librustdoc/lib.rs b/src/librustdoc/lib.rs
@@ -167,7 +167,7 @@ pub fn main() {
     // `debug_logging = true` is because all rustc logging goes to its version of tracing (the one
     // in the sysroot), and all of rustdoc's logging goes to its version (the one in Cargo.toml).
     init_logging();
-    rustc_driver::init_env_logger("RUSTDOC_LOG");
+    rustc_driver::init_env_logger("RUSTDOC_LOG", "RUSTDOC_ICE_LOG");
 
     let exit_code = rustc_driver::catch_with_exit_code(|| match get_args() {
         Some(args) => main_args(&args),

diff --git a/src/tools/tidy/src/deps.rs b/src/tools/tidy/src/deps.rs
@@ -167,10 +167,12 @@ const PERMITTED_RUSTC_DEPENDENCIES: &[&str] = &[
     "memmap2",
     "memoffset",
     "miniz_oxide",
+    "nu-ansi-term",
     "num_cpus",
     "object",
     "odht",
     "once_cell",
+    "overload",
     "parking_lot",
     "parking_lot_core",
     "pathdiff",
@@ -237,6 +239,7 @@ const PERMITTED_RUSTC_DEPENDENCIES: &[&str] = &[
     "tracing-log",
     "tracing-subscriber",
     "tracing-tree",
+    "tracing-error",
     "twox-hash",
     "type-map",
     "typenum",
@@ -264,6 +267,14 @@ const PERMITTED_RUSTC_DEPENDENCIES: &[&str] = &[
     "winapi-i686-pc-windows-gnu",
     "winapi-util",
     "winapi-x86_64-pc-windows-gnu",
+    "windows-sys",
+    "windows_aarch64_msvc",
+    "windows_aarch64_gnullvm",
+    "windows_i686_gnu",
+    "windows_i686_msvc",
+    "windows_x86_64_gnu",
+    "windows_x86_64_gnullvm",
+    "windows_x86_64_msvc",
     "writeable",
     // this is a false-positive: it's only used by rustfmt, but because it's enabled through a
     // feature, tidy thinks it's used by rustc as well.

diff --git a/tests/ui/associated-inherent-types/bugs/ice-substitution.stderr b/tests/ui/associated-inherent-types/bugs/ice-substitution.stderr
@@ -4,3 +4,4 @@ query stack during panic:
 #0 [typeck] type-checking `weird`
 #1 [typeck_item_bodies] type-checking all item bodies
 end of query stack
+note: run with `RUSTC_ICE_LOG=trace` environment variable to display a SpanTrace
diff --git a/tests/ui/chalkify/bugs/async.rs b/tests/ui/chalkify/bugs/async.rs
@@ -1,6 +1,7 @@
 // edition:2021
 // known-bug: unknown
 // unset-rustc-env:RUST_BACKTRACE
+// rustc-env:RUSTC_ICE_LOG=trace
 // compile-flags:-Z trait-solver=chalk
 // error-pattern:internal compiler error
 // failure-status:101

diff --git a/tests/ui/chalkify/bugs/async.stderr b/tests/ui/chalkify/bugs/async.stderr
@@ -23,6 +23,8 @@ LL | async fn foo(x: u32) -> u32 {
 #8 [check_mod_item_types] checking item types in top-level module
 #9 [analysis] running analysis passes on this crate
 end of query stack
+SpanTrace:
+
 error: aborting due to 2 previous errors
 
 For more information about this error, try `rustc --explain E0277`.
diff --git a/tests/ui/consts/const-eval/const-eval-query-stack.stderr b/tests/ui/consts/const-eval/const-eval-query-stack.stderr
@@ -11,3 +11,4 @@ query stack during panic:
 #3 [lint_mod] linting top-level module
 #4 [analysis] running analysis passes on this crate
 end of query stack
+note: run with `RUSTC_ICE_LOG=trace` environment variable to display a SpanTrace
diff --git a/tests/ui/impl-trait/issues/issue-86800.stderr b/tests/ui/impl-trait/issues/issue-86800.stderr
@@ -22,3 +22,4 @@ query stack during panic:
 #1 [check_mod_item_types] checking item types in top-level module
 #2 [analysis] running analysis passes on this crate
 end of query stack
+
diff --git a/tests/ui/impl-trait/normalize-tait-in-const.stderr b/tests/ui/impl-trait/normalize-tait-in-const.stderr
@@ -4,5 +4,6 @@ query stack during panic:
 #0 [eval_to_allocation_raw] const-evaluating + checking `BAR`
 #1 [eval_to_const_value_raw] simplifying constant for the type system `BAR`
 end of query stack
+note: run with `RUSTC_ICE_LOG=trace` environment variable to display a SpanTrace
 error: aborting due to previous error
 
diff --git a/tests/ui/layout/valid_range_oob.stderr b/tests/ui/layout/valid_range_oob.stderr
@@ -4,3 +4,4 @@ query stack during panic:
 #0 [layout_of] computing layout of `Foo`
 #1 [eval_to_allocation_raw] const-evaluating + checking `FOO`
 end of query stack
+note: run with `RUSTC_ICE_LOG=trace` environment variable to display a SpanTrace
diff --git a/tests/ui/mir/validate/storage-live.stderr b/tests/ui/mir/validate/storage-live.stderr
@@ -11,3 +11,4 @@ query stack during panic:
 #0 [mir_const] preparing `multiple_storage` for borrow checking
 #1 [mir_promoted] processing MIR for `multiple_storage`
 end of query stack
+note: run with `RUSTC_ICE_LOG=trace` environment variable to display a SpanTrace
diff --git a/tests/ui/panics/default-backtrace-ice.stderr b/tests/ui/panics/default-backtrace-ice.stderr
@@ -15,3 +15,4 @@ error: the compiler unexpectedly panicked. this is a bug.
 query stack during panic:
 #0 [resolver_for_lowering] getting the resolver for lowering
 end of query stack
+
diff --git a/tests/ui/treat-err-as-bug/delay_span_bug.stderr b/tests/ui/treat-err-as-bug/delay_span_bug.stderr
@@ -9,3 +9,4 @@ error: the compiler unexpectedly panicked. this is a bug.
 query stack during panic:
 #0 [trigger_delay_span_bug] triggering a delay span bug
 end of query stack
+note: run with `RUSTC_ICE_LOG=trace` environment variable to display a SpanTrace
diff --git a/tests/ui/treat-err-as-bug/err.stderr b/tests/ui/treat-err-as-bug/err.stderr
@@ -10,3 +10,4 @@ query stack during panic:
 #0 [eval_to_allocation_raw] const-evaluating + checking `C`
 #1 [eval_to_allocation_raw] const-evaluating + checking `C`
 end of query stack
+note: run with `RUSTC_ICE_LOG=trace` environment variable to display a SpanTrace