Reverse stacktrace display order

[LilithHafner]

Triage mentioned this favorably a few meetings ago—here's an implementation.

• Add option to keep the old order (requested by @NHDaly)
• Fix tests
• Maybe run nanosoldier to see how bad this will be?

Here's an example of how this works

f(f0, x, args...) = x == 0 ? f0(args...) : g(f0, x, args...)
g(f0, x, args...) = f(f0, x-1, args...)
for i in 1:100
    symi = Symbol(:delay_, i)
    symim1 = Symbol(:delay_, i-1)
    @eval $symi(f, args...) = $symim1(f, args...)
end
delay_0(f, args...) = f(args...)
h(f, g, args...) = try f() catch e g(args...) end

delay_4(h, () -> delay_4(Int∘inv, 0), f, sqrt, 100, -1)

Master:

ERROR: DomainError with -1.0:
sqrt was called with a negative real argument but will only return a complex result if called with a complex argument. Try sqrt(Complex(x)).
Stacktrace:
   [1] throw_complex_domainerror(f::Symbol, x::Float64)
     @ Base.Math ./math.jl:33
   [2] sqrt
     @ Base.Math ./math.jl:686 [inlined]
   [3] sqrt(x::Int64)
     @ Base.Math ./math.jl:1579
   [4] f(f0::Function, x::Int64, args::Int64)
     @ Main ./REPL[1]:1
   [5] g(f0::Function, x::Int64, args::Int64)
     @ Main ./REPL[2]:1
--- the above 2 lines are repeated 99 more times ---
 [204] f(f0::Function, x::Int64, args::Int64)
     @ Main ./REPL[1]:1
 [205] h(::var"#10#11", ::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[5]:1
 [206] delay_0(::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[4]:1
 [207] delay_1(::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[3]:4
 [208] delay_2(::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[3]:4
 [209] delay_3(::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[3]:4
 [210] delay_4(::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[3]:4

caused by: InexactError: Int64(Inf)             <- Primary error is here
Stacktrace:
  [1] Int64
    @ Base ./float.jl:963 [inlined]
  [2] Constructor
    @ Base ./operators.jl:1056 [inlined]
  [3] call_composed
    @ Base ./operators.jl:1052 [inlined]
  [4] (::ComposedFunction{Type{Int64}, typeof(inv)})(x::Int64)
    @ Base ./operators.jl:1049
  [5] delay_0(f::Function, args::Int64)
    @ Main ./REPL[4]:1
  [6] delay_1
    @ Main ./REPL[3]:4 [inlined]
  [7] delay_2
    @ Main ./REPL[3]:4 [inlined]
  [8] delay_3
    @ Main ./REPL[3]:4 [inlined]
  [9] delay_4(f::Function, args::Int64)
    @ Main ./REPL[3]:4
 [10] (::var"#10#11")()
    @ Main ./REPL[6]:1
 [11] h(::var"#10#11", ::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[5]:1
 [12] delay_0(::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[4]:1
 [13] delay_1(::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[3]:4
 [14] delay_2(::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[3]:4
 [15] delay_3(::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[3]:4
 [16] delay_4(::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[3]:4
 [17] top-level scope
    @ REPL[6]:1

PR:

Stacktrace:
 [210] top-level scope
     @ REPL[7]:1
 [209] delay_4(::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[4]:4
 [208] delay_3(::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[4]:4
 [207] delay_2(::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[4]:4
 [206] delay_1(::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[4]:4
 [205] delay_0(::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[5]:1
 [204] h(::var"#10#11", ::Function, ::Function, ::Vararg{Any})
     @ Main ./REPL[6]:1
 [203] f(f0::Function, x::Int64, args::Int64)
     @ Main ./REPL[2]:1
 [202] g(f0::Function, x::Int64, args::Int64)
     @ Main ./REPL[3]:1
--- the above 2 lines are repeated 99 more times ---
   [3] f(f0::Function, x::Int64, args::Int64)
     @ Main ./REPL[2]:1
   [2] sqrt(x::Int64)
     @ Base.Math ./math.jl:1579
   [1] sqrt
     @ Base.Math ./math.jl:686 [inlined]
ERROR: DomainError with -1.0:
sqrt was called with a negative real argument but will only return a complex result if called with a complex argument. Try sqrt(Complex(x)).

caused by: Stacktrace:
 [17] top-level scope
    @ REPL[7]:1
 [16] delay_4(::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[4]:4
 [15] delay_3(::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[4]:4
 [14] delay_2(::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[4]:4
 [13] delay_1(::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[4]:4
 [12] delay_0(::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[5]:1
 [11] h(::var"#10#11", ::Function, ::Function, ::Vararg{Any})
    @ Main ./REPL[6]:1
 [10] (::var"#10#11")()
    @ Main ./REPL[7]:1
  [9] delay_4(f::Function, args::Int64)
    @ Main ./REPL[4]:4
  [8] delay_3
    @ Main ./REPL[4]:4 [inlined]
  [7] delay_2
    @ Main ./REPL[4]:4 [inlined]
  [6] delay_1
    @ Main ./REPL[4]:4 [inlined]
  [5] delay_0(f::Function, args::Int64)
    @ Main ./REPL[5]:1
  [4] (::ComposedFunction{Type{Int64}, typeof(inv)})(x::Int64)
    @ Base ./operators.jl:1049
  [3] call_composed
    @ Base ./operators.jl:1052 [inlined]
  [2] Constructor
    @ Base ./operators.jl:1056 [inlined]
  [1] Int64
    @ Base ./float.jl:963 [inlined]
ERROR: InexactError: Int64(Inf)             <- Primary error is here

[LilithHafner]

I think the option to keep the old order should be in the IOContext (there is no need for it to be as course grained as command line args or environment variables) but open to other ideas.

This should also get triage approval before merging.

[LilithHafner]

[LilithHafner]

Triage likes this and recommends using an environment variable to override ordering (and check the ENV dict on each evaluation)

[Seelengrab]

To document the previous wish from a few triages ago for an environment variable: The reasoning is that this is much easier to control for deployment/CI than just an IOContext setting, which would then have to be special cased in code again anyway. I don't know if that was discussed this time around too.

[LilithHafner]

Okay, how bad is it going to be: @nanosoldier runtests()

[nanosoldier]

The package evaluation job you requested has completed - possible new issues were detected.
The full report is available.

[vchuravy]

I personally find this much harder to read.

For me the relevant information is close to the source of the throw, now in the REPL I have to scroll down away from my current context to see that?

The examples shown is exactly the kind of case where I think that inverted stack traces have much worse UX.

I really think the error message should be close to the code.

[iamed2]

I also find this harder to read. I find the stack traces much more useful when the most relevant content (the error and closest stack frames) is near the most recent output/logs, at the top.

[LilithHafner]

the most recent output/logs, at the top.

More recent content is at the bottom, no?

[Seelengrab]

For me the relevant information is close to the source of the throw, now in the REPL I have to scroll down away from my current context to see that?

In long stack traces, you have to scroll back up to your code (or just press "up" to get the previous input to the REPL) - and worse, in very long stacktraces, neither your code nor the error message (in the current implementation) is visible at all if you hit your terminal output buffering limit.

Either way, this is exactly why there is (going to be) a setting for this. Pretty much everyone on the triage call where this came up agreed on this being a better default, but there being some situations where the current behavior does still make sense.

[vchuravy]

I am okay with making it changeable, but I am going to protest the UX default being changed.This behavior has been the default for a long while and as the proverb goes "there is no accounting for taste".

I dislike that we keep adding environment variables and I feel like we should have a principled system for changing default behaviors for Base probably built around Preferences

[iamed2]

the most recent output/logs, at the top.

More recent content is at the bottom, no?

More precise language for what I meant: the most recent output/logs that precede the error currently appear near the top of the printed stack trace, and this is helpful for seeing as much relevant information as possible at once for diagnosis.

[bvdmitri]

I personally find it a very nice UX improvement. I find the current order is entirely useless in 100% of my usecases. I need to scroll all the time to the top, often scroll a lot, often stacktraces are so long the actual error and first items in the stacktrace don't even fit in the buffer of my terminal. That's especially painful if Julia is run as a script and then there is no way to even inspect the err variable. The error is just gone somewhere above. I know there are some packages that change the order, but it would be extremely useful to have this option in Julia itself.

The idea of a stack-trace is to show the most useful information first and give an opportunity to go deeper into the details. Julia, however, makes it necessary to scroll to actually find the useful information. Julia doesn't even show the actual error first. To see the error you need to scroll up until you find it. I cannot even just press "PageUp" button because the error isn't necessarily on the top of the terminal buffer if you have some other commands executed before

It would be very nice to merge this PR and give users an option to change the order