x/tools/gopls: "addView called before server initialized"

[pommicket]

gopls version

Build info
----------
golang.org/x/tools/gopls v0.11.0
    golang.org/x/tools/[email protected] h1:/nvKHdTtePQmrv9XN3gIUN9MOdUrKzO/dcqgbG6x8EY=
    github.com/BurntSushi/[email protected] h1:9F2/+DoOYIOksmaJFPw1tGFy1eDnIJXg+UHjuD8lTak=
    github.com/google/[email protected] h1:O2Tfq5qg4qc4AmwVlvv0oLiVAGB7enBSJ2x2DqQFi38=
    github.com/sergi/[email protected] h1:we8PVUC3FE2uYfodKH/nBHMSetSfHDR6scGdBi+erh0=
    golang.org/x/[email protected] h1:QfTh0HpN6hlw6D3vu8DAwC8pBIwikq0AI1evdm+FksE=
    golang.org/x/exp/[email protected] h1:fl8k2zg28yA23264d82M4dp+YlJ3ngDcpuB1bewkQi4=
    golang.org/x/[email protected] h1:LapD9S96VoQRhi/GrNTqeBJFrUjs5UHCAtTlgwA5oZA=
    golang.org/x/[email protected] h1:wsuoTGHzEhffawBOhz5CYhcrV4IdKZbEyZjBMuTp12o=
    golang.org/x/[email protected] h1:ljd4t30dBnAvMZaQCevtY0xLLD0A+bRZXbgLMLU1F/A=
    golang.org/x/[email protected] h1:BrVqGRd7+k1DiOgtnFvAkoQEWQvBc25ouMJM6429SFg=
    golang.org/x/[email protected] h1:7/HkGkN/2ktghBCSRRgp31wAww4syfsW52tj7yirjWk=
    golang.org/x/[email protected] h1:qptQiQwEpETwDiz85LKtChqif9xhVkAm8Nhxs0xnTww=
    honnef.co/go/[email protected] h1:oDx7VAwstgpYpb3wv0oxiZlxY+foCpRAwY7Vk6XpAgA=
    mvdan.cc/[email protected] h1:JVf4NN1mIpHogBj7ABpgOyZc65/UUOkKQFkoURsz4MM=
    mvdan.cc/xurls/[email protected] h1:tzxjVAj+wSBmDcF6zBB7/myTy3gX9xvi8Tyr28AuQgc=
go: go1.19.4

What did you do?

Here is a simple "virtual" LSP client:

#!/bin/bash
write_message() {
	printf "Content-Length: ${#1}\r\n\r\n$1"
}

f() {
	write_message '{"jsonrpc":"2.0","id":0,"method":"initialize",
	               "params":{"processId":'$$',"rootUri":"file:///tmp"}}'
	sleep 2
	write_message '{"jsonrpc":"2.0","method":"initialized"}'
	sleep 2
	write_message '{"jsonrpc":"2.0","method":"textDocument/didOpen",
	                "params":{"textDocument":{"uri":"file:///tmp/test.go",
	                                          "languageId":"go","version":0,"text":""}}}'
	sleep 30
}

f | gopls

What did you expect to see?

This is (as far as I'm aware) a perfectly valid series of LSP requests. (By the time the initialized notification is sent,
the server has already sent the initialize response.)

There should be no problems for gopls here.

What did you see instead?

After the 3rd message, gopls gives the client these notifications:

{"jsonrpc":"2.0","method":"window/showMessage","params":{"type":4,"message":"Loading packages..."}}
{"jsonrpc":"2.0","method":"window/showMessage","params":{"type":3,"message":"Error loading packages: addView called before server initialized"}}
{"jsonrpc":"2.0","method":"window/showMessage","params":{"type":1,"message":"Error loading workspace folders (expected 1, got 0)\nfailed to load view for file:///tmp: addView called before server initialized\n"}}

Using workspaceFolders instead of rootUri gives the exact same result (in any case both must be handled by an LSP server).
Waiting for more time after sending initialized does not resolve the issue.

Sending any more requests after this gives back the cryptic response:

{"jsonrpc":"2.0","error":{"code":0,"message":"no views in session"},"id":...}

with the non-existent error code 0.

[findleyr]

I can repro, and will investigate. Thank you for the script. My guess is that it is the lack of workspace folders that causes this script to fail, but I'm surprised that this wouldn't have been reported before now (I verified that this bug exists at least back to [email protected].

How did you first encounter this?

[fischerling]

I can repro, and will investigate. Thank you for the script. My guess is that it is the lack of workspace folders that causes this script to fail, but I'm surprised that this wouldn't have been reported before now (I verified that this bug exists at least back to [email protected].

How did you first encounter this?

I encounter the same bug with a LSP plugin for the vis editor, I maintain.
The LSP client for the vis editor has no sense of LSP workspaces.

But since I had no easy reproducer I did not open an issue yet.
However, I am very happy that @pommicket did :)

[findleyr]

Ok, I investigated and the bug is actually that the initialized notification is never processed, because parsing params fails as a result of the params field missing. If you add "params": {} to the initialized notification, it works.

This is a bug in gopls, as per the jsonrpc2 spec params may be omitted.
https://www.jsonrpc.org/specification#request_object

There is also missing logging that would surface this parse error.

CC @pjweinb, who maintains our protocol package. I think we need to:

1. treat nil params as the zero value
2. log if unmarshalling fails, or return an error from the serverDispatch function in this case (which will cause the jsonrpc2 layer to log)

[gopherbot]

Change https://go.dev/cl/548857 mentions this issue: gopls/internal/lsp/protocol: request.params is optional