Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

precompilation: capture stdout as well as stderr #3573

Merged
merged 5 commits into from
Aug 15, 2023
Merged

precompilation: capture stdout as well as stderr #3573

Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
74c4c1b
precompilation: capture stdout during code load precomp
IanButterworth Aug 9, 2023
b850e23
use two pipes
IanButterworth Aug 11, 2023
8783c7c
suggestions
IanButterworth Aug 15, 2023
6ed7bfd
use a single pipe
IanButterworth Aug 15, 2023
69fdd87
also close in happy path
IanButterworth Aug 15, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
42 changes: 22 additions & 20 deletions src/API.jl
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1273,15 +1273,15 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
end
end

stderr_outputs = Dict{Base.PkgId,String}()
std_outputs = Dict{Base.PkgId,String}()
taskwaiting = Set{Base.PkgId}()
pkgspidlocked = Dict{Base.PkgId,String}()

function monitor_stderr(pkg, iob)
function monitor_std(pkg, pipe)
try
while isopen(iob)
str = readline(iob)
stderr_outputs[pkg] = get(stderr_outputs, pkg, "") * str * "\n"
while !eof(pipe)
str = readline(pipe, keep=true)
std_outputs[pkg] = string(get(std_outputs, pkg, ""), str)
if !in(pkg, taskwaiting) && occursin("waiting for IO to finish", str)
!fancyprint && lock(print_lock) do
println(io, pkg.name, color_string(" Waiting for background task / IO / timer.", Base.warn_color()))
Expand All @@ -1290,7 +1290,7 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
end
if !fancyprint && in(pkg, taskwaiting)
lock(print_lock) do
println(io, str)
print(io, str)
end
end
end
Expand Down Expand Up @@ -1428,8 +1428,8 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
is_direct_dep = pkg in direct_deps

# stderr monitoring
iob = Base.BufferStream()
t_monitor = @async monitor_stderr(pkg, iob)
std_pipe = Base.link_pipe!(Pipe(); reader_supports_async=true, writer_supports_async=true)
t_monitor = @async monitor_std(pkg, std_pipe)

_name = haskey(exts, pkg) ? string(exts[pkg], " → ", pkg.name) : pkg.name
name = is_direct_dep ? _name : string(color_string(_name, :light_black))
Expand All @@ -1449,8 +1449,8 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
# 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)
# The false here means we ignore loaded modules, so precompile for a fresh session
Base.compilecache(pkg, sourcepath, std_pipe, std_pipe, false)
end
end
t_str = timing ? string(lpad(round(t * 1e3, digits = 1), 9), " ms") : ""
Expand All @@ -1469,11 +1469,11 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
end
loaded && (n_loaded += 1)
catch err
close(iob)
close(std_pipe.in) # close pipe to end the std output monitor
wait(t_monitor)
IanButterworth marked this conversation as resolved.
Show resolved Hide resolved
if err isa ErrorException || (err isa ArgumentError && startswith(err.msg, "Invalid header in cache file"))
failed_deps[pkg] = (strict || is_direct_dep) ? string(sprint(showerror, err), "\n", get(stderr_outputs, pkg, "")) : ""
delete!(stderr_outputs, pkg) # so it's not shown as warnings, given error report
failed_deps[pkg] = (strict || is_direct_dep) ? string(sprint(showerror, err), "\n", strip(get(std_outputs, pkg, ""))) : ""
delete!(std_outputs, pkg) # so it's not shown as warnings, given error report
!fancyprint && lock(print_lock) do
println(io, timing ? " "^9 : "", color_string(" ✗ ", Base.error_color()), name)
end
Expand All @@ -1483,6 +1483,8 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
rethrow()
end
finally
isopen(std_pipe.in) && close(std_pipe.in) # close pipe to end the std output monitor
wait(t_monitor)
Base.release(parallel_limiter)
end
else
Expand Down Expand Up @@ -1515,7 +1517,7 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
quick_exit = !all(istaskdone, tasks) || interrupted # if some not finished internal error is likely
seconds_elapsed = round(Int, (time_ns() - time_start) / 1e9)
ndeps = count(values(was_recompiled))
if ndeps > 0 || !isempty(failed_deps) || (quick_exit && !isempty(stderr_outputs))
if ndeps > 0 || !isempty(failed_deps) || (quick_exit && !isempty(std_outputs))
str = sprint() do iostr
if !quick_exit
plural = ndeps == 1 ? "y" : "ies"
Expand Down Expand Up @@ -1545,12 +1547,12 @@ function precompile(ctx::Context, pkgs::Vector{PackageSpec}; internal_call::Bool
end
# 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
filter!(kv -> !isempty(strip(last(kv))), stderr_outputs) # remove empty output
if !isempty(stderr_outputs)
plural1 = length(stderr_outputs) == 1 ? "y" : "ies"
plural2 = length(stderr_outputs) == 1 ? "" : "s"
print(iostr, "\n ", color_string("$(length(stderr_outputs))", Base.warn_color()), " dependenc$(plural1) had output during precompilation:")
for (pkgid, err) in stderr_outputs
filter!(kv -> !isempty(strip(last(kv))), std_outputs) # remove empty output
if !isempty(std_outputs)
plural1 = length(std_outputs) == 1 ? "y" : "ies"
plural2 = length(std_outputs) == 1 ? "" : "s"
print(iostr, "\n ", color_string("$(length(std_outputs))", Base.warn_color()), " dependenc$(plural1) had output during precompilation:")
for (pkgid, err) in std_outputs
err = join(split(strip(err), "\n"), color_string("\n│ ", Base.warn_color()))
print(iostr, color_string("\n┌ ", Base.warn_color()), pkgid, color_string("\n│ ", Base.warn_color()), err, color_string("\n└ ", Base.warn_color()))
end
Expand Down
Loading