Solargraph suggestions are slow on large files

[gencer]

I have two files in this example:

File 1: container.rb
File 2. file.rb

container.rb contains almost 1.700 lines of code and file.rb has around 150. When I work on large file like container.rb suggestions are very slow to respond. See here:

However, on same project if I open file.rb and write there, suggestions are very fast. See:

I tried Socket and stdio as transport. Neither helped.

You can also see output of solargraph i recorded them too.

[castwide]

I've noticed a similar issue on large files. In my tests, the difference starts to be measurable around 600-700 lines and increases from there. It's typically not a problem if it's a background file in the workspace; only while the file is being changed.

The major issue appears to be the mapping process. In your debug log, the start of that process is marked by the Cataloging line.

There are two possible improvements I'm trying:

1. Make sure cataloging runs asynchronously while still being able to run queries on the current maps.
2. Improve detection of trivial code changes to reduce the frequency of cataloging.

[gencer]

Both options sounds promising. Perhaps you should go with one that "faster to implement".

P.S: Oh, It's killing me 😭. May I kindly ask that you prioritize this -more-?

[castwide]

Asynchronous cataloging looks like a very good candidate for inclusion in v0.31.0, which I hope to have ready by next week. I'll keep you updated.

[castwide]

It looks like asynchronous cataloging helps. The mechanism was already there in the form of a cataloger that runs in its own thread. The problem was that certain queries would make unnecessary cataloging requests, resulting in the main thread waiting for the cataloger thread to finish its current operation. Completion item requests, in particular, should be able to query the map in its current state while the cataloger updates it in the background.

My tests look good so far. The gem v0.31.0 branch returns completion items about 10-20 times faster on average. You're still liable to see some slowdown in files with 1000+ lines of code, but hopefully not the 4-5 second lag you've been seeing in container.rb.

[gencer]

@castwide, I've tested that branch, however, i see almost same response times as the previous one.

In this branch, Fil.. and Reser.. class names are instantly seen but not their methods. I still have to wait 4-5 seconds for their methods and attributes being listed. Tried on socket and stdio.

Here is v0.31.0 branch behavior:

[castwide]

I just pushed a change that might affect this issue, albeit slightly. It removes a thread pooling process that turned out to be ineffective when I benchmarked it.

Do you get the same lag with subsequent calls? Example:

Reserve.new # <- Completion after the . is slow the first time
Reserve.    # <- This one might run faster

I also noticed in your output that the most recent cataloging process always finishes between the textDocument/completion request and the response. That might indicate the completion request is still waiting on the cataloger for some reason. I'll keep looking into it.

[gencer]

I think its a bit faster but not that much. See here: (Note: I pulled latest changes from 0.31.0 branch)

[castwide]

Okay, it looks like the problem is somewhere else. This part of the log seems to indicate that asynchronous cataloging works:

Cataloging got scheduled by didChange, and the completion response was sent before cataloging finished. All good signs, but it doesn't explain the lag.

Is d: a local drive or a network share?

Can you give me a rough estimate of how big your project is? Especially number of files and installed gems.

[gencer]

Is d: a local drive or a network share?

Local drive. In fact both C: and D: is a SSD. Much faster than a spinning disk.

Can you give me a rough estimate of how big your project is? Especially number of files and installed gems.

There are 301 .rb files in my directory. Here is my Gemfile and .solargraph.yml: https://gist.github.com/gencer/a5b6a8c8f5708a1cc249a2ab79ffa622

Additional update: There are 589 folders (gems) in my gems folder in Ruby lib dir.

[gencer]

@castwide, 2 questions:

1. I expect ruby.exe exits when I close VSCode as usual, however, with last build it doesn't exits and i see it on task manager after vscode exits. Is that normal?

2. Do you want me to send you the whole container.rb and some other files like classes, (Reserve, File...) files that I also reproduced outside of my original project via e-mail?

[castwide]

1. That's definitely not normal. If it's the Solargraph process, there might be a hung thread somewhere. Let me know if it keeps happening.

2. Yeah, that might help. Thanks.

Another thing you can try: opening the project without gems. The easiest way should be to temporarily rename Gemfile and restart VS Code. I have a feeling it won't make a significant difference, but at least it'll eliminate gem documentation as the bottleneck.

[gencer]

1. For the exiting, yes it is solargraph process but it doesn't exits. Tried with 2 different projects.
2. E-Mail sent.

I will try without a gemfile as you suggested and report back.

[castwide]

I pushed a fix for those rogue processes you saw. It was an unrelated bug in how v0.31.0 handles notifications between the language server and the transport. The transport didn't know the server stopped, so it just kept listening to the socket. Thanks for catching it.

[gencer]

I'm glad I could help on this.

[castwide]

I did some development and troubleshooting using the project you sent me. First, I was a little surprised at how long it took to initialize your workspace. Average was about 105 seconds, even though your project only has 13,633 pins (a pin is a mapped location in code, such as a method definition or a variable assignment). For comparison, I have a project with 12,221 pins that loads in under 6 seconds. Solargraph has 43,253 pins and loads in 20 seconds.

It turns out that one of the bottlenecks is large comment blocks. If I exclude the _ref directory, which has massive comments, the project loads in 2 seconds. If I include _ref but disable Solargraph’s comment parsing, it takes about 6 seconds. I’m not sure what the root cause is, but this issue is on my radar now.

As for slow completion suggestions, I’ve found a significant cause and a possible solution. When the code contains an incomplete statement like File. or Reserve., the parser goes through a couple extra steps to correct for syntax errors so it can generate a map. With a file as large as container.rb, that can add up to 700ms to the map time. Combine that with the fact that each file change gets parsed in sequence, and that sequential parses can still block other requests, and you wind up with several seconds of lag.

My solution is to separate file updates into two parts. First, the server notifies the map that the code has changed, but doesn’t try to update the map itself. That way the completion request knows what code snippet you’re trying to complete and can query it against the map that’s already in place. Second, both parsing and cataloging run asynchronously in the background so they don’t block other queries.

Testing with your project, completion for Reserve. and File. in container.rb are nearly instantaneous.

This update is liable to be too major to make it into gem v0.31.0, so I’ve started a new branch catalog-thread. It involves serious architectural changes in the language server and needs a lot more testing. Feel free to try it and let me know how it goes.

[gencer]

I've tested that branch and yes, it just worked as expected. Instantly get complete results for self., File., Reserve. or other classes.

For the startup delay: I was thought it is slow because i have more gems. It will be better if you can do a workaround for those comment blocks.

Thank you so much for making Solargraph faster.

[castwide]

I pushed another change to catalog-thread that improves comment parsing speed. Testing it on your project, it reduces library load time (the most expensive part of server initialization) from ~92 seconds to ~40 seconds.

[gencer]

Perfect. Tested now. One of my project was taking 2-3 minutes to start now it tooks 1 min 10 seconds. Definitely better than before.

In my case I think ~1 minute is an acceptable load time. If you think it is still higher then expected, let me know.

Thank you once again, Fred. You made my environment and development better than ever!

[castwide]

Thanks, glad to hear it!

I'll keep load time improvements on the radar, but any further enhancements will probably be non-trivial.

The new specs on the catalog-thread branch look solid, so these features should make it into gem v0.31.0.

[castwide]

The changes are published in gem v0.31.0.

[gencer]

Fred, if you got my previous message, please discard it.

It was probably a cache that bundler made. So it was slow because it was using older master branch for v0.31.0.

Gem is awesome.

Thanks.