Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

std: Include line numbers in backtraces. #22839

Merged
merged 4 commits into from
Feb 28, 2015

Conversation

lifthrasiir
Copy link
Contributor

Fixes #20978 for supported platforms (i.e. non-Android POSIX).

This uses backtrace_pcinfo to inspect the DWARF debug info and list the file and line pairs for given stack frame. Such pair is not unique due to the presence of inlined functions and the updated routine correctly handles this case. The code is modelled after libbacktrace's backtrace_full routine.

There is one known issue with this approach. Macros, when invoked, take over the current frame and shadows the file and line pair which has invoked a macro. In particular, this makes many panicking
macros a bit harder to inspect. This really is a debuginfo problem, and the backtrace routine should print them correctly with a correct debuginfo.

Some example trace:

thread '<main>' panicked at 'explicit panic', /home/arachneng/Works/git/rust/src/test/run-pass/backtrace-debuginfo.rs:74
stack backtrace:
   1:         0xd964702f - sys::backtrace::write::h32d93fffb64131b2yxC
   2:         0xd9670202 - panicking::on_panic::h3a4fcb37b873aefeooM
   3:         0xd95b396a - rt::unwind::begin_unwind_inner::h576b3df5f626902dJ2L
   4:         0xd9eb88df - rt::unwind::begin_unwind::h16852273847167740350
   5:         0xd9eb8afb - aux::callback::h15056955655605709172
                        at /home/arachneng/Works/git/rust/<std macros>:3
                        at src/test/run-pass/backtrace-debuginfo-aux.rs:15
   6:         0xd9eb8caa - outer::h2cf96412459fceb6ema
                        at src/test/run-pass/backtrace-debuginfo.rs:73
                        at src/test/run-pass/backtrace-debuginfo.rs:88
   7:         0xd9ebab24 - main::h3f701287441442edasa
                        at src/test/run-pass/backtrace-debuginfo.rs:134
   8:         0xd96daba8 - rust_try_inner
   9:         0xd96dab95 - rust_try
  10:         0xd9671af4 - rt::lang_start::h7da0de9529b4c394liM
  11:         0xd8f3aec4 - __libc_start_main
  12:         0xd9eb8148 - <unknown>
  13:         0xffffffff - <unknown>

Fixes rust-lang#20978 for supported platforms (i.e. non-Android POSIX).

This uses `backtrace_pcinfo` to inspect the DWARF debug info
and list the file and line pairs for given stack frame.
Such pair is not unique due to the presence of inlined functions
and the updated routine correctly handles this case.
The code is modelled after libbacktrace's `backtrace_full` routine.

There is one known issue with this approach. Macros, when invoked,
take over the current frame and shadows the file and line pair
which has invoked a macro. In particular, this makes many panicking
macros a bit harder to inspect. This really is a debuginfo problem,
and the backtrace routine should print them correctly with
a correct debuginfo.
@rust-highfive
Copy link
Collaborator

Thanks for the pull request, and welcome! The Rust team is excited to review your changes, and you should hear from @aturon (or someone else) soon.

If any changes to this PR are deemed necessary, please add them as extra commits. This ensures that the reviewer can see what has changed since they last reviewed the code. The way Github handles out-of-date commits, this should also make it reasonably obvious what issues have or haven't been addressed. Large or tricky changes may require several passes of review and changes.

Please see CONTRIBUTING.md for more information.

@jdm
Copy link
Contributor

jdm commented Feb 26, 2015

Yeah, the macro thing is no different than a backtrace in gdb, since we inline macros and include use their span information.

@lifthrasiir
Copy link
Contributor Author

For the record, it's #18285. I'm sure that the backtrace routine can't improve on that alone.

@alexcrichton
Copy link
Member

Nice! Just to make sure we know what we're dealing with, can you compare the sizes of a "hello world" executable before and after this change as well?

// this is a non-signaling frame, so `ip` refers to the address
// after the calling instruction. account for that.
ip = (ip as usize - 1) as *mut _;
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hm this may explain some of the weird backtraces I saw when I initially wrote all this!

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Was that why _Unwind_FindEnclosingFunction is used?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If I remember correctly, I think so? Although I'd have to test both ways... It's been awhile :(

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Well, I was thinking about replacing that call with backtrace_pcinfo. There is a reason I haven't do so, though:

backtrace_pcinfo does provide a function information as well, but as far as I tested that function name and backtrace_syminfo-based name differ a bit for normal functions and the former is almost unusable for closures (fnfn? seriously?). I guess they go through a different strategy.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Interesting, well I'm pretty much game for whatever works right now :)

@lifthrasiir
Copy link
Contributor Author

@alexcrichton File sizes (note that, obviously, the following does not include debuginfos):

-rwxrwxr-x 1 arachneng 570500 Feb 27 12:34 hello-new-opt0*
-rwxrwxr-x 1 arachneng 570381 Feb 27 12:34 hello-new-opt3*
-rwxrwxr-x 1 arachneng 468274 Feb 27 12:34 hello-new-opt3-lto*
-rwxrwxr-x 1 arachneng 306392 Feb 27 12:34 hello-new-opt3-lto-stripped*
-rwxrwxr-x 1 arachneng 570429 Feb 27 11:30 hello-orig-opt0*
-rwxrwxr-x 1 arachneng 570310 Feb 27 11:31 hello-orig-opt3*
-rwxrwxr-x 1 arachneng 467549 Feb 27 11:31 hello-orig-opt3-lto*
-rwxrwxr-x 1 arachneng 306392 Feb 27 11:31 hello-orig-opt3-lto-stripped*

@alexcrichton
Copy link
Member

Perfect! Looks like there was barely any impact (unless you care about the extra 71 bytes).

@bors: r+ 587f10a

@vhbit
Copy link
Contributor

vhbit commented Feb 27, 2015

Seems to be a reason of rollup failure

@Manishearth
Copy link
Member

Needs Manishearth@53c594e and Manishearth@ee57013 to compile.

Please have a look at the first one; I silenced the warning since there was an issue for macos, but perhaps that should have been fixed differently.

@Manishearth
Copy link
Member

Fails on macos

http://buildbot.rust-lang.org/builders/auto-mac-32-opt/builds/3865/steps/test/logs/stdio


---- [run-pass] run-pass/backtrace-debuginfo.rs stdout ----

error: test run failed!
status: exit code: 101
command: i686-apple-darwin/test/run-pass/backtrace-debuginfo.stage2-i686-apple-darwin 
stdout:
------------------------------------------

------------------------------------------
stderr:
------------------------------------------
thread '<main>' panicked at 'trace does not match position list: test case 0
thread '<main>' panicked at 'explicit panic', /Users/rustbuild/src/rust-buildbot/slave/auto-mac-32-opt/build/src/test/run-pass/backtrace-debuginfo.rs:51
stack backtrace:
   1:   0x1927fa - sys::backtrace::write::hb8abcf3ad25ae5f8lmA
   2:   0x1bd313 - panicking::on_panic::h436869a0a896a62fw8I
   3:    0xedef4 - rt::unwind::begin_unwind_inner::h3a980d3b167b71basRI
   4:    0xd9470 - rt::unwind::begin_unwind::h14711308078462879468
   5:    0xd931a - inner::h1efe2fbb2d14b47csca
   6:    0xd970a - outer::hb4f86a2ea3846118rla
   7:    0xdf337 - main::h8d1983e9f237c03d4qa
   8:   0x22c36d - rust_try_inner
   9:   0x22c346 - rust_try
  10:   0x1bddc4 - rt::lang_start::h0ebea00bcd9cc770c3I
  11:    0xdf521 - main

---
backtrace-debuginfo.rs:86
backtrace-debuginfo.rs:133
', /Users/rustbuild/src/rust-buildbot/slave/auto-mac-32-opt/build/src/test/run-pass/backtrace-debuginfo.rs:100

------------------------------------------

thread '[run-pass] run-pass/backtrace-debuginfo.rs' panicked at 'explicit panic', /Users/rustbuild/src/rust-buildbot/slave/auto-mac-32-opt/build/src/compiletest/runtest.rs:1466

Removing from the rollup and queue, sorry

@Manishearth
Copy link
Member

@bors: r-

(until macos gets fixed)

- Fixed a couple of dead code warnings in std::sys::backtrace.
- Made `backtrace-debuginfo` test a no-op on non-Linux platforms.
- `backtrace-debuginfo` is no longer tested on pretty-rpass.
@lifthrasiir
Copy link
Contributor Author

@Manishearth r? I think I've listed all possible combinations of cfg! for tests, but I'm not sure.

@alexcrichton
Copy link
Member

@bors: r+ ff678ea

@bors
Copy link
Contributor

bors commented Feb 28, 2015

⌛ Testing commit ff678ea with merge 8519e78...

bors added a commit that referenced this pull request Feb 28, 2015
Fixes #20978 for supported platforms (i.e. non-Android POSIX).

This uses `backtrace_pcinfo` to inspect the DWARF debug info and list the file and line pairs for given stack frame. Such pair is not unique due to the presence of inlined functions and the updated routine correctly handles this case. The code is modelled after libbacktrace's `backtrace_full` routine.

There is one known issue with this approach. Macros, when invoked, take over the current frame and shadows the file and line pair which has invoked a macro. In particular, this makes many panicking
macros a bit harder to inspect. This really is a debuginfo problem, and the backtrace routine should print them correctly with a correct debuginfo.

Some example trace:

```
thread '<main>' panicked at 'explicit panic', /home/arachneng/Works/git/rust/src/test/run-pass/backtrace-debuginfo.rs:74
stack backtrace:
   1:         0xd964702f - sys::backtrace::write::h32d93fffb64131b2yxC
   2:         0xd9670202 - panicking::on_panic::h3a4fcb37b873aefeooM
   3:         0xd95b396a - rt::unwind::begin_unwind_inner::h576b3df5f626902dJ2L
   4:         0xd9eb88df - rt::unwind::begin_unwind::h16852273847167740350
   5:         0xd9eb8afb - aux::callback::h15056955655605709172
                        at /home/arachneng/Works/git/rust/<std macros>:3
                        at src/test/run-pass/backtrace-debuginfo-aux.rs:15
   6:         0xd9eb8caa - outer::h2cf96412459fceb6ema
                        at src/test/run-pass/backtrace-debuginfo.rs:73
                        at src/test/run-pass/backtrace-debuginfo.rs:88
   7:         0xd9ebab24 - main::h3f701287441442edasa
                        at src/test/run-pass/backtrace-debuginfo.rs:134
   8:         0xd96daba8 - rust_try_inner
   9:         0xd96dab95 - rust_try
  10:         0xd9671af4 - rt::lang_start::h7da0de9529b4c394liM
  11:         0xd8f3aec4 - __libc_start_main
  12:         0xd9eb8148 - <unknown>
  13:         0xffffffff - <unknown>
```
@bors bors merged commit ff678ea into rust-lang:master Feb 28, 2015
Manishearth added a commit to Manishearth/rust that referenced this pull request Mar 3, 2015
…excrichton

 aarch64-linux-android build has been broken since rust-lang#22839.
Aarch64 android has _Unwind_GetIPInfo, so re-define this only for arm32 android.
r? @alexcrichton
@nikomatsakis
Copy link
Contributor

This is an exciting development!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Include line numbers in backtraces
9 participants