Closed fonsp closed 1 year ago
KristofferC
commented
1 year ago I would assume that means there is some bug in our precompile stale check logic. Maybe https://github.com/JuliaLang/Pkg.jl/pull/3308 is finding some false positives..? Annoying that this is so hard to repro.
IanButterworth
commented
1 year ago Seems like it. Perhaps we need to add more logs to that stale check akin to what JULIA_DEBUG=loading would show.
It happens before the pretty printing starts, so it wouldn't be messy
KristofferC
commented
1 year ago Best would be if we could extract the staleness logic from Base into its own function and then we can directly call that one. Now there is some duplication with a risk of divergence.
fonsp
commented
1 year ago I noticed that the same issue also happens a lot with OpenSSL.jl (a long chain of packages is precompiled again, starting with OpenSSL).
With JULIA_DEBUG="loading", I also see that the cache is missed for OpenSSL_jll when calling import Pluto. Perhaps this is similar to FFMPEG.jl, depending on FFMPEG_jll? (I lost the logs unfortunately... Running import Pluto today gives me 100% cache hits)
IanButterworth
commented
1 year ago We really need JULIA_DEBUG="loading" logs for this. I can't reproduce locally
fonsp
commented
1 year ago It happened again inside Pluto: I ran a notebook once, then shut it down, then started it again. This second run will just take the embedded Manifest and instantiate it, which should be fully cached, but it triggered a long precompilation.
Since it was in Pluto, the logs are split between my terminal (where Pluto is running) and the contents captured with the io kwarg to Pkg.instantiate. I had JULIA_DEBUG="loading,Pluto".
Interesting in these logs:
_jll packages are rejected, including stdlibs like LibSSH2_jll. As reason it states a mismatch in the check_bounds setting, but I have never changed this setting. (Pluto also does not change this, I verified this by running Base.JLOptions() in both the REPL (with the pluto server) and the notebook process, both have check_bounds=0.)Pkg.instantiate within the server process to instantiate the notebook env)fonsp
commented
1 year ago I found a reproducible case! This one seems to be caused by an already loaded package at a different version:
I have two environments, env1 (this is a copy of my v1.9 env), and env2 (this was an empty env where I added Plots). Available here: https://github.com/fonsp/repro3403
Each repeated instantiate call will trigger precompilation of the same 4 packages (FFMPEG, GR_jll, GR, Plots), even though this should do nothing.
https://user-images.githubusercontent.com/6933510/224839431-4d0d059b-1d24-4d18-9172-4abeb9398ea5.mov
Logs: https://github.com/fonsp/repro3403/blob/main/Julia%201.9.0-beta4%20logs.txt
Notes:
import HTTP before instantiating, but my OP happened in a fresh session, my startup.jl is empty, so these packages were not already loadedFFMPEG as dependency, nor vice versals -lhaR /.julia/compiled/v1.9/ after running these tests, available here: https://github.com/fonsp/repro3403/blob/main/file%20listing%20of%20compiled%20v1.9.txthttps://user-images.githubusercontent.com/6933510/224839399-39ae1598-e955-416e-b868-e0e7ab6241f4.mov
Logs: https://github.com/fonsp/repro3403/blob/main/Julia%201.9.0-rc1%20logs.txt
IanButterworth
commented
1 year ago Great!
First impression is that the bug might be related to the is already loaded and incompatible rejections.
Pkg.precompile should be evaluating cache staleness irrespective of what's currently loaded. However it should also be indicating if the version it's trying to precompile is different to the one loaded, which it should print in a different color at the end.
It seems like part of the stale check is sensitive to what's loaded, and another part isn't.
A bit of a hunch though
IanButterworth
commented
1 year ago As for the check_bounds=0 vs . 1 cache rejections. Given you have a reproducer, can you run it in a clean depot. I want to rule out that it could be old caches from times you've run Pkg.test
fonsp
commented
1 year ago Here you go! https://github.com/fonsp/repro3403/blob/main/Julia%201.9.0-rc1%20clean%20depot.txt the depot path was empty before running this
fonsp
commented
1 year ago Awesome! This PR also fixed the OP because it was caused by one of the stdlibs that is loaded by default, right? Either Mmap or UUIDs
➜ ~ julia19b4
_
_ _ _(_)_ | Documentation: https://docs.julialang.org
(_) | (_) (_) |
_ _ _| |_ __ _ | Type "?" for help, "]?" for Pkg help.
| | | | | | |/ _` | |
| | |_| | | | (_| | | Version 1.9.0-beta4 (2023-02-07)
_/ |\__'_|_|_|\__'_| | Official https://julialang.org/ release
|__/ |
julia> values(Base.loaded_modules) .|> println
Downloads
Unicode
Main
REPL
NetworkOptions
OpenBLAS_jll
Serialization
libblastrampoline_jll
Profile
UUIDs
Logging
LinearAlgebra
Random
Printf
ArgTools
SparseArrays
Base64
Markdown
CompilerSupportLibraries_jll
MozillaCACerts_jll
Distributed
LibCURL_jll
TOML
Core
CRC32c
LazyArtifacts
Tar
LibGit2
Mmap
Test
Sockets
Future
nghttp2_jll
SharedArrays
Libdl
SHA
Pkg
FileWatching
Artifacts
Dates
InteractiveUtils
p7zip_jll
LibCURL
Base
I was investigating an issue where adding
Randomto an environment withCSV Dates DataFrames CairoMakie GLM StatsBaseinstalled causes precompilation of Makie and CarioMakie to run again, taking 4 minutes. (From zulip, cc @IanButterworth @nilshg)The original report is in the context of Pluto's package manager, but I was able to reproduce this in the REPL:
In the video recording, you can see which packages are being precompiled again: TiffImages, then ImageIO, Makie, CarioMakie in sequence. This is unexpected because Random is not a dependency if TiffImages.
https://user-images.githubusercontent.com/6933510/223480290-49ca190c-5ef4-41c2-a3a4-4e2b88f49326.mov
(I did not do anything else while this was running, I just went to make some tea.)
Strangely enough, I was not able to reproduce this bug a second time after I ran
sudo rm -r ~/.julia/compiled/v1.9/.