Backtrace rendering inconsistent between `std::backtrace` and panics
RalfJung opened this issue · 5 comments
I tried this code on nightly:
#![feature(backtrace)]
fn main() {
let backtrace = std::backtrace::Backtrace::capture();
eprintln!("{}", backtrace);
panic!();
}This prints:
0: playground::main
at src/main.rs:4
1: std::rt::lang_start::{{closure}}
at /rustc/fa51f810e5b9254904b92660e7280b7d6a46f112/src/libstd/rt.rs:67
2: std::rt::lang_start_internal::{{closure}}
at src/libstd/rt.rs:52
std::panicking::try::do_call
at src/libstd/panicking.rs:297
std::panicking::try
at src/libstd/panicking.rs:274
std::panic::catch_unwind
at src/libstd/panic.rs:394
std::rt::lang_start_internal
at src/libstd/rt.rs:51
3: std::rt::lang_start
at /rustc/fa51f810e5b9254904b92660e7280b7d6a46f112/src/libstd/rt.rs:67
4: main
5: __libc_start_main
6: _start
thread 'main' panicked at 'explicit panic', src/main.rs:7:5
stack backtrace:
0: backtrace::backtrace::libunwind::trace
at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/libunwind.rs:86
1: backtrace::backtrace::trace_unsynchronized
at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/mod.rs:66
2: std::sys_common::backtrace::_print_fmt
at src/libstd/sys_common/backtrace.rs:78
3: <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt
at src/libstd/sys_common/backtrace.rs:59
4: core::fmt::write
at src/libcore/fmt/mod.rs:1069
5: std::io::Write::write_fmt
at src/libstd/io/mod.rs:1532
6: std::sys_common::backtrace::_print
at src/libstd/sys_common/backtrace.rs:62
7: std::sys_common::backtrace::print
at src/libstd/sys_common/backtrace.rs:49
8: std::panicking::default_hook::{{closure}}
at src/libstd/panicking.rs:198
9: std::panicking::default_hook
at src/libstd/panicking.rs:218
10: std::panicking::rust_panic_with_hook
at src/libstd/panicking.rs:477
11: std::panicking::begin_panic
at /rustc/fa51f810e5b9254904b92660e7280b7d6a46f112/src/libstd/panicking.rs:404
12: playground::main
at src/main.rs:7
13: std::rt::lang_start::{{closure}}
at /rustc/fa51f810e5b9254904b92660e7280b7d6a46f112/src/libstd/rt.rs:67
14: std::rt::lang_start_internal::{{closure}}
at src/libstd/rt.rs:52
15: std::panicking::try::do_call
at src/libstd/panicking.rs:297
16: std::panicking::try
at src/libstd/panicking.rs:274
17: std::panic::catch_unwind
at src/libstd/panic.rs:394
18: std::rt::lang_start_internal
at src/libstd/rt.rs:51
19: std::rt::lang_start
at /rustc/fa51f810e5b9254904b92660e7280b7d6a46f112/src/libstd/rt.rs:67
20: main
21: __libc_start_main
22: _start
As you can see, the first backtrace omits the frame number for some functions, probably because these all share a single frame after inlining. The panic backtrace for some reason lacks this information.
Looks like we have two separate pieces of backtrace-printing code in libstd, and they behave differently?
Indeed looks like the we have two backtrace formatters:
Both use the backtrace_rs formatting machinery, but evidently not in the same way.
I have no idea why this is duplicated (other than maybe "historic accident").
@alexcrichton do you have any idea why backtraces are formatted inconsistently between panics and std::backtrace?
Hm I'm not sure why this is inconsistent. It looks like it's all using the same things internally, but I don't have a Linux machine right now to test with unfortunately.
The panic version doesn't require capturing and resolving all frames in advance. This is faster and would be essential for displaying a backtrace in case of OOM or stackoverflow if we want to do thzt in the future because it requires much less memory.
I'm not really familiar with this code yet, but I think the difference in formatting is because our panic backtrace formatter constructs a new BacktraceFrameFmt for each symbol but our Backtrace formatter shares one for all symbols attached to a frame.
I think we can reasonably share some more code between these formatters if we'd like to make formatting and filtering more consistent between them.