haskell-language-server starts up slowly

[mitchellwrosen]

Is your enhancement request related to a problem? Please describe.

I've set up a no-op project with the following files:

-- foo.cabal
cabal-version: 2.4
name: foo
version: 0

library
  build-depends: base
  exposed-modules: Foo

-- Foo.hs
module Foo where

With a warm build, that is, after a cabal build at the command line, followed by an opening and closing of Foo.hs once (after letting haskell-language-server initialize), I observe the following timings upon opening Foo.hs:

where "processing" and "setting up" occur in parallel after "initializing" is complete.

"Initializing" here is the time between the client sending the "initialize" RPC request to haskell-language server and receiving a response.

"Processing" and "setting up" are just what haskell-language-server is reporting it's doing via progress handlers.

Describe the solution you'd like

Well, I'd like this to go much faster :) Or, at least, I wanted to draw attention to the slow startup time, in case it was not yet on anyone's radar who might be able to diagnose and improve.

Thanks!

[georgefst]

With a warm build

Note that the build invoked by HLS uses a different build directory. So the key question here is, is HLS' first startup any slower than a cold cabal build? I've found that when HLS is slow at startup it's usually just waiting around for Cabal.

(I have been investigating this sort of thing. See e.g. https://github.com/haskell/cabal/discussions/9302#discussioncomment-7170243. It's pretty crucial for stuff like #3595 and #155 that Cabal doesn't do more work than necessary when reloading.)

[mitchellwrosen]

@georgefst A cold cabal build on my machine takes about 3s, compared to HLS's 7s. Furthermore, as mentioned above (though it was kind of buried), "warm" here meant both cabal build was performed and HLS was allowed to do its thing once. HLS doesn't seem to get any warmer - it's 7 seconds to initialize the smallest possible Haskell codebase, every time.

[fendor]

Looking at the logs of HLS, there are roughly four calls to cabal:

• cabal exec -v0 -- ghc --print-libdir
• cabal exec -v0 -- ghc -package-env=- -ignore-dot-ghci -e 'Control.Monad.join (Control.Monad.fmap System.IO.putStr System.Environment.getExecutablePath)'
• cabal --builddir=... v2-exec --with-compiler ... --with-hc-pkg ... -v0 -- ghc --print-libdir
• cabal repl --builddir=... --with-compiler ... --with-hc-pkg ... <fp-name>

The former three are relatively fast on a warm build but just as slow as cabal repl on anything else. Performance might be affected by issues such as https://github.com/haskell/cabal/issues/9005

Moreover, it looks like HLS we might invoke cabal sometimes redundantly, but I haven't investigated. I see in my logs:

2023-10-04T18:40:17.707076Z | Debug | executing command: cabal exec -v0 -- ghc --print-libdir
2023-10-04T18:40:17.832197Z | Debug | executing command: cabal exec -v0 -- ghc -package-env=- -ignore-dot-ghci -e Control.Monad.join (Control.Monad.fmap System.IO.putStr System.Environment.getExecutablePath)
2023-10-04T18:40:18.026880Z | Debug | executing command: cabal --builddir=/home/hugin/.cache/hie-bios/dist-hie-bios-e7a73b2ffd58a3db6a855ec871bcd65b v2-exec --with-compiler /home/hugin/.cache/hie-bios/wrapper-b54f81dea4c0e6d1626911c526bc4e36 --with-hc-pkg /home/hugin/.cache/hie-bios/ghc-pkg-079c0a0a06115482afcc30190c1e4f4d ghc -v0 -- --print-libdir
2023-10-04T18:40:18.169020Z | Debug | executing command: cabal exec -v0 -- ghc --print-libdir
2023-10-04T18:40:18.303527Z | Debug | executing command: cabal exec -v0 -- ghc -package-env=- -ignore-dot-ghci -e Control.Monad.join (Control.Monad.fmap System.IO.putStr System.Environment.getExecutablePath)
2023-10-04T18:40:18.498682Z | Debug | executing command: cabal --builddir=/home/hugin/.cache/hie-bios/dist-hie-bios-e7a73b2ffd58a3db6a855ec871bcd65b v2-repl --with-compiler /home/hugin/.cache/hie-bios/wrapper-b54f81dea4c0e6d1626911c526bc4e36 --with-hc-pkg /home/hugin/.cache/hie-bios/ghc-pkg-079c0a0a06115482afcc30190c1e4f4d /home/hugin/Documents/haskell/hie-bios/src/HIE/Bios/Ghc/Gap.hs
2023-10-04T18:40:18.674472Z | Debug | executing command: cabal exec -v0 -- ghc --print-libdir
2023-10-04T18:40:18.799622Z | Debug | executing command: cabal exec -v0 -- ghc -package-env=- -ignore-dot-ghci -e Control.Monad.join (Control.Monad.fmap System.IO.putStr System.Environment.getExecutablePath)
2023-10-04T18:40:18.995500Z | Debug | executing command: cabal --builddir=/home/hugin/.cache/hie-bios/dist-hie-bios-e7a73b2ffd58a3db6a855ec871bcd65b v2-exec --with-compiler /home/hugin/.cache/hie-bios/wrapper-b54f81dea4c0e6d1626911c526bc4e36 --with-hc-pkg /home/hugin/.cache/hie-bios/ghc-pkg-079c0a0a06115482afcc30190c1e4f4d ghc -v0 -- --print-libdir

But only a subset of the command should be really required.

Maybe this info is also interesting to figure out what is going on.