IJulia world age problem when precompilation is triggered (no method matching `pipe_writer(::IJulia.IJuliaStdio{Base.PipeEndpoint})`)

[svilupp]

I wanted to cross-link an issue with IJulia that seems to be affecting 1.10 and 1.11-DEV. This seems to also affect any documentation/report tools that use IJulia execution under the hood (eg, Quarto).

When a package needs precompilation, IJulia will throw the following error:

MethodError: no method matching pipe_writer(::IJulia.IJuliaStdio{Base.PipeEndpoint})
The applicable method may be too new: running in world age 31373, while current world is 31593.

I can replicate this error on Julia 1.10 beta1, 1.10 beta2 and 1.11 (latest main).
1.9.3 works as expected.

MWE:

• Create a mock module in your temp environment

module ABC

greet() = print("Hello World!")

struct A1 end
struct B1 end

greet(::A1) = print("Hello World!")

x(::A1) = "x"

end # module ABC

• Add the packages to the project env
• Create an Ipython notebook with the following cells

using Pkg; Pkg.activate(".")
using StatsPlots # it can help to have some complex package there to trigger the precompilation more often (to get the error)
using ABC

• If precompilation is triggered by adding or Pkg.precompile(), it seems to work
• To trigger the error, make some changes in the ABC module that will trigger recompilation (add a new struct and function)
• When you try to execute the cell with using ABC, the error will be thrown

Versions:

IJulia version: latest (1.24.2)

Versioninfo:

Julia Version 1.10.0-beta2
Commit a468aa1 (2023-08-17 06:27 UTC)
Build Info:
Official https://julialang.org/ release
Platform Info:
OS: macOS (arm64-apple-darwin22.4.0)
CPU: 8 × Apple M1 Pro
WORD_SIZE: 64
LIBM: libopenlibm
LLVM: libLLVM-15.0.7 (ORCJIT, apple-m1)
Threads: 1 on 6 virtual cores

[vtjnash]

Sounds like 614d917 / 59bf9e8 (#49525) @KristofferC

[svilupp]

Wow, this is spot on.

I've just tested the bug on 59bf9e8 and it indeed fails.

I've tried also one commit before it ("feaea2266eabe3d6714e8073ec57cb6bbf14e8ee") and everything works as expected. That saved me a lot of bisecting!

[KristofferC]

I'm having issues reproducing this because I cannot seem to get IJulia to work on 1.10... Trying to repro it with something like:

let
Base.PKG_PRECOMPILE_HOOK[] = Returns(nothing)

struct IJuliaStdio{IO_t <: IO} <: Base.AbstractPipe
    io::IOContext{IO_t}
end
IJuliaStdio(io::IO, stream::AbstractString="unknown") =
    IJuliaStdio{typeof(io)}(IOContext(io, :color=>Base.have_color,
                            :jupyter_stream=>stream,
                            :displaysize=>displaysize()))
Base.pipe_reader(io::IJuliaStdio) = io.io.io
Base.pipe_writer(io::IJuliaStdio) = io.io.io
Base.lock(io::IJuliaStdio) = lock(io.io.io)
Base.unlock(io::IJuliaStdio) = unlock(io.io.io)
Base.in(key_value::Pair, io::IJuliaStdio) = in(key_value, io.io)
Base.haskey(io::IJuliaStdio, key) = haskey(io.io, key)
Base.getindex(io::IJuliaStdio, key) = getindex(io.io, key)
Base.get(io::IJuliaStdio, key, default) = get(io.io, key, default)
Base.displaysize(io::IJuliaStdio) = displaysize(io.io)
Base.unwrapcontext(io::IJuliaStdio) = Base.unwrapcontext(io.io)
Base.setup_stdio(io::IJuliaStdio, readable::Bool) = Base.setup_stdio(io.io.io, readable)

redirect_stdout(IJuliaStdio(stdout,"stdout"))
redirect_stderr(IJuliaStdio(stderr,"stderr"))

using ABC
end

doesn't reproduce.

[KristofferC]

My assumption was that this came from the logging macro outputting [ Info: Precompiling ABC... but the logging macros have an invokelatest now I see so this can't really be the reason.

[svilupp]

When you say you can't get IJulia to work on 1.10, do you mean installing a kernel to run the notebook on?

I tried your example and it indeed works fine.
I've also tried an example closer to what IJulia does with PipeEndpoint (I have no idea what I'm doing), but I cannot repro via REPL:

My attempt

using IJulia: IJuliaStdio

read_stdout = Ref{Base.PipeEndpoint}()
read_stderr = Ref{Base.PipeEndpoint}()

read_stdout[], = redirect_stdout()
redirect_stdout(IJuliaStdio(stdout, "stdout"))
read_stderr[], = redirect_stderr()
redirect_stderr(IJuliaStdio(stderr, "stderr"))

using ABC

using Pkg;
Pkg.precompile(; io=read_stdout[]);

But when I just open a Jupyter Notebook with 1.10 kernel, it's enough to do using ABC to get the error.

I have no idea what I'm looking at, but from the stack trace I would assume it's coming from the nested call to unpack the registry:
~/.julia/juliaup/julia-1.10.0-beta2+0.aarch64.apple.darwin14/share/julia/stdlib/v1.10/Pkg/src/Registry/registry_instance.jl:261

Pipe leak perhaps?

Stacktrace:

MethodError: no method matching pipe_writer(::IJulia.IJuliaStdio{Base.PipeEndpoint})
The applicable method may be too new: running in world age 31373, while current world is 31390.

Closest candidates are:
pipe_writer(::IJulia.IJuliaStdio) (method too new to be called from this world context.)
@ IJulia ~/.julia/packages/IJulia/Vo51o/src/stdio.jl:15
pipe_writer(::Base.ProcessChain)
@ Base process.jl:36
pipe_writer(::Base.Process)
@ Base process.jl:22
...

Stacktrace:
[1] setup_stdio(stdio::IJulia.IJuliaStdio{Base.PipeEndpoint}, readable::Bool)
@ Base ./process.jl:260
[2] setup_stdios(f::Base.var"#784#785"{Cmd}, stdios::Vector{Union{RawFD, IO}})
@ Base ./process.jl:221
[3] _spawn
@ Base ./process.jl:138 [inlined]
[4] open(cmds::Cmd, stdio::Base.DevNull; write::Bool, read::Bool)
@ Base ./process.jl:393
[5] open (repeats 2 times)
@ Base ./process.jl:383 [inlined]
[6] open(::Pkg.Registry.var"#19#22"{IOBuffer, Vector{UInt8}, Dict{String, String}}, ::Cmd; kwargs::@kwargs{})
@ Base ./process.jl:415
[7] open
@ Base ./process.jl:414 [inlined]
[8] uncompress_registry(tar_gz::String)
@ Pkg.Registry ~/.julia/juliaup/julia-1.10.0-beta2+0.aarch64.apple.darwin14/share/julia/stdlib/v1.10/Pkg/src/Registry/registry_instance.jl:261
[9] Pkg.Registry.RegistryInstance(path::String)
@ Pkg.Registry ~/.julia/juliaup/julia-1.10.0-beta2+0.aarch64.apple.darwin14/share/julia/stdlib/v1.10/Pkg/src/Registry/registry_instance.jl:328
[10] reachable_registries(; depots::Vector{String})
@ Pkg.Registry ~/.julia/juliaup/julia-1.10.0-beta2+0.aarch64.apple.darwin14/share/julia/stdlib/v1.10/Pkg/src/Registry/registry_instance.jl:434
[11] reachable_registries
@ Pkg.API ~/.julia/juliaup/julia-1.10.0-beta2+0.aarch64.apple.darwin14/share/julia/stdlib/v1.10/Pkg/src/Registry/registry_instance.jl:404 [inlined]
[12] Context
@ Pkg.API ~/.julia/juliaup/julia-1.10.0-beta2+0.aarch64.apple.darwin14/share/julia/stdlib/v1.10/Pkg/src/Types.jl:395 [inlined]
[13] precompile(pkgs::Vector{Pkg.Types.PackageSpec}; io::IJulia.IJuliaStdio{Base.PipeEndpoint}, kwargs::@kwargs{_from_loading::Bool})
@ Pkg.API ~/.julia/juliaup/julia-1.10.0-beta2+0.aarch64.apple.darwin14/share/julia/stdlib/v1.10/Pkg/src/API.jl:150
[14] precompile
@ Pkg.API ~/.julia/juliaup/julia-1.10.0-beta2+0.aarch64.apple.darwin14/share/julia/stdlib/v1.10/Pkg/src/API.jl:147 [inlined]
[15] #precompile#114
@ Pkg.API ~/.julia/juliaup/julia-1.10.0-beta2+0.aarch64.apple.darwin14/share/julia/stdlib/v1.10/Pkg/src/API.jl:146 [inlined]
[16] _require(pkg::Base.PkgId, env::String)
@ Base ./loading.jl:1957
[17] __require_prelocked(uuidkey::Base.PkgId, env::String)
@ Base ./loading.jl:1806
[18] #invoke_in_world#3
@ Base ./essentials.jl:921 [inlined]
[19] invoke_in_world
@ Base ./essentials.jl:918 [inlined]
[20] _require_prelocked(uuidkey::Base.PkgId, env::String)
@ Base ./loading.jl:1797
[21] macro expansion
@ Base ./loading.jl:1784 [inlined]
[22] macro expansion
@ Base ./lock.jl:267 [inlined]
[23] __require(into::Module, mod::Symbol)
@ Base ./loading.jl:1747
[24] #invoke_in_world#3
@ Base ./essentials.jl:921 [inlined]
[25] invoke_in_world
@ Base ./essentials.jl:918 [inlined]
[26] require(into::Module, mod::Symbol)
@ Base ./loading.jl:1740

[KristofferC]

I have no idea what I'm looking at, but from the stack trace I would assume it's coming from the nested call to unpack the registry:
~/.julia/juliaup/julia-1.10.0-beta2+0.aarch64.apple.darwin14/share/julia/stdlib/v1.10/Pkg/src/Registry/registry_instance.jl:261

That stacktrace is useful, thanks.