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

Obey the return value from the trace visitor under Miri #476

Merged
merged 1 commit into from Aug 30, 2022

Conversation

saethlin
Copy link
Member

We're supposed to stop visiting backtrace frames when the visitor returns false, but this used to just ignore the return value.

It's entirely possible that backtrace pruning has never worked under Miri due to this bug, and nobody noticed because the slowness in rust-lang/miri#2273 which this bug contributes significantly to. Wonderfully circular.

cc @RalfJung

@RalfJung
Copy link
Member

Is the point that RUST_BACKTRACE=1 ./miri run tests/pass/backtrace/backtrace-std.rs -Zmiri-disable-isolation should be printing less than the full backtrace?

   0: func_d
             at tests/pass/backtrace/backtrace-std.rs:27:5
   1: func_c
             at tests/pass/backtrace/backtrace-std.rs:23:5
   2: func_b::<u8>
             at tests/pass/backtrace/backtrace-std.rs:12:5
   3: func_a
             at tests/pass/backtrace/backtrace-std.rs:8:5
   4: main
             at tests/pass/backtrace/backtrace-std.rs:31:19
   5: <fn() as std::ops::FnOnce<()>>::call_once - shim(fn())
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/core/src/ops/function.rs:248:5
   6: std::sys_common::backtrace::__rust_begin_short_backtrace::<fn(), ()>
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/sys_common/backtrace.rs:122:18
   7: std::rt::lang_start::<()>::{closure#0}
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/rt.rs:145:18
   8: std::ops::function::impls::<impl std::ops::FnOnce<()> for &dyn std::ops::Fn() -> i32 + std::marker::Sync + std::panic::RefUnwindSafe>::call_once
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/core/src/ops/function.rs:280:13
   9: std::panicking::try::do_call::<&dyn std::ops::Fn() -> i32 + std::marker::Sync + std::panic::RefUnwindSafe, i32>
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panicking.rs:492:40
  10: std::panicking::try::<i32, &dyn std::ops::Fn() -> i32 + std::marker::Sync + std::panic::RefUnwindSafe>
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panicking.rs:456:19
  11: std::panic::catch_unwind::<&dyn std::ops::Fn() -> i32 + std::marker::Sync + std::panic::RefUnwindSafe, i32>
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panic.rs:137:14
  12: std::rt::lang_start_internal::{closure#2}
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/rt.rs:128:48
  13: std::panicking::try::do_call::<[closure@std::rt::lang_start_internal::{closure#2}], isize>
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panicking.rs:492:40
  14: std::panicking::try::<isize, [closure@std::rt::lang_start_internal::{closure#2}]>
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panicking.rs:456:19
  15: std::panic::catch_unwind::<[closure@std::rt::lang_start_internal::{closure#2}], isize>
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panic.rs:137:14
  16: std::rt::lang_start_internal
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/rt.rs:128:20
  17: std::rt::lang_start::<()>
             at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/rt.rs:144:17

Did you check that this PR fixes that?

@RalfJung
Copy link
Member

Under Linux it shows about the same kinds of frames, I don't see anything being pruned:

   0: backtrace_std::func_d
   1: backtrace_std::func_c
   2: backtrace_std::func_b
   3: backtrace_std::func_a
   4: backtrace_std::main
   5: core::ops::function::FnOnce::call_once
   6: std::sys_common::backtrace::__rust_begin_short_backtrace
   7: std::rt::lang_start::{{closure}}
   8: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once
             at /rustc/4065b89b1e7287047d7d6c65e7abd7b8ee70bcf0/library/core/src/ops/function.rs:280:13
   9: std::panicking::try::do_call
             at /rustc/4065b89b1e7287047d7d6c65e7abd7b8ee70bcf0/library/std/src/panicking.rs:492:40
  10: std::panicking::try
             at /rustc/4065b89b1e7287047d7d6c65e7abd7b8ee70bcf0/library/std/src/panicking.rs:456:19
  11: std::panic::catch_unwind
             at /rustc/4065b89b1e7287047d7d6c65e7abd7b8ee70bcf0/library/std/src/panic.rs:137:14
  12: std::rt::lang_start_internal::{{closure}}
             at /rustc/4065b89b1e7287047d7d6c65e7abd7b8ee70bcf0/library/std/src/rt.rs:128:48
  13: std::panicking::try::do_call
             at /rustc/4065b89b1e7287047d7d6c65e7abd7b8ee70bcf0/library/std/src/panicking.rs:492:40
  14: std::panicking::try
             at /rustc/4065b89b1e7287047d7d6c65e7abd7b8ee70bcf0/library/std/src/panicking.rs:456:19
  15: std::panic::catch_unwind
             at /rustc/4065b89b1e7287047d7d6c65e7abd7b8ee70bcf0/library/std/src/panic.rs:137:14
  16: std::rt::lang_start_internal
             at /rustc/4065b89b1e7287047d7d6c65e7abd7b8ee70bcf0/library/std/src/rt.rs:128:20
  17: std::rt::lang_start
  18: main
  19: __libc_start_call_main
             at ./csu/../sysdeps/nptl/libc_start_call_main.h:58:16
  20: __libc_start_main_impl
             at ./csu/../csu/libc-start.c:389:3
  21: _start

@RalfJung
Copy link
Member

(I agree this is what the trace docs say should be done, I just don't know how it would affect observable behavior in Miri's backtraces)

@saethlin
Copy link
Member Author

How are you testing this? I checked out this branch into the backtrace submodule in my Rust checkout, then on this Cargo project:

fn main() {
    panic!("ow");
}

#[test]
fn oof() {
    panic!("ow");
}

I'm setting MIRI_LIB_SRC to my checkout, running:

╭ ➜ ben@archlinux:/tmp/scratch
╰ ➤ RUST_BACKTRACE=1 MIRIFLAGS="-Zmiri-disable-isolation" MIRI_LIB_SRC=/home/ben/rust/library cargo miri run
Preparing a sysroot for Miri (target: x86_64-unknown-linux-gnu)... done
   Compiling scratch v0.1.0 (/tmp/scratch)
    Finished dev [unoptimized + debuginfo] target(s) in 0.01s
     Running `/home/ben/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/bin/cargo-miri runner target/miri/x86_64-unknown-linux-gnu/debug/scratch`
thread 'main' panicked at 'ow', src/main.rs:2:5
stack backtrace:
   0: std::panicking::begin_panic_handler
             at /home/ben/rust/library/std/src/panicking.rs:584:5
   1: std::rt::panic_fmt
             at /home/ben/rust/library/core/src/panicking.rs:142:14
   2: main
             at src/main.rs:2:5
   3: <fn() as std::ops::FnOnce<()>>::call_once - shim(fn())
             at /home/ben/rust/library/core/src/ops/function.rs:248:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
╭ ➜ ben@archlinux:/tmp/scratch
╰ ➤ RUST_BACKTRACE=1 MIRIFLAGS="-Zmiri-disable-isolation" MIRI_LIB_SRC=/home/ben/rust/library cargo miri test
Preparing a sysroot for Miri (target: x86_64-unknown-linux-gnu)... done
   Compiling scratch v0.1.0 (/tmp/scratch)
    Finished test [unoptimized + debuginfo] target(s) in 0.09s
     Running unittests src/main.rs (target/miri/x86_64-unknown-linux-gnu/debug/deps/scratch-8097932b18eafdc6)

running 1 test
test oof ... FAILED

failures:

---- oof stdout ----
thread 'main' panicked at 'ow', src/main.rs:7:5
stack backtrace:
   0: std::panicking::begin_panic_handler
             at /home/ben/rust/library/std/src/panicking.rs:584:5
   1: std::rt::panic_fmt
             at /home/ben/rust/library/core/src/panicking.rs:142:14
   2: oof
             at src/main.rs:7:5
   3: oof::{closure#0}
             at src/main.rs:6:1
   4: <[closure@src/main.rs:6:1: 8:2] as std::ops::FnOnce<()>>::call_once - shim
             at /home/ben/rust/library/core/src/ops/function.rs:248:5
   5: <fn() as std::ops::FnOnce<()>>::call_once - shim(fn())
             at /home/ben/rust/library/core/src/ops/function.rs:248:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.


failures:
    oof

test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out

error: test failed, to rerun pass '--bin scratch'

@RalfJung
Copy link
Member

How are you testing this?

As I said, I did RUST_BACKTRACE=1 ./miri run tests/pass/backtrace/backtrace-std.rs -Zmiri-disable-isolation. I guess that doesn't do any truncation. The panic backtraces are indeed much nicer than what I get with RUST_BACKTRACE=1 MIRIFLAGS="-Zmiri-disable-isolation" ./miri run tests/panic/panic1.rs!

@saethlin
Copy link
Member Author

Ah 🤦

Picking through the code in std, it looks like the pruning code is only reachable through backtrace::print, which is only called in the default panic hook. I guess this is why we have UI tests.

@alexcrichton
Copy link
Member

Looks reasonable to me, thanks for this! I think the CI issues are unrelated so I'll go ahead and merge.

@alexcrichton alexcrichton merged commit ebc9a85 into rust-lang:master Aug 30, 2022
@saethlin saethlin deleted the miri-pruning branch February 16, 2024 23:43
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants