rust-lang/rust

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.