Hard-to-understand order of lines in backtrace

[safinaskar]

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]

@rustbot label +D-confusing

[safinaskar]

@rustbot label: +A-panic

[bjorn3]

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]

@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.