Where is load-time spent (with skipped precompilation)

General Usage Performance
1

In a new Julia session, I import a custom package of mine:

@time @time_imports using VoltoMapSim

which gives

[ Info: Precompiling VoltoMapSim [f713100b-c48c-421a-b480-5fcb4c589a9e]
[ Info: Skipping precompilation since __precompile__(false). Importing VoltoMapSim [f713100b-c48c-421a-b480-5fcb4c589a9e].
   1214.4 ms  Sciplotlib 58.35% compilation time
      0.5 ms  Adapt
     51.3 ms  StructArrays
     83.4 ms  Latexify 44.93% compilation time (52% recompilation)
      1.1 ms  SpikeLab
     22.1 ms  FiniteDiff 39.95% compilation time (100% recompilation)
    314.1 ms  NLSolversBase
      4.7 ms  LsqFit
Running VoltoMapSim.__init__ … done (0.0 s)
 12.414818 seconds (17.24 M allocations: 947.780 MiB, 5.01% gc time, 65.02% compilation time: 2% of which was recompilation)

There is a large pause between the last import (“4.7 ms LsqFit”)
and the package init (“Running VoltoMapSim.__init__”).
What is happening in those ~10 seconds?

Notes:

  • I do not precompile my top-level package (VoltoMapSim), because I change its code more often than I restart Julia. (Every small code-change would recompile the whole thing). I use Revise.jl instead.
  • Heavy packages are already in a custom sysimage.

An extra question: why is my custom downstream package Sciplotlib being re-compiled (“1214.4 ms Sciplotlib 58.35% compilation time”), even though I haven’t changed it?
Does this have something to do with ‘invalidations’? I do not extend any of its functions.

1 Like
2

Answering myself: I profiled with SnoopCompile:

using SnoopCompile, ProfileView
tinf = @snoopi_deep (using VoltoMapSim)
ProfileView.view(flamegraph(tinf));

Turns out, a lot of this import time is spent in compiling expanded macro calls:

  • @match (Match.jl)
  • @showprogress (ProgressMeter.jl)
  • @with_kw (Parameters.jl)
  • f"Python-style f-string {x:.2f}" (PyFormattedStrings.jl)
  • @set (Setfield.jl)

Plus:

  • ComponentVector(; myname=1, othername=2, …) (ComponentArrays.jl)
  • PyCall.setindex!(::PyDict{…}, …) (PyPlot.jl)
  • a bunch of custom Tuple and NamedTuple constructions

I’ll see if I can get rid of some of those / maybe precompile them in an upstream less-updated package.

2 Likes