From 4a4c4a9888b84c5523547175a8305edbfa07d4ea Mon Sep 17 00:00:00 2001 From: Jameson Nash Date: Tue, 7 Oct 2025 02:33:02 +0000 Subject: [PATCH 1/2] precompile: fail in (closer to) linear time Do not allow serial compile fallbacks, since this causes performance and output degredation when serial precompile fails. The precompilepkg driver already ensured DAG ordering, so this work is not necessary or useful to repeat. A bit of code cleanup and asking for Claude to describe the argument list as well, plus a test to start to cover any of this code functionality in CI. --- base/precompilation.jl | 92 +++++++++++++++++++++--- test/loading.jl | 4 +- test/precompile.jl | 156 +++++++++++++++++++++++++++++++++++++++++ 3 files changed, 240 insertions(+), 12 deletions(-) diff --git a/base/precompilation.jl b/base/precompilation.jl index b4ea4fe49055c..1f545ae3dd15f 100644 --- a/base/precompilation.jl +++ b/base/precompilation.jl @@ -471,6 +471,73 @@ function collect_all_deps(direct_deps, dep, alldeps=Set{Base.PkgId}()) end +""" + precompilepkgs(pkgs; kwargs...) + +Precompile packages and their dependencies, with support for parallel compilation, +progress tracking, and various compilation configurations. + +`pkgs::Union{Vector{String}, Vector{PkgId}}`: Packages to precompile. When +empty (default), precompiles all project dependencies. When specified, +precompiles only the given packages and their dependencies (unless +`manifest=true`). + +# Keyword Arguments +- `internal_call::Bool`: Indicates this is an automatic/internal precompilation call + (e.g., triggered by package loading). When `true`, errors are handled gracefully: in + interactive sessions, errors are stored in `Base.MainInclude.err` instead of throwing; + in non-interactive sessions, errors are printed but not thrown. Default: `false`. + +- `strict::Bool`: Controls error reporting scope. When `false` (default), only reports + errors for direct project dependencies. + +- `warn_loaded::Bool`: When `true` (default), checks for and warns about packages that are + precompiled but already loaded with a different version. Displays a warning that Julia + needs to be restarted to use the newly precompiled versions. + +- `timing::Bool`: When `true` (not default), displays timing information for + each package compilation, but only if compilation might have succeeded. + Disables fancy progress bar output (timing is shown in simple text mode). + +- `_from_loading::Bool`: Internal flag indicating the call originated from the + package loading system. When `true` (not default): returns early instead of + throwing when packages are not found; suppresses progress messages when not + in an interactive session; allows packages outside the current environment to + be added as serial precompilation jobs; skips LOADING_CACHE initialization; + and changes cachefile locking behavior. + +- `configs::Union{Config,Vector{Config}}`: Compilation configurations to use. Each Config + is a `Pair{Cmd, Base.CacheFlags}` specifying command flags and cache flags. When + multiple configs are provided, each package is precompiled for each configuration. + +- `io::IO`: Output stream for progress messages, warnings, and errors. Can be + redirected (e.g., to `devnull` when called from loading in non-interactive mode). + +- `fancyprint::Bool`: Controls output format. When `true`, displays an animated progress + bar with spinners. When `false`, instead enables `timing` mode. Automatically + disabled when `timing=true` or when called from loading in non-interactive mode. + +- `manifest::Bool`: Controls the scope of packages to precompile. When `false` (default), + precompiles only packages specified in `pkgs` and their dependencies. When `true`, + precompiles all packages in the manifest (workspace mode), typically used by Pkg for + workspace precompile requests. + +- `ignore_loaded::Bool`: Controls whether already-loaded packages affect cache + freshness checks. When `false` (not default), loaded package versions are considered when + determining if cache files are fresh. + +# Return +- `Vector{String}`: Paths to cache files for the requested packages. +- `Nothing`: precompilation should be skipped + +# Notes +- Packages in circular dependency cycles are skipped with a warning. +- Packages with `__precompile__(false)` are skipped if they are from loading to + avoid repeated work on every session. +- Parallel compilation is controlled by `JULIA_NUM_PRECOMPILE_TASKS` environment variable + (defaults to CPU_THREADS + 1, capped at 16, halved on Windows). +- Extensions are precompiled when all their triggers are available in the environment. +""" function precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}=String[]; internal_call::Bool=false, strict::Bool = false, @@ -745,8 +812,7 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, pkg_names = [pkg.name for pkg in project_deps] end keep = Set{Base.PkgId}() - for dep in direct_deps - dep_pkgid = first(dep) + for dep_pkgid in keys(direct_deps) if dep_pkgid.name in pkg_names push!(keep, dep_pkgid) collect_all_deps(direct_deps, dep_pkgid, keep) @@ -990,8 +1056,10 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, notify(was_processed[pkg_config]) continue end - # Heuristic for when precompilation is disabled - if occursin(r"\b__precompile__\(\s*false\s*\)", read(sourcepath, String)) + # Heuristic for when precompilation is disabled, which must not over-estimate however for any dependent + # since it will also block precompilation of all dependents + if _from_loading && single_requested_pkg && occursin(r"\b__precompile__\(\s*false\s*\)", read(sourcepath, String)) + Base.@logmsg logcalls "Disabled precompiling $(repr("text/plain", pkg)) since the text `__precompile__(false)` was found in file." notify(was_processed[pkg_config]) continue end @@ -1035,7 +1103,13 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, end # for extensions, any extension in our direct dependencies is one we have a right to load # for packages, we may load any extension (all possible triggers are accounted for above) - loadable_exts = haskey(ext_to_parent, pkg) ? filter((dep)->haskey(ext_to_parent, dep), direct_deps[pkg]) : nothing + loadable_exts = haskey(ext_to_parent, pkg) ? filter((dep)->haskey(ext_to_parent, dep), deps) : nothing + if !isempty(deps) + # if deps is empty, either it doesn't have any (so compiled-modules is + # irrelevant) or we couldn't compute them (so we actually should attempt + # serial compile, as the dependencies are not in the parallel list) + flags = `$flags --compiled-modules=strict` + end if _from_loading && pkg in requested_pkgids # loading already took the cachefile_lock and printed logmsg for its explicit requests t = @elapsed ret = begin @@ -1223,18 +1297,18 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, pluralde = n_direct_errs == 1 ? "y" : "ies" direct = strict ? "" : "direct " err_msg = "The following $n_direct_errs $(direct)dependenc$(pluralde) failed to precompile:\n$(String(take!(err_str)))" - if internal_call # aka. auto-precompilation - if isinteractive() + if internal_call # aka. decide which untested code path to run that does some unsafe behavior + if isinteractive() # XXX: this test is incorrect plural1 = length(failed_deps) == 1 ? "y" : "ies" println(io, " ", color_string("$(length(failed_deps))", Base.error_color()), " dependenc$(plural1) errored.") println(io, " For a report of the errors see `julia> err`. To retry use `pkg> precompile`") - setglobal!(Base.MainInclude, :err, PkgPrecompileError(err_msg)) + setglobal!(Base.MainInclude, :err, PkgPrecompileError(err_msg)) # XXX: this call is dangerous else # auto-precompilation shouldn't throw but if the user can't easily access the # error messages, just show them print(io, "\n", err_msg) end - else + else # XXX: crashing is wrong println(io) throw(PkgPrecompileError(err_msg)) end diff --git a/test/loading.jl b/test/loading.jl index f27451d45b328..4d2fa1728ae7f 100644 --- a/test/loading.jl +++ b/test/loading.jl @@ -1376,10 +1376,8 @@ end """) write(joinpath(foo_path, "Manifest.toml"), """ - # This file is machine-generated - editing it directly is not advised - julia_version = "1.13.0-DEV" + julia_version = "1.13.0" manifest_format = "2.0" - project_hash = "8699765aeeac181c3e5ddbaeb9371968e1f84d6b" [[deps.Foo51989]] path = "." diff --git a/test/precompile.jl b/test/precompile.jl index 2bba1fcac011e..c7ff1c49db199 100644 --- a/test/precompile.jl +++ b/test/precompile.jl @@ -2544,4 +2544,160 @@ let io = IOBuffer() @test isempty(String(take!(io))) end +# Test --compiled-modules=strict in precompilepkgs +@testset "compiled-modules=strict with dependencies" begin + mkdepottempdir() do depot + # Create three packages: one that fails to precompile, one that loads it, one that doesn't + project_path = joinpath(depot, "testenv") + mkpath(project_path) + + # Create FailPkg - a package that can't be precompiled + fail_pkg_path = joinpath(depot, "dev", "FailPkg") + mkpath(joinpath(fail_pkg_path, "src")) + write(joinpath(fail_pkg_path, "Project.toml"), + """ + name = "FailPkg" + uuid = "10000000-0000-0000-0000-000000000001" + version = "0.1.0" + """) + write(joinpath(fail_pkg_path, "src", "FailPkg.jl"), + """ + module FailPkg + print("FailPkg precompiling.\n") + error("fail") + end + """) + + # Create LoadsFailPkg - depends on and loads FailPkg (should fail with strict) + loads_pkg_path = joinpath(depot, "dev", "LoadsFailPkg") + mkpath(joinpath(loads_pkg_path, "src")) + write(joinpath(loads_pkg_path, "Project.toml"), + """ + name = "LoadsFailPkg" + uuid = "20000000-0000-0000-0000-000000000002" + version = "0.1.0" + + [deps] + FailPkg = "10000000-0000-0000-0000-000000000001" + """) + write(joinpath(loads_pkg_path, "src", "LoadsFailPkg.jl"), + """ + module LoadsFailPkg + print("LoadsFailPkg precompiling.\n") + import FailPkg + print("unreachable\n") + end + """) + + # Create DependsOnly - depends on FailPkg but doesn't load it (should succeed) + depends_pkg_path = joinpath(depot, "dev", "DependsOnly") + mkpath(joinpath(depends_pkg_path, "src")) + write(joinpath(depends_pkg_path, "Project.toml"), + """ + name = "DependsOnly" + uuid = "30000000-0000-0000-0000-000000000003" + version = "0.1.0" + + [deps] + FailPkg = "10000000-0000-0000-0000-000000000001" + """) + write(joinpath(depends_pkg_path, "src", "DependsOnly.jl"), + """ + module DependsOnly + # Has FailPkg as a dependency but doesn't load it + print("DependsOnly precompiling.\n") + end + """) + + # Create main project with all packages + write(joinpath(project_path, "Project.toml"), + """ + [deps] + LoadsFailPkg = "20000000-0000-0000-0000-000000000002" + DependsOnly = "30000000-0000-0000-0000-000000000003" + """) + write(joinpath(project_path, "Manifest.toml"), + """ + julia_version = "1.13.0" + manifest_format = "2.0" + + [[DependsOnly]] + deps = ["FailPkg"] + uuid = "30000000-0000-0000-0000-000000000003" + version = "0.1.0" + + [[FailPkg]] + uuid = "10000000-0000-0000-0000-000000000001" + version = "0.1.0" + + [[LoadsFailPkg]] + deps = ["FailPkg"] + uuid = "20000000-0000-0000-0000-000000000002" + version = "0.1.0" + + [[deps.DependsOnly]] + deps = ["FailPkg"] + path = "../dev/DependsOnly/" + uuid = "30000000-0000-0000-0000-000000000003" + version = "0.1.0" + + [[deps.FailPkg]] + path = "../dev/FailPkg/" + uuid = "10000000-0000-0000-0000-000000000001" + version = "0.1.0" + + [[deps.LoadsFailPkg]] + deps = ["FailPkg"] + path = "../dev/LoadsFailPkg/" + uuid = "20000000-0000-0000-0000-000000000002" + version = "0.1.0" + """) + + # Call precompilepkgs with output redirected to a file + LoadsFailPkg_output = joinpath(depot, "LoadsFailPkg_output.txt") + DependsOnly_output = joinpath(depot, "DependsOnly_output.txt") + original_depot_path = copy(Base.DEPOT_PATH) + old_proj = Base.active_project() + try + push!(empty!(DEPOT_PATH), depot) + Base.set_active_project(project_path) + loadsfailpkg = open(LoadsFailPkg_output, "w") do io + # set internal_call to bypass buggy code + Base.Precompilation.precompilepkgs(["LoadsFailPkg"]; io, fancyprint=true, internal_call=true) + end + @test isempty(loadsfailpkg::Vector{String}) + dependsonly = open(DependsOnly_output, "w") do io + # set internal_call to bypass buggy code + Base.Precompilation.precompilepkgs(["DependsOnly"]; io, fancyprint=true, internal_call=true) + end + @test length(dependsonly::Vector{String}) == 1 + finally + Base.set_active_project(old_proj) + append!(empty!(DEPOT_PATH), original_depot_path) + end + + output = read(LoadsFailPkg_output, String) + # LoadsFailPkg should fail because it tries to load FailPkg with --compiled-modules=strict + @test_broken count(output, "ERROR: fail") > 0 + @test_broken count(output, "ERROR: fail") == 1 + @test count("✗ FailPkg", output) > 0 + @test count("✗ LoadsFailPkg", output) > 0 + @test count("FailPkg precompiling.", output) > 0 + @test_broken count("FailPkg precompiling.", output) == 1 + @test 0 < count("LoadsFailPkg precompiling.", output) <= 2 + @test_broken count("LoadsFailPkg precompiling.", output) == 1 + @test !contains(output, "DependsOnly precompiling.") + + # DependsOnly should succeed because it doesn't actually load FailPkg + output = read(DependsOnly_output, String) + @test_broken count(output, "ERROR: fail") > 0 + @test_broken count(output, "ERROR: fail") == 1 + @test count("✗ FailPkg", output) > 0 + @test count("Precompiling DependsOnly finished.", output) == 1 + @test_broken count("FailPkg precompiling.", output) > 0 + @test_broken count("FailPkg precompiling.", output) == 1 + @test count("DependsOnly precompiling.", output) == 1 + end +end + finish_precompile_test!() From 1b89cc25e636da382dc6fd37bf0f228630226690 Mon Sep 17 00:00:00 2001 From: Jameson Nash Date: Mon, 20 Oct 2025 17:58:06 +0000 Subject: [PATCH 2/2] precompile: fix error / output printing I counted at least 4 different places where an (overlapping) subset of package IO might be printed. Now try to be slightly more careful about that: progress goes to logio (either io or devnull) while output goes to io always. Additionally, we don't return an extra copy of some output in the error message (since we already printed that). Additionally, we print all output if the requested packages failed, but we print only output from successful package if all requested packages succeeded. If a package was successful, then its output is required to be printed since it will not be regenerated in the future (we don't reprint precompile output on loading since that might be obnoxious for us to implement). If a required package is successful however, none of the failures mattered and they will be regenerated in the future when they are required, so those should be filtered out. --- base/precompilation.jl | 175 ++++++++++++++++------------- doc/src/devdocs/precompile_hang.md | 2 +- src/jl_uv.c | 2 +- test/precompile.jl | 70 +++++------- 4 files changed, 124 insertions(+), 125 deletions(-) diff --git a/base/precompilation.jl b/base/precompilation.jl index 1f545ae3dd15f..6462051b96770 100644 --- a/base/precompilation.jl +++ b/base/precompilation.jl @@ -406,7 +406,7 @@ function excluded_circular_deps_explanation(io::IOContext{IO}, ext_to_parent::Di else line = " └" * "─" ^j * " " end - hascolor = get(io, :color, false)::Bool + hascolor = get(io, :color, false)::Bool # XXX: this output does not go to `io` so this is bad to call here line = _color_string(line, :light_black, hascolor) * full_name(ext_to_parent, pkg) * "\n" cycle_str *= line end @@ -482,14 +482,17 @@ empty (default), precompiles all project dependencies. When specified, precompiles only the given packages and their dependencies (unless `manifest=true`). +!!! note + Errors will only throw when precompiling the top-level dependencies, given that + not all manifest dependencies may be loaded by the top-level dependencies on the given system. + This can be overridden to make errors in all dependencies throw by setting the kwarg `strict` to `true` + # Keyword Arguments -- `internal_call::Bool`: Indicates this is an automatic/internal precompilation call - (e.g., triggered by package loading). When `true`, errors are handled gracefully: in - interactive sessions, errors are stored in `Base.MainInclude.err` instead of throwing; - in non-interactive sessions, errors are printed but not thrown. Default: `false`. +- `internal_call::Bool`: Indicates this is an automatic precompilation call + from somewhere external (e.g. Pkg). Do not use this parameter. - `strict::Bool`: Controls error reporting scope. When `false` (default), only reports - errors for direct project dependencies. + errors for direct project dependencies. Only relevant when `manifest=true`. - `warn_loaded::Bool`: When `true` (default), checks for and warns about packages that are precompiled but already loaded with a different version. Displays a warning that Julia @@ -564,7 +567,7 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, timing::Bool, _from_loading::Bool, configs::Vector{Config}, - _io::IOContext{IO}, + io::IOContext{IO}, fancyprint::Bool, manifest::Bool, ignore_loaded::Bool) @@ -602,16 +605,18 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, # suppress precompilation progress messages when precompiling for loading packages, except during interactive sessions # or when specified by logging heuristics that explicitly require it # since the complicated IO implemented here can have somewhat disastrous consequences when happening in the background (e.g. #59599) - io = _io + logio = io logcalls = nothing - if _from_loading && !isinteractive() - io = IOContext{IO}(devnull) - fancyprint = false + if _from_loading + if !isinteractive() + logio = IOContext{IO}(devnull) + fancyprint = false + end logcalls = isinteractive() ? CoreLogging.Info : CoreLogging.Debug # sync with Base.compilecache end nconfigs = length(configs) - hascolor = get(io, :color, false)::Bool + hascolor = get(logio, :color, false)::Bool color_string(cstr::String, col::Union{Int64, Symbol}) = _color_string(cstr, col, hascolor) stale_cache = Dict{StaleCacheKey, Bool}() @@ -901,9 +906,10 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, pkg_liveprinted = Ref{Union{Nothing, PkgId}}(nothing) function monitor_std(pkg_config, pipe; single_requested_pkg=false) - pkg, config = pkg_config + local pkg, config = pkg_config try - liveprinting = false + local liveprinting = false + local thistaskwaiting = false while !eof(pipe) local str = readline(pipe, keep=true) if single_requested_pkg && (liveprinting || !isempty(str)) @@ -916,15 +922,18 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, end end write(get!(IOBuffer, std_outputs, pkg_config), str) - if !in(pkg_config, taskwaiting) && occursin("waiting for IO to finish", str) - !fancyprint && @lock print_lock begin - println(io, pkg.name, color_string(" Waiting for background task / IO / timer.", Base.warn_color())) + if thistaskwaiting + if occursin("Waiting for background task / IO / timer", str) + thistaskwaiting = true + !liveprinting && !fancyprint && @lock print_lock begin + println(io, pkg.name, color_string(str, Base.warn_color())) + end + push!(taskwaiting, pkg_config) end - push!(taskwaiting, pkg_config) - end - if !fancyprint && in(pkg_config, taskwaiting) - @lock print_lock begin - print(io, str) + else + # XXX: don't just re-enable IO for random packages without printing the context for them first + !liveprinting && !fancyprint && @lock print_lock begin + print(io, ansi_cleartoendofline, str) end end end @@ -940,10 +949,10 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, (isempty(pkg_queue) || interrupted_or_done[]) && return @lock print_lock begin if target[] !== nothing - printpkgstyle(io, :Precompiling, target[]) + printpkgstyle(logio, :Precompiling, target[]) end if fancyprint - print(io, ansi_disablecursor) + print(logio, ansi_disablecursor) end end t = Timer(0; interval=1/10) @@ -957,7 +966,7 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, n_print_rows = 0 while !printloop_should_exit[] @lock print_lock begin - term_size = displaysize(io)::Tuple{Int, Int} + term_size = displaysize(logio)::Tuple{Int, Int} num_deps_show = max(term_size[1] - 3, 2) # show at least 2 deps pkg_queue_show = if !interrupted_or_done[] && length(pkg_queue) > num_deps_show last(pkg_queue, num_deps_show) @@ -974,7 +983,7 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, # window between print cycles termwidth = (displaysize(io)::Tuple{Int,Int})[2] - 4 if !final_loop - s = sprint(io -> show_progress(io, bar; termwidth, carriagereturn=false); context=io) + s = sprint(io -> show_progress(io, bar; termwidth, carriagereturn=false); context=logio) print(iostr, Base._truncate_at_width_or_chars(true, s, termwidth), "\n") end for pkg_config in pkg_queue_show @@ -1015,11 +1024,11 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, end last_length = length(pkg_queue_show) n_print_rows = count("\n", str_) - print(io, str_) + print(logio, str_) printloop_should_exit[] = interrupted_or_done[] && final_loop final_loop = interrupted_or_done[] # ensures one more loop to tidy last task after finish i += 1 - printloop_should_exit[] || print(io, ansi_moveup(n_print_rows), ansi_movecol1) + printloop_should_exit[] || print(logio, ansi_moveup(n_print_rows), ansi_movecol1) end wait(t) end @@ -1029,7 +1038,7 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, # Base.display_error(ErrorException(""), Base.catch_backtrace()) handle_interrupt(err, true) || rethrow() finally - fancyprint && print(io, ansi_enablecursor) + fancyprint && print(logio, ansi_enablecursor) end end @@ -1081,8 +1090,8 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, end if !circular && is_stale Base.acquire(parallel_limiter) - is_project_dep = pkg in project_deps is_serial_dep = pkg in serial_deps + is_project_dep = pkg in project_deps # std monitoring std_pipe = Base.link_pipe!(Pipe(); reader_supports_async=true, writer_supports_async=true) @@ -1092,7 +1101,7 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, name = describe_pkg(pkg, is_project_dep, is_serial_dep, flags, cacheflags) @lock print_lock begin if !fancyprint && isempty(pkg_queue) - printpkgstyle(io, :Precompiling, something(target[], "packages...")) + printpkgstyle(logio, :Precompiling, something(target[], "packages...")) end end push!(pkg_queue, pkg_config) @@ -1141,11 +1150,11 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, if ret isa Exception push!(precomperr_deps, pkg_config) !fancyprint && @lock print_lock begin - println(io, _timing_string(t), color_string(" ? ", Base.warn_color()), name) + println(logio, _timing_string(t), color_string(" ? ", Base.warn_color()), name) end else !fancyprint && @lock print_lock begin - println(io, _timing_string(t), color_string(" ✓ ", loaded ? Base.warn_color() : :green), name) + println(logio, _timing_string(t), color_string(" ✓ ", loaded ? Base.warn_color() : :green), name) end if ret !== nothing was_recompiled[pkg_config] = true @@ -1161,11 +1170,9 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, close(std_pipe.in) # close pipe to end the std output monitor wait(t_monitor) if err isa ErrorException || (err isa ArgumentError && startswith(err.msg, "Invalid header in cache file")) - errmsg = String(take!(get(IOBuffer, std_outputs, pkg_config))) - delete!(std_outputs, pkg_config) # so it's not shown as warnings, given error report - failed_deps[pkg_config] = (strict || is_project_dep) ? string(sprint(showerror, err), "\n", strip(errmsg)) : "" + failed_deps[pkg_config] = sprint(showerror, err) !fancyprint && @lock print_lock begin - println(io, " "^12, color_string(" ✗ ", Base.error_color()), name) + println(logio, " "^12, color_string(" ✗ ", Base.error_color()), name) end else rethrow() @@ -1213,9 +1220,25 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, quick_exit = any(t -> !istaskdone(t) || istaskfailed(t), tasks) || interrupted[] # all should have finished (to avoid memory corruption) seconds_elapsed = round(Int, (time_ns() - time_start) / 1e9) ndeps = count(values(was_recompiled)) - if ndeps > 0 || !isempty(failed_deps) || (quick_exit && !isempty(std_outputs)) - str = sprint(context=io) do iostr - if !quick_exit + # Determine if any of failures were a requested package + requested_errs = false + for ((dep, config), err) in failed_deps + if dep in requested_pkgids + requested_errs = true + break + end + end + # if every requested package succeeded, filter away output from failed packages + # since it didn't contribute to the overall success and can be regenerated if that package is later required + if !strict && !requested_errs + for (pkg_config, err) in failed_deps + delete!(std_outputs, pkg_config) + end + empty!(failed_deps) + end + if ndeps > 0 || !isempty(failed_deps) + if !quick_exit + logstr = sprint(context=logio) do iostr if fancyprint # replace the progress bar what = isempty(requested_pkgids) ? "packages finished." : "$(join((p.name for p in requested_pkgids), ", ", " and ")) finished." printpkgstyle(iostr, :Precompiling, what) @@ -1248,10 +1271,17 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, ) end end + @lock print_lock begin + println(logio, logstr) + end + end + end + if !isempty(std_outputs) + str = sprint(context=io) do iostr # show any stderr output, even if Pkg.precompile has been interrupted (quick_exit=true), given user may be - # interrupting a hanging precompile job with stderr output. julia#48371 + # interrupting a hanging precompile job with stderr output. let std_outputs = Tuple{PkgConfig,SubString{String}}[(pkg_config, strip(String(take!(io)))) for (pkg_config,io) in std_outputs] - filter!(kv -> !isempty(last(kv)), std_outputs) + filter!(!isempty∘last, std_outputs) if !isempty(std_outputs) local plural1 = length(std_outputs) == 1 ? "y" : "ies" local plural2 = length(std_outputs) == 1 ? "" : "s" @@ -1269,49 +1299,32 @@ function _precompilepkgs(pkgs::Union{Vector{String}, Vector{PkgId}}, end end end - @lock print_lock begin + isempty(str) || @lock print_lock begin println(io, str) end - if interrupted[] - # done cleanup, now ensure caller aborts too - throw(InterruptException()) - end - quick_exit && return Vector{String}[] + end + # Done cleanup and sub-process output, now ensure caller aborts too with the right error + if interrupted[] + throw(InterruptException()) + end + # Fail noisily now with failed_deps if any. + # Include all messages from compilecache since any might be relevant in the failure. + if !isempty(failed_deps) err_str = IOBuffer() - n_direct_errs = 0 - for (pkg_config, err) in failed_deps - dep, config = pkg_config - if strict || (dep in project_deps) - print(err_str, "\n", dep.name, " ") - for cfg in config[1] - print(err_str, cfg, " ") - end - print(err_str, "\n\n", err) - n_direct_errs > 0 && write(err_str, "\n") - n_direct_errs += 1 - end + for ((dep, config), err) in failed_deps + write(err_str, "\n") + print(err_str, "\n", dep.name, " ") + join(err_str, config[1], " ") + print(err_str, "\n", err) end - if position(err_str) > 0 - skip(err_str, -1) - truncate(err_str, position(err_str)) - pluralde = n_direct_errs == 1 ? "y" : "ies" - direct = strict ? "" : "direct " - err_msg = "The following $n_direct_errs $(direct)dependenc$(pluralde) failed to precompile:\n$(String(take!(err_str)))" - if internal_call # aka. decide which untested code path to run that does some unsafe behavior - if isinteractive() # XXX: this test is incorrect - plural1 = length(failed_deps) == 1 ? "y" : "ies" - println(io, " ", color_string("$(length(failed_deps))", Base.error_color()), " dependenc$(plural1) errored.") - println(io, " For a report of the errors see `julia> err`. To retry use `pkg> precompile`") - setglobal!(Base.MainInclude, :err, PkgPrecompileError(err_msg)) # XXX: this call is dangerous - else - # auto-precompilation shouldn't throw but if the user can't easily access the - # error messages, just show them - print(io, "\n", err_msg) - end - else # XXX: crashing is wrong - println(io) - throw(PkgPrecompileError(err_msg)) - end + n_errs = length(failed_deps) + pluraled = n_errs == 1 ? "" : "s" + err_msg = "The following $n_errs package$(pluraled) failed to precompile:$(String(take!(err_str)))\n" + if internal_call + # Pkg does not implement correct error handling, so this sometimes handles them instead + print(io, err_msg) + else + throw(PkgPrecompileError(err_msg)) end end return collect(String, Iterators.flatten((v for (pkgid, v) in cachepath_cache if pkgid in requested_pkgids))) diff --git a/doc/src/devdocs/precompile_hang.md b/doc/src/devdocs/precompile_hang.md index 2204651848509..279ffec5360e8 100644 --- a/doc/src/devdocs/precompile_hang.md +++ b/doc/src/devdocs/precompile_hang.md @@ -17,7 +17,7 @@ If you follow the advice and hit `Ctrl-C`, you might see 1 dependency had warnings during precompilation: ┌ Test1 [ac89d554-e2ba-40bc-bc5c-de68b658c982] -│ [pid 2745] waiting for IO to finish: +│ [pid 2745] Waiting for background task / IO / timer to finish: │ Handle type uv_handle_t->data │ timer 0x55580decd1e0->0x7f94c3a4c340 ``` diff --git a/src/jl_uv.c b/src/jl_uv.c index 766e962288db6..e41b896320693 100644 --- a/src/jl_uv.c +++ b/src/jl_uv.c @@ -68,7 +68,7 @@ static void wait_empty_func(uv_timer_t *t) uv_unref((uv_handle_t*)&signal_async); if (!uv_loop_alive(t->loop)) return; - jl_safe_printf("\n[pid %zd] waiting for IO to finish:\n" + jl_safe_printf("\n[pid %zd] Waiting for background task / IO / timer to finish:\n" " Handle type uv_handle_t->data\n", (size_t)uv_os_getpid()); uv_walk(jl_io_loop, walk_print_cb, NULL); diff --git a/test/precompile.jl b/test/precompile.jl index c7ff1c49db199..12f7a5b1f89ba 100644 --- a/test/precompile.jl +++ b/test/precompile.jl @@ -687,15 +687,7 @@ precompile_test_harness(false) do dir error("break me") end """) - try - Base.require(Main, :FooBar2) - error("the \"break me\" test failed") - catch exc - isa(exc, LoadError) || rethrow() - exc = exc.error - isa(exc, ErrorException) || rethrow() - "break me" == exc.msg || rethrow() - end + @test_throws Base.Precompilation.PkgPrecompileError Base.require(Main, :FooBar2) # Test that trying to eval into closed modules during precompilation is an error FooBar3_file = joinpath(dir, "FooBar3.jl") @@ -707,14 +699,7 @@ precompile_test_harness(false) do dir $code end """) - try - Base.require(Main, :FooBar3) - catch exc - isa(exc, LoadError) || rethrow() - exc = exc.error - isa(exc, ErrorException) || rethrow() - occursin("Evaluation into the closed module `Base` breaks incremental compilation", exc.msg) || rethrow() - end + @test_throws Base.Precompilation.PkgPrecompileError Base.require(Main, :FooBar3) end # Test transitive dependency for #21266 @@ -2563,8 +2548,8 @@ end write(joinpath(fail_pkg_path, "src", "FailPkg.jl"), """ module FailPkg - print("FailPkg precompiling.\n") - error("fail") + print("Now FailPkg is running.\n") + error("expected fail") end """) @@ -2583,7 +2568,7 @@ end write(joinpath(loads_pkg_path, "src", "LoadsFailPkg.jl"), """ module LoadsFailPkg - print("LoadsFailPkg precompiling.\n") + print("Now LoadsFailPkg is running.\n") import FailPkg print("unreachable\n") end @@ -2605,7 +2590,7 @@ end """ module DependsOnly # Has FailPkg as a dependency but doesn't load it - print("DependsOnly precompiling.\n") + print("Now DependsOnly is running.\n") end """) @@ -2661,16 +2646,20 @@ end try push!(empty!(DEPOT_PATH), depot) Base.set_active_project(project_path) - loadsfailpkg = open(LoadsFailPkg_output, "w") do io - # set internal_call to bypass buggy code - Base.Precompilation.precompilepkgs(["LoadsFailPkg"]; io, fancyprint=true, internal_call=true) - end - @test isempty(loadsfailpkg::Vector{String}) - dependsonly = open(DependsOnly_output, "w") do io - # set internal_call to bypass buggy code - Base.Precompilation.precompilepkgs(["DependsOnly"]; io, fancyprint=true, internal_call=true) + precompile_capture(file, pkg) = open(file, "w") do io + try + r = Base.Precompilation.precompilepkgs([pkg]; io, fancyprint=true) + @test r isa Vector{String} + r + catch ex + ex isa Base.Precompilation.PkgPrecompileError || rethrow() + ex + end end - @test length(dependsonly::Vector{String}) == 1 + loadsfailpkg = precompile_capture(LoadsFailPkg_output, "LoadsFailPkg") + @test loadsfailpkg isa Base.Precompilation.PkgPrecompileError + dependsonly = precompile_capture(DependsOnly_output, "DependsOnly") + @test length(dependsonly) == 1 finally Base.set_active_project(old_proj) append!(empty!(DEPOT_PATH), original_depot_path) @@ -2678,25 +2667,22 @@ end output = read(LoadsFailPkg_output, String) # LoadsFailPkg should fail because it tries to load FailPkg with --compiled-modules=strict - @test_broken count(output, "ERROR: fail") > 0 - @test_broken count(output, "ERROR: fail") == 1 + @test count("LoadError: expected fail", output) == 1 + @test count("expected fail", output) == 1 @test count("✗ FailPkg", output) > 0 @test count("✗ LoadsFailPkg", output) > 0 - @test count("FailPkg precompiling.", output) > 0 - @test_broken count("FailPkg precompiling.", output) == 1 - @test 0 < count("LoadsFailPkg precompiling.", output) <= 2 - @test_broken count("LoadsFailPkg precompiling.", output) == 1 - @test !contains(output, "DependsOnly precompiling.") + @test count("Now FailPkg is running.", output) == 1 + @test count("Now LoadsFailPkg is running.", output) == 1 + @test count("DependsOnly precompiling.", output) == 0 # DependsOnly should succeed because it doesn't actually load FailPkg output = read(DependsOnly_output, String) - @test_broken count(output, "ERROR: fail") > 0 - @test_broken count(output, "ERROR: fail") == 1 + @test count("LoadError: expected fail", output) == 0 + @test count("expected fail", output) == 0 @test count("✗ FailPkg", output) > 0 @test count("Precompiling DependsOnly finished.", output) == 1 - @test_broken count("FailPkg precompiling.", output) > 0 - @test_broken count("FailPkg precompiling.", output) == 1 - @test count("DependsOnly precompiling.", output) == 1 + @test count("Now FailPkg is running.", output) == 0 + @test count("Now DependsOnly is running.", output) == 1 end end