Skip to content

LSP textDocument/documentSymbol is delayed by ~350ms #135453

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
squidfunk opened this issue Oct 20, 2021 · 4 comments
Open

LSP textDocument/documentSymbol is delayed by ~350ms #135453

squidfunk opened this issue Oct 20, 2021 · 4 comments
Assignees
Labels
outline Source outline view issues under-discussion Issue is under discussion for relevance, priority, approach

Comments

@squidfunk
Copy link

I'm developing a VS Code extension and the experience so far has been tremendous!

I want my language server to be as fast as possible, which already works well for the textDocument/didChange and textDocument/publishDiagnostics notification roundtrip. However, VS Code seems to wait for ~350ms after the document change notification until it asks the language server for other providers, like for example textDocument/documentSymbol and textDocument/documentColor.

Trace captured with ngrep when run via TCP transport
T 2021/10/19 16:17:06.122088 127.0.0.1:8460 -> 127.0.0.1:53585 [AP] #105
  Content-Length: 278....                                                                                                                                                                 
##
T 2021/10/19 16:17:06.122415 127.0.0.1:8460 -> 127.0.0.1:53585 [AP] #107
  {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"uri":"file:///Users/squidfunk/Desktop/css-test/small.css","version":143},"contentChanges":[{"range":{"star
  t":{"line":10,"character":36},"end":{"line":10,"character":36}},"rangeLength":0,"text":"0"}]}}                                                                                          
##
T 2021/10/19 16:17:06.125139 127.0.0.1:53585 -> 127.0.0.1:8460 [AP] #109
  Content-Length: 147....                                                                                                                                                                 
##
T 2021/10/19 16:17:06.125215 127.0.0.1:53585 -> 127.0.0.1:8460 [AP] #111
  {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///Users/squidfunk/Desktop/css-test/small.css","diagnostics":[]}}                                     
##
T 2021/10/19 16:17:06.461254 127.0.0.1:8460 -> 127.0.0.1:53585 [AP] #113
  Content-Length: 151....                                                                                                                                                                 
##
T 2021/10/19 16:17:06.461386 127.0.0.1:8460 -> 127.0.0.1:53585 [AP] #115
  {"jsonrpc":"2.0","id":18,"method":"textDocument/documentSymbol","params":{"textDocument":{"uri":"file:///Users/squidfunk/Desktop/css-test/small.css"}}}                                 
##
T 2021/10/19 16:17:06.462931 127.0.0.1:53585 -> 127.0.0.1:8460 [AP] #117
  Content-Length: 1888....                                                                                                                                                                
##
T 2021/10/19 16:17:06.462988 127.0.0.1:53585 -> 127.0.0.1:8460 [AP] #119
  {"jsonrpc":"2.0","id":18,"result":[{"kind":5,"name":"div","range":{"start":{"line":0,"character":0},"end":{"line":5,"character":1}},"selectionRange":{"start":{"line":0,"character":0},"
  end":{"line":0,"character":4}},"children":[{"kind":13,"name":"--foo","range":{"start":{"line":3,"character":2},"end":{"line":3,"character":12}},"selectionRange":{"start":{"line":3,"cha
  racter":2},"end":{"line":3,"character":12}}}]},{"kind":11,"name":"@media screen and (min-width: 320px)","range":{"start":{"line":7,"character":0},"end":{"line":24,"character":1}},"sele
  ctionRange":{"start":{"line":7,"character":6},"end":{"line":7,"character":37}},"children":[{"kind":5,"name":"div","range":{"start":{"line":8,"character":2},"end":{"line":12,"character"
  :3}},"selectionRange":{"start":{"line":8,"character":2},"end":{"line":8,"character":6}},"children":[]},{"kind":11,"name":"@media screen","range":{"start":{"line":14,"character":2},"end
  ":{"line":21,"character":3}},"selectionRange":{"start":{"line":14,"character":8},"end":{"line":14,"character":16}},"children":[{"kind":11,"name":"@media print","range":{"start":{"line"
  :15,"character":4},"end":{"line":20,"character":5}},"selectionRange":{"start":{"line":15,"character":10},"end":{"line":15,"character":17}},"children":[{"kind":5,"name":".bar","range":{
  "start":{"line":16,"character":6},"end":{"line":16,"character":13}},"selectionRange":{"start":{"line":16,"character":6},"end":{"line":16,"character":11}},"children":[]},{"kind":11,"nam
  e":"@supports (display: grid)","range":{"start":{"line":17,"character":6},"end":{"line":19,"character":7}},"selectionRange":{"start":{"line":17,"character":15},"end":{"line":17,"charac
  ter":32}},"children":[]}]}]},{"kind":5,"name":".foo","range":{"start":{"line":23,"character":2},"end":{"line":23,"character":9}},"selectionRange":{"start":{"line":23,"character":2},"en
  d":{"line":23,"character":7}},"children":[]}]}]}                                                                                                                                        
##
T 2021/10/19 16:17:07.111888 127.0.0.1:8460 -> 127.0.0.1:53585 [AP] #121
  Content-Length: 150....                                                                                                                                                                 
##
T 2021/10/19 16:17:07.112014 127.0.0.1:8460 -> 127.0.0.1:53585 [AP] #123
  {"jsonrpc":"2.0","id":19,"method":"textDocument/documentColor","params":{"textDocument":{"uri":"file:///Users/squidfunk/Desktop/css-test/small.css"}}}                                  
##
T 2021/10/19 16:17:07.112828 127.0.0.1:53585 -> 127.0.0.1:8460 [AP] #125
  Content-Length: 167....                                                                                                                                                                 
##
T 2021/10/19 16:17:07.112914 127.0.0.1:53585 -> 127.0.0.1:8460 [AP] #127
  {"jsonrpc":"2.0","id":19,"result":[{"color":{"red":255,"green":0,"blue":100,"alpha":1},"range":{"start":{"line":10,"character":22},"end":{"line":10,"character":38}}}]}            

As can be seen from the trace, my language server responds within the order of milliseconds:

textDocument/didChange
  T 2021/10/19 16:17:06.122088 – Content length
  T 2021/10/19 16:17:06.122415 – Content

textDocument/publishDiagnostics
  T 2021/10/19 16:17:06.125139 – Content length
  T 2021/10/19 16:17:06.125215 – Content

However, VS Code will wait for more than 300ms before invoking the other providers, which becomes very noticeable:

textDocument/documentSymbol
  T 2021/10/19 16:17:06.461254 – Content length
  T 2021/10/19 16:17:06.461386 – Content
  Response
    T 2021/10/19 16:17:06.462931 – Content length
    T 2021/10/19 16:17:06.462988 – Content

textDocument/documentColor
  T 2021/10/19 16:17:07.111888 – Content length
  T 2021/10/19 16:17:07.112014 – Content
  Response
    T 2021/10/19 16:17:07.112828 – Content length
    T 2021/10/19 16:17:07.112914 – Content

My question is why does VS Code wait for so long? Can this interval be reduced via a language client, language server option, or setting? I would really like to mitigate this behavior because this delay renders the otherwise instantaneous experience rather sluggish.

I dug into the code base of VS Code and think I've found traces of the issue, e.g. in outlineModel.ts:

new LanguageFeatureRequestDelays(DocumentSymbolProviderRegistry, 350);

A search for this class yields:
https://github.com/microsoft/vscode/search?q=LanguageFeatureRequestDelays


The issue was first reported here: microsoft/vscode-languageserver-node#838

@jrieken jrieken added outline Source outline view issues under-discussion Issue is under discussion for relevance, priority, approach labels Oct 20, 2021
@jrieken
Copy link
Member

jrieken commented Oct 20, 2021

My question is why does VS Code wait for so long? Can this interval be reduced via a language client, language server option, or setting? I would really like to mitigate this behavior because this delay renders the otherwise instantaneous experience rather sluggish.

It is more or less an arbitrary number which is driven by two things: we don't want to overwhelm extensions with requests and we want the UI to be stable. If asking for outline too quickly after typing it raises the chances to ask at an unfavorable time, like at time of invalid syntax. That usually result in visually very different outline, e.g a missing closing bracket of a method makes a huge difference to most outlines

@squidfunk
Copy link
Author

Thanks for the quick response.

It is more or less an arbitrary number which is driven by two things: we don't want to overwhelm extensions with requests and we want the UI to be stable. If asking for outline too quickly after typing it raises the chances to ask at an unfavorable time, like at time of invalid syntax.

I understand the need to debounce sluggish extensions. As I read the source code, the business logic in place measures the time the server needs to respond to a specific request and penalizes it for subsequent requests when it responds slowly. However, the current logic imposes a minimum delay of 350ms. So even when a language server answers within a few milliseconds, the delay will always be +350ms. This does not only affect the outline, but also textDocument/documentColor requests, which leads to a noticeable lag when writing CSS:

Ohne.Titel.mp4

Two ideas:

  1. Could the debounce logic be adjusted in a way that VS Code starts with the 350ms, but then measures the time the server needed to respond, and when the difference is small, reduces the delay step-by-step for subsequent requests?
  2. Another idea could be that the language server signals to VS Code that it updated its language model after the text changes, and is ready for other requests? Is there maybe something part of the LSP I've missed?

I think that this would significantly improve the writing experience.

@jrieken
Copy link
Member

jrieken commented Oct 20, 2021

This does not only affect the outline, but also textDocument/documentColor requests, which leads to a noticeable lag when writing CSS:

Almost everything that updates as you type is debounced but all use different delays and logic so I suggest that we leaf colors out of this.

I think that this would significantly improve the writing experience.

Sure, we can tweak timeouts but I am not yet ready for that. I understand that your POV is one of an extension author that cannot show the true performance of their language service because of use. That's disappointing but different from usage feedback and I haven't seen users complain about this yet

@squidfunk
Copy link
Author

Sure, we can tweak timeouts but I am not yet ready for that.

'Not ready' means that work on this end is planned?

I understand that your POV is one of an extension author that cannot show the true performance of their language service because of use. That's disappointing but different from usage feedback and I haven't seen users complain about this yet

My POV is actually a mixed one, as I use VS Code to write a lot of CSS, but am currently also writing a new CSS language server, so I'm actually on both ends. Going forward, I think maybe an extension to the LSP that allows a language server to send a "ready" notification that can be consumed by the extension host might be more stable option than arbitrary delays. Something like an idle notification that the server can implement as part of an optional capability?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
outline Source outline view issues under-discussion Issue is under discussion for relevance, priority, approach
Projects
None yet
Development

No branches or pull requests

2 participants