Is there a way to get more type information in stack traces / what heuristics are used to decide to strip them?
Debugging chains of functions whose behavior is determined by types of the arguments is much harder when I don’t know what the types are. Constructing objects of the appropriate types to debug would be easy, if I just knew what types to construct.
Note that the original poster on Slack cannot see your response here on Discourse. Consider transcribing the appropriate answer back to Slack, or pinging the poster here on Discourse so they can follow this thread. (Original message )(More Info)
In case anyone finds this while searching for an answer:
I don’t know of a good way to get more details in the stack trace, but
If you’ve checked out the package for development, you can edit the functions to @show any information you want about the arguments and rerun the code thanks to Revise.
Use Cthulhu to descend into the function.
I’d still like to immediately have more details, but newcomers may find suggestions 2 and 3 helpful.
If you’re using an up-to-date version of Cthulhu, you can now use ascend to inspect stack traces. It takes a little time to learn how to use Cthulhu but it is wickedly powerful, and I recommend investing the time to learn it for any Julia programmer who is (1) comfortable with the language, (2) understands the basic ideas of types and at least the general concept of type-inference, and (3) wants to know how to write Julia code of high quality. (EDIT: @Elrod , didn’t realize you were the asker of the question, I know you know Cthulhu!)
There’s a demo using Cthulhu for stacktraces on Cthulhu’s REAMDE:
which I’ve mostly reproduced here to provide more insight into the stack traces themselves.
Let’s take this case:
julia> sqrt(-1)
ERROR: DomainError with -1.0:
sqrt 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
@ ./math.jl:582 [inlined]
[3] sqrt(x::Int64)
@ Base.Math ./math.jl:608
[4] top-level scope
@ REPL[1]:1
You see type information in frames 1 and 3 but not in 2. That’s because of inlining, in the compiled code the code from math.jl:582 gets “pasted in” to its caller at math.jl:608.
julia> using Cthulhu
julia> ascend(bt)
Choose a call for analysis (q to quit):
> throw_complex_domainerror(::Symbol, ::Float64) at ./math.jl:33
sqrt at ./math.jl:582 => sqrt(::Int64) at ./math.jl:608
eval(::Module, ::Any) at ./boot.jl:360
eval_user_input(::Any, ::REPL.REPLBackend) at /home/tim/src/julia-master/usr/share/julia/stdlib/v1.6/REPL/src/REPL.jl:139
repl_backend_loop(::REPL.REPLBackend) at /home/tim/src/julia-master/usr/share/julia/stdlib/v1.6/REPL/src/REPL.jl:200
start_repl_backend(::REPL.REPLBackend, ::Any) at /home/tim/src/julia-master/usr/share/julia/stdlib/v1.6/REPL/src/REPL.jl:185
#run_repl#42(::Bool, ::typeof(REPL.run_repl), ::REPL.AbstractREPL, ::Any) at /home/tim/src/julia-master/usr/share/julia/stdlib/v1.6/REPL/src/REPL.jl:317
run_repl(::REPL.AbstractREPL, ::Any) at /home/tim/src/julia-master/usr/share/julia/stdlib/v1.6/REPL/src/REPL.jl:305
(::Base.var"#878#880"{Bool, Bool, Bool})(::Module) at ./client.jl:387
v #invokelatest#2 at ./essentials.jl:707 => invokelatest at ./essentials.jl:706 => run_main_repl(::Bool, ::Bool, ::Bool, ::Bool, ::Bool) at ./client.jl:372
The inlining is reflected in the second line, the =>. This is an interactive menu; you can select a place to browse and descend in. If I select the line with lines 582/608, then I get
Choose caller of MethodInstance for throw_complex_domainerror(::Symbol, ::Float64) or proceed to typed code:
• "math.jl", sqrt: lines [582]
Browse typed code
Choosing the first opens the file in my editor. Choosing the second shows
Choose caller of MethodInstance for throw_complex_domainerror(::Symbol, ::Float64) or proceed to typed code:
"math.jl", sqrt: lines [582]
• Browse typed code
│ ─ %-1 = invoke sqrt(::Int64)::Float64
Variables
#self#::Core.Const(sqrt)
x::Int64
Body::Float64
@ math.jl:608 within `sqrt'
1 ─ %1 = Base.Math.float(x)::Float64
│ %2 = Base.Math.sqrt(%1)::Float64
└── return %2
Select a call to descend into or ↩ to ascend. [q]uit. [b]ookmark.
Toggles: [o]ptimize, [w]arn, [v]erbose printing for warntype code, [d]ebuginfo, [s]yntax highlight for Source/LLVM/Native.
Show: [S]ource code, [A]ST, [L]LVM IR, [N]ative code
Actions: [E]dit source code, [R]evise and redisplay
Advanced: dump [P]arams cache.
• %1 = float(::Int64)::Float64
%2 = sqrt(::Float64)::Float64
↩
By default ascend turns off optimization, so the inlining hasn’t taken place yet; you can descend into the call %2 and see what’s going on at line 582. Alternatively you can hit o to turn on optimization and see what the “real” code looks like, which includes inlining:
│ ─ %-1 = invoke sqrt(::Int64)::Float64
Variables
#self#::Core.Const(sqrt)
x::Int64
Body::Float64
@ math.jl:608 within `sqrt'
┌ @ float.jl:206 within `float'
│┌ @ float.jl:191 within `AbstractFloat'
││┌ @ float.jl:94 within `Float64'
1 ─│││ %1 = Base.sitofp(Float64, x)::Float64
│ └└└
│ @ math.jl:608 within `sqrt' @ math.jl:582
│ ┌ @ float.jl:371 within `<'
│ │ %2 = Base.lt_float(%1, 0.0)::Bool
│ └
└── goto #3 if not %2
2 ─ invoke Base.Math.throw_complex_domainerror(:sqrt::Symbol, %1::Float64)
└── unreachable
@ math.jl:608 within `sqrt' @ math.jl:583
3 ─ %6 = Base.Math.sqrt_llvm(%1)::Float64
└── goto #4
@ math.jl:608 within `sqrt'
4 ─ return %6
Select a call to descend into or ↩ to ascend. [q]uit. [b]ookmark.
Toggles: [o]ptimize, [w]arn, [v]erbose printing for warntype code, [d]ebuginfo, [s]yntax highlight for Source/LLVM/Native.
Show: [S]ource code, [A]ST, [L]LVM IR, [N]ative code
Actions: [E]dit source code, [R]evise and redisplay
Advanced: dump [P]arams cache.
• %4 = invoke throw_complex_domainerror(::Symbol,::Float64)::Union{}
↩
Thanks for that detailed response! I confess I’ve spent so much time descending into madness, it hadn’t occurred to me to ascend out .
(or check the docs new features)
Just ran into another case where the default printing is basically the opposite of what I want:
I know the types of the arguments to the top level function, don’t really care for the massive type dump for the _avx_! call, but from there it’s suddenly a lot more interesting.
I’ve been making a lot of changes to codegen, both on the LoopVectorization and VectorizationBase side.
So, the question is, is the dispatch chain going as I intend it to?
Yet it’s from here that suddenly all type information is missing. Of course, this also corresponds to which functions are inlined (and @mcabbott also suggested starting Julia with inlining disbaled while debugging).
This is a little unweildy, when inlining is disabled, _avx_! contains 7990 function calls! With optimizations on, most of them are no-ops, and the rest will inline into either builtins or llvmcalls.
This is less than ideal, I’d like to be able to start ascending from tdot itself, ascending up to linear_index and vstore! and ultimately _avx_! if I desire. These are both much smaller, and where the problem occured, and would save me from possibly having to wade through almost 8000 function calls. In this case, getting to _avx_! from top level is easy (but only with the help of Cthulhu, there’s no reasonable way to introspect into LoopVectorization without Cthulhu.jl!), but finding vstore!potentially isn’t.
Emphasis on “potentially” and “possibly”, because as you probably noticed if looking at the snippet of functions:
%7962 = vstore!(…,…,…,…,…,…,…,…)::Union{}
There is a vstore!(...)::Union{}, meaning I do immediately see the problem function failing to return correctly (::Union{}), and can descend to poke around.
So maybe it isn’t a big deal, but
Maybe it’d be more convenient, when picking that option, to start at "math.jl", sqrt: lines [582] so you can ascend (↩) to reach line 608, instead of starting at 602 with the ability to descend to 582?
I sympathize with the challenges. In general the problem is this: when you don’t have the argument types, there’s nothing to @descend into. So you have to start somewhere you have all the types and then work your way downward.
During the inlining phase, the call is of course made with particular argument types, but that information gets discarded in the stack traces. I wonder if you might have more luck looking at @snoopi_deep and seeing what got inferred? As long as you can isolate your error to a relatively small chain of calls. You’ll have to put the operation inside a try/catch in order to retrieve the snooping info. You’ll be interested in the final child, which should be the one terminated by the error, unless that code was inferred on a previous call.
) (More Info)
.