GenieFramework / Genie.jl

🧞The highly productive Julia web framework
https://genieframework.com
MIT License
2.27k stars 192 forks source link

Performance improvements for `using Genie` #447

Open PallHaraldsson opened 2 years ago

PallHaraldsson commented 2 years ago

A. Went from tolerable, not fast, in Julia 1.6.0:

julia> @time using Genie
  1.984320 seconds (2.42 M allocations: 157.321 MiB, 3.01% gc time, 0.33% compilation time)

to, in just released, Julia 1.7.0:

julia> @time using Genie
 19.792401 seconds (36.84 M allocations: 1.695 GiB, 5.98% gc time, 89.93% compilation time)

Precompiling was already slow, and I was hoping it would pay off:

julia> @time using Genie
[ Info: Precompiling Genie [c43c736e-a2d1-11e8-161f-af95117fbd1e]
 90.177432 seconds (36.66 M allocations: 1.691 GiB, 1.38% gc time, 19.97% compilation time)

it turned out I was on the latest version, while on v3.0.0 for Julia 1.6 and using that version is still slightly slower in 1.7:

julia> @time using Genie
  2.146188 seconds (2.69 M allocations: 155.669 MiB, 0.94% gc time, 60.14% compilation time)

for v4.0.0:

julia> @time using Genie
  3.234528 seconds (4.21 M allocations: 250.503 MiB, 2.85% gc time, 40.49% compilation time)

for v4.1.0:

julia> @time using Genie
 19.665928 seconds (36.83 M allocations: 1.694 GiB, 5.78% gc time, 90.08% compilation time)

Do you have any idea what may have caused this?

I tried on 1.6:

(@v1.6) pkg> add Genie@v4.4.1
   Resolving package versions...
ERROR: Unsatisfiable requirements detected for package Atom [c52e3926]:
 Atom [c52e3926] log:
 ├─possible versions are: 0.8.0-0.12.35 or uninstalled
 ├─restricted to versions * by an explicit requirement, leaving only versions 0.8.0-0.12.35
 ├─restricted by compatibility requirements with JuliaFormatter [98e50ef6] to versions: 0.8.0-0.8.8 or uninstalled, leaving only versions: 0.8.0-0.8.8
 │ └─JuliaFormatter [98e50ef6] log:
 │   ├─possible versions are: 0.1.0-0.19.2 or uninstalled
 │   └─restricted by compatibility requirements with Genie [c43c736e] to versions: 0.15.0-0.15.11
 │     └─Genie [c43c736e] log:
 │       ├─possible versions are: 0.9.4-4.4.1 or uninstalled
 │       └─restricted to versions 4.4.1 by an explicit requirement, leaving only versions 4.4.1
 └─restricted by compatibility requirements with Requires [ae029012] to versions: 0.12.0-0.12.35 or uninstalled — no versions left
   └─Requires [ae029012] log:
     ├─possible versions are: 0.5.0-1.1.3 or uninstalled
     └─restricted by compatibility requirements with Tullio [bc48ee85] to versions: 1.0.0-1.1.3
       └─Tullio [bc48ee85] log:
         ├─possible versions are: 0.1.0-0.3.2 or uninstalled
         └─restricted to versions * by MicroHH [9dba9f50], leaving only versions 0.1.0-0.3.2
           └─MicroHH [9dba9f50] log:
             ├─possible versions are: 0.1.0 or uninstalled
             └─MicroHH [9dba9f50] is fixed to version 0.1.0

This could be about your dependencies, since downgrading Genie on Julia 1.7 made it fast and upgrading again, made it slow again and showed:

(@v1.7) pkg> add Genie@v4.4.1
   Resolving package versions...
    Updating `~/.julia/environments/v1.7/Project.toml`
  [c43c736e] ↑ Genie v3.0.0 ⇒ v4.4.1
  [98e50ef6] ↑ JuliaFormatter v0.13.10 ⇒ v0.15.11
    Updating `~/.julia/environments/v1.7/Manifest.toml`
  [00ebfdb7] ↑ CSTParser v2.5.0 ⇒ v3.3.0
  [c43c736e] ↑ Genie v3.0.0 ⇒ v4.4.1
  [98e50ef6] ↑ JuliaFormatter v0.13.10 ⇒ v0.15.11
  [0796e94c] ↑ Tokenize v0.5.13 ⇒ v0.5.21
  [856ac37a] + UrlDownload v1.0.0
  [a637dc6b] + VersionCheck v0.2.0

I tried with an empty .julia folder so that's not it.

I'm willing to look into this, while good if first you could confirm, and let me know if you have any good ideas why.

julia> @time using JuliaFormatter
  0.991517 seconds (1.43 M allocations: 96.471 MiB, 2.66% gc time, 2.73% compilation time)

B. https://github.com/GenieFramework/Genie.jl/commit/36bf0925e1def2c94ad9cdbeecae11f9b37d2bdc

I noticed you added lower case session for:

export Session, session

I suspect you had a typo and kept upper case Session as it might be technically breaking to not keep exporting it? Or am I wrong, so far I've only seen methods exported, and I'm not sure anything else needed.

I'm just trying to learn [from] your code, and also found this intriguing:

const HTTP = HTTP
essenciary commented 2 years ago

Ugh, I don't know what to say... Here is mine, Julia 1.7 with Genie 4.4.1

julia> @time using Genie
[ Info: Precompiling Genie [c43c736e-a2d1-11e8-161f-af95117fbd1e]
 11.875438 seconds (34.53 M allocations: 1.571 GiB, 4.35% gc time, 45.52% compilation time)

julia> @time using Genie
  0.000130 seconds (134 allocations: 10.750 KiB)
essenciary commented 2 years ago

Maybe you can share more details about your setup? I presume you're on Windows? I've had really bad experiences with Pkg on Windows... What about your CPU? These jobs are CPU bound (again, I suffered heavily on a Surface Book Pro).

The fact that switching Julia versions makes things slower, is potentially a hint that the problem is in Julia?

What about running in a clean project? You can see that dropping everything in your global environment causes problems and conflicts, like the one with Atom.

const HTTP I think it's some leftovers from the migration from HTTPServer.jl to HTTP.jl - it can probably be removed. Shouldn't be an issue though.

essenciary commented 2 years ago

We can have a quick video call to check your setup and dig a bit.

essenciary commented 2 years ago

Session and session are different things (one's a type, the other is a method).

JuliaFormatter has been a pain for me as well, causing my Julia 1.7 to crash, so I ended up disabling it - that could be an issue. I assumed it's caused by me running on Apple M1 and JuliaFormatter needing to get better at supporting this.

PallHaraldsson commented 2 years ago

I'm not on Windows, I'm on Linux and your excellent (precompiling) timing is strangely at odds with mine. It seems you didn't exit before the second timing though (the allocations are very low, and 152000x faster is more than I can believe). I suppose you exited before the second timing. I suspected.

I heard Apple M1 fast, but I doubt this is expected. Maybe and hopefully there's some alternative code-path taken for M1, so not about the CPU. Can you check with an empty .julia folder remove it or move it? Just be careful when moving it back (I screwed that up last time... and lost the folder).

essenciary commented 2 years ago

Ah ok, I didn't realise you exited between timings.

Whit exiting I get about 6s

julia> @time using Genie
  5.956358 seconds (34.91 M allocations: 1.592 GiB, 8.51% gc time, 89.87% compilation time)

Let me see if I remove JuliaFormatter.

essenciary commented 2 years ago

Removing JuliaFormatter does speed things up a bit - possibly more for you:

image
essenciary commented 2 years ago

I'll try v4 on my Surface Book / Windows 💀

hhaensel commented 2 years ago
               _
   _       _ _(_)_     |  Documentation: https://docs.julialang.org
  (_)     | (_) (_)    |
   _ _   _| |_  __ _   |  Type "?" for help, "]?" for Pkg help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 1.7.0 (2021-11-30)
 _/ |\__'_|_|_|\__'_|  |  Official https://julialang.org/ release
|__/                   |

julia> @time using Genie
 11.681307 seconds (37.19 M allocations: 1.716 GiB, 5.84% gc time, 86.75% compilation time)
essenciary commented 2 years ago

@PallHaraldsson definitely something on your side - today I installed and used Genie in a Pluto notebook on JuliaHub. Pluto reported some 5.6s for the using statement.

However, let's keep this open as I think there are still opportunities for improvement. I've been looking today into https://timholy.github.io/SnoopCompile.jl/stable/snoopr/ - this can help

AbhimanyuAryan commented 1 year ago

Using with 1.8.3 no issues on my side

(@v1.8) pkg> add Genie
    Updating registry at `~/.julia/registries/General.toml`
   Resolving package versions...
    Updating `~/.julia/environments/v1.8/Project.toml`
  [c43c736e] + Genie v5.11.3
    Updating `~/.julia/environments/v1.8/Manifest.toml`
  [c7e460c6] + ArgParse v1.1.4
  [d1d4a3ce] + BitFlags v0.1.7
  [00ebfdb7] + CSTParser v3.3.6
  [da1fd8a2] + CodeTracking v1.1.1
  [944b1d66] + CodecZlib v0.7.0
  [a80b9123] + CommonMark v0.8.7
  [8f5d6c58] + EzXML v1.1.0
  [48062228] + FilePathsBase v0.9.20
  [c43c736e] + Genie v5.11.3
  [c27321d9] + Glob v1.3.0
  [cd3eb016] + HTTP v1.5.5
  [77172c1b] + HttpCommon v0.5.0
  [83e8ac13] + IniFile v0.5.1
  [682c06a0] + JSON v0.21.3
  [98e50ef6] + JuliaFormatter v1.0.16
  [aa1ae85d] + JuliaInterpreter v0.9.17
  [e6f89c97] + LoggingExtras v1.0.0
  [6f1432cf] + LoweredCodeUtils v2.2.2
  [739be429] + MbedTLS v1.1.7
  [49dea1ee] + Nettle v1.0.0
  [4d1e1d77] + Nullables v1.0.0
  [4d8831e6] + OpenSSL v1.3.2
  [ae029012] + Requires v1.3.0
  [295af30f] + Revise v3.4.0
  [777ac1f9] + SimpleBufferStream v1.1.0
  [b718987f] + TextWrap v1.0.1
  [3bb67fe8] + TranscodingStreams v0.9.10
  [30578b45] + URIParser v0.4.1
  [5c2747f8] + URIs v1.4.1
  [4c82536e] + Nettle_jll v3.7.2+0
  [458c3c95] + OpenSSL_jll v1.1.19+0
  [02c8fc9c] + XML2_jll v2.9.14+0
  [781609d7] + GMP_jll v6.2.1+2

(@v1.8) pkg> st
Status `~/.julia/environments/v1.8/Project.toml`
  [c43c736e] Genie v5.11.3
  [5fb14364] OhMyREPL v0.5.12
  [340e8cb6] SearchLight v2.10.0

julia> @time using Genie
  1.696646 seconds (3.20 M allocations: 243.155 MiB, 7.29% gc time, 29.38% compilation time: 7% of which was recompilation)

julia> versioninfo()
Julia Version 1.8.3
Commit 0434deb161e (2022-11-14 20:14 UTC)
Platform Info:
  OS: Linux (x86_64-linux-gnu)
  CPU: 16 × AMD Ryzen 7 5800H with Radeon Graphics
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-13.0.1 (ORCJIT, znver3)
  Threads: 1 on 16 virtual cores
AbhimanyuAryan commented 1 year ago

should this be closed?