Errors not printed on Raspberry Pi when backtrace enabled

[duncanrhamill]

I've run into a bug when running code on a Raspberry Pi (stable-armv7-unknown-linux-gnueabihf) where the errors do not print if running with RUST_BACKTRACE=1 or full. Simple test code:

use eyre::eyre;
use color_eyre::Result;

fn main() -> Result<()> {
    return Err(eyre!("Panicy panic"));
}

with:

[dependencies]
eyre = "0.4"
color-eyre = "0.3"

On linux (stable-x86_64-unknown-linux-gnu) cargo run produces the following output:

Error: 
   0: Panicy panic

and RUST_BACKTRACE=1 cargo run procudes:

Error: 
   0: Panicy panic

  ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ BACKTRACE ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
                                ⋮ 3 frames hidden ⋮                               
   4: panic_test::main::h5b6f76bd4e619253
      at /home/{USER}/panic_test/src/main.rs:5
                                ⋮ 11 frames hidden ⋮                              

On the raspberry pi cargo run behaves as normal but using RUST_BACKTRACE=1 produces:

thread 'main' panicked at 'assertion failed: (self.addr as usize) < (isize::MAX as usize)', <::std::macros::panic macros>:2:4
stack backtrace:
   0: backtrace::backtrace::libunwind::trace
             at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.44/src/backtrace/libunwind.rs:86
   1: backtrace::backtrace::trace_unsynchronized
             at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.44/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:1063
   5: std::io::Write::write_fmt
             at src/libstd/io/mod.rs:1426
   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:204
   9: std::panicking::default_hook
             at src/libstd/panicking.rs:224
  10: std::panicking::rust_panic_with_hook
             at src/libstd/panicking.rs:470
  11: std::panicking::begin_panic
             at /rustc/8d69840ab92ea7f4d323420088dd8c9775f180cd/src/libstd/panicking.rs:397
  12: <findshlibs::linux::SharedLibrary as findshlibs::SharedLibrary>::virtual_memory_bias
             at /home/pi/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/<::std::macros::panic macros>:2
  13: backtrace::symbolize::gimli::Cache::new::{{closure}}
             at /home/pi/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/symbolize/gimli.rs:427
  14: findshlibs::linux::SharedLibrary::callback::{{closure}}
             at /home/pi/.cargo/registry/src/github.com-1ecc6299db9ec823/findshlibs-0.5.0/src/linux/mod.rs:185
  15: core::ops::function::FnOnce::call_once
             at /rustc/8d69840ab92ea7f4d323420088dd8c9775f180cd/src/libcore/ops/function.rs:232
  16: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/8d69840ab92ea7f4d323420088dd8c9775f180cd/src/libstd/panic.rs:318
  17: std::panicking::try::do_call
             at /rustc/8d69840ab92ea7f4d323420088dd8c9775f180cd/src/libstd/panicking.rs:303
  18: __rust_maybe_catch_panic
             at src/libpanic_unwind/lib.rs:86
  19: std::panicking::try
             at /rustc/8d69840ab92ea7f4d323420088dd8c9775f180cd/src/libstd/panicking.rs:281
  20: std::panic::catch_unwind
             at /rustc/8d69840ab92ea7f4d323420088dd8c9775f180cd/src/libstd/panic.rs:394
  21: findshlibs::linux::SharedLibrary::callback
             at /home/pi/.cargo/registry/src/github.com-1ecc6299db9ec823/findshlibs-0.5.0/src/linux/mod.rs:181
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

When running without color-eyre and just eyre the raspberry pi behaves as expected, just the error and no backtrace. Not 100% sure the problem is inside color-eyre but I thought I'd log this.

[yaahc]

This looks like an explicit panic in backtrace-rs

What happens if you depend on backtrace directly and manually capture and print the backtrace on the pi?

[duncanrhamill]

Ok so with using backtrace explicitly and no dependence on eyre or color-eyre doesn't seem like there's anything wrong.

[yaahc]

Okay, it might take me a little while to fix this one because I have to find and setup a raspberry pi to do it.

Any additional testing you could do to help isolate the issue would be helpful, such as the specific code you used to show the problem doesn't happen without using color-eyre, or any gdb output trying to trace down exactly what it was doing when it panicked.

And fwiw, I'm 99% sure this isn't an issue from color-eyre, its probably a bug in backtrace-rs where it makes assumptions based on x86 arch that didn't hold true when you ran it on arm, but I'm happy to help you figure out the issue and fix it upstream.

[yaahc]

Oh, @duncanrhamill, did you run this on stable? Can you try reproing the backtrace on nightly? It might give more relevant panic location info

[duncanrhamill]

Ok, thank you very much! I'm thinking the same thing with arch changes, maybe something along the lines of this?

I've rerun everything on nightly and I've put together the outputs from running on the pi here, including the source used to generate them.

If you want me to setup remote ssh on the pi I can.

[yaahc]

This is awesome, ty

As for the ssh, we found a pi but I still have to set it up on the network and do the ip addr discovery, but that shouldn't be hard so I don't think that will be necessary, but if I run into trouble getting a repro I'll let you know so you can setup ssh.

[duncanrhamill]

Ahh great, let me know if you need anything else!

[yaahc]

I'm sorry I haven't gotten around to this yet, but I haven't forgotten.

One thing I realized is that it might be the specific backtrace features that color-backtrace sets. Specifically this:

[features]
default = ["gimli-symbolize"]
failure-bt = ["failure"]
gimli-symbolize = ["backtrace/gimli-symbolize"]

Can you try the example again with gimli-symbolize enabled in backtrace and see what happens?

[duncanrhamill]

No worries, just reran it with

backtrace = { version="0.3", features=["gimli-symbolize"] }

and it seems like that's the cause, panicked before printing the backtrace. Full backtrace from this one:

thread 'main' panicked at 'assertion failed: (self.addr as usize) < (isize::MAX as usize)', /rustc/9912925c254589f58338cb2993163e618475ff75/src/libstd/macros.rs:13:23
stack backtrace:
   0:   0x595170 - backtrace::backtrace::libunwind::trace::h19f0e9723381df32
                       at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/libunwind.rs:86
   1:   0x595170 - backtrace::backtrace::trace_unsynchronized::h4689672582c6f73d
                       at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/mod.rs:66
   2:   0x595170 - std::sys_common::backtrace::_print_fmt::h555e818d074d456c
                       at src/libstd/sys_common/backtrace.rs:78
   3:   0x595170 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hda0f74c2888e4e45
                       at src/libstd/sys_common/backtrace.rs:59
   4:   0x5ad140 - core::fmt::write::hd5deabd920c4e4ab
                       at src/libcore/fmt/mod.rs:1069
   5:   0x593074 - std::io::Write::write_fmt::h6d8723e6380c1d4d
                       at src/libstd/io/mod.rs:1537
   6:   0x5976d8 - std::sys_common::backtrace::_print::h1a240c08a14b3ea3
                       at src/libstd/sys_common/backtrace.rs:62
   7:   0x5976d8 - std::sys_common::backtrace::print::he8a632cb741f8cfd
                       at src/libstd/sys_common/backtrace.rs:49
   8:   0x5976d8 - std::panicking::default_hook::{{closure}}::ha92d8871ef11f458
                       at src/libstd/panicking.rs:198
   9:   0x597398 - std::panicking::default_hook::hbe3dd080d55d3d81
                       at src/libstd/panicking.rs:218
  10:   0x597db4 - std::panicking::rust_panic_with_hook::h8566666fb90d07b7
                       at src/libstd/panicking.rs:477
  11:   0x565c0c - std::panicking::begin_panic::ha4fc229687bffc16
                       at /rustc/9912925c254589f58338cb2993163e618475ff75/src/libstd/panicking.rs:404
  12:   0x4dd1cc - <findshlibs::linux::SharedLibrary as findshlibs::SharedLibrary>::virtual_memory_bias::h8aeff40c4e8ca5f2
                       at /rustc/9912925c254589f58338cb2993163e618475ff75/src/libstd/macros.rs:13
  13:   0x4c7b44 - backtrace::symbolize::gimli::Cache::new::{{closure}}::hca979ae6354ba91a
                       at /home/pi/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/symbolize/gimli.rs:427
  14:   0x4d9334 - findshlibs::linux::SharedLibrary::callback::{{closure}}::h9850d3a8fe0dbadd
                       at /home/pi/.cargo/registry/src/github.com-1ecc6299db9ec823/findshlibs-0.5.0/src/linux/mod.rs:185
  15:   0x4cbc6c - core::ops::function::FnOnce::call_once::h5c77f59632c53541
                       at /rustc/9912925c254589f58338cb2993163e618475ff75/src/libcore/ops/function.rs:232
  16:   0x4c5078 - <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h085e56f9f200b22c
                       at /rustc/9912925c254589f58338cb2993163e618475ff75/src/libstd/panic.rs:318
  17:   0x502384 - std::panicking::try::do_call::hbd7d397f01034b36
                       at /rustc/9912925c254589f58338cb2993163e618475ff75/src/libstd/panicking.rs:297
  18:   0x506f18 - __rust_try
  19:   0x5022ac - std::panicking::try::h9ce3104d3376fb8d
                       at /rustc/9912925c254589f58338cb2993163e618475ff75/src/libstd/panicking.rs:274
  20:   0x4c5314 - std::panic::catch_unwind::h21f9bfa8d822b5b1
                       at /rustc/9912925c254589f58338cb2993163e618475ff75/src/libstd/panic.rs:394
  21:   0x4d91ac - findshlibs::linux::SharedLibrary::callback::he57ce783a7ea4f2e
                       at /home/pi/.cargo/registry/src/github.com-1ecc6299db9ec823/findshlibs-0.5.0/src/linux/mod.rs:181

[yaahc]

Perfect, I've opened an issue on backtrace-rs because I'm gonna low key attempt to pass the buck but if they end up too busy to fix it I will try to figure it out and fix it upstream.

[yaahc]

Looks like its already fixed upstream, so we will bump our dependency versions in color-eyre and color-backtrace to make it use the newest version.

Can you verify that this issue doesn't reproduce when you set the backtrace version to 0.3.48?

[yaahc]

@duncanrhamill Once you've verified that 0.3.48 fixes the issue I will merge #10

[duncanrhamill]

Yep, 0.3.48 works with the backtrace only version and gimli enabled.

Thanks for your effort on this, really appreciated!

[yaahc]

my pleasure!