Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Shorten backtraces for queries in ICEs #108938

Merged
merged 1 commit into from
May 18, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
93 changes: 58 additions & 35 deletions compiler/rustc_query_impl/src/plumbing.rs
Original file line number Diff line number Diff line change
Expand Up @@ -488,6 +488,18 @@ macro_rules! expand_if_cached {
};
}

/// Don't show the backtrace for query system by default
/// use `RUST_BACKTRACE=full` to show all the backtraces
#[inline(never)]
pub fn __rust_begin_short_backtrace<F, T>(f: F) -> T
where
F: FnOnce() -> T,
{
let result = f();
std::hint::black_box(());
result
}

// NOTE: `$V` isn't used here, but we still need to match on it so it can be passed to other macros
// invoked by `rustc_query_append`.
macro_rules! define_queries {
Expand All @@ -498,21 +510,25 @@ macro_rules! define_queries {
use super::*;

$(
#[inline(always)]
#[tracing::instrument(level = "trace", skip(tcx))]
pub(super) fn $name<'tcx>(
tcx: TyCtxt<'tcx>,
span: Span,
key: query_keys::$name<'tcx>,
mode: QueryMode,
) -> Option<Erase<query_values::$name<'tcx>>> {
get_query_incr(
queries::$name::config(tcx),
QueryCtxt::new(tcx),
span,
key,
mode
)
// Adding `__rust_end_short_backtrace` marker to backtraces so that we emit the frames
// when `RUST_BACKTRACE=1`, add a new mod with `$name` here is to allow duplicate naming
pub mod $name {
use super::*;
#[inline(never)]
pub fn __rust_end_short_backtrace<'tcx>(
cjgillot marked this conversation as resolved.
Show resolved Hide resolved
tcx: TyCtxt<'tcx>,
span: Span,
key: query_keys::$name<'tcx>,
mode: QueryMode,
) -> Option<Erase<query_values::$name<'tcx>>> {
get_query_incr(
queries::$name::config(tcx),
QueryCtxt::new(tcx),
span,
key,
mode
)
}
}
)*
}
Expand All @@ -521,32 +537,34 @@ macro_rules! define_queries {
use super::*;

$(
#[inline(always)]
#[tracing::instrument(level = "trace", skip(tcx))]
pub(super) fn $name<'tcx>(
tcx: TyCtxt<'tcx>,
span: Span,
key: query_keys::$name<'tcx>,
__mode: QueryMode,
) -> Option<Erase<query_values::$name<'tcx>>> {
Some(get_query_non_incr(
queries::$name::config(tcx),
QueryCtxt::new(tcx),
span,
key,
))
pub mod $name {
use super::*;
#[inline(never)]
pub fn __rust_end_short_backtrace<'tcx>(
tcx: TyCtxt<'tcx>,
span: Span,
key: query_keys::$name<'tcx>,
__mode: QueryMode,
) -> Option<Erase<query_values::$name<'tcx>>> {
Some(get_query_non_incr(
queries::$name::config(tcx),
QueryCtxt::new(tcx),
span,
key,
))
}
}
)*
}

pub(crate) fn engine(incremental: bool) -> QueryEngine {
if incremental {
QueryEngine {
$($name: get_query_incr::$name,)*
$($name: get_query_incr::$name::__rust_end_short_backtrace,)*
}
} else {
QueryEngine {
$($name: get_query_non_incr::$name,)*
$($name: get_query_non_incr::$name::__rust_end_short_backtrace,)*
}
}
}
Expand Down Expand Up @@ -578,10 +596,15 @@ macro_rules! define_queries {
query_cache: offset_of!(QueryCaches<'tcx> => $name),
cache_on_disk: |tcx, key| ::rustc_middle::query::cached::$name(tcx, key),
execute_query: |tcx, key| erase(tcx.$name(key)),
compute: |tcx, key| query_provided_to_value::$name(
tcx,
call_provider!([$($modifiers)*][tcx, $name, key])
),
compute: |tcx, key| {
use crate::plumbing::__rust_begin_short_backtrace;
__rust_begin_short_backtrace(||
query_provided_to_value::$name(
tcx,
call_provider!([$($modifiers)*][tcx, $name, key])
)
)
},
can_load_from_disk: should_ever_cache_on_disk!([$($modifiers)*] true false),
try_load_from_disk: should_ever_cache_on_disk!([$($modifiers)*] {
|tcx, key, prev_index, index| {
Expand Down
11 changes: 6 additions & 5 deletions library/std/src/sys_common/backtrace.rs
Original file line number Diff line number Diff line change
Expand Up @@ -68,13 +68,17 @@ unsafe fn _print_fmt(fmt: &mut fmt::Formatter<'_>, print_fmt: PrintFmt) -> fmt::
}

let mut hit = false;
let mut stop = false;
backtrace_rs::resolve_frame_unsynchronized(frame, |symbol| {
hit = true;

// Any frames between `__rust_begin_short_backtrace` and `__rust_end_short_backtrace`
// are omitted from the backtrace in short mode, `__rust_end_short_backtrace` will be
// called before the panic hook, so we won't ignore any frames if there is no
// invoke of `__rust_begin_short_backtrace`.
if print_fmt == PrintFmt::Short {
if let Some(sym) = symbol.name().and_then(|s| s.as_str()) {
if start && sym.contains("__rust_begin_short_backtrace") {
stop = true;
start = false;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can this have an effect on existing code?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

no, the original code only supports one pair of __rust_begin_short_backtrace and __rust_end_short_backtrace, we extend it to support multiple pairs.

return;
}
if sym.contains("__rust_end_short_backtrace") {
Expand All @@ -88,9 +92,6 @@ unsafe fn _print_fmt(fmt: &mut fmt::Formatter<'_>, print_fmt: PrintFmt) -> fmt::
res = bt_fmt.frame().symbol(frame, symbol);
}
});
if stop {
return false;
}
#[cfg(target_os = "nto")]
if libc::__my_thread_exit as *mut libc::c_void == frame.ip() {
if !hit && start {
Expand Down
9 changes: 9 additions & 0 deletions tests/run-make/short-ice/Makefile
Original file line number Diff line number Diff line change
@@ -0,0 +1,9 @@
include ../tools.mk

# ignore-windows

export RUSTC := $(RUSTC_ORIGINAL)
export TMPDIR := $(TMPDIR)

all:
bash check.sh
36 changes: 36 additions & 0 deletions tests/run-make/short-ice/check.sh
Original file line number Diff line number Diff line change
@@ -0,0 +1,36 @@
#!/bin/sh

RUST_BACKTRACE=1 $RUSTC src/lib.rs -Z treat-err-as-bug=1 1>$TMPDIR/rust-test-1.log 2>&1
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This fails on the SGX platform with:

/home/jenkins/workspace/rust-sgx-ci/rust/build/x86_64-unknown-linux-gnu/stage1/bin/rustc: error while loading shared libraries: librustc_driver-b910c833a504f4dd.so: cannot open shared object file: No such file or directory

I'm confused why we get that error. You can ignore the SGX platform for this test as well.

RUST_BACKTRACE=full $RUSTC src/lib.rs -Z treat-err-as-bug=1 1>$TMPDIR/rust-test-2.log 2>&1

short=$(cat $TMPDIR/rust-test-1.log | wc -l)
full=$(cat $TMPDIR/rust-test-2.log | wc -l)
rustc_query_count=$(cat $TMPDIR/rust-test-1.log | grep rustc_query_ | wc -l)
rustc_query_count_full=$(cat $TMPDIR/rust-test-2.log | grep rustc_query_ | wc -l)

begin_count=$(cat $TMPDIR/rust-test-2.log | grep __rust_begin_short_backtrace | wc -l)
end_count=$(cat $TMPDIR/rust-test-2.log | grep __rust_end_short_backtrace | wc -l)

cat $TMPDIR/rust-test-1.log
echo "====================="
cat $TMPDIR/rust-test-2.log
echo "====================="

echo "short backtrace: $short"
echo "full backtrace: $full"
echo "begin_count: $begin_count"
echo "end_count : $end_count"
echo "rustc_query_count: $rustc_query_count"
echo "rustc_query_count_full: $rustc_query_count_full"

## backtraces to vary a bit depending on platform and configuration options,
## here we make sure that the short backtrace of rustc_query is shorter than the full,
## and marks are in pairs.
if [ $short -lt $full ] &&
[ $begin_count -eq $end_count ] &&
[ $(($rustc_query_count + 10)) -lt $rustc_query_count_full ] &&
[ $rustc_query_count_full -gt 10 ]; then
exit 0
else
exit 1
fi
7 changes: 7 additions & 0 deletions tests/run-make/short-ice/src/lib.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,7 @@
fn func(s: &str) {
println!("{}", s);
}

fn main() {
func(1);
}
2 changes: 2 additions & 0 deletions tests/ui/panics/default-backtrace-ice.stderr
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,8 @@ LL | fn main() { missing_ident; }
stack backtrace:
(end_short_backtrace)
(begin_short_backtrace)
(end_short_backtrace)
(begin_short_backtrace)

error: the compiler unexpectedly panicked. this is a bug.

Expand Down
61 changes: 61 additions & 0 deletions tests/ui/panics/short-ice-remove-middle-frames-2.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,61 @@
// compile-flags:-Cstrip=none
// run-fail
// check-run-results
// exec-env:RUST_BACKTRACE=1
// ignore-android FIXME #17520
// ignore-wasm no panic support
// ignore-openbsd no support for libbacktrace without filename
// ignore-emscripten no panic
// ignore-sgx Backtraces not symbolized
// ignore-fuchsia Backtraces not symbolized
// ignore-msvc the `__rust_{begin,end}_short_backtrace` symbols aren't reliable.

/// This test case make sure that we can have multiple pairs of `__rust_{begin,end}_short_backtrace`

#[inline(never)]
fn __rust_begin_short_backtrace<T, F: FnOnce() -> T>(f: F) -> T {
let result = f();
std::hint::black_box(result)
}

#[inline(never)]
fn __rust_end_short_backtrace<T, F: FnOnce() -> T>(f: F) -> T {
let result = f();
std::hint::black_box(result)
}

fn first() {
__rust_end_short_backtrace(|| second());
}

fn second() {
third(); // won't show up
}

fn third() {
fourth(); // won't show up
}

fn fourth() {
__rust_begin_short_backtrace(|| fifth());
}

fn fifth() {
__rust_end_short_backtrace(|| sixth());
}

fn sixth() {
seven(); // won't show up
}

fn seven() {
__rust_begin_short_backtrace(|| eight());
}

fn eight() {
panic!("debug!!!");
}

fn main() {
first();
}
11 changes: 11 additions & 0 deletions tests/ui/panics/short-ice-remove-middle-frames-2.run.stderr
Original file line number Diff line number Diff line change
@@ -0,0 +1,11 @@
thread 'main' panicked at 'debug!!!', $DIR/short-ice-remove-middle-frames-2.rs:56:5
stack backtrace:
0: std::panicking::begin_panic
1: short_ice_remove_middle_frames_2::eight
2: short_ice_remove_middle_frames_2::seven::{{closure}}
3: short_ice_remove_middle_frames_2::fifth
4: short_ice_remove_middle_frames_2::fourth::{{closure}}
5: short_ice_remove_middle_frames_2::first
6: short_ice_remove_middle_frames_2::main
7: core::ops::function::FnOnce::call_once
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
57 changes: 57 additions & 0 deletions tests/ui/panics/short-ice-remove-middle-frames.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,57 @@
// compile-flags:-Cstrip=none
// run-fail
// check-run-results
// exec-env:RUST_BACKTRACE=1
// ignore-android FIXME #17520
// ignore-wasm no panic support
// ignore-openbsd no support for libbacktrace without filename
// ignore-emscripten no panic
// ignore-sgx Backtraces not symbolized
// ignore-fuchsia Backtraces not symbolized
// ignore-msvc the `__rust_{begin,end}_short_backtrace` symbols aren't reliable.


#[inline(never)]
fn __rust_begin_short_backtrace<T, F: FnOnce() -> T>(f: F) -> T {
let result = f();
std::hint::black_box(result)
}

#[inline(never)]
fn __rust_end_short_backtrace<T, F: FnOnce() -> T>(f: F) -> T {
let result = f();
std::hint::black_box(result)
}

fn first() {
__rust_end_short_backtrace(|| second());
// do not take effect since we already has a inner call of __rust_end_short_backtrace
}

fn second() {
__rust_end_short_backtrace(|| third());
}

fn third() {
fourth(); // won't show up in backtrace
}

fn fourth() {
fifth(); // won't show up in backtrace
}

fn fifth() {
__rust_begin_short_backtrace(|| sixth());
}

fn sixth() {
seven();
}

fn seven() {
panic!("debug!!!");
}

fn main() {
first();
}
12 changes: 12 additions & 0 deletions tests/ui/panics/short-ice-remove-middle-frames.run.stderr
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
thread 'main' panicked at 'debug!!!', $DIR/short-ice-remove-middle-frames.rs:52:5
stack backtrace:
0: std::panicking::begin_panic
1: short_ice_remove_middle_frames::seven
2: short_ice_remove_middle_frames::sixth
3: short_ice_remove_middle_frames::fifth::{{closure}}
4: short_ice_remove_middle_frames::second
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you please emit some kind of marker to indicate that frames have been omitted? This is just plain confusing. For example

Suggested change
4: short_ice_remove_middle_frames::second
[some frames omitted]
4: short_ice_remove_middle_frames::second

or

Suggested change
4: short_ice_remove_middle_frames::second
[2 frames omitted]
4: short_ice_remove_middle_frames::second

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I made a change: ddacb2d

Found out we need to update https://github.com/rust-lang/backtrace-rs.git to add an API to emit the message.

Maybe we can enhance it in another PR?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you open an issue for adding the "N frame omitted" line, please?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure, I will create an issue, then make a PR for backtrace-rs first, then another follow-up PR for it.

5: short_ice_remove_middle_frames::first::{{closure}}
6: short_ice_remove_middle_frames::first
7: short_ice_remove_middle_frames::main
8: core::ops::function::FnOnce::call_once
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.