Backtrace is <unknown> for dynamic library loaded through dlopen using absolute file path for rust >= 1.37.0 on OSX

[t-mw]

From Rust v1.37.0 onwards on Mac OS 10.14.6, a panic triggered in a dynamically loaded library does not produce a full stacktrace if the library was loaded by passing an absolute path to dlopen. I haven't been able to test other platforms Windows and Linux do not have the issue, see #67599 (comment) and #67599 (comment).

The project at https://github.com/t-mw/libreloading-test-rs loads a library using its absolute path by default. The loading is done by libloading which uses dlopen internally.

With Rust 1.40 and RUST_BACKTRACE=full cargo run the following output is produced (Rust 1.37 produces similar output):

thread '<unnamed>' panicked at '!!!', src/lib.rs:6:9
stack backtrace:
   0:        0x10d4df815 - <unknown>
   1:        0x10d4f6a20 - <unknown>
   2:        0x10d4de60b - <unknown>
   3:        0x10d4e0f73 - <unknown>
   4:        0x10d4e0c7a - <unknown>
   5:        0x10d4e15cb - <unknown>
   6:        0x10d4db94c - <unknown>
   7:        0x10d4db5a4 - <unknown>
   8:        0x10d4db3b1 - <unknown>
   9:        0x10d445269 - libloading_test::main::h9b608f0903e21359
                               at src/main.rs:13
...

The expected output can be seen by compiling the same code with Rust 1.36. However, this is still missing some details about line numbers, for example for reloadable::RELOAD_API::{{closure}}:

thread '<unnamed>' panicked at '!!!', src/lib.rs:6:9
stack backtrace:
   0:        0x101056663 - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::hbc4a87dc97d9c209
   1:        0x1010535d2 - std::sys_common::backtrace::_print::h411a08c36ea9f4e9
   2:        0x101055ca6 - std::panicking::default_hook::{{closure}}::hc6f50b761777cef2
   3:        0x101055a4f - std::panicking::default_hook::h871283332e86768d
   4:        0x10105632f - std::panicking::rust_panic_with_hook::hddd286a9c773fc67
   5:        0x10104e010 - std::panicking::begin_panic::h6dc165374aa0a9bd
   6:        0x10104e923 - reloadable::RELOAD_API::{{closure}}::h42ed074a77f6faff
   7:        0x10104e830 - core::ops::function::FnOnce::call_once::h5642339838887a68
   8:        0x100fba70d - libloading_test::main::h7208d4e03f17b192
                               at src/main.rs:13
...

Ideally, the output would be the same as when a relative path name is passed to dlopen (by uncommenting https://github.com/t-mw/libreloading-test-rs/blob/master/src/main.rs#L11), which produces a complete backtrace in Rust 1.36 to 1.40. Rust 1.40 produces the following output in that case:

thread '<unnamed>' panicked at '!!!', src/lib.rs:6:9
stack backtrace:
   0:        0x10fe8c815 - backtrace::backtrace::libunwind::trace::hb16ec6045891ce5a
                               at /Users/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/libunwind.rs:88
   1:        0x10fe8c815 - backtrace::backtrace::trace_unsynchronized::hcacbd0efdffd74c6
                               at /Users/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/mod.rs:66
   2:        0x10fe8c815 - std::sys_common::backtrace::_print_fmt::h39e22de9d6757d12
                               at src/libstd/sys_common/backtrace.rs:77
   3:        0x10fe8c815 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h415ddd0ba88caaaf
                               at src/libstd/sys_common/backtrace.rs:61
   4:        0x10fea3a20 - core::fmt::write::h3335552e2df81c1d
                               at src/libcore/fmt/mod.rs:1028
   5:        0x10fe8b60b - std::io::Write::write_fmt::he6837371b9a45188
                               at src/libstd/io/mod.rs:1412
   6:        0x10fe8df73 - std::sys_common::backtrace::_print::h89459d14ba97f5fa
                               at src/libstd/sys_common/backtrace.rs:65
   7:        0x10fe8df73 - std::sys_common::backtrace::print::ha4c6688e811b8829
                               at src/libstd/sys_common/backtrace.rs:50
   8:        0x10fe8df73 - std::panicking::default_hook::{{closure}}::h708e66cfeb0483ba
                               at src/libstd/panicking.rs:188
   9:        0x10fe8dc7a - std::panicking::default_hook::h39ea8ddf674c04ec
                               at src/libstd/panicking.rs:205
  10:        0x10fe8e5cb - std::panicking::rust_panic_with_hook::h9db77b22c2255a16
                               at src/libstd/panicking.rs:464
  11:        0x10fe8894c - std::panicking::begin_panic::h21574f5509dfe34a
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libstd/panicking.rs:400
  12:        0x10fe885a4 - reloadable::RELOAD_API::{{closure}}::haea0cf290bcd83d5
                               at src/lib.rs:6
  13:        0x10fe883b1 - core::ops::function::FnOnce::call_once::h32c523a7aa5b79f3
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libcore/ops/function.rs:227
  14:        0x10fdf2279 - libloading_test::main::h9b608f0903e21359
                               at src/main.rs:13
...

[jumbatm]

I get the correct backtrace when I run the repro repo (ha) for both relative and absolute paths on Linux, using rustc 1.40.0:

thread '<unnamed>' panicked at '!!!', src/lib.rs:6:9
stack backtrace:
   0:     0x7efbff47ad04 - backtrace::backtrace::libunwind::trace::h65597d255cb1398b
                               at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/libunwind.rs:88
   1:     0x7efbff47ad04 - backtrace::backtrace::trace_unsynchronized::hd4f479d7150ec4a0
                               at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/mod.rs:66
   2:     0x7efbff47ad04 - std::sys_common::backtrace::_print_fmt::h015072984a2b172c
                               at src/libstd/sys_common/backtrace.rs:77
   3:     0x7efbff47ad04 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h6df05d3335f32194
                               at src/libstd/sys_common/backtrace.rs:61
   4:     0x7efbff49265c - core::fmt::write::h1f444f4312eb6c27
                               at src/libcore/fmt/mod.rs:1028
   5:     0x7efbff479c37 - std::io::Write::write_fmt::h8d147888220078ef
                               at src/libstd/io/mod.rs:1412
   6:     0x7efbff47cc2e - std::sys_common::backtrace::_print::h8a6df0fa81d6af62
                               at src/libstd/sys_common/backtrace.rs:65
   7:     0x7efbff47cc2e - std::sys_common::backtrace::print::h6f05b4733407e509
                               at src/libstd/sys_common/backtrace.rs:50
   8:     0x7efbff47cc2e - std::panicking::default_hook::{{closure}}::h0d0a23bd02315dd8
                               at src/libstd/panicking.rs:188
   9:     0x7efbff47c921 - std::panicking::default_hook::h8d15a9aecb4efac6
                               at src/libstd/panicking.rs:205
  10:     0x7efbff47d25b - std::panicking::rust_panic_with_hook::hbe174577402a475d
                               at src/libstd/panicking.rs:464
  11:     0x7efbff47634f - std::panicking::begin_panic::h634f0a45cd79b13c
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libstd/panicking.rs:400
  12:     0x7efbff47760d - reloadable::RELOAD_API::{{closure}}::h6be6a6421c7d5bd6
                               at src/lib.rs:6
  13:     0x7efbff476b3e - core::ops::function::FnOnce::call_once::hd3d414ac216f7262
                               at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14/src/libcore/ops/function.rs:227
  14:     0x565555559cb5 - libreloading_test::main::h100c07e459594b27
                               at src/main.rs:16
...

Perhaps an OSX issue. Give me a moment - I'll see if Windows is affected.

[jumbatm]

Backtrace is fine on Windows 10, too.

thread '<unnamed>' panicked at '!!!', src\lib.rs:6:9
stack backtrace:
   0: backtrace::backtrace::trace_unsynchronized
             at C:\Users\VssAdministrator\.cargo\registry\src\github.com-1ecc6299db9ec823\backtrace-0.3.40\src\backtrace\mod.rs:66
   1: std::sys_common::backtrace::_print_fmt
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\sys_common\backtrace.rs:77
   2: std::sys_common::backtrace::_print::{{impl}}::fmt
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\sys_common\backtrace.rs:61
   3: core::fmt::write
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libcore\fmt\mod.rs:1028
   4: std::io::Write::write_fmt<std::sys::windows::stdio::Stderr>
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\io\mod.rs:1412
   5: std::sys_common::backtrace::_print
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\sys_common\backtrace.rs:65
   6: std::sys_common::backtrace::print
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\sys_common\backtrace.rs:50
   7: std::panicking::default_hook::{{closure}}
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\panicking.rs:188
   8: std::panicking::default_hook
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\panicking.rs:205
   9: std::panicking::rust_panic_with_hook
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\panicking.rs:464
  10: std::panicking::begin_panic<str*>
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\src\libstd\panicking.rs:400
  11: reloadable::RELOAD_API::{{closure}}
             at .\src\lib.rs:6
  12: core::ops::function::FnOnce::call_once<closure-0,()>
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\src\libcore\ops\function.rs:227
  13: libreloading_test::main
             at .\src\main.rs:16
  14: std::rt::lang_start::{{closure}}<()>
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\src\libstd\rt.rs:61
  15: std::rt::lang_start_internal::{{closure}}
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\rt.rs:48
  16: std::panicking::try::do_call<closure-0,i32>
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\panicking.rs:287
  17: panic_unwind::__rust_maybe_catch_panic
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libpanic_unwind\lib.rs:78
  18: std::panicking::try
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\panicking.rs:265
  19: std::panic::catch_unwind
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\panic.rs:396
  20: std::rt::lang_start_internal
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\/src\libstd\rt.rs:47
  21: std::rt::lang_start<()>
             at /rustc/73528e339aae0f17a15ffa49a8ac608f50c6cf14\src\libstd\rt.rs:61
  22: main
  23: invoke_main
             at d:\agent\_work\5\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl:78
  24: __scrt_common_main_seh
             at d:\agent\_work\5\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl:288
  25: BaseThreadInitThunk
  26: RtlUserThreadStart
...

I do also appear to get a segfault after the backtrace dump, though I'm not sure that's unexpected:

...
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
error: process didn't exit successfully: `target\debug\libreloading-test.exe` (exit code: 0xc0000005, STATUS_ACCESS_VIOLATION)

[t-mw]

Thanks for checking. As an aside, I noticed that the issue hasn't been labelled while most other new issues are, I'm not sure if that means it's slipped through some cracks.

[jumbatm]

Hmm, not 100% sure -- there's quite a few open issues without labels right now, but there's also been quite a number of issues in the past that were resolved without being labelled. I feel like not having labels is more just an indication that @jonas-schievink, who seems to be the one to label most new issues, didn't happen to see it when it first was submitted.

In any case, you can use rustbot to add labels yourself, like this:
@rustbot modify labels to +O-macos, +A-runtime, +regression-from-stable-to-stable

[rustbot]

Error: Label regression-from-stable-to-stable can only be set by Rust team members

Please let @rust-lang/release know if you're having trouble with this bot.

[jumbatm]

Oof, alright. Fair enough.

@rustbot modify labels to +O-macos, +A-runtime

[t-mw]

Bisecting shows it starting with d1040fe.

[spastorino]

This is really a libs-impl thing, fixing labels accordingly.

[alexcrichton]

A bisection pointing to d1040fe likely indicates that the implementation in the backtrace crate is different from the implementation that was previously in the standard library. Regardless though it looks like this bug is only on macOS, and it looks to me like it's a bug in libbacktrace itself.

From what it looks like I think this is an instance of rust-lang/backtrace-rs#318. That bug affected both the libbacktrace implementation as well as gimli, and gimli has since been fixed. If you add in a dependency on the backtrace crate, which uses gimli by default right now, it'll print the right backtrace whereas the previous libbacktrace prints the wrong backtrace.

For the standard library there's not really a great solution right now, unfortunately. There's an issue about using gimli in libstd, but that will take some time.

[spastorino]

This was I-nominated for prioritization but I-nominated now means let's discuss during the compiler weekly meeting. So removing the label.

[theduke]

As a note of reference, this has also recently started to appear on Linux on nightly.

NixOS, to be specific.
rustc version: rustc 1.52.0-nightly (3e826bb11 2021-02-21)

Only seems to happen when I set LD_LIBRARY_PATH with some absolute paths, but I'm investigating the details.

[joshtriplett]

We think the issue on macOS may have been switched by the switch to gimli. Could someone verify if the issue is fixed on macOS? cc @t-mw

Separately, @theduke, could you please file an issue for what you've observed on Linux? (That in turn may be a gimli issue as well.)

[t-mw]

Thanks, I can't reproduce this any more with Rust 1.53.0 on Mac OS 10.14.6. Absolute and relative paths produce the complete backtrace. I also tested the repro project on Arch Linux with Rust 1.53.0, and can't reproduce the issue there.