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.

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

[1.10] precompile silently dies due to SystemError when opening .ji files #3984

Closed
topolarity opened this issue Aug 8, 2024 · 1 comment
Closed

Comments

@topolarity
Copy link
Member

topolarity commented Aug 8, 2024

Unfortunately, no MWE yet but I'm opening this issue early to share what I have. The basic problem is that I have a large project that 50% of the time when precompiling in a particular workflow results in a silent cancellation of precompilation.

When this happens, Pkg leaves behind an incomplete progress bar + spinners:

  Progress [===================>                     ]  134/293
  ◒ MLStyle
  ◑ Parsers

Otherwise, no error is printed to the terminal. The only other sign that something went wrong is that you'll often fall immediately into (undesirable) serial pre-compilation, etc.

Stack trace from a (slightly modified) build of 1.10:

    systemerror(p::String, errno::Int32; extrainfo::Nothing) at error.jl:176,
    kwcall(::@NamedTuple{extrainfo::Nothing}, ::typeof(systemerror), p::String, errno::Int32) at error.jl:176,
    kwcall(::@NamedTuple{extrainfo::Nothing}, ::typeof(systemerror), p::String) at error.jl:176,
    #systemerror#88 at error.jl:175 [inlined],
    systemerror at error.jl:175 [inlined],
    open(fname::String; lock::Bool, read::Bool, write::Nothing, create::Nothing, truncate::Nothing, append::Nothing) at iostream.jl:293,
    open at iostream.jl:275 [inlined],
    open(fname::String, mode::String; lock::Bool) at iostream.jl:356,
    open at iostream.jl:355 [inlined],
    stale_cachefile(modkey::Base.PkgId, build_id::UInt128, modpath::String, cachefile::String; ignore_loaded::Bool) at loading.jl:3008,
    stale_cachefile at loading.jl:3007 [inlined],
    #stale_cachefile#984 at loading.jl:3005 [inlined],
    stale_cachefile at loading.jl:3004 [inlined],
    isprecompiled(pkg::Base.PkgId; ignore_loaded::Bool, stale_cache::Dict{Tuple{Base.PkgId, UInt128, String, String}, Bool}, cachepaths::Vector{String}, sourcepath::String) at loading.jl:1397,
    isprecompiled at loading.jl:1389 [inlined],
    (::Pkg.API.var"#247#285"{Bool, Bool, Pkg.Types.Context, Vector{Task}, IOStream, Dict{Base.PkgId, String}, Dict{Base.PkgId, String}, Base.Event, Base.Event, ReentrantLock, Vector{Base.PkgId}, Vector{Base.PkgId}, Dict{Base.PkgId, String}, Vector{Base.PkgId}, Vector{Base.PkgId}, Dict{Base.PkgId, Bool}, Dict{Base.PkgId, Base.Event}, Dict{Base.PkgId, Bool}, Vector{Pkg.Types.PackageSpec}, Dict{Base.PkgId, String}, Dict{Tuple{Base.PkgId, UInt128, String, String}, Bool}, Vector{Base.PkgId}, Pkg.API.var"#color_string#258"{Bool}, Bool, Bool, Base.TTY, Base.Semaphore, Bool, String, Vector{String}, Vector{Base.PkgId}, Base.PkgId})() at API.jl:1503

This shows that SystemError is a ENOENT from this open: https://github.com/JuliaLang/julia/blob/4954197196d657d14edd3e9c61ac101866e6fa25/base/loading.jl#L3008

I think this suggests several problems:

  1. Base loading should probably not have an unguarded open like this (pretty much ever, I think - open can essentially always fail...)
  2. Pkg.precompile does not know the difference between a user interrupt vs. a failed assertion / internal error, so it silently discards this internal error assuming it has been "interrupted"
  3. (The actual bug) It seems there is maybe a race condition and/or caching misbehavior causing the file not to be where it is expected

I'm also worried this issue is quite common, but just hard to notice so that we don't get bug reports...

The 5 people on my team that work on this (or other similarly large) projects have all hit this issue. I actually hit this for 2+ months before I was informed the spinners aren't supposed to just die like that 😅

@topolarity topolarity added this to the 1.10 milestone Aug 8, 2024
IanButterworth added a commit to JuliaLang/julia that referenced this issue Aug 9, 2024
Testing:

- with a package error
```
(SimpleLooper) pkg> precompile
Precompiling all packages...
  ✗ SimpleLooper
  0 dependencies successfully precompiled in 2 seconds

ERROR: The following 1 direct dependency failed to precompile:

SimpleLooper 

Failed to precompile SimpleLooper [ff33fe5-d8e3-4cbd-8bd9-3d2408ff8cab] to "/Users/ian/.julia/compiled/v1.12/SimpleLooper/jl_PQArnH".
ERROR: LoadError: 
Stacktrace:
  [1] error()
    @ Base ./error.jl:53
```

- with interrupt
```
(SimpleLooper) pkg> precompile
Precompiling all packages...
^C Interrupted: Exiting precompilation...
  ◒ SimpleLooper
  1 dependency had output during precompilation:
┌ SimpleLooper
│  [57879] signal 2: Interrupt: 2
│  in expression starting at /Users/ian/Documents/GitHub/SimpleLooper.jl/src/SimpleLooper.jl:2
└  
```

- an internal error simulated in the same scope that
JuliaLang/Pkg.jl#3984 was failing to throw
from
 ```
  JULIA stdlib/release.image
Unhandled Task ERROR: 
Stacktrace:
 [1] error()
   @ Base ./error.jl:53
[2] (::Base.Precompilation.var"#27#65"{Bool, Bool, Vector{Task},
Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}}, String},
Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}}, String}, Base.Event,
Base.Event, ReentrantLock, Vector{Tuple{Base.PkgId, Pair{Cmd,
Base.CacheFlags}}}, Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}},
String}, Vector{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}}}, Int64,
Vector{Base.PkgId}, Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}},
Bool}, Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}}, Base.Event},
Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}}, Bool},
Vector{Base.PkgId}, Dict{Base.PkgId, String}, Dict{Tuple{Base.PkgId,
UInt128, String, String}, Bool},
Base.Precompilation.var"#color_string#38"{Bool}, Bool, Base.Semaphore,
Bool, String, Vector{String}, Vector{Base.PkgId}, Base.PkgId,
Base.CacheFlags, Cmd, Pair{Cmd, Base.CacheFlags}, Tuple{Base.PkgId,
Pair{Cmd, Base.CacheFlags}}})()
   @ Base.Precompilation ./precompilation.jl:819
```
@IanButterworth
Copy link
Member

#3986 fixed this.
#3987 also fixed swallowing internal errors.

KristofferC pushed a commit to JuliaLang/julia that referenced this issue Aug 13, 2024
lazarusA pushed a commit to lazarusA/julia that referenced this issue Aug 17, 2024
Testing:

- with a package error
```
(SimpleLooper) pkg> precompile
Precompiling all packages...
  ✗ SimpleLooper
  0 dependencies successfully precompiled in 2 seconds

ERROR: The following 1 direct dependency failed to precompile:

SimpleLooper 

Failed to precompile SimpleLooper [ff33fe5-d8e3-4cbd-8bd9-3d2408ff8cab] to "/Users/ian/.julia/compiled/v1.12/SimpleLooper/jl_PQArnH".
ERROR: LoadError: 
Stacktrace:
  [1] error()
    @ Base ./error.jl:53
```

- with interrupt
```
(SimpleLooper) pkg> precompile
Precompiling all packages...
^C Interrupted: Exiting precompilation...
  ◒ SimpleLooper
  1 dependency had output during precompilation:
┌ SimpleLooper
│  [57879] signal 2: Interrupt: 2
│  in expression starting at /Users/ian/Documents/GitHub/SimpleLooper.jl/src/SimpleLooper.jl:2
└  
```

- an internal error simulated in the same scope that
JuliaLang/Pkg.jl#3984 was failing to throw
from
 ```
  JULIA stdlib/release.image
Unhandled Task ERROR: 
Stacktrace:
 [1] error()
   @ Base ./error.jl:53
[2] (::Base.Precompilation.var"JuliaLang#27#65"{Bool, Bool, Vector{Task},
Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}}, String},
Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}}, String}, Base.Event,
Base.Event, ReentrantLock, Vector{Tuple{Base.PkgId, Pair{Cmd,
Base.CacheFlags}}}, Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}},
String}, Vector{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}}}, Int64,
Vector{Base.PkgId}, Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}},
Bool}, Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}}, Base.Event},
Dict{Tuple{Base.PkgId, Pair{Cmd, Base.CacheFlags}}, Bool},
Vector{Base.PkgId}, Dict{Base.PkgId, String}, Dict{Tuple{Base.PkgId,
UInt128, String, String}, Bool},
Base.Precompilation.var"#color_string#38"{Bool}, Bool, Base.Semaphore,
Bool, String, Vector{String}, Vector{Base.PkgId}, Base.PkgId,
Base.CacheFlags, Cmd, Pair{Cmd, Base.CacheFlags}, Tuple{Base.PkgId,
Pair{Cmd, Base.CacheFlags}}})()
   @ Base.Precompilation ./precompilation.jl:819
```
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants