precompile: respect and report cache pidlocking

src/API.jl

@@ -10,6 +10,9 @@ import LibGit2
 import Logging
 using Serialization
 using REPL.TerminalMenus
+import FileWatching
+
+import Base: StaleCacheKey
 
 import ..depots, ..depots1, ..logdir, ..devdir, ..printpkgstyle
 import ..Operations, ..GitTools, ..Pkg, ..Registry
@@ -1053,46 +1056,6 @@ function build(ctx::Context, pkgs::Vector{PackageSpec}; verbose=false, kwargs...
     Operations.build(ctx, Set{UUID}(pkg.uuid for pkg in pkgs), verbose)
 end
 
-# should sync with the types of arguments of `Base.stale_cachefile`
-const StaleCacheKey = Tuple{Base.PkgId, UInt128, String, String}
-
-function _is_stale!(stale_cache::Dict{StaleCacheKey,Bool}, paths::Vector{String}, sourcepath::String)
-    for path_to_try in paths
-        staledeps = Base.stale_cachefile(sourcepath, path_to_try, ignore_loaded = true)
-        if staledeps === true
-            continue
-        end
-        staledeps, _ = staledeps::Tuple{Vector{Any}, Union{Nothing, String}}
-        # finish checking staledeps module graph
-        for i in 1:length(staledeps)
-            dep = staledeps[i]
-            dep isa Module && continue
-            modpath, modkey, modbuild_id = dep::Tuple{String, Base.PkgId, UInt128}
-            modpaths = Base.find_all_in_cache_path(modkey)
-            for modpath_to_try in modpaths::Vector{String}
-                stale_cache_key = (modkey, modbuild_id, modpath, modpath_to_try)::StaleCacheKey
-                if get!(() -> Base.stale_cachefile(stale_cache_key..., ignore_loaded=true) === true,
-                        stale_cache, stale_cache_key)
-                    continue
-                end
-                @goto check_next_dep
-            end
-            @goto check_next_path
-            @label check_next_dep
-        end
-        try
-            # update timestamp of precompilation file so that it is the first to be tried by code loading
-            touch(path_to_try)
-        catch ex
-            # file might be read-only and then we fail to update timestamp, which is fine
-            ex isa Base.IOError || rethrow()
-        end
-        return false
-        @label check_next_path
-    end
-    return true
-end
-
 function get_or_make_pkgspec(pkgspecs::Vector{PackageSpec}, ctx::Context, uuid)
     i = findfirst(ps -> ps.uuid == uuid, pkgspecs)
     if !isnothing(i)
@@ -1289,11 +1252,6 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
     printloop_should_exit::Bool = !fancyprint # exit print loop immediately if not fancy printing
     interrupted_or_done = Base.Event()
 
-    function color_string(cstr::String, col::Union{Int64, Symbol})
-        enable_ansi  = get(Base.text_colors, col, Base.text_colors[:default])
-        disable_ansi = get(Base.disable_text_style, col, Base.text_colors[:default])
-        return string(enable_ansi, cstr, disable_ansi)
-    end
     ansi_moveup(n::Int) = string("\e[", n, "A")
     ansi_movecol1 = "\e[1G"
     ansi_cleartoend = "\e[0J"
@@ -1317,6 +1275,7 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
 
     stderr_outputs = Dict{Base.PkgId,String}()
     taskwaiting = Set{Base.PkgId}()
+    pkgspidlocked = Dict{Base.PkgId,String}()
 
     function monitor_stderr(pkg, iob)
         try
@@ -1394,7 +1353,10 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
                                 # If not offset, on larger terminal fonts it looks odd that they all sync-up
                                 anim_char = anim_chars[(i + Int(dep.name[1])) % length(anim_chars) + 1]
                                 anim_char_colored = dep in direct_deps ? anim_char : color_string(anim_char, :light_black)
-                                waiting = if dep in taskwaiting
+                                waiting = if haskey(pkgspidlocked, dep)
+                                    who_has_lock = pkgspidlocked[dep]
+                                    color_string(" Being precompiled by another $(who_has_lock)", Base.info_color())
+                                elseif dep in taskwaiting
                                     color_string(" Waiting for background task / IO / timer. Interrupt to inspect", Base.warn_color())
                                 else
                                     ""
@@ -1426,7 +1388,7 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
     end
     ## precompilation loop
     for (pkg, deps) in depsmap
-        paths = Base.find_all_in_cache_path(pkg)
+        cachepaths = Base.find_all_in_cache_path(pkg)
         sourcepath = Base.locate_package(pkg)
         if sourcepath === nothing
             failed_deps[pkg] = "Error: Missing source file for $(pkg)"
@@ -1454,7 +1416,7 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
                 # skip stale checking and force compilation if any dep was recompiled in this session
                 any_dep_recompiled = any(map(dep->was_recompiled[dep], deps))
                 is_stale = true
-                if !circular && (queued || any_dep_recompiled || (!suspended && (is_stale = _is_stale!(stale_cache, paths, sourcepath))))
+                if !circular && (queued || any_dep_recompiled || (!suspended && (is_stale = !Base.isprecompiled(pkg; ignore_loaded=true, stale_cache, cachepaths, sourcepath))))
                     Base.acquire(parallel_limiter)
                     is_direct_dep = pkg in direct_deps
 
@@ -1476,9 +1438,13 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
                         return
                     end
                     try
-                        t = @elapsed ret = Logging.with_logger(Logging.NullLogger()) do
-                            # capture stderr, send stdout to devnull, don't skip loaded modules
-                            Base.compilecache(pkg, sourcepath, iob, devnull, false)
+                        # allows processes to wait if another process is precompiling a given package to
+                        # a functionally identical package cache (except for preferences, which may differ)
+                        t = @elapsed ret = maybe_cachefile_lock(io, print_lock, fancyprint, pkg, pkgspidlocked) do
+                            Logging.with_logger(Logging.NullLogger()) do
+                                # capture stderr, send stdout to devnull, don't skip loaded modules
+                                Base.compilecache(pkg, sourcepath, iob, devnull, false)
+                            end
                         end
                         t_str = timing ? string(lpad(round(t * 1e3, digits = 1), 9), " ms") : ""
                         if ret isa Base.PrecompilableError
@@ -1615,6 +1581,39 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
     nothing
 end
 
+function color_string(cstr::String, col::Union{Int64, Symbol})
+    enable_ansi  = get(Base.text_colors, col, Base.text_colors[:default])
+    disable_ansi = get(Base.disable_text_style, col, Base.text_colors[:default])
+    return string(enable_ansi, cstr, disable_ansi)
+end
+
+function maybe_cachefile_lock(f, io::IO, print_lock::ReentrantLock, fancyprint::Bool, pkg::Base.PkgId, pkgspidlocked::Dict{Base.PkgId,String})
+    pidfile = Base.compilecache_pidfile_path(pkg)
+    cachefile = FileWatching.trymkpidlock(f, pidfile; stale_age=300) # match stale_age in loading.jl
+    if cachefile === false
+        pid, hostname, age = FileWatching.Pidfile.parse_pidfile(pidfile)
+        pkgspidlocked[pkg] = if isempty(hostname) || hostname == gethostname()
+            "process (pid: $pid)"
+        else
+            "machine (hostname: $hostname, pid: $pid)"
+        end
+        !fancyprint && lock(print_lock) do
+            println(io, "    ", pkg.name, color_string(" Being precompiled by another $(pkgspidlocked[pkg])", Base.info_color()))
+        end
+        # wait until the lock is available
+        FileWatching.mkpidlock(pidfile; stale_age=300) do # match stale_age in loading.jl
+            # double-check in case the other process crashed or the lock expired
+            if Base.isprecompiled(pkg; ignore_loaded=true) # don't use caches for this as the env state will have changed
+                return nothing # returning nothing indicates a process waited for another
+            else
+                delete!(pkgspidlocked, pkg)
+                return f() # precompile
+            end
+        end
+    end
+    return cachefile
+end
+
 const pkgs_precompile_suspended = PackageSpec[] # packages that shouldn't be retried during autoprecomp
 const pkgs_precompile_pending = PackageSpec[] # packages that need to be retried after restart
 function save_precompile_state()

test/api.jl

@@ -128,6 +128,13 @@ end
                 sleep(2)
                 end""")
             end
+            Pkg.generate("SlowPrecompile")
+            open(joinpath("SlowPrecompile","src","SlowPrecompile.jl"), "w") do io
+                write(io, """
+                module SlowPrecompile
+                sleep(10)
+                end""")
+            end
         end
         Pkg.develop(Pkg.PackageSpec(path="packages/Dep1"))
 
@@ -245,6 +252,28 @@ end
             @test occursin("Precompiling", str)
             @test occursin("Waiting for background task / IO / timer.", str)
         end
+
+        @testset "pidlocked precompile" begin
+            proj = joinpath(pwd(), "packages", "SlowPrecompile")
+            cmd = setenv(`$(Base.julia_cmd()) --color=no --startup-file=no --project="$(pkgdir(Pkg))" -e "
+                using Pkg
+                Pkg.activate(\"$(escape_string(proj))\")
+                Pkg.precompile()
+            "`,
+                    "JULIA_PKG_PRECOMPILE_AUTO" => "0")
+            iob1 = IOBuffer()
+            iob2 = IOBuffer()
+            Base.Experimental.@sync begin
+                @async run(pipeline(cmd, stderr=iob1, stdout=devnull))
+                @async run(pipeline(cmd, stderr=iob2, stdout=devnull))
+            end
+            s1 = String(take!(iob1))
+            s2 = String(take!(iob2))
+            @test occursin("Precompiling", s1)
+            @test occursin("Precompiling", s2)
+            @test any(contains("Being precompiled by another process (pid: "), (s1, s2))
+        end
+
     end end
     # ignoring circular deps, to avoid deadlock
     isolate() do; cd_tempdir() do tmp