Slow start up and package loading times

Michael_Barmann · December 30, 2020, 11:57pm

I’m new to Julia, and I’m a little dismayed by what seems like excessively long times for starting up the kernel and and loading packages. First I timed how long it took for julia> to appear in the REPL, starting from the moment I hit enter. This took 21 seconds. Then I used the @time macro to check the package loading times for my most commonly used packages (see screenshot of results below). using DifferentialEquations alone took more than a minute…Is this normal? I hate to think that every time I start a new kernel I have to wait ~21 seconds to do anything, and then another ~90s just to load packages when starting a new script. Is there anything I can do to speed this up?

ianshmean · December 31, 2020, 12:32am

Load time will be improving in 1.6, but for 1.5.3 your load times seem excessively slow. using Plots; gr() takes 8.9s for me on 1.5.3 on MacOS and 10.8s on Windows, 2x faster than yours.

(I don’t believe the times you’ve reported include precompilation, but please correct me if not. i.e. the times you report aren’t the first time the packages have been loaded.)

I notice you’re on windows. What kind of drive is your .julia depot on? If that sits on a network drive it’s known to cause significant slowdown on windows.

Or alternatively is your system older/lower power?

Also, do you have anything in your .julia/confit/startup.jl? If not, 21 seconds to start julia is ~80x slower than it should be…

AndiMD · December 31, 2020, 3:14am

You could build a custom sysimage with all the slow packages using PackageCompiler.jl. It is relatively straightforward to use:
https://julialang.github.io/PackageCompiler.jl/dev/sysimages/

ianshmean · December 31, 2020, 3:32am

I’d recommend figuring out why basic loading times are so slow before trying out PackageCompiler

CameronBieganek · December 31, 2020, 3:40am

No, 21 seconds to start the Julia REPL is not normal. When I launch Julia v1.5 in the Terminal on MacOS, it starts in about a second or less.

DNF · December 31, 2020, 8:48am

Starting Julia both on my new and my 7 years old laptop definitely takes less than one second, it’s almost instant.

Do you have a lot of stuff in your startup.jl?

Hm. Are you running it in Atom? Perhaps that’s part of the problem. How long does it take to start in a terminal?

albertoguiggiani · January 1, 2021, 2:03am

My loading times were nowhere slow as yours, but I recently switched from Atom to VS Code and noticed a sensible improvement in both starting the REPL and using modules.

You can check this talk for a brief tutorial in setting it up:

Michael_Barmann · January 1, 2021, 2:37am

Hi, thanks for your reply. This was not the first time I loaded the packages. And I have .julia installed in C:/Users/Michael, though I save my Julia scripts to C:/Users/Michael/Documents/Julia. And I have my entire Documents folder synced to my Google Drive…does that count as a “network drive”? And I don’t see any folder in julia called confit.

Here’s my computer info: ASUS ZenBook UX303UA 13.3-Inch FHD Touchscreen Laptop, Intel Core i5, 8 GB RAM, 256 GB SSD, Windows 10 (64 bit). I use Python 3.7 + Spyder regularly and I’ve never had issues with slow load times. It generally works really well.

Also, I downloaded Julia Pro. Does that make a difference? I see that it comes with a lot of extra stuff, so would that possibly increase the load times?

ianshmean · January 1, 2021, 3:54pm

You might want to try moving the julia installation out of google drive.

Also, you could try and see how your system compares to a reference system by running this, which may help identify if it’s a disk, memory, or cpu speed issue

using SystemBenchmark
comparetoref()

https://github.com/ianshmean/SystemBenchmark.jl

PetrKryslUCSD · January 1, 2021, 4:23pm

Thanks for making the benchmark suite. Looks pretty spiffy. I did get an error (which I reported), so it hasn’t finished on my system.

I will try to read the documentation to your package, but if you have a quick answer that’ll be great:
I wonder if you are aware of the conversation we’ve had on discourse sometime ago about slow registry installation/operations on Windows, for instance Why is the update of the registries so slow?? Does your tool investigate this as well?

ianshmean · January 1, 2021, 5:24pm

Thanks for the report. I’ve seen that Windows can hang onto files even after the GC completes, which I added a pause for previously, and increased here. Would you mind giving it another go with this PR?
https://github.com/ianshmean/SystemBenchmark.jl/pull/33

As for the slow registry update issue, the disk io benchmarks may suffer from the same issue given that they read/write to a file in the julia depot, so would likely be monitored in the same way by windows defender (I believe that was the main cause of slow down, but I may be uninformed)

SystemBenchmark needs some love. It was put together rather quickly and I’ve not maintained it since. With 1.6 on the horizon it’s good incentive to tidy it up and review the tests.

Michael_Barmann · January 1, 2021, 6:23pm

Hi Ian:

I moved my julia programs folder directly into my C drive, and the load time was a little better–about 16 seconds. Also, Differential Equations loaded in 46.9s this time.
I ran the benchmark program and got this:

Look like it encountered some issue…

I found the startup.jl file that you asked about earlier. Here it is:

# DO NOT EDIT THIS FILE, Use <HOME-DIRECTORY>\\.julia\\config\\startup.jl instead

ENV["JULIA_PKG_SERVER"] = get(ENV, "JULIA_PKG_SERVER", "pkg.juliahub.com")
using Pkg
const is_authenticating = Ref(false)

function register_auth_handler(pkgserver::Union{Regex, AbstractString})
    tries = 0
    return Pkg.PlatformEngines.register_auth_error_handler(pkgserver, (url, svr, err) -> begin
        tries += 1
        if is_authenticating[]
            return true, tries < 3
        end
        is_authenticating[] = true
        server = string(svr, "/auth")
        PkgAuthentication_path = joinpath(DEPOT_PATH[1],"dev","PkgAuthentication")
        cmd = ```
            $(first(Base.julia_cmd()))
            --project=PkgAuthentication_path
            -e "using PkgAuthentication; PkgAuthentication.authenticate(\"$(server)\")"
            ```
        try
            run(cmd, wait = true)
        catch err
            @error "JuliaTeam authentication handler failed."
            return false, false
        finally
            is_authenticating[] = false
        end
        return true, tries < 3
    end)
end
register_auth_handler(ENV["JULIA_PKG_SERVER"])

pushfirst!(LOAD_PATH, normpath(joinpath(DEPOT_PATH[1],"environments","JuliaPro_v1.5.3-1")))
ENV["JULIA_DEPOT_PATH"]=join(DEPOT_PATH, ";")
ENV["JULIA_LOAD_PATH"]=join(LOAD_PATH, ";")

PetrKryslUCSD · January 1, 2021, 7:13pm

Looks like the problem that was just fixed in a PR (https://github.com/ianshmean/SystemBenchmark.jl/pulls)

ianshmean · January 1, 2021, 10:30pm

Yes, hopefully it fixes the problem for @Michael_Barmann too. (thanks for testing it @PetrKryslUCSD)

@Michael_Barmann, the PR is merged so please retry in a fresh session with

pkg> add SystemBenchmark#master
pkg> update
julia> using SystemBenchmark
julia> comparetoref()

Michael_Barmann · January 1, 2021, 11:45pm

I followed your instructions but I keep getting the same exact error message. (I even tried it 3 times, just to be sure.) Do I need to go to Github and download the new version of the package from there directly?

ianshmean · January 2, 2021, 6:49am

@Michael_Barmann try this

Restart julia
run this

pkg> activate --temp
pkg> add SystemBenchmark#master
julia> using SystemBenchmark
julia> comparetoref()

Copy all the terminal text from the very start of the session and paste here as a code snippet

PetrKryslUCSD · January 2, 2021, 4:21pm

The first line needs to be --temp.

ianshmean · January 2, 2021, 4:23pm

Thanks. My phone converts two dashes into a long dash, and I didn’t notice

Michael_Barmann · January 2, 2021, 6:31pm

Alright, here it is:


Starting Julia...
               _
   _       _ _(_)_     |  Documentation: https://docs.julialang.org
  (_)     | (_) (_)    |
   _ _   _| |_  __ _   |  Type "?" for help, "]?" for Pkg help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 1.5.3 (2020-11-09)
 _/ |\__'_|_|_|\__'_|  |  Official https://julialang.org/ release
|__/                   |

(@JuliaPro_v1.5.3-1) pkg> activate --temp
 Activating new environment at `C:\Users\Michael\AppData\Local\Temp\jl_TI2Md7\Project.toml`

(jl_TI2Md7) pkg> add SystemBenchmark#master
    Cloning git-repo `https://github.com/ianshmean/SystemBenchmark.jl.git`
   Updating git-repo `https://github.com/ianshmean/SystemBenchmark.jl.git`
   Updating registry at `C:\Users\Michael\.julia\registries\General`
   Updating registry at `C:\Users\Michael\.julia\registries\JuliaComputingRegistry`
   Updating registry at `C:\Users\Michael\.julia\registries\JuliaPro`
  Resolving package versions...
  Installed BFloat16s ─── v0.1.0
  Installed URIs ──────── v1.1.0
  Installed GPUCompiler ─ v0.8.3
  Installed HTTP ──────── v0.9.2
  Installed LLVM ──────── v3.5.1
  Installed GPUArrays ─── v6.1.2
  Installed VideoIO ───── v0.8.4
  Installed CUDA ──────── v2.3.0
Updating `C:\Users\Michael\AppData\Local\Temp\jl_TI2Md7\Project.toml`
  [30cdaa97] + SystemBenchmark v0.3.4 `https://github.com/ianshmean/SystemBenchmark.jl.git#master`
Updating `C:\Users\Michael\AppData\Local\Temp\jl_TI2Md7\Manifest.toml`
  [621f4979] + AbstractFFTs v0.5.0
  [79e6a3ab] + Adapt v2.3.0
  [56f22d72] + Artifacts v1.3.0
  [13072b0f] + AxisAlgorithms v1.0.0
  [ab4f0b2a] + BFloat16s v0.1.0
  [6e4b80f9] + BenchmarkTools v0.5.0
  [6e34b625] + Bzip2_jll v1.0.6+5
  [fa961155] + CEnum v0.4.1
  [336ed68f] + CSV v0.8.2
  [052768ef] + CUDA v2.3.0
  [324d7699] + CategoricalArrays v0.9.0
  [d360d2e6] + ChainRulesCore v0.9.24
  [3da002f7] + ColorTypes v0.10.9
  [c3611d14] + ColorVectorSpace v0.8.7
  [5ae59095] + Colors v0.12.6
  [34da2185] + Compat v3.25.0
  [e66e0078] + CompilerSupportLibraries_jll v0.3.4+0
  [150eb455] + CoordinateTransformations v0.6.1
  [a8cc5b0e] + Crayons v4.0.4
  [9a962f9c] + DataAPI v1.4.0
  [a93c6f00] + DataFrames v0.22.2
  [864edb3b] + DataStructures v0.18.8
  [e2d170a0] + DataValueInterfaces v1.0.0
  [e2ba6199] + ExprTools v0.1.3
  [c87230d0] + FFMPEG v0.4.0
  [b22a6f82] + FFMPEG_jll v4.3.1+4
  [53c48c17] + FixedPointNumbers v0.8.4
  [59287772] + Formatting v0.4.2
  [d7e528f0] + FreeType2_jll v2.10.1+5
  [559328eb] + FriBidi_jll v1.0.5+6
  [0c68f7d7] + GPUArrays v6.1.2
  [61eb1bfa] + GPUCompiler v0.8.3
  [bc5e4493] + GitHub v5.4.0
  [c27321d9] + Glob v1.3.0
  [a2bd30eb] + Graphics v1.0.2
  [cd3eb016] + HTTP v0.9.2
  [bbac6d45] + IdentityRanges v0.3.1
  [a09fc81d] + ImageCore v0.8.20
  [02fcd773] + ImageTransformations v0.8.8
  [83e8ac13] + IniFile v0.5.0
  [a98d9a8b] + Interpolations v0.13.1
  [41ab1584] + InvertedIndices v1.0.0
  [82899510] + IteratorInterfaceExtensions v1.0.0
  [692b3bcd] + JLLWrappers v1.1.4
  [682c06a0] + JSON v0.21.1
  [c1c5ebd0] + LAME_jll v3.100.0+3
  [929cbde3] + LLVM v3.5.1
  [dd192d2f] + LibVPX_jll v1.9.0+1
  [1914dd2f] + MacroTools v0.5.6
  [dbb5928d] + MappedArrays v0.3.0
  [739be429] + MbedTLS v1.0.3
  [c8ffd9c3] + MbedTLS_jll v2.16.8+1
  [e1d29d7a] + Missings v0.4.4
  [e94cdb99] + MosaicViews v0.2.4
  [46d2c3a1] + MuladdMacro v0.2.2
  [872c559c] + NNlib v0.7.9
  [77ba4419] + NaNMath v0.3.5
  [6fe1bfb0] + OffsetArrays v1.4.2
  [e7412a2a] + Ogg_jll v1.3.4+2
  [458c3c95] + OpenSSL_jll v1.1.1+6
  [efe28fd5] + OpenSpecFun_jll v0.5.3+4
  [91d4177d] + Opus_jll v1.3.1+3
  [bac558e1] + OrderedCollections v1.3.2
  [5432bcbf] + PaddedViews v0.5.7
  [69de0a69] + Parsers v1.0.15
  [2dfb63ee] + PooledArrays v0.5.3
  [08abe8d2] + PrettyTables v0.10.1
  [92933f4c] + ProgressMeter v1.4.1
  [c84ed2f1] + Ratios v0.4.0
  [189a3867] + Reexport v0.2.0
  [ae029012] + Requires v1.1.2
  [6038ab10] + Rotations v1.0.2
  [6c6a2e73] + Scratch v1.0.3
  [91c51154] + SentinelArrays v1.2.16
  [2133526b] + SodiumSeal v0.1.1
  [a2af1166] + SortingAlgorithms v0.3.1
  [276daf66] + SpecialFunctions v1.2.1
  [90137ffa] + StaticArrays v1.0.1
  [2913bbd2] + StatsBase v0.33.2
  [856f2bd8] + StructTypes v1.2.1
  [30cdaa97] + SystemBenchmark v0.3.4 `https://github.com/ianshmean/SystemBenchmark.jl.git#master`
  [3783bdb8] + TableTraits v1.0.0
  [bd369af6] + Tables v1.2.2
  [a759f4b9] + TimerOutputs v0.5.7
  [5c2747f8] + URIs v1.1.0
  [d6d074c3] + VideoIO v0.8.4
  [efce3f68] + WoodburyMatrices v0.5.3
  [83775a58] + Zlib_jll v1.2.11+18
  [0ac62f75] + libass_jll v0.14.0+4
  [f638f0a6] + libfdk_aac_jll v0.1.6+4
  [a9144af2] + libsodium_jll v1.0.18+1
  [f27f6e37] + libvorbis_jll v1.3.6+6
  [1270edf5] + x264_jll v2020.7.14+2
  [dfaa095f] + x265_jll v3.0.0+3
  [2a0f44e3] + Base64
  [ade2ca70] + Dates
  [8bb1440f] + DelimitedFiles
  [8ba89e20] + Distributed
  [9fa8497b] + Future
  [b77e0a4c] + InteractiveUtils
  [76f85450] + LibGit2
  [8f399da3] + Libdl
  [37e2e46d] + LinearAlgebra
  [56ddb016] + Logging
  [d6f4376e] + Markdown
  [a63ad114] + Mmap
  [44cfe95a] + Pkg
  [de0858da] + Printf
  [3fa0cd96] + REPL
  [9a3f8284] + Random
  [ea8e919c] + SHA
  [9e88b42a] + Serialization
  [1a1011a3] + SharedArrays
  [6462fe0b] + Sockets
  [2f01184e] + SparseArrays
  [10745b16] + Statistics
  [8dfed614] + Test
  [cf7118a7] + UUIDs
  [4ec0a83e] + Unicode

julia> using SystemBenchmark

julia> comparetoref()
[ Info: CUDA.functional() == false. No usable GPU detected
Compilation tests 86%|████████████████████████████████████████████████████████████████████████████████████████████████████████████████████                   |  ETA: 0:00:31ERROR: IOError: unlink: resource busy or locked (EBUSY)
Stacktrace:
 [1] uv_error at .\libuv.jl:97 [inlined]
 [2] unlink(::String) at .\file.jl:918
 [3] rm(::String; force::Bool, recursive::Bool) at .\file.jl:268
 [4] create_expr_cache(::String, ::String, ::Array{Pair{Base.PkgId,UInt64},1}, ::Nothing) at .\loading.jl:1166
 [5] ##core#344(::String, ::String, ::Array{Pair{Base.PkgId,UInt64},1}, ::Base.PkgId) at C:\Users\Michael\.julia\packages\BenchmarkTools\eCEpo\src\execution.jl:371
 [6] ##sample#345(::BenchmarkTools.Parameters) at C:\Users\Michael\.julia\packages\BenchmarkTools\eCEpo\src\execution.jl:377
 [7] sample at C:\Users\Michael\.julia\packages\BenchmarkTools\eCEpo\src\execution.jl:394 [inlined]
 [8] _lineartrial(::BenchmarkTools.Benchmark{Symbol("##benchmark#343")}, ::BenchmarkTools.Parameters; maxevals::Int64, kwargs::Base.Iterators.Pairs{Union{},Union{},Tuple{},NamedTuple{(),Tuple{}}}) at C:\Users\Michael\.julia\packages\BenchmarkTools\eCEpo\src\execution.jl:133
 [9] _lineartrial(::BenchmarkTools.Benchmark{Symbol("##benchmark#343")}, ::BenchmarkTools.Parameters) at C:\Users\Michael\.julia\packages\BenchmarkTools\eCEpo\src\execution.jl:125  
 [10] #invokelatest#1 at .\essentials.jl:710 [inlined]
 [11] invokelatest at .\essentials.jl:709 [inlined]
 [12] #lineartrial#38 at C:\Users\Michael\.julia\packages\BenchmarkTools\eCEpo\src\execution.jl:33 [inlined]
 [13] lineartrial at C:\Users\Michael\.julia\packages\BenchmarkTools\eCEpo\src\execution.jl:33 [inlined]
 [14] tune!(::BenchmarkTools.Benchmark{Symbol("##benchmark#343")}, ::BenchmarkTools.Parameters; progressid::Nothing, nleaves::Float64, ndone::Float64, verbose::Bool, pad::String, kwargs::Base.Iterators.Pairs{Union{},Union{},Tuple{},NamedTuple{(),Tuple{}}}) at C:\Users\Michael\.julia\packages\BenchmarkTools\eCEpo\src\execution.jl:209
 [15] tune! at C:\Users\Michael\.julia\packages\BenchmarkTools\eCEpo\src\execution.jl:208 [inlined] (repeats 2 times)
 [16] macro expansion at C:\Users\Michael\.julia\packages\BenchmarkTools\eCEpo\src\execution.jl:288 [inlined]
 [17] runbenchmark(; printsysinfo::Bool) at C:\Users\Michael\.julia\packages\SystemBenchmark\deI1I\src\SystemBenchmark.jl:180
 [18] comparetoref() at C:\Users\Michael\.julia\packages\SystemBenchmark\deI1I\src\SystemBenchmark.jl:93
 [19] top-level scope at none:1

julia>

ianshmean · January 2, 2021, 7:04pm

Thanks.

Ok, so SystemBenchmark makes an assumption about when the files under test will be freed, given there appears to be a file freeing bug on windows, and whatever is causing your system to run slowly is exceeding that assumption.

I’ve allowed that delay to be adjustable. Can you retry with this in a fresh session:

pkg> activate --temp
pkg> add SystemBenchmark#ib/adjustable_slowgc
julia> using SystemBenchmark
julia> comparetoref(slowgcsleep=1.5)

and if that still errors, re-run the last line increasing slowgcsleep=1.5 which is delay in seconds. It’s 1 second on master.

Thanks for persevering!