Backtrace rendering inconsistent between std::backtrace and panics

[RalfJung]

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.heygears.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/libunwind.rs:86
   1: backtrace::backtrace::trace_unsynchronized
             at /cargo/registry/src/github.heygears.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?

[RalfJung]

Indeed looks like the we have two backtrace formatters:

• for panicking
• for std::backtracke::Backtrace

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").

[RalfJung]

@alexcrichton do you have any idea why backtraces are formatted inconsistently between panics and std::backtrace?

[alexcrichton]

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.

[bjorn3]

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.

[KodrAus]

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.

[RodBurman]

The following code (a trimmed version of the original version):

fn main() {
    let backtrace = std::backtrace::Backtrace::capture();
    eprintln!("{}", backtrace);

    panic!();
}

compiled using:

% cargo -v -V       
cargo 1.85.0 (d73d2caf9 2024-12-31)
release: 1.85.0
commit-hash: d73d2caf9e41a39daf2a8d6ce60ec80bf354d2a7
commit-date: 2024-12-31
host: aarch64-apple-darwin
libgit2: 1.8.1 (sys:0.19.0 vendored)
libcurl: 8.7.1 (sys:0.4.74+curl-8.9.0 system ssl:(SecureTransport) LibreSSL/3.3.6)
ssl: OpenSSL 1.1.1w  11 Sep 2023
os: Mac OS 15.3.1 [64-bit]

produces no warnings or errors. Then run with RUST_BACKTRACE=1 produces:

./target/debug/bt2 
   0: std::backtrace_rs::backtrace::libunwind::trace
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/../../backtrace/src/backtrace/libunwind.rs:116:5
   1: std::backtrace_rs::backtrace::trace_unsynchronized
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2: std::backtrace::Backtrace::create
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/backtrace.rs:331:13
   3: bt2::main
             at ./src/main.rs:2:21
   4: core::ops::function::FnOnce::call_once
             at /Users/rod/.rustup/toolchains/stable-aarch64-apple-darwin/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5
   5: std::sys::backtrace::__rust_begin_short_backtrace
             at /Users/rod/.rustup/toolchains/stable-aarch64-apple-darwin/lib/rustlib/src/rust/library/std/src/sys/backtrace.rs:152:18
   6: std::rt::lang_start::{{closure}}
             at /Users/rod/.rustup/toolchains/stable-aarch64-apple-darwin/lib/rustlib/src/rust/library/std/src/rt.rs:195:18
   7: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/core/src/ops/function.rs:284:13
   8: std::panicking::try::do_call
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/panicking.rs:584:40
   9: std::panicking::try
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/panicking.rs:547:19
  10: std::panic::catch_unwind
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/panic.rs:358:14
  11: std::rt::lang_start_internal::{{closure}}
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/rt.rs:174:48
  12: std::panicking::try::do_call
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/panicking.rs:584:40
  13: std::panicking::try
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/panicking.rs:547:19
  14: std::panic::catch_unwind
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/panic.rs:358:14
  15: std::rt::lang_start_internal
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/rt.rs:174:20
  16: std::rt::lang_start
             at /Users/rod/.rustup/toolchains/stable-aarch64-apple-darwin/lib/rustlib/src/rust/library/std/src/rt.rs:194:17
  17: _main


thread 'main' panicked at src/main.rs:5:5:
explicit panic
stack backtrace:
   0: rust_begin_unwind
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/std/src/panicking.rs:692:5
   1: core::panicking::panic_fmt
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/core/src/panicking.rs:75:14
   2: core::panicking::panic_display
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/core/src/panicking.rs:261:5
   3: core::panicking::panic_explicit
             at /rustc/4d91de4e48198da2e33413efdcd9cd2cc0c46688/library/core/src/panicking.rs:234:5
   4: bt2::main::panic_cold_explicit
             at /Users/rod/.rustup/toolchains/stable-aarch64-apple-darwin/lib/rustlib/src/rust/library/core/src/panic.rs:88:13
   5: bt2::main
             at ./src/main.rs:5:5
   6: core::ops::function::FnOnce::call_once
             at /Users/rod/.rustup/toolchains/stable-aarch64-apple-darwin/lib/rustlib/src/rust/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

Which seems have the same differences as the original issue but with more/less items order reversed?