Rustig panics when analysing a binary

[Michael-F-Bryan]

I just came across your post to the user forums and thought I'd try rustig out against a no_std gcode parsing library i'm working on. When I ran the program on the cli-reader example in my gcode-rs crate, rustig itself panicked...

Here's a copy of the offending binary:

cli-reader.zip

And steps to reproduce:

$ cd /tmp
$ git clone https://github.com/Michael-F-Bryan/gcode-rs
Cloning into 'gcode-rs'...
remote: Counting objects: 851, done.
remote: Compressing objects: 100% (112/112), done.
remote: Total 851 (delta 112), reused 195 (delta 98), pack-reused 633
Receiving objects: 100% (851/851), 3.92 MiB | 263.00 KiB/s, done.
Resolving deltas: 100% (475/475), done.
$ cd gcode-rs 
$ cargo rustc --release --example cli-reader -- -g
    Updating registry `https://github.com/rust-lang/crates.io-index`
   Compiling nodrop v0.1.12                                                                                                                       
   Compiling difference v2.0.0                                                                                                                    
   Compiling ansi_term v0.11.0                                                                                                                    
   Compiling arrayvec v0.4.7                                                                                                                      
   Compiling pretty_assertions v0.5.1                                                                                                             
   Compiling gcode v0.3.0 (file:///tmp/gcode-rs)                                                                                                  
warning: unused import: `ErrorKind`============================>         ] 6/7: gcode                                                             
 --> examples/cli-reader.rs:7:34
  |
7 | use std::io::{self, Read, Error, ErrorKind, BufReader, BufRead};
  |                                  ^^^^^^^^^
  |
  = note: #[warn(unused_imports)] on by default

    Finished release [optimized] target(s) in 10.44s                                                                                              
$ rustig --binary target/release/examples/cli-reader
thread 'main' panicked at 'index 40 out of range for slice of length 0', libcore/slice/mod.rs:1962:5
note: Run with `RUST_BACKTRACE=1` for a backtrace.
$ RUST_BACKTRACE=1 rustig --binary target/release/examples/cli-reader
thread 'main' panicked at 'index 40 out of range for slice of length 0', libcore/slice/mod.rs:1962:5
stack backtrace:
   0: std::sys::unix::backtrace::tracing::imp::unwind_backtrace
             at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
   1: std::sys_common::backtrace::print
             at libstd/sys_common/backtrace.rs:71
             at libstd/sys_common/backtrace.rs:59
   2: std::panicking::default_hook::{{closure}}
             at libstd/panicking.rs:211
   3: std::panicking::default_hook
             at libstd/panicking.rs:227
   4: std::panicking::rust_panic_with_hook
             at libstd/panicking.rs:475
   5: std::panicking::continue_panic_fmt
             at libstd/panicking.rs:390
   6: rust_begin_unwind
             at libstd/panicking.rs:325
   7: core::panicking::panic_fmt
             at libcore/panicking.rs:77
   8: core::slice::slice_index_len_fail
             at libcore/slice/mod.rs:1962
   9: panic_analysis::panic_calls::panic_message::get_bytes_at_address
  10: <panic_analysis::panic_calls::panic_message::CorePanickingPanicMessageFinder as panic_analysis::panic_calls::panic_message::PanicMessageFinder>::find_panic_message
  11: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &'a mut F>::call_once
  12: <alloc::vec::Vec<T> as alloc::vec::SpecExtend<T, I>>::from_iter
  13: <panic_analysis::panic_calls::DefaultPanicCallsFinder as panic_analysis::panic_calls::PanicCallsFinder>::find_panics
  14: panic_analysis::find_panics
  15: rustig::main
  16: std::rt::lang_start::{{closure}}
  17: std::panicking::try::do_call
             at libstd/rt.rs:59
             at libstd/panicking.rs:310
  18: __rust_maybe_catch_panic
             at libpanic_unwind/lib.rs:105
  19: std::rt::lang_start_internal
             at libstd/panicking.rs:289
             at libstd/panic.rs:392
             at libstd/rt.rs:58
  20: main
  21: __libc_start_main
  22: _start

[egrtechno]

Hi Michael,

Thanks for reporting this. Using your reproduction steps the tool had the following output for me:

cli_reader::main (gcode-rs) calls std::env::args (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls <std::env::Args as core::iter::iterator::Iterator>::next (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls std::env::args (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls <std::env::Args as core::iter::iterator::Iterator>::next (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls <std::env::Args as core::iter::iterator::Iterator>::next (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls std::io::stdio::stdin (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls <std::io::buffered::BufReader<R>>::new (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls <std::io::Lines<B> as core::iter::iterator::Iterator>::next (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls std::io::stdio::_print (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls std::fs::File::open (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls std::io::stdio::_eprint (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:28
cli_reader::main (gcode-rs) calls std::io::stdio::_eprint (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:33
cli_reader::main (gcode-rs) calls alloc::alloc::oom (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls alloc::alloc::oom (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::usage (gcode-rs) calls std::env::args (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:54
cli_reader::usage (gcode-rs) calls <std::env::Args as core::iter::iterator::Iterator>::next (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:54
cli_reader::usage (gcode-rs) calls core::panicking::panic (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:54
cli_reader::usage (gcode-rs) calls std::io::stdio::_eprint (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:54
cli_reader::usage (gcode-rs) calls std::process::exit (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:55
cli_reader::main (gcode-rs) calls <std::io::stdio::Stdin as std::io::Read>::read (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls <std::io::stdio::Stdin as std::io::Read>::read_to_end (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls <std::io::stdio::Stdin as std::io::Read>::read_to_string (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls <std::io::stdio::Stdin as std::io::Read>::read_exact (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls std::io::Read::read_to_end (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls std::io::Read::read_to_string (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls std::io::Read::read_exact (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:27
cli_reader::main (gcode-rs) calls <std::io::error::Error as core::fmt::Display>::fmt (stdlib@1.27.1) at /tmp/gcode-rs/examples/cli-reader.rs:28

It does not panic here. This is the toolchain I have used:

active toolchain
----------------

stable-x86_64-unknown-linux-gnu (default)
rustc 1.27.1 (5f2b325f6 2018-07-07)

Any differences?

[egrtechno]

Oh, and while developing this tool we had some issues when running on various versions of Linux (linker specific issues). I'm running on a somewhat older Linux Mint (based on Ubuntu 16.04 LTS).

Yours?

[egrtechno]

As an example of verbose output, I have an expanded version of one of the reported paths below:

Command line used:

rustig --binary target/release/examples/cli-reader --verbose

First output:

--#01 -- Pattern: Unrecognized -- Message: 'capacity overflow'

 0: cli_reader::main (gcode-rs)
      at /tmp/gcode-rs/examples/cli-reader.rs:27
      <inline cli_reader::run at /tmp/gcode-rs/examples/cli-reader.rs:10 >
      <inline cli_reader::parse_args at /tmp/gcode-rs/examples/cli-reader.rs:41 >
 1: std::env::args (stdlib@1.27.1)
      at /checkout/src/libstd/env.rs:701
      <inline std::env::args_os at /checkout/src/libstd/env.rs:723 >
      <inline std::sys::unix::args::args at /checkout/src/libstd/sys/unix/args.rs:30 >
      <inline std::sys::unix::args::imp::args at /checkout/src/libstd/sys/unix/args.rs:100 >
      <inline std::sys::unix::args::imp::clone at /checkout/src/libstd/sys/unix/args.rs:108 >
      <inline core::iter::iterator::Iterator::collect at /checkout/src/libcore/iter/iterator.rs:1375 >
      <inline <alloc::vec::Vec<T> as core::iter::traits::FromIterator<T>>::from_iter at /checkout/src/liballoc/vec.rs:1752 >
 2: <alloc::vec::Vec<T> as alloc::vec::SpecExtend<T, I>>::from_iter (stdlib@1.27.1)
      at /checkout/src/liballoc/vec.rs:1866
      <inline <alloc::vec::Vec<T> as alloc::vec::SpecExtend<T, I>>::spec_extend at /checkout/src/liballoc/vec.rs:1879 >
      <inline <alloc::vec::Vec<T>>::reserve at /checkout/src/liballoc/vec.rs:467 >
 3: <alloc::raw_vec::RawVec<T, A>>::reserve (stdlib@1.27.1)
      at /checkout/src/liballoc/raw_vec.rs:556
 4: alloc::raw_vec::capacity_overflow (stdlib@1.27.1)
      at /checkout/src/liballoc/raw_vec.rs:741
 5: core::panicking::panic (stdlib@1.27.1)

[Michael-F-Bryan]

I was using nightly on an Arch Linux machine when I encountered that error. I'm not 100% sure which linker rustc was using when I installed rustig because I've got both the most recent version of the GNU and LLVM linkers installed.

I'll try it on stable when I get home and see if there are any differences.

[Michael-F-Bryan]

This is really strange! I just installed rustig using stable on my linux machine and it's still panicking.

I just reinstalled it using --debug so we get more debug info and the compiler doesn't do inlining, this should give us a nicer backtrace.

$ cargo install --git https://github.com/Technolution/rustig rustig --force --debug
$ RUST_BACKTRACE=full rustig --binary target/release/examples/cli-reader
thread 'main' panicked at 'index 40 out of range for slice of length 0', libcore/slice/mod.rs:2256:5
stack backtrace:
   0:     0x557d09553c4e - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::haed5aa61d2719d78
                               at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
   1:     0x557d09559506 - std::sys_common::backtrace::print::h8b247be0ccf8b0fd
                               at libstd/sys_common/backtrace.rs:71
                               at libstd/sys_common/backtrace.rs:59
   2:     0x557d095479fb - std::panicking::default_hook::{{closure}}::h5f529b7f0e62b280
                               at libstd/panicking.rs:211
   3:     0x557d095476d3 - std::panicking::default_hook::h546f65830e1e0096
                               at libstd/panicking.rs:227
   4:     0x557d09547fce - std::panicking::rust_panic_with_hook::h55e258944e31bc6d
                               at libstd/panicking.rs:463
   5:     0x557d09547b6c - std::panicking::begin_panic_fmt::ha93d510596c1ce0e
                               at libstd/panicking.rs:350
   6:     0x557d09547b31 - rust_begin_unwind
                               at libstd/panicking.rs:328
   7:     0x557d09599d92 - core::panicking::panic_fmt::h48a9dc276960b80c
                               at libcore/panicking.rs:71
   8:     0x557d095a47f0 - core::slice::slice_index_len_fail::hbb3f71d2c1ebea76
                               at libcore/slice/mod.rs:2256
   9:     0x557d093f55b8 - <core::ops::range::Range<usize> as core::slice::SliceIndex<[T]>>::index::h298095dd4184e8af
                               at /checkout/src/libcore/slice/mod.rs:2387
  10:     0x557d094613f0 - core::slice::<impl core::ops::index::Index<I> for [T]>::index::h2bd08eca92242532
                               at /checkout/src/libcore/slice/mod.rs:2238
  11:     0x557d0925802d - panic_analysis::panic_calls::panic_message::get_bytes_at_address::hcefd0b582bae48d4
                               at lib/panic_analysis/src/panic_calls/panic_message.rs:335
  12:     0x557d09255a8f - <panic_analysis::panic_calls::panic_message::CorePanickingPanicMessageFinder as panic_analysis::panic_calls::panic_message::PanicMessageFinder>::find_panic_message::h4f6d0e2655aa7280
                               at lib/panic_analysis/src/panic_calls/panic_message.rs:79
  13:     0x557d092491ee - <panic_analysis::panic_calls::DefaultPanicCallsFinder as panic_analysis::panic_calls::PanicCallsFinder>::find_panics::{{closure}}::{{closure}}::h6ea0c8ca965b72eb
                               at lib/panic_analysis/src/panic_calls/mod.rs:87
  14:     0x557d09253690 - <core::iter::FilterMap<I, F> as core::iter::iterator::Iterator>::next::h0514f3547cc55692
                               at /checkout/src/libcore/iter/mod.rs:1593
  15:     0x557d092495c2 - <panic_analysis::panic_calls::DefaultPanicCallsFinder as panic_analysis::panic_calls::PanicCallsFinder>::find_panics::{{closure}}::heff07e976359a5f3
                               at lib/panic_analysis/src/panic_calls/mod.rs:85
  16:     0x557d0923f8b1 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &'a mut F>::call_once::h41b196feac28d1df
                               at /checkout/src/libcore/ops/function.rs:271
  17:     0x557d09214a3c - <core::option::Option<T>>::map::h1469438c5ab6a380
                               at /checkout/src/libcore/option.rs:404
  18:     0x557d09250f78 - <core::iter::Map<I, F> as core::iter::iterator::Iterator>::next::hf5a2de1e03033a92
                               at /checkout/src/libcore/iter/mod.rs:1347
  19:     0x557d091d01e7 - <alloc::vec::Vec<T>>::extend_desugared::hef77035c4bf7b335
                               at /checkout/src/liballoc/vec.rs:1960
  20:     0x557d091d97bd - <alloc::vec::Vec<T> as alloc::vec::SpecExtend<T, I>>::spec_extend::h824c2ef7c6de5516
                               at /checkout/src/liballoc/vec.rs:1857
  21:     0x557d091db039 - <alloc::vec::Vec<T> as alloc::vec::SpecExtend<T, I>>::from_iter::h6498a732a38a96d6
                               at /checkout/src/liballoc/vec.rs:1852
  22:     0x557d091dc84c - <alloc::vec::Vec<T> as core::iter::traits::FromIterator<T>>::from_iter::h0150de99ed3f297e
                               at /checkout/src/liballoc/vec.rs:1752
  23:     0x557d0924cf79 - core::iter::iterator::Iterator::collect::h12b0129575b0500a
                               at /checkout/src/libcore/iter/iterator.rs:1375
  24:     0x557d092490cf - <panic_analysis::panic_calls::DefaultPanicCallsFinder as panic_analysis::panic_calls::PanicCallsFinder>::find_panics::hcddb7c37a37edc98
                               at lib/panic_analysis/src/panic_calls/mod.rs:48
  25:     0x557d092628f3 - panic_analysis::find_panics::h1818afbeee27791e
                               at lib/panic_analysis/src/lib.rs:357
  26:     0x557d08fb97a0 - rustig::main::h7c5c12e803d18a7c
                               at src/main.rs:52
  27:     0x557d08fd2f7f - std::rt::lang_start::{{closure}}::hdcd934f4e1f2e151
                               at /checkout/src/libstd/rt.rs:74
  28:     0x557d09547ab2 - std::panicking::try::do_call::hc2917ab2c572e22d
                               at libstd/rt.rs:59
                               at libstd/panicking.rs:310
  29:     0x557d09560589 - __rust_maybe_catch_panic
                               at libpanic_unwind/lib.rs:105
  30:     0x557d0954c965 - std::rt::lang_start_internal::h106bcdfb2e3beaf8
                               at libstd/panicking.rs:289
                               at libstd/panic.rs:374
                               at libstd/rt.rs:58
  31:     0x557d08fd2f57 - std::rt::lang_start::h4afb9adbc14c17c2
                               at /checkout/src/libstd/rt.rs:74
  32:     0x557d08fb992c - main
  33:     0x7f3ba994d06a - __libc_start_main
  34:     0x557d08f9a4f9 - _start
  35:                0x0 - <unknown>

Interestingly enough, telling rustc to use lld as a linker instead of whatever GCC does was enough to make things work.

$ RUST_FLAGS="-C linker-flavor lld" cargo build --verbose --examples
$ r5ustig --binary target/debug/examples/cli-reader
cli_reader::run (gcode-rs) calls <std::io::Lines<B> as core::iter::iterator::Iterator>::next (stdlib@1.27.1) at /home/michael/Documents/gcode-rs/examples/cli-reader.rs:12
(lots of output elided)

A cursory glance through the backtrace makes it look like the call to get_bytes_at_address() in CorePanickingPanicMessageFinder::find_panic_message() is the culprit. I think there's something fishy in get_bytes_at_address() where section.data().len() and section.size() don't agree (here).

[egrtechno]

Ok, monday morning here. Let's try to crack this one.

First: rustig! comes with a very complete set of unit- and systemtests. You can run them by cloning the repo and running cargo test --all. Can you run these tests? If these tests fail on your system, rustig! is not operational on your system.

The systemtest compile a bunch of test binaries, run the callgraph and panic_analysis libraries on them and tests for known results. These tests are also run as part of the Travis build, so the are tested for every PR and merge.

Note: the tests install a very specific version of the Rust compiler to ensure that the base of the callgraph library still works, see build.rs in lib/test_common. If a newer version of the compiler breaks the tool, these tests proof the difference.

[Michael-F-Bryan]

Hmm, I just got a very interesting error message.

$ cargo test --all
  ...
error: toolchain 'stable-2018-05-10-x86_64-unknown-linux-gnu' does not have the binary `cargo`
thread 'main' panicked at 'Could not build test subjects, manual intervention needed', lib/test_common/build.rs:93:13
note: Run with `RUST_BACKTRACE=1` for a backtrace.

$ rustup run stable-2018-05-10-x86_64-unknown-linux-gnu cargo build
error: toolchain 'stable-2018-05-10-x86_64-unknown-linux-gnu' does not have the binary `cargo`

It looks like, for whatever reason, the stable-2018-05-10 build of stable doesn't contain a cargo binary. To see if it makes a difference I tried manually patching lib/test_common/build.rs to use 1.26.0 (which should be the same thing) and all the tests passed. Maybe rustup uses different release dates depending on the timezone (I'm UTC+8)?

diff --git a/lib/test_common/build.rs b/lib/test_common/build.rs
index 4c60116..1d001e7 100644
--- a/lib/test_common/build.rs
+++ b/lib/test_common/build.rs
@@ -23,7 +23,7 @@ use std::process::Command;
 
 static RES_PATH: &str = "test_subjects";
 static RES_PATH_STABLE_RUSTC: &str = "test_subjects_stable_rustc";
-static STABLE_RUSTC_VERSION: &str = "stable-2018-05-10"; // 1.26.0
+static STABLE_RUSTC_VERSION: &str = "1.26.0"; // 1.26.0
 
 static BUILD_MODE_ARGS: &[Option<&str>] = &[None, Some("--release")];

---

EDIT: I just tried to use rustig again on the original binary and now everything works without panicking, so I doubt we'll be able to reproduce the original error... Should this be closed as transient and not reproducible?

[egrtechno]

Ok, I did the same thing as you did, namely:

$ rustup run stable-2018-05-10-x86_64-unknown-linux-gnu cargo build
   Compiling unicode-xid v0.0.4
   Compiling quote v0.3.15
   <<SNIP>>

I have no idea what goes wrong on your side. The build works on my machine and on the Travis CI builds.

[egrtechno]

Ok, I'll close this. I hope you can use the tool as it is intended now.