Stale dependencies check prohibitively slow

[KeithWM]

A bit of a long shot to post this here, but maybe others have encountered this issue too and there is something I can to fix it.

When running Aqua locally, the test_stale_deps takes so long that I've never actually seen it complete (even after leaving the machine for several hours). There is no issue when running the same tests in our CI/CD pipeline (on Bitbucket).

Does anyone know what could be the cause of this?

[fingolfin]

Never have encountered this or heard about it (though perhaps this is the same as #30?).

But as long as we cannot reproduce this and in general have no more information than "it hangs", we can't do anything about it. Perhaps you can tell us more:

• which OS are you using?
• which Julia version?
• what exactly are you doing to trigger the hang?
• ideally a link to the repo of your package so we can try to repro it
• baring that, perhaps you can ctrl-c the hanging check and report whatever backtrace it prints?

[KeithWM]

Thanks for the reply. Sorry for not being more verbose in my question, but I managed to reproduce the error locally. I will try to make a MBE that I can share. In the meantime, answers to your questions:

• Windows 10 Enterprise 22H2
• Julia v1.8.3
• See below
• Can't share the repo as is, (way) too confidential of an algorithm, but I will work on a MBE
• See below

Steps to reproduce:

julia> TestEnv.activate()
julia> import Aqua
julia> import BrokenAqua  # the name of the MBE to follow
julia> Aqua.test_stale_deps(BrokenAqua)

I am quite sure I encountered the error before without using TestEnv, both in a clean ]test and when using ReTest with some manual modifications to the environment.

Ctrl-C:

^C
ERROR: InterruptException:
Stacktrace:
  [1] try_yieldto(undo::typeof(Base.ensure_rescheduled))
    @ Base .\task.jl:871
  [2] wait()
    @ Base .\task.jl:931
  [3] wait(c::Base.GenericCondition{Base.Threads.SpinLock})
    @ Base .\condition.jl:124
  [4] wait_readnb(x::Base.PipeEndpoint, nb::Int64)
    @ Base .\stream.jl:416
  [5] read(stream::Base.PipeEndpoint)
    @ Base .\stream.jl:928
  [6] read(cmd::Cmd)
    @ Base .\process.jl:448
  [7] read(cmd::Cmd, #unused#::Type{String})
    @ Base .\process.jl:458
  [8] _analyze_stale_deps_1(pkg::Base.PkgId; ignore::Vector{Symbol})
    @ Aqua C:\Users\myerscoughk\.julia\packages\Aqua\2aeHf\src\stale_deps.jl:55
  [9] _analyze_stale_deps_1
    @ C:\Users\myerscoughk\.julia\packages\Aqua\2aeHf\src\stale_deps.jl:32 [inlined]
 [10] #30
    @ .\none:0 [inlined]
 [11] iterate
    @ .\generator.jl:47 [inlined]
 [12] collect(itr::Base.Generator{Vector{Base.PkgId}, Aqua.var"#30#31"{Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}}}})
    @ Base .\array.jl:787
 [13] analyze_stale_deps
    @ C:\Users\myerscoughk\.julia\packages\Aqua\2aeHf\src\stale_deps.jl:29 [inlined]
 [14] macro expansion
    @ C:\Users\myerscoughk\AppData\Local\Programs\Julia-1.8.3\share\julia\stdlib\v1.8\Test\src\Test.jl:1455 [inlined]
 [15] test_stale_deps(packages::Module; kwargs::Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
    @ Aqua C:\Users\myerscoughk\.julia\packages\Aqua\2aeHf\src\stale_deps.jl:22
 [16] test_stale_deps(packages::Module)
    @ Aqua C:\Users\myerscoughk\.julia\packages\Aqua\2aeHf\src\stale_deps.jl:21
 [17] top-level scope
    @ REPL[12]:1

[fingolfin]

Excellent, thank you! An MBE would be fantastic

so it is waiting for a subprocess. I guess next we'd need a backtrace for that.

[KeithWM]

https://github.com/KeithWM/BrokenAqua.jl I think this is a breaking example.

[fingolfin]

Thank you! I tried this on macOS, but it "just works", when I do this in a fresh Julia 1.9 session:

import Aqua
import BrokenAqua
Aqua.test_stale_deps(BrokenAqua)

So it would be good to reduce differences to your setup...

• I was using Julia 1.9.0, I will next try with Julia 1.8.5 -- but you have 1.8.3. Perhaps you could also install 1.8.5 or 1.9.0 to see if the issue occurs with either?
• you are on Windows, I only have easy access to macOS and Linux right now. I'll try to install Julia and everything via a remote access to a Windows machine now. But in the meantime it would be good to know if you or anyone else can reproduce the issue on a non-Windows machine?
• I did not yet use TestEnv, which I am not familiar with, but since you used it..
  • does the issue also reliably occur w/o TestEnv
  • if not, i.e. if it "requires" TestEnv to always occur, I need some precise instructions how you are using it. If I just enter using TestEnv ; TestEnv.activate() I get an error. So I am assuming you activate a specific environment/project? Which one? That of BrokenAqua.jl? A full session including the command you used to start Julia and all inputs would be helpful!

[fingolfin]

I've now tried to reproduce this on Windows, with Julia 1.9.0; I also tried it with TestEnv (using the assumption that you did Pkg.activate the (BrokenAqua package). Still couldn't reproduce it.

Waiting now to hear whether you can repo with Julia 1.8.5 and/or 1.9.0

[KeithWM]

For the BrokenAqua.jl repo, I did not need TestEnv nor ReTest for it to fail.

I just tried it on my Mac with Julia 1.8.3, and it passes there too. So it might be a Windows issue more than anything else. And it appears to only happen with PlotlyJS as a dependency.

I will install Julia 1.9 on one of the Windows machine I have access to and try that. (Not to brag 😁 .)

[KeithWM]

Just tried on a Windows 10 system and it also hangs.

After ctrl-c:

(BrokenAqua) pkg> test
     Testing BrokenAqua
      Status `C:\Users\myerscoughk\AppData\Local\Temp\jl_FORm6V\Project.toml` 
  [4c88cf16] Aqua v0.6.2
  [c2512556] BrokenAqua v0.1.0 `C:\Users\myerscoughk\SQM\review\BrokenAqua.jl`
  [8dfed614] Test `@stdlib/Test`
      Status `C:\Users\myerscoughk\AppData\Local\Temp\jl_FORm6V\Manifest.toml`
  [4c88cf16] Aqua v0.6.2
  [bf4720bc] AssetRegistry v0.1.0
  [d1d4a3ce] BitFlags v0.1.7     
  [ad839575] Blink v0.12.7
  [c2512556] BrokenAqua v0.1.0 `C:\Users\myerscoughk\SQM\review\BrokenAqua.jl`
  [944b1d66] CodecZlib v0.7.1
  [35d6a980] ColorSchemes v3.21.0
  [3da002f7] ColorTypes v0.11.4
  [c3611d14] ColorVectorSpace v0.9.10
  [5ae59095] Colors v0.12.10
  [34da2185] Compat v4.6.1
  [f0e56b4a] ConcurrentUtilities v2.2.0
  [9a962f9c] DataAPI v1.15.0
  [e2d170a0] DataValueInterfaces v1.0.0
  [8bb1440f] DelimitedFiles v1.9.1
  [ffbed154] DocStringExtensions v0.9.3
  [53c48c17] FixedPointNumbers v0.8.4
  [de31a74c] FunctionalCollections v0.5.0
  [cd3eb016] HTTP v1.9.6
  [9fb69e20] Hiccup v0.2.2
  [92d709cd] IrrationalConstants v0.2.2
  [82899510] IteratorInterfaceExtensions v1.0.0
  [692b3bcd] JLLWrappers v1.4.1
  [97c1335a] JSExpr v0.5.4
  [682c06a0] JSON v0.21.4
  [b964fa9f] LaTeXStrings v1.3.0
  [50d2b5c4] Lazy v0.15.1
  [2ab3a3ac] LogExpFunctions v0.3.23
  [e6f89c97] LoggingExtras v1.0.0
  [1914dd2f] MacroTools v0.5.10
  [739be429] MbedTLS v1.1.7
  [ffc61752] Mustache v1.0.15
  [a975b10e] Mux v1.0.1
  [510215fc] Observables v0.5.4
  [4d8831e6] OpenSSL v1.4.1
  [bac558e1] OrderedCollections v1.6.0
  [d96e819e] Parameters v0.12.3
  [69de0a69] Parsers v2.5.10
  [fa939f87] Pidfile v1.3.0
  [a03496cd] PlotlyBase v0.8.19
  [f0f68f2c] PlotlyJS v0.18.10
  [aea7be01] PrecompileTools v1.1.1
  [21216c6a] Preferences v1.4.0
  [189a3867] Reexport v1.2.2
  [ae029012] Requires v1.3.0
  [777ac1f9] SimpleBufferStream v1.1.0
  [276daf66] SpecialFunctions v2.2.0
  [3783bdb8] TableTraits v1.0.1
  [bd369af6] Tables v1.10.1
  [62fd8b95] TensorCore v0.1.1
  [3bb67fe8] TranscodingStreams v0.9.13
  [5c2747f8] URIs v1.4.2
  [3a884ed6] UnPack v1.0.2
  [0f1e0344] WebIO v0.8.20
  [104b5d7c] WebSockets v1.6.0
  [cc8bc4a8] Widgets v0.6.6
  [f7e6163d] Kaleido_jll v0.2.1+0
  [458c3c95] OpenSSL_jll v3.0.9+0
  [efe28fd5] OpenSpecFun_jll v0.5.5+0
  [0dad84c5] ArgTools v1.1.1 `@stdlib/ArgTools`
  [56f22d72] Artifacts `@stdlib/Artifacts`
  [2a0f44e3] Base64 `@stdlib/Base64`
  [ade2ca70] Dates `@stdlib/Dates`
  [8ba89e20] Distributed `@stdlib/Distributed`
  [f43a241f] Downloads v1.6.0 `@stdlib/Downloads`
  [7b1f6079] FileWatching `@stdlib/FileWatching`
  [b77e0a4c] InteractiveUtils `@stdlib/InteractiveUtils`
  [b27032c2] LibCURL v0.6.3 `@stdlib/LibCURL`
  [76f85450] LibGit2 `@stdlib/LibGit2`
  [8f399da3] Libdl `@stdlib/Libdl`
  [37e2e46d] LinearAlgebra `@stdlib/LinearAlgebra`
  [56ddb016] Logging `@stdlib/Logging`
  [d6f4376e] Markdown `@stdlib/Markdown`
  [a63ad114] Mmap `@stdlib/Mmap`
  [ca575930] NetworkOptions v1.2.0 `@stdlib/NetworkOptions`
  [44cfe95a] Pkg v1.9.0 `@stdlib/Pkg`
  [de0858da] Printf `@stdlib/Printf`
  [3fa0cd96] REPL `@stdlib/REPL`
  [9a3f8284] Random `@stdlib/Random`
  [ea8e919c] SHA v0.7.0 `@stdlib/SHA`
  [9e88b42a] Serialization `@stdlib/Serialization`
  [6462fe0b] Sockets `@stdlib/Sockets`
  [2f01184e] SparseArrays `@stdlib/SparseArrays`
  [10745b16] Statistics v1.9.0 `@stdlib/Statistics`
  [fa267f1f] TOML v1.0.3 `@stdlib/TOML`
  [a4e569a6] Tar v1.10.0 `@stdlib/Tar`
  [8dfed614] Test `@stdlib/Test`
  [cf7118a7] UUIDs `@stdlib/UUIDs`
  [4ec0a83e] Unicode `@stdlib/Unicode`
  [e66e0078] CompilerSupportLibraries_jll v1.0.2+0 `@stdlib/CompilerSupportLibraries_jll`
  [deac9b47] LibCURL_jll v7.84.0+0 `@stdlib/LibCURL_jll`
  [29816b5a] LibSSH2_jll v1.10.2+0 `@stdlib/LibSSH2_jll`
  [c8ffd9c3] MbedTLS_jll v2.28.2+0 `@stdlib/MbedTLS_jll`
  [14a3606d] MozillaCACerts_jll v2022.10.11 `@stdlib/MozillaCACerts_jll`
  [4536629a] OpenBLAS_jll v0.3.21+4 `@stdlib/OpenBLAS_jll`
  [05823500] OpenLibm_jll v0.8.1+0 `@stdlib/OpenLibm_jll`
  [bea87d4a] SuiteSparse_jll v5.10.1+6 `@stdlib/SuiteSparse_jll`
  [83775a58] Zlib_jll v1.2.13+0 `@stdlib/Zlib_jll`
  [8e850b90] libblastrampoline_jll v5.7.0+0 `@stdlib/libblastrampoline_jll`
  [8e850ede] nghttp2_jll v1.48.0+0 `@stdlib/nghttp2_jll`
  [3f19e933] p7zip_jll v17.4.0+0 `@stdlib/p7zip_jll`
Precompiling project...
  60 dependencies successfully precompiled in 95 seconds. 6 already precompiled.
     Testing Running tests...

     Testing Tests interrupted. Exiting the test process

ERROR: LoadError: InterruptException:
Stacktrace:
  [1] poptask(W::Base.IntrusiveLinkedListSynchronized{Task})
    @ Base .\task.jl:974
  [2] wait()
    @ Base .\task.jl:983
  [3] wait(c::Base.GenericCondition{Base.Threads.SpinLock}; first::Bool)
    @ Base .\condition.jl:130
  [4] wait
    @ .\condition.jl:125 [inlined]
  [5] wait_readnb(x::Base.PipeEndpoint, nb::Int64)
    @ Base .\stream.jl:416
  [6] read(stream::Base.PipeEndpoint)
    @ Base .\stream.jl:930
  [7] read(cmd::Cmd)
    @ Base .\process.jl:448
  [8] read
    @ .\process.jl:458 [inlined]
  [9] _analyze_stale_deps_1(pkg::Base.PkgId; ignore::Vector{Symbol})
    @ Aqua C:\Users\myerscoughk\.julia\packages\Aqua\7PMmc\src\stale_deps.jl:56
 [10] _analyze_stale_deps_1
    @ C:\Users\myerscoughk\.julia\packages\Aqua\7PMmc\src\stale_deps.jl:31 [inlined]
 [11] #30
    @ .\none:0 [inlined]
 [12] iterate
    @ .\generator.jl:47 [inlined]
 [13] collect(itr::Base.Generator{Vector{Base.PkgId}, Aqua.var"#30#31"{Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}}}})
    @ Base .\array.jl:782
 [14] analyze_stale_deps
    @ C:\Users\myerscoughk\.julia\packages\Aqua\7PMmc\src\stale_deps.jl:28 [inlined]
 [15] macro expansion
    @ C:\Users\myerscoughk\AppData\Local\Programs\Julia-1.9.0\share\julia\stdlib\v1.9\Test\src\Test.jl:1609 [inlined] 
 [16] test_stale_deps(packages::Module; kwargs::Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
    @ Aqua C:\Users\myerscoughk\.julia\packages\Aqua\7PMmc\src\stale_deps.jl:21
 [17] test_stale_deps(packages::Module)
    @ Aqua C:\Users\myerscoughk\.julia\packages\Aqua\7PMmc\src\stale_deps.jl:20
 [18] top-level scope
    @ C:\Users\myerscoughk\SQM\review\BrokenAqua.jl\test\runtests.jl:6
 [19] include(fname::String)
    @ Base.MainInclude .\client.jl:478
 [20] top-level scope
    @ none:6
in expression starting at C:\Users\myerscoughk\SQM\review\BrokenAqua.jl\test\runtests.jl:6

(BrokenAqua) pkg> 

[KeithWM]

Tried it on a different Windows machine and there it passes on 1.8.3 and 1.9.0.

I tried it both before and after doing an up and it works in both cases. The only delta in the environment after an up compared to the test for 1.9.0 on the other machine posted above is

  [2ab3a3ac] LogExpFunctions v0.3.24
  [aea7be01] PrecompileTools v1.1.2

I suspect these two packages happen to have had an update over the past day and a half.

So the issue does seem to be rare. Any ideas/suggestions/requests on other things to try?

[fingolfin]

Hmm... Could you please verify that using PlotlyJS on its own in the REPL works? Does it make a difference if you do it right before starting the Aqua test?

It might help to enable debug logging.

So right before you invoke Aqua, you could do ENV["JULIA_DEBUG"] = "all" and perhaps the additional logging will reveal something helpful.