I see the same thing, only that my computer is so fast that with 1.11 I might have 0.2s delay where you report 1s delay.
And I would say that this is to be expected because the REPL is no longer part to the system image.
julia> versioninfo()
Julia Version 1.11.1
Commit 8f5b7ca12ad (2024-10-16 10:53 UTC)
Build Info:
Official https://julialang.org/ release
Platform Info:
OS: Linux (x86_64-linux-gnu)
CPU: 8 Γ Intel(R) Core(TM) i7-10510U CPU @ 1.80GHz
WORD_SIZE: 64
LLVM: libLLVM-16.0.6 (ORCJIT, skylake)
Threads: 1 default, 0 interactive, 1 GC (on 8 virtual cores)
@ufechner7 show-off 
Closer inspection suggests my delay is closer to 500-600ms, but that still feels sluggish.
Not quite, both startup-file=no are fast with Julia 1.11.1 vs 1.10.4
ββ(13:40:10)ββ> time julia-1.10.4 --startup-file="no" -e "exit()" ββ(Do,Okt17)ββ
julia-1.10.4 --startup-file="no" -e "exit()" 0.06s user 0.10s system 127% cpu 0.126 total
(base) ββ(/tmp)ββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββ(felix@saturn:pts/8)ββ
ββ(13:40:17)ββ> time julia-1.10.4 --startup-file="yes" -e "exit()" ββ(Do,Okt17)ββ
At startup Revise.jl and !OhMyREPL.jl loadedjulia-1.10.4 --startup-file="yes" -e "exit()" 0.34s user 0.83s system 343% cpu 0.342 total
(base) ββ(/tmp)ββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββ(felix@saturn:pts/8)ββ
ββ(13:40:19)ββ> time julia-1.11 --startup-file="no" -e "exit()" ββ(Do,Okt17)ββ
julia-1.11 --startup-file="no" -e "exit()" 0.07s user 0.06s system 130% cpu 0.105 total
(base) ββ(/tmp)ββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββ(felix@saturn:pts/8)ββ
ββ(13:40:31)ββ> time julia-1.11 --startup-file="yes" -e "exit()" ββ(Do,Okt17)ββ
At startup Revise.jl and !OhMyREPL.jl loadedjulia-1.11 --startup-file="yes" -e "exit()" 1.69s user 0.23s system 202% cpu 0.946 total
I donβt think that measures the interactive mode initialization. If I use -e "exit()" all versions are quite fast:
~ $ time julia +1.11.1 --startup-file=no -e "exit()"
________________________________________________________
Executed in 145.18 millis fish external
usr time 84.10 millis 0.76 millis 83.34 millis
sys time 63.36 millis 1.14 millis 62.22 millis
~ $ time julia +1.10 --startup-file=no -e "exit()"
________________________________________________________
Executed in 153.63 millis fish external
usr time 92.41 millis 0.41 millis 91.99 millis
sys time 65.85 millis 1.06 millis 64.79 millis
Itβs only when I let Julia show the banner and REPL that itβs slow.
Does that make a difference?
ββ(13:49:12)ββ> time julia-1.11 --startup-file=no -e "using REPL; exit()" ββ(Do,Okt17)ββ
julia-1.11 --startup-file=no -e "using REPL; exit()" 1.00s user 0.10s system 398% cpu 0.274 total
(base) ββ(~)βββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββββ(felix@saturn:pts/8)ββ
ββ(13:49:15)ββ> time julia --startup-file=no -e "using REPL; exit()" ββ(Do,Okt17)ββ
The latest version of Julia in the `release` channel is 1.11.1+0.x64.linux.gnu. You currently have `1.10.5+0.x64.linux.gnu` installed. Run:
juliaup update
in your terminal shell to install Julia 1.11.1+0.x64.linux.gnu and update the `release` channel to that version.
julia --startup-file=no -e "using REPL; exit()" 0.07s user 0.10s system 129% cpu 0.134 total
ufechner@framework:~$ time julia +1.11 --startup-file=no -e "using REPL; exit()"
real 0m0,248s
user 0m0,742s
sys 0m0,076s
ufechner@framework:~$ time julia +1.10 --startup-file=no -e "using REPL; exit()"
real 0m0,111s
user 0m0,051s
sys 0m0,070s
As expected. You can always create your own system image that contains the REPL if you donβt like this change. I am not getting nervous if I have to wait 0.25 s. Did you have used Matlab? There you probably have to wait 10s to get a prompt.
Yep that accounts for most of the new latency:
~ $ time julia +1.10 --startup-file=no -e "using REPL; exit()"
________________________________________________________
Executed in 154.40 millis fish external
usr time 98.02 millis 80.00 micros 97.94 millis
sys time 62.90 millis 949.00 micros 61.95 millis
~ $ time julia +1.11.1 --startup-file=no -e "using REPL; exit()"
________________________________________________________
Executed in 401.48 millis fish external
usr time 674.65 millis 8.00 micros 674.64 millis
sys time 75.98 millis 923.00 micros 75.06 millis
Obviously not a deal breaker but I think itβs really too bad to lose that snappy feeling that Julia got in recent versionsβ¦
2 Likes
I think my PR addresses this if backported to 1.11.2 (I thought I forgot print actually, but itβs covered by println that calls it, I believe), I just added precompile to it:
Iβve been working on eliminating allocations, and the last one is quite the rabbit hole to figure out and get rid of (I know possible, at least for single-threaded code)
Iβve already matched 1.10/fixed the 1.11 regression, and actually improved on 1.10/1.11, but getting even better to 0 allocations is elusive:
julia> @edit write(stdout, "1");
julia> s= "1"; io=stdout
Base.TTY(RawFD(15) open, 0 bytes waiting)
julia> @time write(stdout, "1"); # but what it calls below, basically, adds 1 allocation, not sure why:
1 0.000045 seconds (1 allocation: 16 bytes)
julia> @time GC.@preserve s unsafe_write(stdout, pointer(s), UInt(1));
1 0.000074 seconds (2 allocations: 32 bytes)
julia> test2() = (s = "1"; GC.@preserve s unsafe_write(stdout, pointer(s), UInt(1));)
test2 (generic function with 1 method)
julia> @time test2();
1 0.000053 seconds (2 allocations: 32 bytes)
It does actually print, not sure why segfaults right after (and thus can't count its supposed non-allocations):
julia> Base.uv_write(stdout, pointer(s), UInt(1));
1
[215864] signal (11.1): Segmentation fault
julia> @time (GC.@preserve s (Base.iolock_begin(); Base.uv_write(stdout, pointer(s), UInt(1)); Base.iolock_end()))
1
[238190] signal (11.1): Segmentation fault
in expression starting at REPL[2]:1
jl_mutex_unlock_nogc at /cache/build/builder-amdci4-4/julialang/julia-release-1-dot-10/src/julia_locks.h:85 [inlined]
...
Thatβs in 1.10.5. I actually get less info in 1.11.1, just:
julia> @time (GC.@preserve s (Base.iolock_begin(); Base.uv_write(stdout, pointer(s), UInt(1)); Base.iolock_end()))
1Segmentation fault (core dumped)
Iβve see take! in code (right before the other uv_write there), that I think is responsible for allocation (as opposed to the locking), and maybe _unsafe_take!(s)) is the solution like here?:
3 Likes
I just tried this PR, and some things are different but for me the overall timing is the same. In details:
With this PR, @time_imports doesnβt report any compilation, and @time reports a shorter time, but the actual total time (from shell time) is not affected:
$ time julia +1.11.1 --startup-file=no -e "using InteractiveUtils; @time @time_imports using REPL"
44.7 ms StyledStrings
0.2 ms Unicode
β 0.0 ms REPL.REPLCompletions.__init__()
β 0.0 ms REPL.TerminalMenus.__init__()
β 0.0 ms REPL.__init__()
266.0 ms REPL 41.03% compilation time
0.353727 seconds (496.07 k allocations: 27.602 MiB, 40.60% compilation time)
________________________________________________________
Executed in 582.45 millis fish external
usr time 837.22 millis 0.73 millis 836.49 millis
sys time 94.42 millis 2.06 millis 92.36 millis
$ time ./julia --startup-file=no -e "using InteractiveUtils; @time @time_imports using REPL"
0.2 ms Unicode
β 0.0 ms REPL.REPLCompletions.__init__()
β 0.0 ms REPL.__init__()
163.0 ms REPL
0.169121 seconds (160.80 k allocations: 9.175 MiB)
________________________________________________________
Executed in 597.49 millis fish external
usr time 854.20 millis 1.00 micros 854.20 millis
sys time 92.03 millis 980.00 micros 91.05 millis
and when tracing a real interactive session (not with julia -e but starting Julia and exiting with Ctrl+d) I see more compilation reported:
With julia +1.11.1 --startup-file=no --trace-compile=stderr:
precompile(Tuple{typeof(Base.print), Base.TTY, String})
With ./julia --startup-file=no --trace-compile=stderr:
precompile(Tuple{typeof(Base.print_to_string), String, String, String, String, String, String, String, String, String, String, Vararg{Any}}) precompile(Tuple{Base.var"#readcb_specialized#uv_readcb##0", Base.TTY, Int64, UInt64})
precompile(Tuple{typeof(Base.peek), Base.TTY, Type{UInt8}})
precompile(Tuple{typeof(Base.get), Base.Dict{Char, Any}, Char, Nothing})
precompile(Tuple{Base.Returns{Symbol}, Any})
precompile(Tuple{typeof(Base.indexed_iterate), Tuple{Base.GenericIOBuffer{Memory{UInt8}}, Bool, Bool}, Int64})
precompile(Tuple{typeof(Base.indexed_iterate), Tuple{Base.GenericIOBuffer{Memory{UInt8}}, Bool, Bool}, Int64, Int64}) # recompile