Repeated Precompilation in 1.9rc2

hexaeder · April 19, 2023, 12:11pm

Using 1.9-rc2 in noticed, that quite often precompilation repeats even though there is no apparent reason for that. What I observe in my day to day usage:

start Julia (Revise and Test is loaded in startup)
activate environment
trigger ] precompile, precompiles stuff
close julia
start julia again and activate same environment
trigger ] precompile → precompiles some subset of the environment again

This seem somewhat erratic, sometimes I don’t need to precompile again, sometimes its precompiling a different subset of the environment.

I think this is due to some interaction with my global env and the stuff I am using in the startup.jl. For me a reproducible example to “set up” this problem is:

$ rm -r .julia/compiled
$ rm -r tmpenv
$ mkdir tmpenv
$ julia --startup-file=no
(@v1.9) pkg> activate tmpenv
  Activating new project at `~/tmpenv`

(tmpenv) pkg> add Makie, GLMakie, CSV
Precompiling environment...
  211 dependencies successfully precompiled in 144 seconds

julia> @time using Makie
  5.128032 seconds (7.62 M allocations: 515.051 MiB, 2.76% gc time, 0.63% compilation time)
# eveything as expected

Next I try again with my startup file and really strange stuff happens

$ julia
[ Info: Precompiling Revise [295af30f-e4ad-537b-8983-00126c2a3abe]
# Revise and Test loaded

(@v1.9) pkg> activate tmpenv
  Activating project at `~/tmpenv`

(tmpenv) pkg> precompile
# no output, Julia thinks its ready! nice!

but then, if i try to actually use a Package it does some precompiling (not in parallel unfortunate)

julia> @time using Makie
[ Info: Precompiling Makie [ee78f7c6-11fb-53f2-987a-cfe4a2b5a57a]
[ Info: Precompiling DistributionsChainRulesCoreExt [6db1f127-056a-568b-bd49-ae61d42389fa]
 77.489913 seconds (7.75 M allocations: 524.765 MiB, 0.22% gc time, 0.08% compilation time: 14% of which was recompilation)

Then, still in the same session, I trigger ] precompile again, I get a lot of precompilation and even some warnings

(tmpenv) pkg> precompile
Precompiling environment...
  ✓ ImageIO
  ✓ Makie
  7 dependencies successfully precompiled in 124 seconds. 204 already precompiled.
  2 dependencies precompiled but different versions are currently loaded. Restart julia to access the new versions
  1 dependency had warnings during precompilation:
┌ ShaderAbstractions [65257c39-d410-5151-9873-9b3e5be5013e]
│  ┌ Warning: The call to compilecache failed to create a usable precompiled cache file for StructArrays [09ab397b-f2b6-538f-b94a-2f83cf4a842a]
│  │   exception = Required dependency Tables [bd369af6-aec1-5ad0-b16a-f7cc5008161c] failed to load from a cache file.
│  └ @ Base loading.jl:1785
│  ┌ Warning: Module StructArrays with build ID ffffffff-ffff-ffff-000a-64231126fe01 is missing from the cache.
│  │ This may mean StructArrays [09ab397b-f2b6-538f-b94a-2f83cf4a842a] does not support precompilation but is imported by a module that does.
│  └ @ Base loading.jl:1760
└

Whats happening there? How to deal with this? I’d really like to not recompile so much because it just takes a long time…

julia> versioninfo()
Julia Version 1.9.0-rc2
Commit 72aec423c2a (2023-04-01 10:41 UTC)
Platform Info:
  OS: macOS (arm64-apple-darwin21.3.0)
  CPU: 8 × Apple M1
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-14.0.6 (ORCJIT, apple-m1)
  Threads: 4 on 4 virtual cores
Environment:
  JULIA_NUM_THREADS = 4

lmiq · April 19, 2023, 12:23pm

Why you are starting here without the startup file? The second time you started Julia you did it with the startup file. Then, the Revise and Test packages are loaded, and that can cause invalidations triggering precompilation of the environment packages again. It is less likely to get recompilation if you start Julia always with the same set of packages loaded.

hexaeder · April 19, 2023, 12:27pm

In practice, I use my startup.jl allways. Quite often, I get the behavior described at the top (repeated precompilation). But its not really reproducible for me. I included the example with the change between no startupt and startup to show that there is really something strange going in in the logic (first precompile call does nothing, second precompile call does something, shows warnings and so on).

EDIT: just tried it a few times in a row and all of the sudden i get something like that:

(tmpenv) pkg> precompile
Precompiling environment...
  13 dependencies successfully precompiled in 97 seconds. 203 already precompiled.

julia> @time using Makie
[ Info: Precompiling Makie [ee78f7c6-11fb-53f2-987a-cfe4a2b5a57a]
[ Info: Precompiling DistributionsChainRulesCoreExt [6db1f127-056a-568b-bd49-ae61d42389fa]
 77.962825 seconds (7.78 M allocations: 527.436 MiB, 0.26% gc time, 0.11% compilation time: 15% of which was recompilation)

so first a repeated precompilation of a precompiled env followed by another recompile upon using?

lmiq · April 19, 2023, 12:34pm

I cannot help with those specific warnings. But a possible reason for recompilation is any update of a package that is loaded on startup or from the default or any other shared environment (this is the greatest gotcha, I think). For example, if you have BenchmarkTools installed in the default environment and happen to load it with using in your environment, that may cause other packages in your environment to recompile.

To completely avoid those unexpected results, try keeping the default shared environment completely clean as well. (Not that I do that, but in principle with a clean default environment and not having anything in the startup file, precompilation should never happen again unless you install or update a new a package in your environment, or define a function that causes invalidations to the loaded packages).

vchuravy · April 19, 2023, 2:29pm

Does this reproduce reliably? Can you set JULIA_DEBUG=loading as an environment variable?

That should give us at least a hint for why we decided to recompile.

  7 dependencies successfully precompiled in 124 seconds. 204 already precompiled.
  2 dependencies precompiled but different versions are currently loaded. Restart julia to access the new versions
  1 dependency had warnings during precompilation:

This is suspicious… It means we activated and loaded versions from an environment before switching to the tempenv. What happens if you do julia --project=tmpenv directly?

hexaeder · April 20, 2023, 8:14am

Okay I managed to collect some logs. Unfortunately only after I enabled my normal startup.jl again which is using several packages (which makes stuff complicated as I understand). The first set of logs contains the following procedure:

load Julia with different startup (I reenabled BenchmarkTools.jl and also AbbriviatedStackTraces.jl which is suspect to be problematic in that scenario)
]precompile (does nothing)
using ... (does some precompiling)
]precompile (does something now including warnings).

EDIT: I reduced my startup file to only using Revise, deleted all compile caches and started over. Same problems

Here are the logs on those commands:
https://gist.githubusercontent.com/hexaeder/f441a1f7cb9fbb4e43feca3936731683/raw/07c11dcfb6e44bb47c81778213358d3beb032efc/load_with_changed_startup

I was then able to start Julia again multiple times without need for repeated precompiling (no output on ]precompile and no precompile logs on using, so I gave up on the testing. However, its the next morning now and I am not able to reuse the compile cache anymore. Whenever I activate the environment and triggger ] precompile it precompiles 10 packages with the following logs:

https://gist.githubusercontent.com/hexaeder/f441a1f7cb9fbb4e43feca3936731683/raw/92394d16bd2f97167e8a8ffdade3d1c15a995063/repated_precomile_after_some_time

After this,while still in the same session, I get precompile logs again whenever I am using some package. Those logs look like this:

https://gist.githubusercontent.com/hexaeder/f441a1f7cb9fbb4e43feca3936731683/raw/92394d16bd2f97167e8a8ffdade3d1c15a995063/using_in_broken_env

This state is now fully reproducible, I would probably need to delete .julia/compiled to make it work again. I totally get that indirectly using some lower level dependencies such as DataStructures at a different version in the startup.jl is problematic, but i also think it is quite common for a lot of workflows.

vchuravy · April 20, 2023, 1:51pm

Yeah I don’t have a good answer here…

We can only load one version of a package and so startup.jl loading one version than activating a different environment loading a different version is undefined behavior.

I use a slightly different workflow where I use --project=. and I think this would help since then the global environment is second in the load path and the environment versions would take precedent.