x/tools/gopls: initial semantic token request slow

[leitzler]

What version of Go are you using (go version)?

$ go version
go version devel go1.17-912f075047 Fri Jul 2 21:06:08 2021 +0000 darwin/amd64
$ go list -m golang.org/x/tools golang.org/x/tools/gopls
golang.org/x/tools v0.1.5-0.20210708231608-69948257bde7
golang.org/x/tools/gopls v0.0.0-20210708231608-69948257bde7

Does this issue reproduce with the latest release?

Yes

What did you do?

Start up a new instance of a LSP client that requests semantic tokens right away (opening internal/lsp/semantic.go in x/tools @ 6e9046b).

The request is a ranged request for the first 33 lines.

What did you expect to see?

A swifter response on the semantic token request.

What did you see instead?

The semantic token request takes ~1.7s:

[Trace - 21:24:59.036 PM] Received response 'textDocument/semanticTokens/range - (2)' in 1658ms.
Result: {"resultId":"2021-07-29 21:24:59.035662 +0200 CEST m=+2.811627468","data":[0,0,54,6,0,1,0,53,6,0,1,0,49,6,0,2,0,7,2,0,0,8,3,9,0,2,0,6,2,0,1,2,5,9,0,1,2,7,9,0,1,2,3,9,0,1,5,3,9,0,1,5,5,9,0,1,5,5,9,0,1,7,8,9,0,1,2,4,9,0,1,2,7,9,0,1,2,4,9,0,2,30,5,9,0,1,34,8,9,0,1,34,6,9,0,1,34,8,9,0,1,1,6,9,0,3,0,83,6,0,1,0,83,6,0,1,0,63,6,0,2,0,54,6,0,1,0,5,2,0,0,6,15,3,6,0,16,3,1,512,0,6,6,7,0,2,0,4,2,0,0,6,1,3,0,0,2,1,8,0,0,1,6,1,0,0,8,18,5,2,0,19,3,10,2,0,4,7,9,0,0,8,7,1,0,0,9,1,10,2,0,2,1,8,0,0,1,8,9,0,0,9,20,1,0,0,23,1,8,0,0,1,8,9,0,0,9,14,1,0,0,16,5,1,0,1,1,3,3,2,0,5,3,3,2,0,4,2,8,0,0,3,1,3,0,0,2,21,4,0,0,22,3,3,0,0,5,1,3,0,0,2,12,3,0,0,14,3,3,516]}

(full log: https://gist.github.com/leitzler/d50361de1e196bebf074822062f98990)

If I understand it correctly gopls currently require full type check before responding to semantic token requests, and that is why it is so much slower on the initial request.

Would it be possible to instead take on an iterative approach and first parse AST and deliver results basted on that, and then when type checking is done provide the rest? For example via SemanticTokensPartialResult or using workspace/semanticTokens/refresh when type checking is done.

[leitzler]

Another example of opening up a larger file (close to the limit 100k) where the initial load takes >9 seconds:

[hyangah]

cc @pjweinb @stamblerre

[pjweinb]

The semantic token code will handle identifiers without any type information, so presumably it could be made to work if it were called before type checking gets done. I think of semantic tokens as being supplementary to the IDE's syntax marking, and much of the supplementary information is from types. When you ask for semantic tokens, has your editor already done syntax marking, or do the semantic tokens supply all the syntax marking?

[leitzler]

The intent is to have gopls as the (sole) source of truth for syntax marking. From what I've seen so far it provides most of the old syntax highlighting, as well as things that the old one can't provide.

Even though LSP writes about "additional coloring" it would be really useful if gopls could provide "fast-enough" full syntax marking. With plugins like tree-sitter becoming increasingly popular there is a demand for something fast and lightweight.

[stamblerre]

@leitzler: Does registering the tokens in initialization (instead of dynamically) improve the situation at all? You can patch in this CL to try it out: https://golang.org/cl/340478.

[leitzler]

Thanks for looking in to this @stamblerre. I tried that CL on top of d529aec and compared to d529aec now (this is on a slower machine, MBPr 2016, than what I used when I wrote the issue). Just opened up internal/lsp/semantic.go and restarted a few times:

w/o CL 340478 just grep'ing the semTok request:

[Trace - 21:19:31.886 PM] Sending request 'textDocument/semanticTokens/range - (2)'.
[Trace - 21:19:35.631 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3744ms.
[Trace - 21:19:42.580 PM] Sending request 'textDocument/semanticTokens/range - (2)'.
[Trace - 21:19:46.372 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3792ms.
[Trace - 21:19:51.799 PM] Sending request 'textDocument/semanticTokens/range - (2)'.
[Trace - 21:19:55.582 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3782ms.
[Trace - 21:20:00.557 PM] Sending request 'textDocument/semanticTokens/range - (2)'.
[Trace - 21:20:04.502 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3944ms.
[Trace - 21:20:09.771 PM] Sending request 'textDocument/semanticTokens/range - (2)'.
[Trace - 21:20:13.732 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3960ms.
[Trace - 21:20:19.162 PM] Sending request 'textDocument/semanticTokens/range - (2)'.
[Trace - 21:20:23.137 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3975ms.

with CL 340478:

[Trace - 21:21:05.430 PM] Sending request 'textDocument/semanticTokens/range - (2)'.
[Trace - 21:21:09.325 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3894ms.
[Trace - 21:21:14.927 PM] Sending request 'textDocument/semanticTokens/range - (2)'.
[Trace - 21:21:18.816 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3889ms.
[Trace - 21:21:24.381 PM] Sending request 'textDocument/semanticTokens/range - (2)'.
[Trace - 21:21:28.207 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3825ms.
[Trace - 21:21:34.599 PM] Sending request 'textDocument/semanticTokens/range - (2)'.
[Trace - 21:21:38.467 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3868ms.
[Trace - 21:21:47.691 PM] Sending request 'textDocument/semanticTokens/range - (2)'.
[Trace - 21:21:51.500 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3809ms.

Doesn't seem to do any difference.

[stamblerre]

Thanks for trying it out! I guess then that's just getting type information that's blocking it then. @pjweinb has https://golang.org/cl/339772 out right now, but I don't think it would fix the problem because we will still block on loading the file. I'm not exactly sure how we want to move forward here yet, since the type information enables us to provide better syntax highlighting in general, and most other clients already have good syntax highlighting so gopls just provides the extra on top of that.

[pjweinb]

I think the original idea, that the time is going to type checking, is correct. In gopls the semantic token request comes after several other requests, and at least in my client, i don't see the slow response. for tsprotocol.go (150KB, which would be too big, but I turned off that checking), the RPC takes 93ms of which 12.6 ms are in the semantic token processing. But it doesn't happen until about 2 seconds after initialization, and after initial workspace load.

…

On Sun, Aug 8, 2021 at 3:27 PM Pontus Leitzler ***@***.***> wrote: Thanks for looking in to this @stamblerre <https://github.com/stamblerre>. I tried that CL on top of d529aec and compared to d529aec now (this is on a slower machine, MBPr 2016, than what I used when I wrote the issue). Just opened up internal/lsp/semantic.go and restarted a few times: w/o CL 340478 just grep'ing the semTok request: [Trace - 21:19:31.886 PM] Sending request 'textDocument/semanticTokens/range - (2)'. [Trace - 21:19:35.631 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3744ms. [Trace - 21:19:42.580 PM] Sending request 'textDocument/semanticTokens/range - (2)'. [Trace - 21:19:46.372 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3792ms. [Trace - 21:19:51.799 PM] Sending request 'textDocument/semanticTokens/range - (2)'. [Trace - 21:19:55.582 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3782ms. [Trace - 21:20:00.557 PM] Sending request 'textDocument/semanticTokens/range - (2)'. [Trace - 21:20:04.502 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3944ms. [Trace - 21:20:09.771 PM] Sending request 'textDocument/semanticTokens/range - (2)'. [Trace - 21:20:13.732 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3960ms. [Trace - 21:20:19.162 PM] Sending request 'textDocument/semanticTokens/range - (2)'. [Trace - 21:20:23.137 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3975ms. with CL 340478: [Trace - 21:21:05.430 PM] Sending request 'textDocument/semanticTokens/range - (2)'. [Trace - 21:21:09.325 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3894ms. [Trace - 21:21:14.927 PM] Sending request 'textDocument/semanticTokens/range - (2)'. [Trace - 21:21:18.816 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3889ms. [Trace - 21:21:24.381 PM] Sending request 'textDocument/semanticTokens/range - (2)'. [Trace - 21:21:28.207 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3825ms. [Trace - 21:21:34.599 PM] Sending request 'textDocument/semanticTokens/range - (2)'. [Trace - 21:21:38.467 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3868ms. [Trace - 21:21:47.691 PM] Sending request 'textDocument/semanticTokens/range - (2)'. [Trace - 21:21:51.500 PM] Received response 'textDocument/semanticTokens/range - (2)' in 3809ms. Doesn't seem to do any difference. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#47465 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ABJIAI6A2BFER4EI5YWPFADT33LD7ANCNFSM5BHKA4DQ> . Triage notifications on the go with GitHub Mobile for iOS <https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675> or Android <https://play.google.com/store/apps/details?id=com.github.android&utm_campaign=notification-email> .

[stamblerre]

But it doesn't happen until about 2 seconds after initialization, and after initial workspace load.

I think we need to validate that semantic tokens doesn't block on the initial workspace load, because that should be asynchronous, and semantic tokens should be doing a file= package loading query. If it's not--that might be the issue.

[leitzler]

Yeah, it seems like it is the package loading / getting type information that is blocking.

I don't know in detail how it works so bare with me, but this is how I understand it.

The client doesn't really do anything that require type information before the initial semantic token request, so gopls should be able to provide tokens based on AST alone if type information isn't available.

I.e.:

• Initial semantic tokens based on AST alone
• "Improved" semantic tokens when type information is loaded (by using either SemanticTokensPartialResult or a gopls initiated workspace/semanticTokens/refresh)
• When a file is loaded its AST should be loaded as a priority, and semantic token information made available as a priority, with a call to semantic tokens only blocking on type information when the initial load is complete (on the basis that subsequent type checks will be quicker)
• As a separate(?) future thing add support for textDocument/semanticTokens/full/delta to improve performance further

[stamblerre]

While I agree that it might be nice to support semantic tokens without type information, it would add more complexity (type information is almost always available, except on startup and when an import changes), and that might make it look like semantic tokens are flickering. Since other clients already have a baseline implementation for semantic tokens, this doesn't seem like something we will be able to prioritize.