x/tools/gopls: log errors during gopls check

[russelldavis]

What did you do?

Trigger a simple error in gopls, for example by setting GOROOT to an invalid path:

GOROOT=/invalid gopls -rpc.trace -v check compile/main.go

What did you expect to see?

gopls should immediately exit after printing the error.

What did you see instead?

gopls hangs for 30s after printing the error, then prints gopls: timed out waiting for results from ...

I suspect the same thing is happening with the 30s delay in #35520

Build info

golang.org/x/tools/gopls 0.2.0
    golang.org/x/tools/gopls@v0.2.0 h1:ddCHfScTYOG6auAcEKXCFN5iSeKSAnYcPv+7zVJBd+U=
    github.com/BurntSushi/toml@v0.3.1 h1:WXkYYl6Yr3qBf1K79EBnL4mak0OimBfB0XUf9Vl28OQ=
    github.com/sergi/go-diff@v1.0.0 h1:Kpca3qRNrduNnOQeazBd0ysaKrUJiIuISHxogkT9RPQ=
    golang.org/x/sync@v0.0.0-20190423024810-112230192c58 h1:8gQV6CLnAEikrhgkHFbMAEhagSSnXWGV915qUMm9mrU=
    golang.org/x/tools@v0.0.0-20191108194844-46f05828f2fe h1:FNzasIzfY1IIdyTs/+o3Qv1b7YdffPbBXyjZ5VJJdIA=
    golang.org/x/xerrors@v0.0.0-20190717185122-a985d3407aa7 h1:9zdDQZ7Thm29KFXgAX/+yaf3eVbP7djjWp/dXAppNCc=
    honnef.co/go/tools@v0.0.1-2019.2.3 h1:3JgtbtFHMiCmsznwGVTUWbgGov+pVqnlf1dEJTNAXeM=

Go info

go version go1.13.4 darwin/amd64

GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/russell/Library/Caches/go-build"
GOENV="/Users/russell/Library/Application Support/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/russell/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/Cellar/go/1.13.4/libexec"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/Cellar/go/1.13.4/libexec/pkg/tool/darwin_amd64"
GCCGO="gccgo"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/bk/1vdjn7vd19x41x0ztsbvmw400000gq/T/go-build194598443=/tmp/go-build -gno-record-gcc-switches -fno-common"

[gopherbot]

Thank you for filing a gopls issue! Please take a look at the Troubleshooting guide, and make sure that you have provided all of the relevant information here.

[ianthehat]

The trouble is the nature of diagnostics in the LSP.
They are delivered asynchronously to the client on the servers whim, and they can be delivered multiple times for any given file, changing the list of issues each time. There is no call the client can use to know if the server is done delivering diagnostics or not, which means the command line gopls has to just wait and see if it gets diagnostics for the file of interest. It currently waits for at most 30s before giving up.
So there are two issues:

1. we try in gopls to make sure we always deliver diagnostics exactly once for any file/version of interest, which we are failing to do in this case
2. we need a signal that no more diagnostics are pending so that the command line does not have to have a time out wait (fixing this would mean we could relax the restriction in 1)

[stamblerre]

In gopls check, we might able to handle the logging of errors in some special way to indicate that we're exiting early. What do you think, @ianthehat?

[ianthehat]

Yeah, that is kind of what I was thinking when I said some kind of signal, but I know there was also a proposal and some work on adding background task and progress monitoring to the LSP spec, if those have arrived (or are likely to in the future) we could do something cleaner than just trying to recognize a log message

[stamblerre]

Yeah, there's definitely support for in-progress replies for the majority of the requests, but I think for diagnostics there isn't anything like that (yet).

[stamblerre]

So, to summarize this issue, we need 2 key fixes for gopls check:

1. Errors sent by window/logMessage should be shown to the user.
2. There needs to be some consistent way that gopls can tell the user that it is done sending diagnostics for the file in question.

@ianthehat is going to take a look at implementing these fixes.

[stamblerre]

We are now relying on the fact that the diagnostics will come for file version 1 to determine when diagnostics are done being sent. The remaining work would be make sure that logged errors are shown to the user.

[pjweinbgo]

It's worse than that. If there are just Errors, they are eaten by something and never seen by the loop checking for file diagnostics. Thinking...

[stamblerre]

I just tried running GOPATH=/invalid gopls -rpc.trace -v check ./internal/lsp/server.go to test this out, and I saw errors being logged as expected. I think that this has been fixed by our switch to using a non-standard request (diagnoseFiles).