# Reverse stack trace order

**URL:** <https://users.rust-lang.org/t/reverse-stack-trace-order/8786>\
**Category:** uncategorized\
**Created:** [January 7, 2017, 1:54pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786 "2017-01-07T13:54:43Z")\
**Posts on this page:** 20\
**Page:** 1

<div class="post-metadata">

**Author:** ![emilk](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/emilk/32/3486_2.png) [@emilk](https://users.rust-lang.org/u/emilk)\
**Post date:** [January 7, 2017, 1:54pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/1 "2017-01-07T13:54:43Z")

</div>

**This whole topic is a copy of [https://github.com/rust-lang/rust/issues/38873](https://github.com/rust-lang/rust/issues/38873). I think this may be a better place for what could be a very heated debate.**

A big improvement to the speed at which I can find the origin of a panic would be to reverse the order of the stack trace. At the moment the last line of the stack trace is always `main`. This means the stack trace is written deep-\>shallow, or in reverse(!) chronological order:

```rust
1: 0x10977219c - function_that_caused_the_panic
2: 0x1097738ee - foo
3: 0x109773590 - bar
4: 0x109773cf6 - baz
5: 0x109773b94 - badger
6: 0x109757669 - main

```

What you are generally looking for is the place that caused the panic (e.g. the line with an `assert!` or `panic!` on it), and so I think it would make sense to have that line _last_ so that it is easy to find. This is particularly important when the call stack is deep and it fills your terminal. [Here is a more in-depth argument for this](http://yellerapp.com/posts/2015-01-22-upside-down-stacktraces.html).

So my suggestion is: reverse the stack trace to print the stack frames in chronological order, shallow-\>deep, with `main` on the top and the stack frame with the panic at the end:

```rust
6: 0x109757669 - main
5: 0x109773b94 - badger
4: 0x109773cf6 - baz
3: 0x109773590 - bar
2: 0x1097738ee - foo
1: 0x10977219c - function_that_caused_the_panic

```

Until I read the blog linked to above I didn't realize that most languages – including Rust – was doing it "wrong", and that there was a better way. In C++ I switched the order I print stack traces about a year ago, and since then it has saved me a lot of scrolling.

---

<div class="post-metadata">

**Author:** ![akatechis](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/akatechis/32/2832_2.png) [@akatechis](https://users.rust-lang.org/u/akatechis)\
**Post date:** [January 7, 2017, 2:33pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/2 "2017-01-07T14:33:14Z")

</div>

I don't see any reasoning why a reverse stack trace would be more useful: I would say that more often than not, it's actually the middle of the stack that is more useful to diagnosing the error. Many times, some value has been set to an incorrect value, hasn't been initialized or some other issue has occured before the actual error itself, that is the root cause of the error.

Another reason why "reverse" order might be preferrable, is that it matches programmers' mental model of what a stack looks like. Usually, when people are taught about stacks, the mental picture is that of a stack of "things" that grows upwards, then things are taken off, put back on, etc.

Finally, as you mention, most languages do it this way. Turning it around, without a very good reason, would put extra barrier to entry, one that doesn't really provide much benefit.

---

<div class="post-metadata">

**Author:** ![tyoc213](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/tyoc213/32/1146_2.png) [@tyoc213](https://users.rust-lang.org/u/tyoc213)\
**Post date:** [January 7, 2017, 11:50pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/3 "2017-01-07T23:50:12Z")

</div>

Just to put something to the article about "usability" of the stack trace and watching that there is a ongoing PR to "clean" a little the output, I will add this

Taking the original example

```rust
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: ()', src/libcore/result.rs:837
stack backtrace:
   1: 0x56381e42288e - std::sys::imp::backtrace::tracing::imp::write::hfc2edb670e5eda97
   2: 0x56381e424b91 - std::panicking::default_hook::{{closure}}::hc66a547fab0b4d38
   3: 0x56381e424776 - std::panicking::default_hook::h7fba1b2f69474bdc
   4: 0x56381e424f78 - std::panicking::rust_panic_with_hook::h5d3597668c9f0035
   5: 0x56381e424e12 - std::panicking::begin_panic::hfaa38fdbc7d103f6
   6: 0x56381e424d50 - std::panicking::begin_panic_fmt::h69e0397ed8fc5362
   7: 0x56381e424cd1 - rust_begin_unwind
   8: 0x56381e46db2f - core::panicking::panic_fmt::h2ba266031787cf7b
   9: 0x56381e41cc55 - core::result::unwrap_failed::h0a78b8b4914ea99c
                               at /home/yamakaky/dev/rust/rust/src/libcore/macros.rs:29
  10: 0x56381e41c99b - <core::result::Result<T, E>>::unwrap::h2f7c43c0e2d4b7cd
                               at /home/yamakaky/dev/rust/rust/src/libcore/result.rs:737
  11: 0x56381e41ccd8 - t::main::h86d9b74d94eb7fff
                               at /tmp/pote/t.rs:2
  12: 0x56381e42f0f6 - __rust_maybe_catch_panic
  13: 0x56381e4255a8 - std::rt::lang_start::ha33d35ddc5bfd7d2
  14: 0x56381e41cd12 - main
  15: 0x7f6dc966c290 - __libc_start_main
  16: 0x56381e41c7f9 - _start

```

Can be put some like

```rust
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: ()', src/libcore/result.rs:837
stack backtrace:
1: std::sys::imp::backtrace::tracing::imp::write <- std::panicking::default_hook::{{closure}}
3: std::panicking::default_hook <- std::panicking::rust_panic_with_hook <- std::panicking::begin_panic
6: std::panicking::begin_panic_fmt <- rust_begin_unwind
8: core::panicking::panic_fmt <- core::result::unwrap_failed
                               at /home/yamakaky/dev/rust/rust/src/libcore/macros.rs:29
10: <core::result::Result<T, E>>::unwrap
                               at /home/yamakaky/dev/rust/rust/src/libcore/result.rs:737
11: t::main::h86d9b74d94eb7fff at /tmp/pote/t.rs:2 <- __rust_maybe_catch_panic
13: std::rt::lang_start::ha33d35ddc5bfd7d2 <- main <- __libc_start_main <- _start

```

Even more it could be only the list of the functions and on each change (from file or library, print the switch)

```rust
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: ()', src/libcore/result.rs:837
stack backtrace:
1: std::sys::imp::backtrace::tracing::imp::write, std::panicking::default_hook::{{closure}},
3: default_hook, rust_panic_with_hook, begin_panic, begin_panic_fmt, rust_begin_unwind,
8: core::panicking::panic_fmt, core::result::unwrap_failed at /home/yamakaky/dev/rust/rust/src/libcore/macros.rs:29
10: <core::result::Result<T, E>>::unwrap at /home/yamakaky/dev/rust/rust/src/libcore/result.rs:737
11: t::main at /tmp/pote/t.rs:2, __rust_maybe_catch_panic, std::rt::lang_start, main,__ libc_start_main, _start

```

Also I have an extra question... backtraces are for know where... but what about the data?? why it is never printed? it would be nice i the callback can be unrolled with the passed arguments to each funtion (well that can be done in a debugger, thought maybe in one or two places coul clear it up a little more, I mean normally if you are working on terminal you see the stack trace, the next step would be to maybe put a log there to print the values ;).

---

<div class="post-metadata">

**Author:** ![fweimer](https://avatars.discourse-cdn.com/v4/letter/f/d2c977/32.png) [@fweimer](https://users.rust-lang.org/u/fweimer)\
**Post date:** [January 8, 2017, 8:21am UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/4 "2017-01-08T08:21:19Z")

</div>

> [@tyoc213](#):
>
> backtraces are for know where... but what about the data?? why it is never printed?

How can you be sure that the data will not leak across a trust boundary?

---

<div class="post-metadata">

**Author:** ![fweimer](https://avatars.discourse-cdn.com/v4/letter/f/d2c977/32.png) [@fweimer](https://users.rust-lang.org/u/fweimer)\
**Post date:** [January 8, 2017, 8:23am UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/5 "2017-01-08T08:23:46Z")

</div>

> [@emilk](#):
>
> At the moment the last line of the stack trace is always main. This means the stack trace is written deep-\>shallow, or in reverse(!) chronological order

The stack trace shows where the execution would have ended up if the panic had not occurred. It does not show history, but the future. (The difference matters with tail calls.) As such, it is actually in chronological order.

---

<div class="post-metadata">

**Author:** ![jethrogb](https://avatars.discourse-cdn.com/v4/letter/j/43a26b/32.png) [@jethrogb](https://users.rust-lang.org/u/jethrogb)\
**Post date:** [January 8, 2017, 8:33am UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/6 "2017-01-08T08:33:53Z")

</div>

Every debugger I've ever used prints the most recent stack frame first. I see no reason to deviate from this in Rust.

---

<div class="post-metadata">

**Author:** ![emilk](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/emilk/32/3486_2.png) [@emilk](https://users.rust-lang.org/u/emilk)\
**Post date:** [January 8, 2017, 11:18am UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/7 "2017-01-08T11:18:15Z")

</div>

> Also I have an extra question... backtraces are for know where... but what about the data?? why it is never printed?

I love this feature. In my C++ logging library this is an opt-in feature called `ERROR_CONTEXT`: [GitHub - emilk/loguru: A lightweight C++ logging library](https://github.com/emilk/loguru#error-context). Being opt-in it does not leak unwanted (sensitive) data. It is also extremely cheap (a few cycles).

I would love to have something like this in std Rust.

---

<div class="post-metadata">

**Author:** ![Wulfklaue](https://avatars.discourse-cdn.com/v4/letter/w/ecb155/32.png) [@Wulfklaue](https://users.rust-lang.org/u/Wulfklaue)\
**Post date:** [January 8, 2017, 11:39am UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/8 "2017-01-08T11:39:38Z")

</div>

+1 on Reverse ( Lets call it "correct" ) order.

In my IDE a compile comes down to:

- Code
- Shift+F10 ( Run / Compile )
- Error in Terminal output
- Grab mouse
- Scroll and check error
- Put focus back to Editor
- Fix Error

In a reverse order, this becomes:

- Code
- Shift+F10 ( Run / Compile )
- Error in Terminal output
- Fix Error

It cuts a large part of a bad habit. Its funny how we get used to doing something ( incorrectly ), that we never question the efficiency of it. It boils down to the issue that we are used to reading on normal pages from top to bottom. But when dealing with IDEs where part of your screen is occupied with a terminal / editor etc, you fo not dedicate a full page to its output.

At minimum the reserve order needs to be a option. For any compiler error / warning.or stack trace.

---

<div class="post-metadata">

**Author:** ![tyoc213](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/tyoc213/32/1146_2.png) [@tyoc213](https://users.rust-lang.org/u/tyoc213)\
**Post date:** [January 8, 2017, 8:33pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/9 "2017-01-08T20:33:23Z")

</div>

Related features a [http://unroller.rubyforge.org/](http://unroller.rubyforge.org/) it prints all the trace or [The Mono log profiler | Mono](http://www.mono-project.com/docs/debug+profile/profile/profiler/) which can be used to something like that.

But here talking about stack traces, it would be nice if the stack trace could if opted in print the passed data, so you dont need later to "put logs traces to see what is happening" if oyu dont have a real debugger at hand.

---

<div class="post-metadata">

**Author:** ![mgeisler](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/mgeisler/32/3420_2.png) [@mgeisler](https://users.rust-lang.org/u/mgeisler)\
**Post date:** [January 9, 2017, 10:35am UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/10 "2017-01-09T10:35:34Z")

</div>

For reference, Python prints its tracebacks in the order suggested here, with the most recent call last:

```python
>>> def boom():
... 1 / 0
...
>>> def main():
... boom()
...
>>> main()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "<stdin>", line 2, in main
  File "<stdin>", line 2, in boom
ZeroDivisionError: integer division or modulo by zero

```

I've always felt this made it easy to see the relevant details quickly: the function that triggered the exception is printed right above the exception itself and this is generally right above your terminal cursor.

---

<div class="post-metadata">

**Author:** ![aidanhs](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/aidanhs/32/865_2.png) [@aidanhs](https://users.rust-lang.org/u/aidanhs)\
**Post date:** [January 9, 2017, 3:38pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/11 "2017-01-09T15:38:20Z")

</div>

I'd agree with reversing the stack order, but mainly because it seems more natural to read the stack trace downwards ("main calls x calls y") since that's the order of execution.

---

<div class="post-metadata">

**Author:** ![jethrogb](https://avatars.discourse-cdn.com/v4/letter/j/43a26b/32.png) [@jethrogb](https://users.rust-lang.org/u/jethrogb)\
**Post date:** [January 9, 2017, 5:05pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/12 "2017-01-09T17:05:45Z")

</div>

> [@aidanhs](#):
>
> ("main calls x calls y") since that's the order of execution.

Except as @fweimer already pointed out, that's not what a native stack trace represents. It represents "y returns to x returns to main".

---

<div class="post-metadata">

**Author:** ![aidanhs](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/aidanhs/32/865_2.png) [@aidanhs](https://users.rust-lang.org/u/aidanhs)\
**Post date:** [January 9, 2017, 6:24pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/13 "2017-01-09T18:24:54Z")

</div>

Well yes, but I'm not sure the distinction is meaningful until Rust gets tail calls. From the point of view of someone trying to debug, I want to know how it got to the current state which feels more natural to me by scanning down (only my opinion of course).

Tail calls aside, writing code where returns and calls are not 1-1 seems a bit niche? So it becomes a question of user-friendliness, which is fairly subjective.

---

<div class="post-metadata">

**Author:** ![cuviper](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/cuviper/32/3156_2.png) [@cuviper](https://users.rust-lang.org/u/cuviper)\
**Post date:** [January 9, 2017, 6:30pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/14 "2017-01-09T18:30:18Z")

</div>

Rust (or LLVM) can do TCO already -- it's just not guaranteed, not something you can _rely_ on for limiting stack depth. But you may already see the effect of tail calls in your backtraces.

---

<div class="post-metadata">

**Author:** ![jethrogb](https://avatars.discourse-cdn.com/v4/letter/j/43a26b/32.png) [@jethrogb](https://users.rust-lang.org/u/jethrogb)\
**Post date:** [January 9, 2017, 6:55pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/15 "2017-01-09T18:55:26Z")

</div>

> [@aidanhs](#):
>
> From the point of view of someone trying to debug, I want to know how it got to the current state

I'd also love to have the ability to know how my code got to a certain point, but this is just not something that's recorded (unless you're using very new processor features). TCO and inlining can easily mess up any idea of the past and only the future is accurately represented.

---

<div class="post-metadata">

**Author:** ![emilk](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/emilk/32/3486_2.png) [@emilk](https://users.rust-lang.org/u/emilk)\
**Post date:** [January 9, 2017, 9:50pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/16 "2017-01-09T21:50:21Z")

</div>

I feel this discussion is getting slightly out of hand. I think the most important thing is UX - not philosophy or points of views. [The 2017 roadmap](https://github.com/aturon/rfcs/blob/roadmap-2017/text/0000-roadmap-2017.md) is all about \* productivity\* with an explicit mention of "a pleasant edit-compile-debug cycle". A core part of this for many (most?), is to quickly diagnose a panic by viewing terminal output. The question is then what leads to faster diagnosing: having the deepest stack frame close to the terminal cursor, or having `main` there. I think there are some advantages to both:

- Current system (main at the bottom): scanning upwards gives us a quick idea of "what lead to the error"
- Proposed system (panic at the bottom): a quick scan tells you the function that had the problem.

I find arguments from philosophy (this system "feels more natural") or from inertia ("this is how it's always been done") to be far less powerful than arguments from experience!

Now: I have used both systems, and in my experience the proposed system is vastly superior. Has anybody else tried both systems and find the opposite to be true?

---

<div class="post-metadata">

**Author:** ![aidanhs](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/aidanhs/32/865_2.png) [@aidanhs](https://users.rust-lang.org/u/aidanhs)\
**Post date:** [January 9, 2017, 10:31pm UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/17 "2017-01-09T22:31:38Z")

</div>

> [@emilk](#):
>
> I find arguments from philosophy (this system "feels more natural") or from inertia ("this is how it's always been done") to be far less powerful than arguments from experience!

My impression is that both myself and @jethrogb are discussing this based on experience. My "seems more natural" was meant in the sense of "I find this more natural" and my interpretation of what @jethrogb says is that they appreciate the 1-1 mapping between what is displayed and what a stack trace actually means (which I do sympathise with, even if I don't value it so highly) - both of these perspectives are rooted in having used the feature.

I'd also note that personal experience is very much a point of view!

---

<div class="post-metadata">

**Author:** ![azriel91](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/azriel91/32/3110_2.png) [@azriel91](https://users.rust-lang.org/u/azriel91)\
**Post date:** [January 10, 2017, 5:56am UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/18 "2017-01-10T05:56:27Z")

</div>

I favour the current stack order — `main()` at the bottom, function that panics at the top. My rationale:

- What is more "natural":

- Scrolling - neither clearly wins

---

<div class="post-metadata">

**Author:** ![Nemo157](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/nemo157/32/3046_2.png) [@Nemo157](https://users.rust-lang.org/u/Nemo157)\
**Post date:** [January 10, 2017, 10:28am UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/19 "2017-01-10T10:28:35Z")

</div>

On this discussion of what is more "natural" (ignoring how other languages represent it for a moment), especially in reference to

> [@akatechis](#):
>
> [the current order] matches programmers' mental model of what a stack looks like. Usually, when people are taught about stacks, the mental picture is that of a stack of "things" that grows upwards, then things are taken off, put back on, etc.

I actually feel the _reversed_ order (`_start` at top) feels much more natural. I may have been taught weirdly by learning embedded development early, but I've always pictured the stack growing downwards from the top of memory space. Similarly people always talk about "exceptions bubbling up the stack", which makes no sense when the function that produced the exception/panic is sitting at the top of the stack.

> [@jethrogb](#):
>
> Every debugger I've ever used prints the most recent stack frame first.

Every debugger I've ever used either limits the number of frames it shows or has the stack trace in a separate scrollable window that starts scrolled to the top. Also, how come the command to move _down_ the backtrace in `gdb` is _`up`_.

```plaintext
(gdb) bt
#0 ki_setup ()
#1 in test_runner
#2 in main
(gdb) up
#1 in test_runner
(gdb) up
#2 in main

```

---

<div class="post-metadata">

**Author:** ![parasyte](https://sea1.discourse-cdn.com/flex019/user_avatar/users.rust-lang.org/parasyte/32/24763_2.png) [@parasyte](https://users.rust-lang.org/u/parasyte)\
**Post date:** [January 11, 2017, 3:09am UTC](https://users.rust-lang.org/t/reverse-stack-trace-order/8786/20 "2017-01-11T03:09:23Z")

</div>

So let me get this right ... The runtime stack frames cannot be treated as a historical context, and printing the optimized stack frames can suck for determining how the program entered the panic state?

Sounds like what we really need is for `panic!` to know to provide the nice Python-like stack traces for debug/non-optimized builds. Since hey, we're not optimizing out stack frames, so the stack will preserve call history. For release builds, you just have to suffer with the ugly optimized stack.

[Next page](https://users.rust-lang.org/t/reverse-stack-trace-order/8786.md?page=2)
