IO information statement after successful precompilation

[thofma]

I updated to 1.10 and noticed that a warning(?) is printed after precompiling a package extension: With a fresh depot, I see the following:

julia> import Pkg; Pkg.add(["Polymake", "Hecke"]); using Polymake, Hecke;
[...]
Precompiling project...
  71 dependencies successfully precompiled in 113 seconds
  1 dependency had output during precompilation:
┌ Hecke → PolymakeExt
│  [pid 43163] waiting for IO to finish:
│   Handle type        uv_handle_t->data
│   timer              0x600002616c00->0x10d7cc5e0
│  This means that a package has started a background task or event source that has not finished running. For precompilation to complete successfully, the event source needs to be closed explicitly. See the developer documentation on fixing precompilation hangs for more help.
│
│  [pid 43163] waiting for IO to finish:
│   Handle type        uv_handle_t->data
│   timer              0x600002616c00->0x10d7cc5e0
│  This means that a package has started a background task or event source that has not finished running. For precompilation to complete successfully, the event source needs to be closed explicitly. See the developer documentation on fixing precompilation hangs for more help.
└

Everything works fine afterwards, but why do I get this scary looking warning if everything was successfully precompiled? I am also not sure what to do with this warning. I believe I am not doing any fancy IO stuff in Hecke → PolymakeExt, just some ordinary method overloading.

This is a regression, since on 1.9 everything is working as expected (no warning).

Version:

julia> versioninfo()
Julia Version 1.10.0
Commit 3120989f39b (2023-12-25 18:01 UTC)
Build Info:
  Official https://julialang.org/ release
Platform Info:
  OS: macOS (arm64-apple-darwin22.4.0)
  CPU: 8 × Apple M1
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-15.0.7 (ORCJIT, apple-m1)
  Threads: 1 on 4 virtual cores
Environment:
  JULIA_DEPOT_PATH = /var/folders/vw/fn8vgctd5bv0llw3_fnmrdz00000gn/T/tmp.HUocLdw3Y0

[IanButterworth]

I am also not sure what to do with this warning

Note "See the developer documentation on fixing precompilation hangs for more help" which is directing you to https://docs.julialang.org/en/v1/devdocs/precompile_hang/

This messaging is definitely more internal looking/scary than it needs to be. There's been a lot of discussion about that

[thofma]

Yes, I saw that hint after everything "succesfully precompiled" (as printed in the terminal). Sorry for my naive question, but why print the warning if everything was successful?

[thofma]

I identified the dependency which causes this (https://github.com/oscar-system/Polymake.jl/). But the dependency runs the recommended Aqua check and it passes:

  Persistent tasks                           |    1      1   6.4s

(https://github.com/oscar-system/Polymake.jl/actions/runs/7379376449/job/20075564999?pr=466#step:7:217)

"Fixing" it with call(:jl_generating_output, Cint, ()) == 1 && return nothing is not an option because of #50914 (comment).

I am happy to hear that we are doing something wrong, but I am not sure where to look for the problem.

[benlorenz]

I looked into this a bit and I can reproduce this with a dummy package and a second package that depends on it:

/tmp/tmpdepot $ rm -rf compiled/v1.10/PkgA* artifacts/4c207c7dc70b23755d9281a92daa9b8f11dc746d/
/tmp/tmpdepot $ JULIA_DEPOT_PATH=/tmp/tmpdepot julia-latest --project=mwe/PkgC
               _
   _       _ _(_)_     |  Documentation: https://docs.julialang.org
  (_)     | (_) (_)    |
   _ _   _| |_  __ _   |  Type "?" for help, "]?" for Pkg help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 1.10.0 (2023-12-25)
 _/ |\__'_|_|_|\__'_|  |  Official https://julialang.org/ release
|__/                   |

(PkgC) pkg> precompile
Precompiling project...
        Info Given PkgC was explicitly requested, output will be shown live 

[pid 21092] waiting for IO to finish:
 Handle type        uv_handle_t->data
 timer              0x23fc180->0x7f4ff22aa5f0
This means that a package has started a background task or event source that has not finished running. For precompilation to complete successfully, the event source needs to be closed explicitly. See the developer documentation on fixing precompilation hangs for more help.

[pid 21092] waiting for IO to finish:
 Handle type        uv_handle_t->data
 timer              0x23fc180->0x7f4ff22aa5f0
This means that a package has started a background task or event source that has not finished running. For precompilation to complete successfully, the event source needs to be closed explicitly. See the developer documentation on fixing precompilation hangs for more help.
  2 dependencies successfully precompiled in 32 seconds. 1 already precompiled.
  1 dependency had output during precompilation:
┌ PkgC
│  [Output was shown above]
└  

PkgC is empty except for using PkgA and PkgA contains:

using Pkg.Artifacts

function __init__()
  download_artifact(Base.SHA1("4c207c7dc70b23755d9281a92daa9b8f11dc746d"), "https://github.com/JuliaBinaryWrappers/GMP_jll.jl/releases/download/GMP-v6.2.1+6/GMP.v6.2.1.x86_64-linux-gnu-cxx11.tar.gz", "cb20b68a814c37fa091f38a83f160c5025ecf3234401758c9ca820b10adc58b0")
end

The warning only appears when the artifact is missing (and then installed) during precompilation.
Which artifact is probably irrelevant but Polymake.jl needs the proper GMP_jll (instead of the stdlib) for the headers.
The same warning will be shown when depending on PkgA with a Pkg extension but it doesn't seem to be necessary for this to trigger.

So it seems the Task / Timer comes from Pkg.jl (or Downloads.jl) ?

And I guess it doesn't trigger during the Polymake.jl Aqua tests because the main test file runs using Polymake (which installs the artifact) before running the Aqua tests.

PS: PkgA and PkgC are here https://github.com/benlorenz/MWEPkgTimer

[vtjnash]

The warning here is that Downloads sleeps for 30 seconds after finishing, so precompile takes 30 seconds longer than it should

[thofma]

dup

[IanButterworth]

dup

If this is a dup please link to the dup

The warning here is that Downloads sleeps for 30 seconds after finishing, so precompile takes 30 seconds longer than it should

@vtjnash is Downloads.jl sleeping like this fixed?

[IanButterworth]

Looks like it isn't fixed JuliaLang/Downloads.jl#223