Precompilation: Prettier printing, opt-out auto

Project.toml

@@ -10,6 +10,7 @@ Artifacts = "56f22d72-fd6d-98f1-02f0-08ddc0907c33"
 Dates = "ade2ca70-3891-5945-98fb-dc099432e06a"
 LibGit2 = "76f85450-5226-5b5a-8eaa-529ad045b433"
 Libdl = "8f399da3-3557-5675-b5ff-fb832c97cbdb"
+Logging = "56ddb016-857b-54e1-b83d-db4d58db5568"
 Markdown = "d6f4376e-aef5-505a-96c1-9c027394607a"
 Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7"
 REPL = "3fa0cd96-eef1-5676-8a61-b3b8758bbffb"

src/API.jl

@@ -7,6 +7,7 @@ using Printf
 import Random
 using Dates
 import LibGit2
+import Logging
 
 import ..depots, ..depots1, ..logdir, ..devdir
 import ..Operations, ..GitTools, ..Pkg, ..UPDATED_REGISTRY_THIS_SESSION
@@ -922,7 +923,7 @@ function precompile(ctx::Context; internal_call::Bool=false)
         Base.PkgId(uuid, name) 
         for (name, uuid) in ctx.env.project.deps if !Base.in_sysimage(Base.PkgId(uuid, name))
     ]
-    
+
     man = Pkg.Types.read_manifest(ctx.env.manifest_file)
     deps_pair_or_nothing = Iterators.map(man) do dep
         pkg = Base.PkgId(first(dep), last(dep).name)
@@ -938,10 +939,12 @@ function precompile(ctx::Context; internal_call::Bool=false)
             for x in ctx.env.project.deps if !Base.in_sysimage(Base.PkgId(last(x), first(x)))
         ]
     end
-
+
+    started = Dict{Base.PkgId,Bool}()
     was_processed = Dict{Base.PkgId,Base.Event}()
     was_recompiled = Dict{Base.PkgId,Bool}()
     for pkgid in keys(depsmap)
+        started[pkgid] = false
         was_processed[pkgid] = Base.Event()
         was_recompiled[pkgid] = false
     end
@@ -959,9 +962,81 @@ function precompile(ctx::Context; internal_call::Bool=false)
             !internal_call && @warn "Circular dependency detected. Precompilation skipped for $pkg"
         end
     end
-
+
+    pkg_queue = Base.PkgId[]
+    failed_deps = Base.PkgId[]
+    skipped_deps = Base.PkgId[]
+
     print_lock = stdout isa Base.LibuvStream ? stdout.lock : ReentrantLock()
-    errored = false
+    first_started = Base.Event()
+    finished = false
+    should_exit = false
+
+    t_print = @async begin
+        wait(first_started)
+        isempty(pkg_queue) && return
+        lock(print_lock) do 
+            printpkgstyle(ctx, :Precompiling, "project...")
+        end
+        t = Timer(0; interval=1/10)
+        anim_chars = ["◐","◓","◑","◒"]
+        i = 1
+        last_length = 0
+        while !should_exit
+            lock(print_lock) do
+                term_size = Base.displaysize(stdout)::Tuple{Int,Int}
+                num_deps_show = term_size[1] - 2
+                pkg_queue_show = if !finished && length(pkg_queue) > num_deps_show 
+                    last(pkg_queue, num_deps_show)
+                else
+                    pkg_queue
+                end
+                str = ""
+                if i > 1
+                    str *= "\e[$(last_length)A\e[1G\e[0J"
+                end
+                for dep in pkg_queue_show
+                    finished && was_recompiled[dep] && continue
+                    name = dep in direct_deps ? "  $(dep.name)" : "  \e[38;5;244m$(dep.name)\e[0m"
+                    if dep in failed_deps
+                        str *= string(name, " \e[38;5;160m✗\e[0m\n")
+                    elseif was_recompiled[dep]
+                        str *= string(name, " \e[38;5;46m✓\e[0m\n")
+                        @async begin # keep successful deps visible for short period 
+                            sleep(1);
+                            lock(print_lock) do
+                                filter!(!isequal(dep), pkg_queue)
+                            end
+                        end
+                    elseif started[dep]
+                        anim_char = anim_chars[i % length(anim_chars) + 1]
+                        anim_char_colored = dep in direct_deps ? anim_char : "\e[38;5;244m$(anim_char)\e[0m"
+                        str *= string(name, " $anim_char_colored\n")
+                    else
+                        str *= name * "\n"
+                    end
+                end
+                last_length = length(pkg_queue_show)
+                print(str)
+            end
+            should_exit = finished
+            i += 1
+            wait(t)
+        end
+        ndeps = count(values(was_recompiled))
+        str = "$(ndeps) dependencies successfully precompiled"
+        !isempty(failed_deps) && (str *= ", $(length(failed_deps)) errored")
+        n_already = length(depsmap) - ndeps - length(failed_deps)
+        if n_already > 0  || length(skipped_deps) > 0 
+            str *= " ("
+            n_already > 0 && (str *= "$n_already already precompiled")
+            !isempty(skipped_deps) && (str *= ", $(length(skipped_deps)) skipped in auto mode due to previous errors")
+            str *= ")"
+        end
+        lock(print_lock) do
+            println(str)
+        end
+    end
     toml_c = Base.TOMLCache()
     @sync for (pkg, deps) in depsmap
         paths = Base.find_all_in_cache_path(pkg)
@@ -980,40 +1055,34 @@ function precompile(ctx::Context; internal_call::Bool=false)
 
             # skip stale checking and force compilation if any dep was recompiled in this session
             any_dep_recompiled = any(map(dep->was_recompiled[dep], deps))
-            if !errored && !Operations.precomp_suspended(pkg) && (any_dep_recompiled || _is_stale(paths, sourcepath, toml_c))
-
-                Base.acquire(parallel_limiter)
-                if errored # catch things queued before error occurred
-                    notify(was_processed[pkg])
-                    Base.release(parallel_limiter)
-                    return
-                end
-                is_direct_dep =  pkg in direct_deps
-                try
-                    lock(print_lock) do
-                        if !any(values(was_recompiled))
-                            printpkgstyle(ctx, :Precompiling, "project...")
+            if !Operations.precomp_suspended(pkg) 
+                if (any_dep_recompiled || _is_stale(paths, sourcepath, toml_c))
+                    Base.acquire(parallel_limiter)
+                    is_direct_dep = pkg in direct_deps
+                    try
+                        push!(pkg_queue, pkg)
+                        notify(first_started)
+                        started[pkg] = true
+                        Logging.with_logger(Logging.NullLogger()) do 
+                            Base.compilecache(pkg, sourcepath, toml_c, false) # don't print errors from indirect deps
                         end
-                        was_recompiled[pkg] = true # needs to be in lock to prevent async race on printing
+                        was_recompiled[pkg] = true
+                    catch err
+                        Operations.precomp_suspend!(pkg)
+                        push!(failed_deps, pkg)
+                    finally
+                        Base.release(parallel_limiter)
                     end
-                    Base.compilecache(pkg, sourcepath, toml_c, is_direct_dep) # don't print errors from indirect deps
-                catch err
-                    Operations.precomp_suspend!(pkg)
-                    if is_direct_dep # only throw errors for direct dependencies (in Project)
-                        errored = true
-                        throw(err) 
-                    else
-                        @warn "Precompilation failed for indirect dependency $(pkg)"
-                    end
-                finally
-                    notify(was_processed[pkg])
-                    Base.release(parallel_limiter)
                 end
             else
-                notify(was_processed[pkg])
+                push!(skipped_deps, pkg)
             end
+            notify(was_processed[pkg])
         end
     end
+    finished = true
+    notify(first_started) # in case of no-op
+    wait(t_print)
     nothing
 end
 

src/Operations.jl

@@ -20,10 +20,10 @@ import ...Pkg: pkg_server
 #########
 
 const pkgs_precompile_suspended = Base.PkgId[]
-precomp_suspend!(pkg) = push!(pkgs_precompile_suspended, pkg)
-precomp_unsuspend!(pkg) = filter!(!isequal(pkg), pkgs_precompile_suspended)
+precomp_suspend!(pkg::Base.PkgId) = push!(pkgs_precompile_suspended, pkg)
+precomp_unsuspend!(pkg::Base.PkgId) = filter!(!isequal(pkg), pkgs_precompile_suspended)
 precomp_unsuspend!() = empty!(pkgs_precompile_suspended)
-precomp_suspended(pkg) = pkg in pkgs_precompile_suspended
+precomp_suspended(pkg::Base.PkgId) = pkg in pkgs_precompile_suspended
 
 function find_installed(name::String, uuid::UUID, sha1::SHA1)
     slug_default = Base.version_slug(uuid, sha1)
@@ -121,6 +121,7 @@ function is_instantiated(ctx::Context)::Bool
 end
 
 function update_manifest!(ctx::Context, pkgs::Vector{PackageSpec}, deps_map)
+    manifest_before = deepcopy(ctx.env.manifest)
     manifest = ctx.env.manifest
     empty!(manifest)
     if ctx.env.pkg !== nothing
@@ -135,8 +136,10 @@ function update_manifest!(ctx::Context, pkgs::Vector{PackageSpec}, deps_map)
         else
             entry.deps = deps_map[pkg.uuid]
         end
+        if !haskey(manifest_before, pkg.uuid) || manifest_before[pkg.uuid] != entry
+            precomp_unsuspend!(Base.PkgId(pkg.uuid, pkg.name))
+        end
         ctx.env.manifest[pkg.uuid] = entry
-        precomp_unsuspend!(pkg)
     end
     prune_manifest(ctx)
 end