Ignore more frames on backtrace unwinding. #40264

Yamakaky · 2017-03-04T18:21:03Z

Correctly handles panics in threads and tests. First, the frames after the last __rust_maybe_catch_panic are discarded, then it uses a blacklist that does some more fine-tuning. Since frames after the call to __rust_maybe_catch_panic seem to be platform-independant, BAD_PREFIXES_BOTTOM could probably be cleaned a bit.

#[test]
fn b() {
    None::<()>.unwrap();
}

   0: <core::option::Option<T>>::unwrap
             at /home/yamakaky/dev/rust/rust/src/libcore/macros.rs:21
   1: t::b
             at ./t.rs:12

fn main() {
    ::std::thread::spawn(|| panic!()).join().unwrap();
}

   0: t::main::{{closure}}
             at ./t.rs:2
...
   0: <core::result::Result<T, E>>::unwrap
             at /home/yamakaky/dev/rust/rust/src/libcore/result.rs:737
   1: t::main
             at ./t.rs:2

fn main() {
    let result = ::std::panic::catch_unwind(|| {
        panic!("oh no!");
    });
    assert!(result.is_err());
}

   0: t::main::{{closure}}
             at ./t.rs:10
   1: std::panicking::try::do_call
             at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:454
   2: __rust_try
   3: __rust_maybe_catch_panic
             at /home/yamakaky/dev/rust/rust/src/libpanic_unwind/lib.rs:98
   4: std::panicking::try
             at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:433
   5: std::panic::catch_unwind
             at /home/yamakaky/dev/rust/rust/src/libstd/panic.rs:361
   6: t::main
             at ./t.rs:9

Any idea about use-cases I would have forgotten?

Correctly handles panics in threads and tests. First, the frames after `__rust_maybe_catch_panic` are discarded, then it uses a blacklist that does some more fine-tuning. Since frames after the call to `__rust_maybe_catch_panic` seem to be platform-independant, `BAD_PREFIXES_BOTTOM` could probably be cleaned a bit. Fixes rust-lang#40201

rust-highfive · 2017-03-04T18:21:18Z

r? @alexcrichton

(rust_highfive has picked a reviewer for you, use r? to override)

nagisa · 2017-03-04T19:25:33Z

First, the frames after __rust_maybe_catch_panic are discarded

This may be troublesome due to std::panic::catch_unwind which calls this function as well.

Yamakaky · 2017-03-04T19:25:55Z

Yeah, I fixed that in the latest commit ;) First post updated.

petrochenkov · 2017-03-04T19:26:43Z

Some thoughts:

~~no_std programs don't have rust_maybe_catch_panic~~ D'oh.
~~dropping frames at thread boundary doesn't seem good.~~ I was pretty sure I've seen backtraces spanning across thread boundaries with gdb and C code, but that doesn't seem to be true.
rust_maybe_catch_panic is called as a part of usual catch_unwind, e.g. at boundaries with C libraries, for example. dropping frames from C libraries doesn't seem good as well.

petrochenkov · 2017-03-04T19:28:44Z

src/libstd/sys_common/backtrace.rs

+        let mut is_rmcp = false;
+        let _ = resolve_symname(*frame, |symname| {
+            if let Some(mangled_symbol_name) = symname {
+                if mangled_symbol_name == "__rust_maybe_catch_panic" {


This needs to be mangled_symbol_name.contains("rust_maybe_catch_panic") (regardless of other concerns) because the symbol can be named panic_unwind::__rust_maybe_catch_panic or _rust_maybe_catch_panic (on Windows).

Yamakaky · 2017-03-04T19:31:26Z

The backtrace printing code is in libstd, so I think it doesn't matter?
What information would you want? The current behaviour doesn't have much: https://play.rust-lang.org/?gist=7a2efc9f3db3662f7887dc2ce89edc47&version=nightly&backtrace=1. Maybe modify the header to show the thread ID/name?
True, I didn't check that. On it.

Yamakaky · 2017-03-04T20:21:43Z

C-calling-rust works as expected, all the C frames are kept.

petrochenkov · 2017-03-04T20:24:02Z

@Yamakaky
I meant C calling Rust wrapped into catch_unwind, not just C calling Rust.

Yamakaky · 2017-03-04T20:26:11Z

Hum, right. Is it possible to detect if the current crate is a .so or .a?

Also, I'm not sure it's that bad. It's a very specific use case, and we can't clean the C backtrace so it would have the same bottom frames than RUST_BACKTRACE=full. On the other hand, we gain robustness against all the different frame setups on the supported platforms.

alexcrichton

I'm getting slightly worried about how aggressively we're trying to hide frames while yet having a desire for this to be general purpose. It looks like we're already dropping frames that are otherwise valid and this continues to be very light on tests....

alexcrichton · 2017-03-06T16:00:31Z

src/libstd/sys_common/backtrace.rs

        "_ZN4core6result13unwrap_failed",
        "ZN4core6result13unwrap_failed",
        "core::result::unwrap_failed",
+
        "rust_begin_unwind",
        "_ZN4drop",


Er was this added in the previous PR? This definitely seems like something that we shouldn't be dropping, this is just a normal function?

alexcrichton · 2017-03-06T16:01:13Z

src/libstd/sys_common/backtrace.rs

+         $LT$$LP$$RP$$GT$$GT$9call_once",
+        "ZN91_$LT$std..panic..AssertUnwindSafe$LT$F$GT$$u20$as$u20$core..ops..FnOnce\
+         $LT$$LP$$RP$$GT$$GT$9call_once",
+        "<std::panic::AssertUnwindSafe<F> as core::ops::FnOnce<()>>::call_once",


I don't think that these are correct to have because this is just the beginning of a catch_unwind, right?

So? It's std stuff, we want to remove it.

alexcrichton · 2017-03-06T16:01:28Z

src/libstd/sys_common/backtrace.rs

+
+        "_ZN42_$LT$F$u20$as$u20$test..FnBox$LT$T$GT$$GT$8call_box",
+        "ZN42_$LT$F$u20$as$u20$test..FnBox$LT$T$GT$$GT$8call_box",
+        "<F as test::FnBox<T>>::call_box",


These can happen at any time, right? Not just during tests?

Not sure, but it was fine during my tests.

Yamakaky · 2017-03-06T20:17:25Z

The frames in BAD_PREFIXES_BOTTOM/TOP are only removed if all the frames before (resp. after) were removed. Like if BAD_PREFIXES_TOP = [A, D] and the stackframe is

A
B
C
D
E

it will only remove A and not D.

I can remove the special handling of __rust_maybe_catch_panic, but it will mean BAD_PREFIXES_BOTTOM will stay big, and with platform-specific function names in libstd/sys_common. If we revert it, then maybe split between the platform-specific frames and the common ones?

alexcrichton · 2017-03-08T00:20:16Z

I don't think that's the problem though, if the stack trace as B/C/D/E we'd remove everything but E?

Yamakaky · 2017-03-08T00:36:03Z

if BAD_PREFIXES_TOP = [A, D] and the stacktrace is B/C/D/E, then it's not modified.

alexcrichton · 2017-03-09T15:39:17Z

Ok but the point still stands I think, can we be less aggressive about pruning frames? Many of these patterns are legitimate Rust functions not related to unwinding.

alexcrichton · 2017-03-09T15:40:09Z

src/libstd/sys_common/backtrace.rs

-        "__rust_maybe_catch_panic",
-        "_rust_maybe_catch_panic",
-        "__libc_start_main",
+
        "__rust_try",


I don't think that we want this to be the bottom of a frame, this is just one panic::catch_unwind and there could be many on the stack.

alexcrichton · 2017-03-09T15:40:25Z

src/libstd/sys_common/backtrace.rs

+
+        "_ZN4core3ops6FnOnce9call_once",
+        "ZN4core3ops6FnOnce9call_once",
+        "core::ops::FnOnce::call_once",


Like above, these could be any rust function, so we shouldn't prune these

I fail to find an example where this frame would be at the beginning of the frame and you would not want to remove it. There will always be the main, or a function if it's a library.

Yamakaky · 2017-03-09T19:36:24Z

Like for this backtrace (rustc without optimisations), what would you want to remove?

thread 'main' panicked at 'explicit panic', t.rs:2
stack backtrace:
   0:     0x562b31ac45f8 - std::sys::imp::backtrace::tracing::imp::unwind_backtrace::hf65740f571b3b062
                               at /home/yamakaky/dev/rust/rust/src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
   1:     0x562b31af430e - std::sys_common::backtrace::_print::h49fe0d471b73c20e
                               at /home/yamakaky/dev/rust/rust/src/libstd/sys_common/backtrace.rs:71
   2:     0x562b31af351e - std::sys_common::backtrace::print::hd65a646efeb9e475
                               at /home/yamakaky/dev/rust/rust/src/libstd/sys_common/backtrace.rs:60
   3:     0x562b31ac704e - std::panicking::default_hook::{{closure}}::h25191b25fd3a12b5
                               at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:355
   4:     0x562b31ac6b1c - std::panicking::default_hook::hf7e171cc5ec0b024
                               at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:371
   5:     0x562b31ac795c - std::panicking::rust_panic_with_hook::h01e0c787710839ce
                               at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:549
   6:     0x562b31ab5343 - std::panicking::begin_panic::h67ddf8e748228f4b
                               at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:511
   7:     0x562b31ab5852 - t::main::hf31397ea67eea730
                               at /tmp/t.rs:2
   8:     0x562b31ac7e85 - core::ops::FnOnce::call_once::h97136135af0c9b86
   9:     0x562b31ac737a - std::panicking::try::do_call::h0b3ba9923f346cc7
                               at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:454
  10:     0x562b31b08347 - __rust_try
  11:     0x562b31b08227 - __rust_maybe_catch_panic
                               at /home/yamakaky/dev/rust/rust/src/libpanic_unwind/lib.rs:98
  12:     0x562b31ac7167 - std::panicking::try::h2b94160ac273c42a
                               at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:433
  13:     0x562b31adc66a - std::panic::catch_unwind::h8c1f7b1121d92ea1
                               at /home/yamakaky/dev/rust/rust/src/libstd/panic.rs:361
  14:     0x562b31adf67e - std::rt::lang_start::h29d9bdfd34a5eab2
                               at /home/yamakaky/dev/rust/rust/src/libstd/rt.rs:57
  15:     0x562b31ab5892 - main
  16:     0x7feb00a57290 - __libc_start_main
  17:     0x562b31ab5169 - _start
  18:                0x0 - <unknown>

alexcrichton · 2017-03-10T05:30:41Z

Ideally we'd only show frame 7 in that stack trace, but I think that we need to show 7-13 because we don't know if frames 8-13 are a nested catch panic or not.

I think we can safely assume though that frames 0-6 are panicking machinery which can be ignored by default. Similarly 14-18 are safely system frames.

Yamakaky · 2017-03-10T15:38:12Z

Same question with explicit panic catch (the last example in my first post) https://gist.github.com/Yamakaky/b4c5168b8478311f66b02d47013f7cf1

alexcrichton · 2017-03-13T17:20:34Z

Yes that should only strip frames 0-6 and 14-24 ideally as those weren't written by the user. I don't know of a heuristic which will actually do that though.

Yamakaky · 2017-03-13T18:50:47Z

That's exactly what the current code does ;)

alexcrichton · 2017-03-27T21:46:27Z

src/libstd/sys_common/backtrace.rs

        "core::result::unwrap_failed",
+        "ZN4core6result13unwrap_failed",
+
        "rust_begin_unwind",
        "_ZN4drop",
        "mingw_set_invalid_parameter_handler",


This and drop above should be removed

alexcrichton · 2017-03-27T21:49:55Z

src/libstd/sys_common/backtrace.rs

+    // Frames to remove from the top of the backtrace.
+    //
+    // The raw form is used so that we don't have to demangle the symbol names.
+    // The `a::b::c` form can show up on Windows/MSVC.
    static BAD_PREFIXES_TOP: &'static [&'static str] = &[


Can we remove this array entirely? Currently rust_panic is the "canonical frame name" of the panic, and if there's a lower frame we should start from then we should just give that a canonical name instead.

What to you think about removing the frames from the core::panicking::panic* functions?

I think it's fine to strive to eliminate them, but we shouldn't have such a long list of what to filter. There should be one frame that we look for and if we find it maybe do a few calculations based off that. Substring searching is basically guarantee to go wrong in the future.

alexcrichton · 2017-04-11T19:56:30Z

@Yamakaky any update on removing the large lists of whitelists to canonical frames to prune?

Yamakaky · 2017-04-11T20:28:47Z

No, sorry. I'm near the end of the school semester so I have a lot of things to do.

alexcrichton · 2017-04-12T19:36:04Z

No worries! Thanks for the update.

arielb1 · 2017-04-18T08:51:33Z

Ping @Yamakaky - are you still working on this PR?

Yamakaky · 2017-04-18T13:45:03Z

Not now, I still have a week before the end of the semester. You can work on it if you want!

It was discovered rust-lang#40264 that this backtrace pruning logic is a little too aggressive, so while we figure how out to handle rust-lang#40264 this commit backs out the changes to prune frames. Note that other cosmetic changes, such as better path printing and such remain.

…r=petrochenkov std: Back out backtrace pruning logic It was discovered rust-lang#40264 that this backtrace pruning logic is a little too aggressive, so while we figure how out to handle rust-lang#40264 this commit backs out the changes to prune frames. Note that other cosmetic changes, such as better path printing and such remain.

bors · 2017-04-18T21:25:16Z

☔ The latest upstream changes (presumably #41373) made this pull request unmergeable. Please resolve the merge conflicts.

alexcrichton · 2017-04-27T19:39:58Z

Ok I'm going to close this for now, but please feel free to resubmit @Yamakaky if you find the time!

Yamakaky · 2017-05-07T14:43:18Z

Is it OK if I open a PR with only the bottom cleaning, and leave the top for a later PR?

alexcrichton · 2017-05-07T16:26:26Z

Certainly!

…r=alexcrichton Improve cleaning of the bottom of the backtrace Following rust-lang#40264. It only cleans the bottom of the trace (after the main). It handles correctly the normal main, tests, benchmarks and threads. I kept `skipped_before` since it will be used later for the cleaning of the top.

Improve cleaning of the bottom of the backtrace Following #40264. It only cleans the bottom of the trace (after the main). It handles correctly the normal main, tests, benchmarks and threads. I kept `skipped_before` since it will be used later for the cleaning of the top.

whitequark · 2017-06-24T11:03:20Z

@Yamakaky Do you think you can take another look on this PR? It would be really great to say goodbye to all the junk in the backtraces.

rust-highfive assigned alexcrichton Mar 4, 2017

Yamakaky added 3 commits March 4, 2017 13:34

Remove unneeded blacklisted functions

2183ef6

Fix long lines

dfaed07

Handle panic::catch_unwind.

c40ea76

petrochenkov reviewed Mar 4, 2017

View reviewed changes

Yamakaky added 3 commits March 4, 2017 14:32

Support of _rust... and panic_unwind::__rust...

33e42a3

Fix index calculation

d54caab

Hide backtrace when RUST_BACKTRACE is empty

3353a42

alexcrichton reviewed Mar 6, 2017

View reviewed changes

alexcrichton reviewed Mar 9, 2017

View reviewed changes

alexcrichton added the T-libs-api Relevant to the library API team, which will review and decide on the PR/issue. label Mar 14, 2017

alexcrichton reviewed Mar 27, 2017

View reviewed changes

Yamakaky added 2 commits March 27, 2017 17:56

Use unique backtrace start frame for all std

e1ca626

Unused frames

d72937d

Mark-Simulacrum added the S-waiting-on-author Status: This is awaiting some action (such as code changes or more information) from the author. label Apr 14, 2017

arielb1 closed this Apr 18, 2017

arielb1 reopened this Apr 18, 2017

alexcrichton mentioned this pull request Apr 18, 2017

std: Back out backtrace pruning logic #41364

Merged

CryZe mentioned this pull request Apr 27, 2017

Rust never lets you know about RUST_BACKTRACE=full #41584

Closed

alexcrichton closed this Apr 27, 2017

Yamakaky deleted the improve-backtrace branch May 7, 2017 17:40

Yamakaky mentioned this pull request May 7, 2017

Improve cleaning of the bottom of the backtrace #41815

Merged

kennytm mentioned this pull request Oct 30, 2017

Ignore panic functions in backtraces. Print inlined functions on Windows #45637

Closed

SimonSapin mentioned this pull request Jan 14, 2018

Short backtrace have regressed #47429

Closed

Ignore more frames on backtrace unwinding. #40264

Ignore more frames on backtrace unwinding. #40264

Conversation

Yamakaky commented Mar 4, 2017 • edited Loading

rust-highfive commented Mar 4, 2017

nagisa commented Mar 4, 2017

Yamakaky commented Mar 4, 2017 • edited Loading

petrochenkov commented Mar 4, 2017 • edited Loading

Choose a reason for hiding this comment

Yamakaky commented Mar 4, 2017

Yamakaky commented Mar 4, 2017

petrochenkov commented Mar 4, 2017

Yamakaky commented Mar 4, 2017 • edited Loading

alexcrichton left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Yamakaky commented Mar 6, 2017

alexcrichton commented Mar 8, 2017

Yamakaky commented Mar 8, 2017

alexcrichton commented Mar 9, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Yamakaky commented Mar 9, 2017

alexcrichton commented Mar 10, 2017

Yamakaky commented Mar 10, 2017

alexcrichton commented Mar 13, 2017

Yamakaky commented Mar 13, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

alexcrichton commented Apr 11, 2017

Yamakaky commented Apr 11, 2017

alexcrichton commented Apr 12, 2017

arielb1 commented Apr 18, 2017

Yamakaky commented Apr 18, 2017

bors commented Apr 18, 2017

alexcrichton commented Apr 27, 2017

Yamakaky commented May 7, 2017

alexcrichton commented May 7, 2017

whitequark commented Jun 24, 2017

Yamakaky commented Mar 4, 2017 •

edited

Loading

Yamakaky commented Mar 4, 2017 •

edited

Loading

petrochenkov commented Mar 4, 2017 •

edited

Loading

Yamakaky commented Mar 4, 2017 •

edited

Loading