Slowdown in loading packages on master

[KristofferC]

pkg> st GR_jll
...
  [d2c73de3] GR_jll v0.59.0+0

1.7 branch:

julia> t = time(); using GR_jll; time() - t
0.0660698413848877

julia> VERSION
v"1.7.0-rc1.34"

master:

julia> t = time(); using GR_jll; time() - t
2.45320200920105

julia> VERSION
v"1.8.0-DEV.543"

Profiling shows a lot of time in LLVM and inserting backedges. I am wondering if something with the specialization and no inference that the Jlls use broke (https://github.com/JuliaPackaging/JLLWrappers.jl/blob/dd045e0576ddf834754100af4cc4829b236ae801/src/toplevel_generators.jl#L55).

[maleadt]

Bisect blaims #42128:

5405994f2c5a2a91813dccd203e8f07f72b07521 is the first bad commit
commit 5405994f2c5a2a91813dccd203e8f07f72b07521
Author: Tim Holy <tim.holy@gmail.com>
Date:   Thu Sep 9 19:09:25 2021 -0500

    Add a `@compile` directive to disable interpreter (#42128)
    
    We currently use a `while false; end` hack to disable to interpreter,
    and this is getting more widely used outside of base. Unfortunately,
    improvements to the interpreter that would allow us to interpret loops
    would defeat the intention. This allows developers to annotate blocks
    with `@compile` to specify that they want to force the compiler to run
    on this block.

 base/expr.jl   |  7 +++++++
 base/timing.jl | 10 +++++-----
 src/toplevel.c | 12 ++++++++----
 3 files changed, 20 insertions(+), 9 deletions(-)
bisect run success

[KristofferC]

#41914 (comment) also identified that commit as a slowdown to Plots but then we just chalked it up as it had something to do with @time now being compiled. But I specifically didn't use that here. So perhaps there is something more sinister going on.

[aviatesk]

I also confirmed there seems to be a regression. Will try to bisect.

[KristofferC]

#42373 (comment) already bisected?

[aviatesk]

I'm wondering @maleadt used @timed in bisect script ? I'm not sure why 5405994 can be a direct cause of this regression.

[KristofferC]

My guess is that there is some mixup with how compile_sym is used. Remember it was introduced in #37041 and is exactly what all the jll packages use. And then it got given an additional meaning in 5405994.

So, maybe the issue is something along the line of all methods from jll packages that have e.g. a compile=min annotation (all in the module), now counts as having a meta with compile and thus gets forced to be compiled?

This one sets it on the module, but that shouldn't influence the methods within I think?

julia/base/experimental.jl

Line 149 in 53aa65a

push!(opts.args, Expr(:meta, :compile, a))

[timholy]

Ugh. First couple of things I poked at did not reveal the problem. I will try to look this weekend.

[staticfloat]

I can confirm that removing the @compiler_options invocation completely in JLLWrappers has no effect on julia-master; meaning that it looks like it has been completely subverted. So I think it's a good bet that Kristoffer is right!

[maleadt]

I'm wondering @maleadt used @timed in bisect script ? I'm not sure why 5405994 can be a direct cause of this regression.

No. I used the follownig bisect script:

using Pkg

Pkg.activate(; temp=true)
Pkg.add("GR_jll")

t = time()
using GR_jll
@show elapsed = time() - t
if elapsed > 2
    exit(1)
else
    exit(0)
end

... and confirmed manually that the commit regressed the elapsed time from 0.5 to 2.5s or so.