lexical-lsp / lexical

Lexical is a next-generation elixir language server
888 stars 82 forks source link

Missing features when compiling/indexing #792

Open orlera opened 4 months ago

orlera commented 4 months ago

At Remote we have been suffering from the lack of a performant LS that can cope with the size of our codebase (approaching 800k lines excluding deps, tests, comments, etc)

We were delighted at the beginning of the year when Lexical became the officially recommended LSP for Elixir within the company. It was a welcome change of pace compared to the tools we were using previously.

Our codebase has grown significantly since then and Lexical is struggling to keep up with the pace.

The main pain we identified is related to compilation & indexing times and the fact that several features are not available or extremely slow when those operations are undergoing.

To put it into numbers, Lexical compiles our project in around 11 minutes and indexes it in 5 minutes. That means that when doing a full compile+indexing, Lexical's most important functionalities are not available for 16 minutes.

Considering the 3 following scenarios, this happens with the features we rely on the most (Go to definition, Code completion, Find references):

  1. When the project compilation is underway and the search store is not enabled:

    • Go to definition raises an error [warn] ** (ErlangError) Erlang error: "CompileError during metadata build pre:\nnofile;
    • Code completion: it gets requested (Completion for LxPos<<34, 20>>) but there is no follow up to the request in the logs;
    • Find references: as expected, it raises an error complaining that search store isn't enabled yet
  2. When compilation is underway and Search store is enabled:

    • Go to definition works fine;
    • Code completion: it gets requested (Completion for LxPos<<34, 20>>) but there is no follow up to the request in the logs;
    • Find references: works fine;
  3. When project indexing is underway:

    • Go to definition: times out

      [error] Task #PID<0.1741.0> started from LXical.Server.Provider.Queue terminating
      ** (stop) {:exception, {:timeout, {GenServer, :call, [LXical.RemoteControl.Search.Store, {:exact, "<Module.Name>", [type: :module, subtype: :definition]}, 5000]}}}
          (kernel 9.2.4.1) erpc.erl:700: :erpc.call/5
          (lx_server 0.5.0) lib/lexical/server/provider/handlers/go_to_definition.ex:9: LXical.Server.Provider.Handlers.GoToDefinition.handle/2
          (lx_server 0.5.0) lib/lexical/server/provider/queue.ex:99: anonymous fn/2 in LXical.Server.Provider.Queue.State.as_task/2
          (elixir 1.17.2) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
          (elixir 1.17.2) lib/task/supervised.ex:36: Task.Supervised.reply/4
      Function: #Function<2.109870111/0 in LXical.Server.Provider.Queue.State.as_task/2>
          Args: []
    • Code completion: times out

      [error] Task #PID<0.1725.0> started from LXical.Server.Provider.Queue terminating
      ** (stop) {:exception, {:timeout, {GenServer, :call, [LXical.RemoteControl.Search.Store, {:exact, "<Module.Name>", [type: :module, subtype: :definition]}, 5000]}}}
          (kernel 9.2.4.1) erpc.erl:700: :erpc.call/5
          (lx_server 0.5.0) lib/lexical/server/provider/handlers/go_to_definition.ex:9: LXical.Server.Provider.Handlers.GoToDefinition.handle/2
          (lx_server 0.5.0) lib/lexical/server/provider/queue.ex:99: anonymous fn/2 in LXical.Server.Provider.Queue.State.as_task/2
          (elixir 1.17.2) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
          (elixir 1.17.2) lib/task/supervised.ex:36: Task.Supervised.reply/4
      Function: #Function<2.109870111/0 in LXical.Server.Provider.Queue.State.as_task/2>
          Args: []
    • Find References: when it is available, it can take up to 30s to output the code completions.

    We tried to parallelise compilation and indexing in the hope that the issue fixed serialising their execution in https://github.com/lexical-lsp/lexical/pull/526 disappeared with the latest Elixir & Erlang versions. We can confirm that the issue is still present and that both compilation and indexing took twice the time.

zachallaun commented 4 months ago

Thanks for the detailed report! Supporting large projects such as yours is certainly one of Lexical's goals.

There are a few axes it sounds like we can improve on:

I have some thoughts on these, but I expect @scohen will have more/better ones, so I'll let him share first. 🙂

As a baseline, how long does from-scratch compilation usually take when run outside of Lexical? i.e. removing _build and mix compile?

scohen commented 4 months ago

I'm a little confused as to why lexical's compilation would take significantly longer than mix compile, since that's what it does. Also, a full project index should only really happen once at the start of the project.

If a full index is happening often, then something else is wrong with lexical in your project, we can definitely help you get up and running if that's the case.

For what it's worth, there's another project that has 1.5mm lines, which also uses lexical, they also had some problems with compilation that we helped them with, and this sounds somewhat familiar to the issues they had.

orlera commented 4 months ago

Thanks @zachallaun and @scohen for the quick replies.

@zachallaun I compiled the project from scratch as suggested (on the same machine used to produce the figures described in the issue) and it takes around 7 minutes.

@scohen As far as I could see a full index only happens when at the beginning as you mentioned. Still, even a partial index triggered by switching to another branch takes more than 2 minutes. Things improved dramatically with https://github.com/lexical-lsp/lexical/pull/646, but it is still not ideal.

One thing that I noticed playing around is that after a while the Find References functionality has some hiccups (it returns no references for some module/function, while it works properly for most) and forcing a full index via the VSCode command fixes it. I suspect that partial indexes somehow "corrupt" the search store, but I haven't dug into this yet, so I can't confirm.

scohen commented 4 months ago

It's extremely surprising to me that a partial index would take 2 minutes, do you have an idea how many files are changing when you switch branches?

I think what's actually happening is that the index isn't being corrupted, but lexical isn't getting a full list of files from the editor, and it only indexes what it sees. We can fix this.

it takes around 7 minutes

Sadly, we're never going to be able to improve upon that speed for a full build. I'm actually wondering why lexical is adding overhead there. Is it the mix deps.get command? When lexical compiles your code, it just runs a series of mix tasks. We'll need to time each one to find out which is taking the extra 4 minutes.

The hiccups you're seeing are kind of intentional; For some reason, when we index and compile at the same time, compilation slows to a crawl, so we have do disable indexing before we compile. I'd love to be able to do both at the same time, but maybe a fix would to be to not allow these features (and provide an error message) before the store is ready.

zachallaun commented 4 months ago

I'm actually wondering why lexical is adding overhead there. Is it the mix deps.get command? When lexical compiles your code, it just runs a series of mix tasks. We'll need to time each one to find out which is taking the extra 4 minutes.

I'd also think that, in the general case, compilation would be partial ever since #582.

scohen commented 4 months ago

Yes, that's correct, @zachallaun

orlera commented 4 months ago

I switched from master to a branch created 2 days ago.

Compilation took 24s, indexing 1m25s, 913 file changes (421 to compile)

> git diff --name-only HEAD..master | wc -l
913
> git diff --name-only HEAD..master | awk '/.ex$/' | wc -l
421

We'll need to time each one to find out which is taking the extra 4 minutes.

Ok, I'll look into this and come back to you

scohen commented 4 months ago

how big are the files? Indexing is linearly proportional to the size of the AST.

That said, I'm very surprised that indexing 900 files takes over a minute. My current project has 2400 files and it indexes everything in ~10 seconds

scohen commented 4 months ago

And to give you an idea, it has 560,000 total lines (including deps, which are indexed)

orlera commented 4 months ago

Played around with the compilation steps within Lexical, these are the results I got:

mix local.hex --force --if-missing: 9.334 ms mix local.rebar --force --if-missing: 9.875 ms mix deps.get: 2501.934 ms (2.5 s) mix loadconfig: 9.308 ms mix deps.safe_compile --skip-umbrella-children: 127067.816 ms (2m7s) Plugin.Discovery.run(): 6.598 ms mix compile --return-errors --ignore-module-conflict --all-warnings --docs --debug-info --no-protocol-consolidation: 335546.676 ms (5m35s)

Summing up to roughly 7.5 minutes. I ran it a few times and I get similar results (within 10 seconds). I guess the other day I was getting 11 minutes because I was running it while doing other thinks, keeping the CPU busy.

I also timed the compilation of each file within Lexical.RemoteControl.Compilation.Tracer and the slowest takes around 8ms

how big are the files?

Those 900+ files amount to 309k lines. I didn't check, though, if there are deps changes between the two branches. I guess it would index only new/updated deps, right? Although I was switching from master to an older branch, so there would be less deps (or downgrades)

scohen commented 3 months ago

Is this just from changing branches, or is it a fresh compile?

scohen commented 3 months ago

@orlera , would it be possible for you to pop into our discord so we can help?