stack traces are broken when debug info is disabled, per design

[fredcallaway]

When passing a --sysimage argument (generated by PackageCompiler.jl), stack traces have many (at least nine) extraneous lines for REPL and Base code. In practice, this means one usually has to scroll to see the relevant part of an error message, which has a substantial negative impact on workflow.

Here is without a sysimage

julia> error()
ERROR:
Stacktrace:
 [1] error()
   @ Base ./error.jl:42
 [2] top-level scope
   @ REPL[3]:1

and with a sysimage (an "empty" one, generated with create_sysimage([], sysimage_path="17.so")

julia> error()
ERROR:
Stacktrace:
  [1] error()
    @ Base ~/lib/precompile-julia/17.so:-1
  [2] top-level scope
    @ REPL[3]:1
  [3] eval_user_input(ast::Any, backend::REPL.REPLBackend)
    @ REPL ~/lib/precompile-julia/17.so:-1
  [4] repl_backend_loop(backend::REPL.REPLBackend)
    @ REPL ~/lib/precompile-julia/17.so:-1
  [5] start_repl_backend(backend::REPL.REPLBackend, consumer::Any)
    @ REPL ~/lib/precompile-julia/17.so:-1
  [6] run_repl(repl::REPL.AbstractREPL, consumer::Any; backend_on_current_task::Bool)
    @ REPL ~/lib/precompile-julia/17.so:-1
  [7] run_repl(repl::REPL.AbstractREPL, consumer::Any)
    @ REPL ~/lib/precompile-julia/17.so:-1
  [8] (::Base.var"#930#932"{Bool, Bool, Bool})(REPL::Module)
    @ Base ~/lib/precompile-julia/17.so:-1
  [9] run_main_repl(interactive::Bool, quiet::Bool, banner::Bool, history_file::Bool, color_set::Bool)
    @ Base ~/lib/precompile-julia/17.so:-1
 [10] exec_options(opts::Base.JLOptions)
    @ Base ~/lib/precompile-julia/17.so:-1
 [11] _start()
    @ Base ~/lib/precompile-julia/17.so:-1

This example was generated with v1.7.0-rc2, but it's the same in v1.6.0.

I was planning to try to address this in Base._simplify_include_frames (context: JuliaLang/PackageCompiler.jl#517 and #41566) but I realized that it isn't specific to include. I assume there is some similar code somewhere else that usually removes the extraneous REPL and Base lines, but doesn't work with a sysimage. I couldn't find it in errorshow.jl though.

I'd like to debug/fix this, but it would help to know where to start. I scanned through errorshow.jl and couldn't find anything relevant. Maybe @c42f or @KristofferC might have an idea?

[vtjnash]

Looks like debug info was disabled, so we can't be expected to give good results when that was removed

[KristofferC]

What is PackageCompiler doing wrong that results in the debug info being disabled?

[BioTurboNick]

FWIW, the REPL-frame-scrubbing code is located in client.jl and it specifically looks for a function named eval. That appears to be absent, so it does not scrub the stacktrace.

This is something I addressed in my https://github.com/BioTurboNick/AbbreviatedStackTraces.jl package, and I believe it can be done by amending the test as follows:

function scrub_repl_backtrace(bt)
    if bt !== nothing && !(bt isa Vector{Any}) # ignore our sentinel value types
        bt = stacktrace(bt)
        # remove REPL-related frames from interactive printing
        eval_ind = findlast(frame -> !frame.from_c && frame.func === :eval, bt)
        # sysimages may drop debug info and won't have inlined frames present in the backtrace
        # in that case, `eval` may be dropped, but `eval_user_input` should be present
        eval_ind === nothing && (eval_ind = findlast(frame -> !frame.from_c && frame.func === :eval_user_input, bt))
        eval_ind === nothing || deleteat!(bt, eval_ind:length(bt))
    end
    return bt
end

[fredcallaway]

@BioTurboNick's solution works for me! I can't do a full test though because I haven't been able to build julia from source. Just reading the code, the logic seems foolproof though.

Also worth noting that AbbreviatedStackTraces already handles sysimages gracefully (I'll be putting this in my startup file!)

[fredcallaway]

Hi @vtjnash, it sounds like you don't think this should be fixed in Julia. Can you give us any hints on what PackageCompiler can do to keep debug info enabled? Or even, how can you tell that debug info is disabled?

[vtjnash]

I can tell it is disabled since it does not print any debug info. I assume you turned it off somewhere, since it doesn't look like PackageCompiler uses the -g flag anywhere, and because when I run the command above to test PackageCompiler myself I get correct stack traces with complete info.

[fredcallaway]

Gosh, I'm sorry if this is just user error, but I don't think I've used the g flag either. What information is missing in my stack trace?

I just went through the above steps again explicitly passing -g 2 (which should be more verbose than the default right?) and I get nearly exactly the same output. The only difference is that the first line of the stack trace is attributed to @ Base ./error.jl:42 rather than @ Base ~/lib/precompile-julia/17.so:-1

$ julia -g 2 --startup-file=no
julia> using PackageCompiler
julia> create_sysimage(Symbol[], sysimage_path="bare.so");
julia> exit()
$ julia -g 2 --startup-file=no --sysimage bare.so
julia> error()
ERROR:
Stacktrace:
  [1] error()
    @ Base ./error.jl:42
  [2] top-level scope
    @ REPL[1]:1
...

To be clear, when you run my example, you get a short stack trace? I've replicated this on both mac and linux so it's not super likely to be an OS thing...

[vtjnash]

Yes, the difference in the stack trace shows that it has gone from disabled to enabled. I get a short stack trace, testing my source build on linux with julia master.

[BioTurboNick]

FWIW a similar issue was reported to me from someone else using PackageCompiler, which is why my package was able to address it. So something is going on somewhere...

Like vtjnash, I don't see your issue on my Windows system with that example, with Julia 1.6.3. Also WSL with a 4-day-old master branch.

Debug info that's missing includes inlined frames (which is why eval was missing), and source file path and line information are replaced by an invalid line number (-1) and just points to the sysimage path.

[fredcallaway]

Ah, I think I cut off the stack trace in an unfortunate position. Here are a few more lines

  [1] error()
    @ Base ./error.jl:42
  [2] top-level scope
    @ REPL[1]:1
  [3] eval_user_input(ast::Any, backend::REPL.REPLBackend)
    @ REPL ~/lib/precompile-julia/bare.so:-1
  [4] repl_backend_loop(backend::REPL.REPLBackend)
    @ REPL ~/lib/precompile-julia/bare.so:-1

So, I do still have missing line numbers, even when explicitly passing -g 2 when building and using the sysimage.

However, given that neither of you can reproduce this problem, it seems like this is probably some weird idiosyncratic thing with my system (although perhaps not entirely unique to me). Given that Nick's package solves the issue for me, perhaps it's not worth putting more time into this.