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.