x/tools/gopls/internal/regtest/diagnostic: TestMultipleModules_Warning consistently fails when run locally with a 'go' build from head

[bcmills]

~/src/golang.org/x/tools/gopls$ go version
go version devel go1.17-303b194c6d Fri Apr 30 00:32:42 2021 +0000 linux/amd64

~/src/golang.org/x/tools/gopls$ git rev-parse HEAD
aec13729f18012eee88146c2c9a1069fbe1227ae

~/src/golang.org/x/tools/gopls$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/usr/local/google/home/bcmills/.cache/go-build"
GOENV="/usr/local/google/home/bcmills/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/usr/local/google/home/bcmills/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/usr/local/google/home/bcmills"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/google/home/bcmills/go-review"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/google/home/bcmills/go-review/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="devel go1.17-303b194c6d Fri Apr 30 00:32:42 2021 +0000"
GCCGO="/usr/local/google/home/bcmills/bin/gccgo"
AR="ar"
CC="gcc"
CXX="c++"
CGO_ENABLED="1"
GOMOD="/usr/local/google/home/bcmills/src/golang.org/x/tools/gopls/go.mod"
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 -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build322604320=/tmp/go-build -gno-record-gcc-switches"

Test failure log:

go test ./internal/regtest/diagnostics -run=TestMultipleModules_Warning/GO111MODULE=on/singleton

~/src/golang.org/x/tools/gopls$ go test ./internal/regtest/diagnostics -run=TestMultipleModules_Warning/GO111MODULE=on/singleton

#### Start Gopls Test Logs for "TestMultipleModules_Warning/GO111MODULE=on/singleton"
[Trace - 23:02:00.891 PM] Sending request 'initialize - (1)'.
Params: {"processId":0,"clientInfo":{"name":"fakeclient","version":"v1.0.0"},"rootUri":"","capabilities":{"workspace":{"didChangeConfiguration":{},"didChangeWatchedFiles":{"dynamicRegistration":true},"executeCommand":{},"semanticTokens":{},"codeLens":{},"configuration":true},"textDocument":{"synchronization":{},"completion":{"completionItem":{"snippetSupport":true,"tagSupport":{"valueSet":null},"resolveSupport":{"properties":null},"insertTextModeSupport":{"valueSet":null}},"completionItemKind":{}},"hover":{},"signatureHelp":{"signatureInformation":{"parameterInformation":{}}},"declaration":{},"definition":{},"typeDefinition":{},"implementation":{},"references":{},"documentHighlight":{},"documentSymbol":{"symbolKind":{},"tagSupport":{"valueSet":null}},"codeAction":{"codeActionLiteralSupport":{"codeActionKind":{"valueSet":null}},"resolveSupport":{"properties":null}},"codeLens":{},"documentLink":{},"colorProvider":{},"formatting":{},"rangeFormatting":{},"onTypeFormatting":{},"rename":{},"foldingRange":{},"selectionRange":{},"publishDiagnostics":{"tagSupport":{"valueSet":null}},"callHierarchy":{},"semanticTokens":{"requests":{},"tokenTypes":null,"tokenModifiers":null,"formats":null},"linkedEditingRange":{},"moniker":{}},"window":{"workDoneProgress":true,"showMessage":{"messageActionItem":{}},"showDocument":{"support":false}},"general":{"staleRequestSupport":{"cancel":false,"retryOnContentModified":null},"regularExpressions":{"engine":""},"markdown":{"parser":""}}},"initializationOptions":{"completionBudget":"10s","env":{"GO111MODULE":"on","GOMODCACHE":"","GOPACKAGESDRIVER":"off","GOPATH":"/tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/gopath","GOPROXY":"file:///tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/proxy","GOSUMDB":"off"},"expandWorkspaceToModule":true,"experimentalDiagnosticsDelay":"10ms","verboseWorkDoneProgress":true},"trace":"messages","workspaceFolders":[{"uri":"file:///tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/work","name":"work"}]}


[Trace - 23:02:00.891 PM] Received response 'initialize - (1)' in 0ms.
Result: {"capabilities":{"textDocumentSync":{"openClose":true,"change":2,"save":{}},"completionProvider":{"triggerCharacters":["."],"completionItem":{}},"hoverProvider":true,"signatureHelpProvider":{"triggerCharacters":["(",","]},"definitionProvider":true,"typeDefinitionProvider":true,"implementationProvider":true,"referencesProvider":true,"documentHighlightProvider":true,"documentSymbolProvider":true,"codeActionProvider":true,"codeLensProvider":{},"documentLinkProvider":{},"workspaceSymbolProvider":true,"documentFormattingProvider":true,"documentOnTypeFormattingProvider":{"firstTriggerCharacter":""},"renameProvider":true,"foldingRangeProvider":true,"executeCommandProvider":{"commands":["gopls.add_dependency","gopls.add_import","gopls.apply_fix","gopls.check_upgrades","gopls.gc_details","gopls.generate","gopls.generate_gopls_mod","gopls.go_get_package","gopls.list_known_packages","gopls.regenerate_cgo","gopls.remove_dependency","gopls.run_tests","gopls.start_debugging","gopls.test","gopls.tidy","gopls.toggle_gc_details","gopls.update_go_sum","gopls.upgrade_dependency","gopls.vendor","gopls.workspace_metadata"]},"callHierarchyProvider":true,"workspace":{"workspaceFolders":{"supported":true,"changeNotifications":"workspace/didChangeWorkspaceFolders"}}},"serverInfo":{"name":"gopls","version":"{\"path\":\"gopls, built in GOPATH mode\",\"version\":\"master\"}"}}


[Trace - 23:02:00.892 PM] Sending notification 'initialized'.
Params: {}


[Trace - 23:02:00.892 PM] Received request 'window/workDoneProgress/create - (1)'.
Params: {"token":"5577006791947779410"}


[Trace - 23:02:00.892 PM] Sending response 'window/workDoneProgress/create - (1)' in 0ms.
Result: 


[Trace - 23:02:00.892 PM] Received notification '$/progress'.
Params: {"token":"5577006791947779410","value":{"kind":"begin","title":"diagnosing initial workspace load","message":"Calculating diagnostics for initial workspace load..."}}


[Trace - 23:02:00.892 PM] Received request 'window/workDoneProgress/create - (2)'.
Params: {"token":"8674665223082153551"}


[Trace - 23:02:00.892 PM] Sending response 'window/workDoneProgress/create - (2)' in 0ms.
Result: 


[Trace - 23:02:00.893 PM] Received notification '$/progress'.
Params: {"token":"8674665223082153551","value":{"kind":"begin","title":"Setting up workspace","message":"Loading packages..."}}


[Trace - 23:02:00.893 PM] Received request 'workspace/configuration - (3)'.
Params: {"items":[{"scopeUri":"file:///tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/work","section":"gopls"}]}


[Trace - 23:02:00.893 PM] Sending response 'workspace/configuration - (3)' in 0ms.
Result: [{"completionBudget":"10s","env":{"GO111MODULE":"on","GOMODCACHE":"","GOPACKAGESDRIVER":"off","GOPATH":"/tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/gopath","GOPROXY":"file:///tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/proxy","GOSUMDB":"off"},"expandWorkspaceToModule":true,"experimentalDiagnosticsDelay":"10ms","verboseWorkDoneProgress":true}]


[Trace - 23:02:00.911 PM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2021/04/29 23:02:00 go env for /tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/work\n(root /tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/work)\n(go version go version devel go1.17-303b194c6d Fri Apr 30 00:32:42 2021 +0000 linux/amd64)\n(valid build configuration = true)\n(build flags: [])\nGO111MODULE=on\nGOINSECURE=\nGOROOT=/usr/local/google/home/bcmills/go-review\nGOSUMDB=off\nGOCACHE=/usr/local/google/home/bcmills/.cache/go-build\nGONOPROXY=\nGOPATH=/tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/gopath\nGONOSUMDB=\nGOFLAGS=\nGOPRIVATE=\nGOPROXY=file:///tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/proxy\nGOMOD=/dev/null\nGOMODCACHE=\n\n"}


[Trace - 23:02:00.915 PM] Received notification 'window/logMessage'.
Params: {"type":1,"message":"2021/04/29 23:02:00 initial workspace load failed: err: exit status 1: stderr: go: go.mod file not found in current directory or any parent directory; see 'go help modules'\n: packages.Load error\n"}


[Trace - 23:02:00.916 PM] Received notification 'window/logMessage'.
Params: {"type":1,"message":"2021/04/29 23:02:00 go/packages.Load: err: exit status 1: stderr: go: go.mod file not found in current directory or any parent directory; see 'go help modules'\n\n\tsnapshot=0\n\tdirectory=/tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/work\n\tquery=[./... builtin]\n\tpackages=0\n"}


[Trace - 23:02:00.916 PM] Received notification '$/progress'.
Params: {"token":"8674665223082153551","value":{"kind":"end","message":"Finished loading packages."}}


[Trace - 23:02:00.916 PM] Received request 'client/registerCapability - (4)'.
Params: {"registrations":[{"id":"workspace/didChangeWatchedFiles-0","method":"workspace/didChangeWatchedFiles","registerOptions":{"watchers":[{"globPattern":"**/*.{go,mod,sum}","kind":7}]}}]}


[Trace - 23:02:00.917 PM] Sending response 'client/registerCapability - (4)' in 0ms.
Result: 


[Trace - 23:02:00.917 PM] Received notification '$/progress'.
Params: {"token":"5577006791947779410","value":{"kind":"end","message":"Done."}}


[Trace - 23:02:00.918 PM] Sending notification 'textDocument/didOpen'.
Params: {"textDocument":{"uri":"file:///tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/work/a/a.go","languageId":"go","version":1,"text":"package a\n"}}


[Trace - 23:02:00.918 PM] Sending notification 'textDocument/didOpen'.
Params: {"textDocument":{"uri":"file:///tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/work/b/go.mod","languageId":"","version":1,"text":"module b.com\n\ngo 1.12\n"}}


[Trace - 23:02:00.918 PM] Received request 'window/workDoneProgress/create - (5)'.
Params: {"token":"6129484611666145821"}


[Trace - 23:02:00.918 PM] Sending response 'window/workDoneProgress/create - (5)' in 0ms.
Result: 


[Trace - 23:02:00.918 PM] Received notification '$/progress'.
Params: {"token":"6129484611666145821","value":{"kind":"begin","title":"diagnosing opened files","message":"Calculating file diagnostics..."}}


[Trace - 23:02:00.919 PM] Received request 'client/registerCapability - (6)'.
Params: {"registrations":[{"id":"workspace/didChangeWatchedFiles-1","method":"workspace/didChangeWatchedFiles","registerOptions":{"watchers":[{"globPattern":"**/*.{go,mod,sum}","kind":7},{"globPattern":"{/tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/work/a}","kind":7}]}}]}


[Trace - 23:02:00.919 PM] Received notification 'window/logMessage'.
Params: {"type":1,"message":"2021/04/29 23:02:00 checking for builtin: no builtin package for view work\n"}


[Trace - 23:02:00.919 PM] Sending response 'client/registerCapability - (6)' in 0ms.
Result: 


[Trace - 23:02:00.919 PM] Received request 'client/unregisterCapability - (7)'.
Params: {"unregisterations":[{"id":"workspace/didChangeWatchedFiles-0","method":"workspace/didChangeWatchedFiles"}]}


[Trace - 23:02:00.920 PM] Sending response 'client/unregisterCapability - (7)' in 0ms.
Result: 


[Trace - 23:02:00.920 PM] Received request 'window/workDoneProgress/create - (8)'.
Params: {"token":"4037200794235010051"}


[Trace - 23:02:00.920 PM] Sending response 'window/workDoneProgress/create - (8)' in 0ms.
Result: 


[Trace - 23:02:00.920 PM] Received notification '$/progress'.
Params: {"token":"4037200794235010051","value":{"kind":"begin","title":"diagnosing opened files","message":"Calculating file diagnostics..."}}


[Trace - 23:02:00.921 PM] Received request 'client/registerCapability - (9)'.
Params: {"registrations":[{"id":"workspace/didChangeWatchedFiles-2","method":"workspace/didChangeWatchedFiles","registerOptions":{"watchers":[{"globPattern":"**/*.{go,mod,sum}","kind":7},{"globPattern":"{/tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/work/a,/tmp/gopls-regtest-3525144785/TestMultipleModules_Warning/GO111MODULE=on/singleton/work/b}","kind":7}]}}]}


[Trace - 23:02:00.921 PM] Received notification 'window/logMessage'.
Params: {"type":1,"message":"2021/04/29 23:02:00 checking for builtin: no builtin package for view work\n"}


[Trace - 23:02:00.921 PM] Sending response 'client/registerCapability - (9)' in 0ms.
Result: 


[Trace - 23:02:00.921 PM] Received request 'client/unregisterCapability - (10)'.
Params: {"unregisterations":[{"id":"workspace/didChangeWatchedFiles-1","method":"workspace/didChangeWatchedFiles"}]}


[Trace - 23:02:00.921 PM] Sending response 'client/unregisterCapability - (10)' in 0ms.
Result: 


[Trace - 23:02:00.921 PM] Received notification '$/progress'.
Params: {"token":"6129484611666145821","value":{"kind":"end","message":"Done."}}


[Trace - 23:02:00.931 PM] Received notification '$/progress'.
Params: {"token":"4037200794235010051","value":{"kind":"end","message":"Done."}}


#### End Gopls Test Logs for "TestMultipleModules_Warning/GO111MODULE=on/singleton"
--- FAIL: TestMultipleModules_Warning (20.02s)
    --- FAIL: TestMultipleModules_Warning/GO111MODULE=on (20.02s)
        --- FAIL: TestMultipleModules_Warning/GO111MODULE=on/singleton (20.02s)
            diagnostics_test.go:1682: waiting on:
                	Unmet: a/a.go: diagnostic at {line:0, column:0} (location of "package a")
                	Unmet: b/go.mod: diagnostic at {line:0, column:0} (location of "module b.com")
                	Unmet: outstanding work: Error loading workspace
                
                err:context deadline exceeded
                
                state:
                #### log messages (see RPC logs for full text):
                	Info: "2021/04/29 23:02:00 go env for /tmp/gopls-regtest-...
                	Error: "2021/04/29 23:02:00 initial workspace load failed...
                	Error: "2021/04/29 23:02:00 go/packages.Load: err: exit s...
                	Error: "2021/04/29 23:02:00 checking for builtin: no buil...
                	Error: "2021/04/29 23:02:00 checking for builtin: no buil...
                
                #### diagnostics:
                
                #### outstanding work:
                #### completed work:
                	Setting up workspace: 1
                	diagnosing initial workspace load: 1
                	diagnosing opened files: 2
            runner.go:300: Shutdown: context deadline exceeded
FAIL
FAIL	golang.org/x/tools/gopls/internal/regtest/diagnostics	20.132s
FAIL

CC @heschi @stamblerre @findleyr

[findleyr]

This is an unintended consequence of https://golang.org/cl/307169: we are again subject to breakages related to the Google internal GOPACKAGESDRIVER.

I think we all unfortunately run with GOPACKAGESDRIVER=off, so didn't notice the failure. Bryan, would you mind confirming that the test passes with GOPACKAGESDRIVER=off?

Removing Soon, as this should only affect Googlers, but should still be fixed.

[bcmills]

Confirmed, the test passes for me with GOPACKAGESDRIVER=off.

[gopherbot]

Change https://golang.org/cl/315649 mentions this issue: internal/lsp/regtest: force GOPACKAGESDRIVER=off

[findleyr]

Thanks, and thanks for the report. Fix incoming.