How to debug compilation time and loading time of packages?

While waiting for general improvements in compile and load times (cf. comment in Roadmap for a faster time-to-first-plot? - #199 by ChrisRackauckas), what else can we do to improve the user experience for the packages we develop?

Here is my list of ideas, along with all the problems I encounter. I’d be happy to hear your feedback and suggestions. :slight_smile:

1. Analyse what’s going wrong

I struggle to reproduce the analysis of @ChrisRackauckas https://github.com/JuliaPlots/Plots.jl/pull/2157 on a package of mine. I ran

using Profile, ProfileView
Profile.clear()
@profile using MyPackage
ProfileView.view(C=true)

but I find it really hard to read that graph. How are you getting those exact information on how long it takes to load what part of the code?

2. Provide a manual for PackageCompiler tailored to your package

My package’s tests are basically non-existant right now:

# test/runtests.jl
using MyPackage

But having them allows me to use the simpler interface of PackageCompiler.jl’s compile_incremental:

using PackageCompiler
compile_incremental(:MyPackage)

However, the above process fails. At first because it didn’t know my package in the project PackageCompiler.jl creates, so I ]deved it into the default environment/project, but that didn’t help much:

...
[ Info: used 161 out of 161 precompile statements
┌ Info: activating new environment at ~/.julia/packages/PackageCompiler/CJQcs/packages/Project.toml.
└ @ Pkg.API /buildworker/worker/package_linux64/build/usr/share/julia/stdlib/v1.0/Pkg/src/API.jl:605
  Updating registry at `~/.julia/registries/General`
  Updating git-repo `https://github.com/JuliaRegistries/General.git`
fatal: error thrown and no exception handler available.
ErrorException("Task cannot be serialized")

...

jl_save_system_image_to_stream at /buildworker/worker/package_linux64/build/src/staticdata.c:1273
jl_create_system_image at /buildworker/worker/package_linux64/build/src/staticdata.c:1378
jl_write_compiler_output at /buildworker/worker/package_linux64/build/src/precompile.c:68
jl_atexit_hook at /buildworker/worker/package_linux64/build/src/init.c:233
main at /buildworker/worker/package_linux64/build/ui/repl.c:234
__libc_start_main at /build/glibc-LK5gWL/glibc-2.23/csu/../csu/libc-start.c:291
_start at /scratch/jschulze/julia-1.0.5/bin/julia (unknown line)
ERROR: failed process: Process(`/scratch/jschulze/julia-1.0.5/bin/julia --optimize=3 --output-o=/home/jschulze/.julia/packages/PackageCompiler/CJQcs/sysimg/sys.a -g1 --track-allocation=none --startup-file=no --code-coverage=none --history-file=yes --inline=yes --math-mode=ieee --handle-signals=yes --warn-overwrite=no --compile=yes --depwarn=yes --cpu-target=native --track-allocation=none --sysimage-native-code=yes --sysimage=/scratch/jschulze/julia-1.0.5/lib/julia/sys.so -g1 --compiled-modules=yes --optimize=2 /home/jschulze/.julia/packages/PackageCompiler/CJQcs/sysimg/run_julia_code.jl`, ProcessExited(1)) [1]                                                                                           
Stacktrace:
 [1] error(::String, ::Base.Process, ::String, ::Int64, ::String) at ./error.jl:42
 [2] pipeline_error at ./process.jl:705 [inlined]
 [3] #run#505(::Bool, ::Function, ::Cmd) at ./process.jl:663
 [4] run at ./process.jl:661 [inlined]
 [5] #run_julia#1 at /home/jschulze/.julia/packages/PackageCompiler/CJQcs/src/compiler_flags.jl:225 [inlined]
 [6] #run_julia at ./none:0 [inlined]
 [7] #compile_incremental#62(::Bool, ::Bool, ::Bool, ::Nothing, ::Function, ::String, ::String) at /home/jschulze/.julia/packages/PackageCompiler/CJQcs/src/incremental.jl:137
 [8] compile_incremental at /home/jschulze/.julia/packages/PackageCompiler/CJQcs/src/incremental.jl:134 [inlined]
 [9] #compile_incremental#63 at /home/jschulze/.julia/packages/PackageCompiler/CJQcs/src/incremental.jl:177 [inlined]
 [10] compile_incremental(::Symbol) at /home/jschulze/.julia/packages/PackageCompiler/CJQcs/src/incremental.jl:176
 [11] top-level scope at none:0

What am I missing?
Is this the wrong way?

3. Your suggestions

[to be continued]

2 Likes

I didn’t use the profile for that. The profile was to know the amount of LLVM time. As for finding the different parts, the process is described in full in the post. Leon made a way to instrument the compiler for more precise information on this though

1 Like

Check SnoopCompile.jl, as stated in the docs “SnoopCompile is designed to try to make it easy to try precompilation to see whether it produces measurable benefits.”

SnoopCompile

3 Likes

If your packages are like my packages, most of the entries are all about inserting methods into method tables (almost all the top-level calls derive from jl_insert_methods or similarly-named functions). Using the code is very different from loading the package. That’s where SnoopCompile/PackageCompiler will have biggest benefits.

I had the same problem and solved it by using dev instead of add when adding PackageCompiler (proposed here). However, I’m now having the same problem as decribed in this thread.