Compilation time differences with custom sysimg

I was doing some tests with custom sysimages, based on @kristoffer.carlsson’s JuliaCon video.

$ cat genimg.jl 
using PackageCompiler

create_sysimage([:Plots]; sysimage_path="")

$ cat precompile_plots.jl 
using Plots
p = plot(rand(2,2))

$ cat genimg2.jl 
using PackageCompiler

create_sysimage([:Plots]; sysimage_path="", precompile_execution_file="precompile_plots.jl")

$ julia genimg.jl
[ Info: PackageCompiler: creating system image object file, this might take a while...

$ julia genimg2.jl
[ Info: ===== Start precompile execution =====
[ Info: ===== End precompile execution =====
[ Info: PackageCompiler: creating system image object file, this might take a while...

$ ls -l sysimage_plots*
-rwxr-xr-x 1 melis users 225341080 Jun 22 14:35
-rwxr-xr-x 1 melis users 220192976 Jun 22 14:29

The differences in time to plot clearly show the sysimages at work:

$ julia testplot.jl 
  8.225244 seconds (10.30 M allocations: 601.803 MiB, 1.68% gc time, 16.18% compilation time)

$ julia testplot.jl 
  5.807044 seconds (8.93 M allocations: 523.475 MiB, 1.51% gc time, 59.42% compilation time)

$ julia testplot.jl 
  0.389013 seconds (115.43 k allocations: 7.312 MiB, 8.79% compilation time)

But I was wondering about the reported compilation times:

  • With default sysimg: 0.1618 * 8.225244s = 1.3308444792 s
  • With Plots sysimg: 0.5942 * 5.807044s = 3.4505455448 s
  • With Plots + script sysimg: 0.0879 * 0.389013s = 0.0341942427 s

How come the compilation time at runtime is longer for the Plots sysimg than for the default sysimg? Wouldn’t one expect less compilation at runtime, as most of it would have been baked into the sysimg? Checking with --trace-compile indeed seems to suggest there are mostly fewer methods to precompile at runtime, but also a few extra:

$ julia --trace=sysimage_default.trace testplot.jl
$ julia --trace=sysimage_plots.trace testplot.jl

$ diff -ur sysimage_default.trace sysimage_plots.trace | grep "^\+precompile"
+precompile(Tuple{Type{Base.Dict{Any, Plots.Subplot{T} where T<:RecipesBase.AbstractBackend}}})
+precompile(Tuple{typeof(Base.empty!), Base.Dict{Symbol, Nothing}})
+precompile(Tuple{typeof(Base.get!), Base.var"#156#157"{Base.Set{Symbol}}, Base.Dict{Symbol, Base.Set{Symbol}}, Symbol})

$ diff -ur sysimage_default.trace sysimage_plots.trace | grep "^\-precompile"
-precompile(Tuple{typeof(Base.print), Base.GenericIOBuffer{Array{UInt8, 1}}, UInt16})
-precompile(Tuple{Base.Sort.var"##sortperm#12", Base.Sort.QuickSortAlg, Function, Function, Bool, Base.Order.ForwardOrdering, typeof(Base.sortperm), Array{Float64, 1}})
-precompile(Tuple{Type{Base.Order.Perm{O, V} where V<:(AbstractArray{T, 1} where T) where O<:Base.Order.Ordering}, Base.Order.ReverseOrdering{Base.Order.ForwardOrdering}, Array{Float64, 1}})
-precompile(Tuple{typeof(Base.sort!), Array{Int64, 1}, Base.Sort.QuickSortAlg, Base.Order.Perm{Base.Order.ReverseOrdering{Base.Order.ForwardOrdering}, Array{Float64, 1}}})
-precompile(Tuple{typeof(Plots.get_linecolor), Plots.Series, Float64, Float64, Int64})
-precompile(Tuple{Plots.var"#gr_polyline##kw", NamedTuple{(:arrowside, :arrowstyle), Tuple{Symbol, Symbol}}, typeof(Plots.gr_polyline), Base.UnitRange{Int64}, Array{Float64, 1}})
-precompile(Tuple{typeof(Plots.gr_add_legend), Plots.Subplot{Plots.GRBackend}, NamedTuple{(:w, :h, :dy, :leftw, :textw, :rightw, :xoffset, :yoffset, :width_factor), Tuple{Float64, Float64, Float64, Float64, Float64, Float64, Float64, Float64, Float64}}, Array{Float64, 1}})

$ diff -ur sysimage_default.trace sysimage_plots.trace | grep "^\+precompile" | wc -l
$ diff -ur sysimage_default.trace sysimage_plots.trace | grep "^\-precompile" | wc -l

Another question: compilation of the sysimages themselves takes quite a bit of time, around 3 minutes for the Plots sysimg, around 4 minutes for Plots + script. Is there a way to get statistics on the number of compiled methods and such, to get some idea of the amount of work done?

Julia Version 1.6.1
Commit 6aaedecc44* (2021-04-23 05:59 UTC)
Platform Info:
  OS: Linux (x86_64-pc-linux-gnu)
  CPU: Intel(R) Core(TM) i5-4460  CPU @ 3.20GHz
  LIBM: libopenlibm
  LLVM: libLLVM-11.1.0 (ORCJIT, haswell)
1 Like