From 8057e62e9b65e405344592ec1e107650b2cbd365 Mon Sep 17 00:00:00 2001 From: Jane Losare-Lusby Date: Fri, 4 Nov 2022 23:46:15 +0000 Subject: [PATCH] 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 --- Cargo.lock | 40 ++++++++++++++----- compiler/rustc_driver_impl/Cargo.toml | 4 +- compiler/rustc_driver_impl/src/lib.rs | 15 +++++-- compiler/rustc_log/Cargo.toml | 3 +- compiler/rustc_log/src/lib.rs | 25 +++++++++--- compiler/rustc_session/src/session.rs | 1 + src/librustdoc/lib.rs | 2 +- src/tools/tidy/src/deps.rs | 11 +++++ .../bugs/ice-substitution.stderr | 1 + tests/ui/chalkify/bugs/async.rs | 1 + tests/ui/chalkify/bugs/async.stderr | 2 + .../const-eval/const-eval-query-stack.stderr | 1 + tests/ui/impl-trait/issues/issue-86800.stderr | 1 + .../impl-trait/normalize-tait-in-const.stderr | 1 + tests/ui/layout/valid_range_oob.stderr | 1 + tests/ui/mir/validate/storage-live.stderr | 1 + tests/ui/panics/default-backtrace-ice.stderr | 1 + .../ui/treat-err-as-bug/delay_span_bug.stderr | 1 + tests/ui/treat-err-as-bug/err.stderr | 1 + 19 files changed, 90 insertions(+), 23 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 49b89c71994a8..d6f34c20e4a29 100644 --- 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 index 7b59a52cffeda..fda6d2cae4a21 100644 --- 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 index 555917c8b5e9c..927446a83dc5b 100644 --- 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 index 7f955b0a75090..4803962182abd 100644 --- 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 index 22924efa94842..f352918c54414 100644 --- a/compiler/rustc_log/src/lib.rs +++ b/compiler/rustc_log/src/lib.rs @@ -45,6 +45,7 @@ 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::{ @@ -52,13 +53,24 @@ use tracing_subscriber::fmt::{ 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 index fdacf814dd672..a01ede860eecc 100644 --- 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 index 4fcf0873600ab..807ae92813491 100644 --- 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 index d71fa5c8be5e7..16845659567a3 100644 --- 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 index 7b0d1c5051624..ca596874614d4 100644 --- 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 index a1ef4732b6313..69ce07f0e53d3 100644 --- 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 index 9c559640b2308..c33268852ee0a 100644 --- 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 index 01fb8153cf384..b77cf06695cb0 100644 --- 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 index f3a773837785e..ad794b0a8e91a 100644 --- 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 index 84b00918724e0..cefe6101f4936 100644 --- 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 index a3a514fb83095..8c013af4ec659 100644 --- 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 index b586a8658498f..31ad4fa784203 100644 --- 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 index 4bd4780e25f6b..5721bff5cd9a1 100644 --- 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 index 22c6175048a63..2a1f8badb8377 100644 --- 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 index 3a56445a26b58..73bd86ba96c45 100644 --- 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