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.

Sign up for GitHub

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

Jump to bottom

Hard-to-understand order of lines in backtrace #99560

Open
safinaskar opened this issue Jul 21, 2022 · 4 comments
Open

Hard-to-understand order of lines in backtrace #99560

safinaskar opened this issue Jul 21, 2022 · 4 comments
Labels
A-panic Area: Panicking machinery C-bug Category: This is a bug. D-confusing Diagnostics: Confusing error or lint that should be reworked.

Comments

@safinaskar
Copy link
Contributor

safinaskar commented Jul 21, 2022 •
edited
Loading

UPD: See this comment #99560 (comment) for possibly better explanation what is wrong with current backtrace (with images!)

Rust backtraces are hard to read. Let's consider this example ( https://play.rust-lang.org/?version=stable&mode=debug&edition=2021&gist=e171ae87e31ca0f91a502a619f2070ee ):

fn g() { //1
    panic!(); //2
} //3

fn f() { //5
    g(); //6
} //7

fn main() { //9
    f(); //10
} // 11

How I would pronounce backtrace in my own words? I would say: "Entered main, then executed until we reached main.rs:10, then entered f, then got to main.rs:6 and called g...". In other words, I first pronounce name of function f, then I pronounce place where f calls g and then I pronounce g. But rust backtrace gives us instead something completely different (I tested locally):

$ rustc -g --edition 2021 oo.rs 
$ RUST_BACKTRACE=1 ./oo
thread 'main' panicked at 'explicit panic', oo.rs:2:5
stack backtrace:
   0: rust_begin_unwind
             at /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/std/src/panicking.rs:584:5
   1: core::panicking::panic_fmt
             at /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/core/src/panicking.rs:142:14
   2: core::panicking::panic
             at /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/core/src/panicking.rs:48:5
   3: oo::g
             at ./oo.rs:2:5
   4: oo::f
             at ./oo.rs:6:5
   5: oo::main
             at ./oo.rs:10:5
   6: core::ops::function::FnOnce::call_once
             at /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/core/src/ops/function.rs:248:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

So I have to dechiper this output using my eyes when reading this! I have to move my eyes to 4: oo::f, then to at ./oo.rs:6:5, then to 3: oo::g. I propose the following backtrace instead:

             /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/std/src/panicking.rs:584:5
   0: rust_begin_unwind
             /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/core/src/panicking.rs:142:14
   1: core::panicking::panic_fmt
             /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/core/src/panicking.rs:48:5
   2: core::panicking::panic
             ./oo.rs:2:5
   3: oo::g
             ./oo.rs:6:5
   4: oo::f
             ./oo.rs:10:5
   5: oo::main
             /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/core/src/ops/function.rs:248:5
   6: core::ops::function::FnOnce::call_once

Alternatively, we can simply reverse order of frames, i. e.:

   6: core::ops::function::FnOnce::call_once
             at /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/core/src/ops/function.rs:248:5
   5: oo::main
             at ./oo.rs:10:5
   4: oo::f
             at ./oo.rs:6:5
   3: oo::g
             at ./oo.rs:2:5
   2: core::panicking::panic
             at /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/core/src/panicking.rs:48:5
   1: core::panicking::panic_fmt
             at /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/core/src/panicking.rs:142:14
   0: rust_begin_unwind
             at /rustc/f8588549c3c3d45c32b404210cada01e2a45def3/library/std/src/panicking.rs:584:5

$ rustc --version --verbose
rustc 1.64.0-nightly (f8588549c 2022-07-18)
binary: rustc
commit-hash: f8588549c3c3d45c32b404210cada01e2a45def3
commit-date: 2022-07-18
host: x86_64-unknown-linux-gnu
release: 1.64.0-nightly
LLVM version: 14.0.6
@safinaskar safinaskar added the C-bug Category: This is a bug. label Jul 21, 2022
@safinaskar
Copy link
Contributor Author

@rustbot label D-confusing

@rustbot rustbot added the D-confusing Diagnostics: Confusing error or lint that should be reworked. label Feb 16, 2023
@safinaskar safinaskar mentioned this issue Oct 7, 2023
Merged
@safinaskar
Copy link
Contributor Author

@rustbot label: A-panic

@rustbot rustbot added the A-panic Area: Panicking machinery label Oct 9, 2023
@bjorn3
Copy link
Member

bjorn3 commented Oct 9, 2023

I personally read backtraces the other way around. I start from the place where the panic happened and work my way back to the main function. In other words from top to bottom. Thus order is generally the most useful for me as towards the main function there is often a lot of irrelevant functions like all the functions that form the tokio runtime, while near the panic site is likely the code that is in the end responsible for the bug.

@safinaskar
Copy link
Contributor Author

safinaskar commented Oct 9, 2023 •
edited
Loading

@bjorn3, it seems you didn't read my report properly. Current order is not "top to bottom" nor it is "bottom to top". It is simply absolutely alien. Let me explain again in simple terms (using images!). Let's assume that main calls f at line 10 and then f calls g at line 6. (10 is line of call, i. e. it is line of f(); statement.) Here is one possible good backtrace:

  • main
  • Line 10
  • f
  • Line 6
  • g

Here is another possible good backtrace:

  • g
  • Line 6
  • f
  • Line 10
  • main

Both backtraces above can be easily read by eye.
Now let me show you actual rustc backtrace:

  • f
  • Line 6
  • main
  • Line 10

Or in verbatim form:

   4: oo::f
             at ./oo.rs:6:5
   5: oo::main
             at ./oo.rs:10:5

As you can see, the backtrace is absolutely impossible to read.

Now let me show you the same using images. At these two images we see actual backtrace. Red arrows show how you should move your eyes to follow "main to packing function" path and blue show path "panic point to main". As you can see, in both cases eyes should follow very unintuitive, impossible-to-understand path.
rustc2
rustc3

@safinaskar safinaskar mentioned this issue Oct 14, 2023
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
A-panic Area: Panicking machinery C-bug Category: This is a bug. D-confusing Diagnostics: Confusing error or lint that should be reworked.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@safinaskar @bjorn3 @rustbot