x/tools/gopls/internal/regtest/diagnostics: TestEditGoDirective/experimental failure with deadline exceeded

[hyangah]

https://storage.googleapis.com/go-build-log/b95d332c/windows-386-2008_1bfb115d.log

Observed during trybot run for https://go-review.googlesource.com/c/tools/+/395694.

#### End Gopls Test Logs for "TestEditGoDirective/experimental"
--- FAIL: TestEditGoDirective (386.05s)
    --- FAIL: TestEditGoDirective/experimental (384.98s)
        diagnostics_test.go:2213: waiting on:
            	Unmet: empty diagnostics for "main.go"
            
            err:context deadline exceeded
            
            state:
            #### log messages (see RPC logs for full text):
            	Info: "2022/03/24 21:46:57 go env for C:\\Users\\gopher\\...
            	Info: "2022/03/24 21:46:57 go/packages.Load\n\tsnapshot=0...
            	Error: "2022/03/24 21:46:57 building workspace mod file: ...
            	Error: "2022/03/24 21:46:57 errors loading workspace: no ...
            	Info: "2022/03/24 21:47:27 background imports cache refre...
            	Info: "2022/03/24 21:47:27 background refresh finished af...
            
            #### diagnostics:
            	main.go (version 0):
            		(2, 7): type parameters require go1.18 or later
            		(2, 9): undeclared name: any (requires version go1.18 or later)
            	go.mod (version 0):
            		(0, 0): no module path for file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/go.mod
            
            #### outstanding work:
            	Error loading workspace: 0.00
            #### completed work:
            	Load: 1
            	Setting up workspace: 1
            	diagnosing initial workspace load: 1
            	diagnosing files changed on disk: 1
        runner.go:324: closing editor: Shutdown: context deadline exceeded
FAIL
FAIL	golang.org/x/tools/gopls/internal/regtest/diagnostics	590.381s

This log message when running gopls.edit_go_directive command is suspicious:

[Trace - 21:46:57.910 PM] Received notification 'window/logMessage'.
Params: {"type":1,"message":"2022/03/24 21:46:57 building workspace mod file: no module declaration for file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/go.mod\n"}

Potential file corruption or windows file mishandling? (windows)

full gopls test logs

``` #### Start Gopls Test Logs for "TestEditGoDirective/experimental" [Trace - 21:46:57.134 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":{},"inlineValue":{},"inlayHint":{},"configuration":true},"textDocument":{"synchronization":{},"completion":{"completionItem":{"snippetSupport":true,"tagSupport":{"valueSet":[1]},"resolveSupport":{"properties":null},"insertTextModeSupport":{"valueSet":null}},"completionItemKind":{},"completionList":{}},"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":{"full":true},"tokenTypes":["namespace","type","class","enum","interface","struct","typeParameter","parameter","variable","property","enumMember","event","function","method","macro","keyword","modifier","comment","string","number","regexp","operator"],"tokenModifiers":null,"formats":null},"linkedEditingRange":{},"moniker":{},"typeHierarchy":{},"inlineValue":{},"inlayHint":{"resolveSupport":{"properties":null}}},"window":{"workDoneProgress":true,"showMessage":{"messageActionItem":{}},"showDocument":{"support":false}},"general":{"staleRequestSupport":{"cancel":false,"retryOnContentModified":null},"regularExpressions":{"engine":""},"markdown":{"parser":""}}},"initializationOptions":{"completionBudget":"10s","diagnosticsDelay":"10ms","env":{"GO111MODULE":"","GOMODCACHE":"","GOPACKAGESDRIVER":"off","GOPATH":"C:\\Users\\gopher\\AppData\\Local\\Temp\\gopls-regtest-628564068\\TestEditGoDirective\\experimental\\gopath","GOPROXY":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/proxy","GOSUMDB":"off"},"expandWorkspaceToModule":true,"verboseWorkDoneProgress":true},"trace":"messages","workspaceFolders":[{"uri":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work","name":"work"}]}

[Trace - 21:46:57.134 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.edit_go_directive","gopls.gc_details","gopls.generate","gopls.generate_gopls_mod","gopls.go_get_package","gopls.list_imports","gopls.list_known_packages","gopls.regenerate_cgo","gopls.remove_dependency","gopls.run_tests","gopls.run_vulncheck_exp","gopls.start_debugging","gopls.test","gopls.tidy","gopls.toggle_gc_details","gopls.update_go_sum","gopls.upgrade_dependency","gopls.vendor"]},"callHierarchyProvider":true,"workspace":{"workspaceFolders":{"supported":true,"changeNotifications":"workspace/didChangeWorkspaceFolders"}}},"serverInfo":{"name":"gopls","version":"{"GoVersion":"devel b95d332","Path":"","Main":{"Path":"","Version":"","Sum":"","Replace":null},"Deps":null,"Settings":null,"Version":"master"}"}}

[Trace - 21:46:57.135 PM] Sending notification 'initialized'.
Params: {}

[Trace - 21:46:57.135 PM] Received request 'window/workDoneProgress/create - (1)'.
Params: {"token":"1439228946174806623"}

[Trace - 21:46:57.135 PM] Sending response 'window/workDoneProgress/create - (1)' in 0ms.
Result:

[Trace - 21:46:57.135 PM] Received notification '$/progress'.
Params: {"token":"1439228946174806623","value":{"kind":"begin","title":"diagnosing initial workspace load","message":"Calculating diagnostics for initial workspace load..."}}

[Trace - 21:46:57.135 PM] Received request 'window/workDoneProgress/create - (2)'.
Params: {"token":"4995735335659635616"}

[Trace - 21:46:57.135 PM] Sending response 'window/workDoneProgress/create - (2)' in 0ms.
Result:

[Trace - 21:46:57.135 PM] Received notification '$/progress'.
Params: {"token":"4995735335659635616","value":{"kind":"begin","title":"Setting up workspace","message":"Loading packages..."}}

[Trace - 21:46:57.136 PM] Received request 'workspace/configuration - (3)'.
Params: {"items":[{"scopeUri":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work","section":"gopls"}]}

[Trace - 21:46:57.136 PM] Sending response 'workspace/configuration - (3)' in 0ms.
Result: [{"completionBudget":"10s","diagnosticsDelay":"10ms","env":{"GO111MODULE":"","GOMODCACHE":"","GOPACKAGESDRIVER":"off","GOPATH":"C:\Users\gopher\AppData\Local\Temp\gopls-regtest-628564068\TestEditGoDirective\experimental\gopath","GOPROXY":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/proxy","GOSUMDB":"off"},"expandWorkspaceToModule":true,"verboseWorkDoneProgress":true}]

[Trace - 21:46:57.283 PM] Received request 'window/workDoneProgress/create - (4)'.
Params: {"token":"2477080916348470461"}

[Trace - 21:46:57.283 PM] Sending response 'window/workDoneProgress/create - (4)' in 0ms.
Result:

[Trace - 21:46:57.283 PM] Received notification '$/progress'.
Params: {"token":"2477080916348470461","value":{"kind":"begin","title":"Load","message":"Loading query=[builtin mod.com/...]"}}

[Trace - 21:46:57.356 PM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2022/03/24 21:46:57 go env for C:\Users\gopher\AppData\Local\Temp\gopls-regtest-628564068\TestEditGoDirective\experimental\work\n(root C:\Users\gopher\AppData\Local\Temp\gopls-regtest-628564068\TestEditGoDirective\experimental\work)\n(go version go version devel b95d332 windows/386)\n(valid build configuration = true)\n(build flags: [])\nGOFLAGS=\nGOINSECURE=\nGOWORK=\nGONOSUMDB=\nGO111MODULE=\nGOCACHE=C:\Users\gopher\AppData\Local\go-build\nGOMOD=C:\Users\gopher\AppData\Local\Temp\gopls-regtest-628564068\TestEditGoDirective\experimental\work\go.mod\nGOSUMDB=off\nGOPATH=C:\Users\gopher\AppData\Local\Temp\gopls-regtest-628564068\TestEditGoDirective\experimental\gopath\nGOROOT=C:\workdir\go\nGONOPROXY=\nGOPROXY=file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/proxy\nGOPRIVATE=\nGOMODCACHE=\n\n"}

[Trace - 21:46:57.772 PM] Received notification '$/progress'.
Params: {"token":"2477080916348470461","value":{"kind":"end","message":"Done."}}

[Trace - 21:46:57.773 PM] Received notification '$/progress'.
Params: {"token":"4995735335659635616","value":{"kind":"end","message":"Finished loading packages."}}

[Trace - 21:46:57.776 PM] Received request 'client/registerCapability - (5)'.
Params: {"registrations":[{"id":"workspace/didChangeWatchedFiles-0","method":"workspace/didChangeWatchedFiles","registerOptions":{"watchers":[{"globPattern":"**/*.{go,mod,sum,work}","kind":7}]}}]}

[Trace - 21:46:57.776 PM] Sending response 'client/registerCapability - (5)' in 0ms.
Result:

[Trace - 21:46:57.777 PM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2022/03/24 21:46:57 go/packages.Load\n\tsnapshot=0\n\tdirectory=C:\Users\gopher\AppData\Local\Temp\gopls-workspace-mod1975635461\n\tquery=[builtin mod.com/...]\n\tpackages=2\n"}

[Trace - 21:46:57.810 PM] Received notification 'textDocument/publishDiagnostics'.
Params: {"uri":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/main.go","diagnostics":[{"range":{"start":{"line":2,"character":7},"end":{"line":2,"character":12}},"severity":1,"code":"UnsupportedFeature","codeDescription":{"href":"https://pkg.go.dev/golang.org/x/tools/internal/typesinternal?utm_source=gopls#UnsupportedFeature"},"source":"compiler","message":"type parameters require go1.18 or later"},{"range":{"start":{"line":2,"character":9},"end":{"line":2,"character":12}},"severity":1,"code":"UndeclaredName","codeDescription":{"href":"https://pkg.go.dev/golang.org/x/tools/internal/typesinternal?utm_source=gopls#UndeclaredName"},"source":"compiler","message":"undeclared name: any (requires version go1.18 or later)"}]}

[Trace - 21:46:57.811 PM] Received notification '$/progress'.
Params: {"token":"1439228946174806623","value":{"kind":"end","message":"Done."}}

[Trace - 21:46:57.813 PM] Sending request 'textDocument/codeAction - (2)'.
Params: {"textDocument":{"uri":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/main.go"},"range":{"start":{"line":0,"character":0},"end":{"line":0,"character":0}},"context":{"diagnostics":[{"range":{"start":{"line":2,"character":7},"end":{"line":2,"character":12}},"severity":1,"code":"UnsupportedFeature","codeDescription":{"href":"https://pkg.go.dev/golang.org/x/tools/internal/typesinternal?utm_source=gopls#UnsupportedFeature"},"source":"compiler","message":"type parameters require go1.18 or later"},{"range":{"start":{"line":2,"character":9},"end":{"line":2,"character":12}},"severity":1,"code":"UndeclaredName","codeDescription":{"href":"https://pkg.go.dev/golang.org/x/tools/internal/typesinternal?utm_source=gopls#UndeclaredName"},"source":"compiler","message":"undeclared name: any (requires version go1.18 or later)"}],"only":["source.fixAll","quickfix"]}}

[Trace - 21:46:57.815 PM] Received response 'textDocument/codeAction - (2)' in 1ms.
Result: [{"title":"go mod edit -go=1.18","kind":"quickfix","diagnostics":[{"range":{"start":{"line":2,"character":7},"end":{"line":2,"character":12}},"severity":1,"code":"UnsupportedFeature","codeDescription":{"href":"https://pkg.go.dev/golang.org/x/tools/internal/typesinternal?utm_source=gopls#UnsupportedFeature"},"source":"compiler","message":"type parameters require go1.18 or later"}],"edit":{},"command":{"title":"go mod edit -go=1.18","command":"gopls.edit_go_directive","arguments":[{"URI":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/main.go","Version":"1.18"}]}},{"title":"go mod edit -go=1.18","kind":"quickfix","diagnostics":[{"range":{"start":{"line":2,"character":9},"end":{"line":2,"character":12}},"severity":1,"code":"UndeclaredName","codeDescription":{"href":"https://pkg.go.dev/golang.org/x/tools/internal/typesinternal?utm_source=gopls#UndeclaredName"},"source":"compiler","message":"undeclared name: any (requires version go1.18 or later)"}],"edit":{},"command":{"title":"go mod edit -go=1.18","command":"gopls.edit_go_directive","arguments":[{"URI":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/main.go","Version":"1.18"}]}}]

[Trace - 21:46:57.815 PM] Sending request 'workspace/executeCommand - (3)'.
Params: {"command":"gopls.edit_go_directive","arguments":[{"URI":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/main.go","Version":"1.18"}]}

[Trace - 21:46:57.855 PM] Received response 'workspace/executeCommand - (3)' in 40ms.
Result: null

[Trace - 21:46:57.857 PM] Sending notification 'workspace/didChangeWatchedFiles'.
Params: {"changes":[{"uri":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/go.mod","type":2}]}

[Trace - 21:46:57.857 PM] Received request 'window/workDoneProgress/create - (6)'.
Params: {"token":"8741248032194605601"}

[Trace - 21:46:57.858 PM] Sending response 'window/workDoneProgress/create - (6)' in 0ms.
Result:

[Trace - 21:46:57.858 PM] Received notification '$/progress'.
Params: {"token":"8741248032194605601","value":{"kind":"begin","title":"diagnosing files changed on disk","message":"Calculating file diagnostics..."}}

[Trace - 21:46:57.863 PM] Sending request 'workspace/executeCommand - (4)'.
Params: {"command":"gopls.edit_go_directive","arguments":[{"URI":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/main.go","Version":"1.18"}]}

[Trace - 21:46:57.910 PM] Received notification 'window/logMessage'.
Params: {"type":1,"message":"2022/03/24 21:46:57 building workspace mod file: no module declaration for file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/go.mod\n"}

[Trace - 21:46:57.911 PM] Received response 'workspace/executeCommand - (4)' in 47ms.
Result: null

[Trace - 21:46:57.922 PM] Received request 'window/workDoneProgress/create - (7)'.
Params: {"token":"7174218026911131881"}

[Trace - 21:46:57.923 PM] Sending response 'window/workDoneProgress/create - (7)' in 0ms.
Result:

[Trace - 21:46:57.923 PM] Received notification '$/progress'.
Params: {"token":"7174218026911131881","value":{"kind":"begin","title":"Error loading workspace","message":"no module path for file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/go.mod"}}

[Trace - 21:46:57.924 PM] Received notification 'window/logMessage'.
Params: {"type":1,"message":"2022/03/24 21:46:57 errors loading workspace: no module path for file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/go.mod\n\tsnapshot=1\n\tdirectory=file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work\n"}

[Trace - 21:46:57.924 PM] Received notification 'textDocument/publishDiagnostics'.
Params: {"uri":"file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/go.mod","diagnostics":[{"range":{"start":{"line":0,"character":0},"end":{"line":0,"character":0}},"severity":1,"source":"go list","message":"no module path for file:///C:/Users/gopher/AppData/Local/Temp/gopls-regtest-628564068/TestEditGoDirective/experimental/work/go.mod"}]}

[Trace - 21:46:57.924 PM] Received notification '$/progress'.
Params: {"token":"8741248032194605601","value":{"kind":"end","message":"Done."}}

[Trace - 21:47:27.852 PM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2022/03/24 21:47:27 background imports cache refresh starting\n"}

[Trace - 21:47:27.969 PM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2022/03/24 21:47:27 background refresh finished after 151.3671ms\n"}

</details>

[bcmills]

I suspect there may be two different failure modes here. The failure rate on plan9-386 in particular is much higher than the failure rate elsewhere.

greplogs --dashboard -md -l -e 'FAIL: TestEditGoDirective' --omit=plan9 --since=2022-01-01

2022-04-08T13:27:25-7dd9f20-9535031/freebsd-386-12_3
2022-04-04T06:48:45-153e30b-492c85a/windows-amd64-race
2022-03-25T20:23:27-e309672-3dac914/linux-amd64-wsl
2022-03-22T21:30:29-87a8611-ac3efc8/linux-amd64-wsl
2022-03-18T23:20:51-5ea13d0-7ca6902/aix-ppc64
2022-03-18T13:39:41-5ea13d0-4aa1efe/linux-amd64-wsl
2022-03-16T17:41:38-77aa08b-c0158b6/windows-386-2008

greplogs --dashboard -md -l -e '(?ms)\Aplan9-.*FAIL: TestEditGoDirective' --since=2022-01-01

2022-04-08T18:30:53-fe932b4-3a19102/plan9-386-0intro
2022-04-07T20:56:02-ee2bc8b-8d581f5/plan9-386-0intro
2022-04-07T18:45:34-48e6d8d-c0bbeb0/plan9-386-0intro
2022-04-07T14:59:24-7cc24c2-063f403/plan9-386-0intro
2022-04-07T14:42:13-b3e0236-063f403/plan9-386-0intro
2022-04-06T22:27:40-b3e0236-9a6acc8/plan9-386-0intro
2022-04-06T22:00:21-b3e0236-81ae993/plan9-386-0intro
2022-04-06T18:19:46-6731659-5bb2628/plan9-386-0intro
2022-04-06T03:13:34-37acb39-5bb2628/plan9-386-0intro
2022-04-05T14:34:18-4077921-1a955bc/plan9-386-0intro
2022-04-05T01:54:27-4077921-07b0c57/plan9-386-0intro
2022-04-04T06:48:45-153e30b-492c85a/plan9-386-0intro
2022-04-03T21:26:39-153e30b-3451844/plan9-386-0intro
2022-04-01T21:28:32-153e30b-67d6a51/plan9-386-0intro
2022-04-01T14:08:14-cda13e2-1fc3346/plan9-386-0intro
2022-04-01T03:43:34-cda13e2-029d2c4/plan9-386-0intro
2022-04-01T03:16:26-cda13e2-f5290ef/plan9-386-0intro
2022-03-31T16:58:48-b9a4807-3706584/plan9-386-0intro
2022-03-31T04:40:46-8e193c2-3943d97/plan9-386-0intro
2022-03-30T22:30:03-8e193c2-3b7fce2/plan9-386-0intro
2022-03-30T03:52:37-9d8009b-f5a42cd/plan9-386-0intro
2022-03-30T02:40:41-761e51f-f5a42cd/plan9-386-0intro
2022-03-29T02:25:12-e693fb4-1724077/plan9-386-0intro
2022-03-28T18:20:56-e693fb4-0a69c98/plan9-386-0intro
2022-03-25T21:22:33-ed5a15c-3dac914/plan9-386-0intro
2022-03-25T19:08:41-e309672-2bbf383/plan9-386-0intro
2022-03-25T18:19:09-54af36e-f25631b/plan9-386-0intro
2022-03-24T22:24:35-78ff15e-a10a209/plan9-386-0intro
2022-03-24T19:25:44-4737f45-b95d332/plan9-386-0intro
2022-03-24T18:41:54-4460e9b-b95d332/plan9-386-0intro
2022-03-24T17:50:47-9fd677e-b95d332/plan9-386-0intro
2022-03-24T14:44:47-9fd677e-cccfb8f/plan9-386-0intro
2022-03-24T03:55:46-9fd677e-9058080/plan9-386-0intro
2022-03-23T19:31:59-9fd677e-947bf33/plan9-386-0intro
2022-03-23T14:57:56-87a8611-20ba3f5/plan9-386-0intro
2022-03-22T17:37:31-1428e83-63ea27e/plan9-386-0intro
2022-03-22T16:51:29-c717623-63ea27e/plan9-386-0intro
2022-03-21T22:42:59-c717623-86c8075/plan9-386-0intro
2022-03-21T18:29:06-c717623-b9d6cea/plan9-386-0intro
2022-03-21T17:27:41-c717623-129a2fc/plan9-386-0intro
2022-03-20T21:02:35-5ea13d0-7eaad60/plan9-386-0intro
2022-03-18T19:32:40-5ea13d0-a682a5c/plan9-amd64-0intro
2022-03-18T15:35:06-5ea13d0-2c92b23/plan9-386-0intro
2022-03-17T13:53:41-e998cd2-c379c3d/plan9-386-0intro
2022-03-17T08:43:51-85d68bc-c379c3d/plan9-386-0intro
2022-03-17T03:41:50-85d68bc-9956a54/plan9-386-0intro
2022-03-16T20:10:07-77aa08b-91631bc/plan9-386-0intro
2022-03-14T20:31:55-24806f2-41fe746/plan9-386-0intro
2022-03-14T14:50:06-49d48a0-7900576/plan9-386-0intro
2022-03-14T11:03:14-198cae3-7900576/plan9-386-0intro
2022-03-11T22:34:28-198cae3-baf61e4/plan9-386-0intro
2022-03-11T06:03:26-ee31f70-c1f2213/plan9-386-0intro
2022-03-10T23:06:14-622cf7b-5003ed8/plan9-386-0intro
2022-03-10T18:50:50-9f99e95-8cf1169/plan9-386-0intro
2022-03-10T06:26:28-1670aad-29b968e/plan9-386-0intro
2022-03-10T01:34:17-1670aad-604140d/plan9-386-0intro
2022-03-08T23:18:30-b59c441-20d333b/plan9-386-0intro
2022-03-08T22:23:42-b59c441-0add064/plan9-386-0intro
2022-03-08T21:00:10-b59c441-e030833/plan9-386-0intro
2022-03-08T15:42:25-b59c441-291bda8/plan9-386-0intro
2022-03-07T23:46:55-b59c441-d9d5572/plan9-386-0intro
2022-03-07T20:00:56-b59c441-114d5de/plan9-386-0intro
2022-03-07T16:24:54-b59c441-cc9d3f5/plan9-386-0intro
2022-03-07T16:11:49-b59c441-63bd6f6/plan9-386-0intro
2022-03-07T09:29:14-e155b03-8893175/plan9-386-0intro
2022-03-07T06:23:26-e155b03-82a6529/plan9-386-0intro
2022-03-05T08:36:13-e155b03-55a60ca/plan9-386-0intro
2022-03-04T19:04:50-121d1e4-7d7b9bb/plan9-386-0intro
2022-03-04T18:29:58-121d1e4-ca384f7/plan9-386-0intro
2022-03-04T18:26:08-0eabed7-ca384f7/plan9-386-0intro
2022-03-04T18:03:16-19fe2d7-ca384f7/plan9-386-0intro
2022-03-04T15:48:03-19fe2d7-46afa89/plan9-386-0intro
2022-03-04T01:18:57-3ce7728-81767e2/plan9-386-0intro
2022-03-03T18:04:51-09e0201-58804ea/plan9-386-0intro
2022-03-03T17:28:58-09e0201-78070ec/plan9-386-0intro
2022-03-03T14:42:03-09e0201-86371b0/plan9-386-0intro
2022-03-03T02:46:20-09e0201-86b5f6a/plan9-386-0intro
2022-03-03T01:58:56-09e0201-2e9facb/plan9-386-0intro
2022-03-03T00:37:10-09e0201-301fd8a/plan9-386-0intro
2022-03-03T00:23:02-09e0201-d367205/plan9-386-0intro
2022-03-02T21:27:47-a972457-bcb89fc/plan9-386-0intro
2022-03-02T18:52:17-7103138-986b04c/plan9-386-0intro

[findleyr]

I think I know what is causing these failures, approximately.

The example in the test has two diagnostics with quick fixes:

package main

func F[T any](_ T) {
}

1. The use of type parameters.
2. The use of any.

In the test, we call "apply quick fixes" which applies quick-fixes in rapid succession. However, we asynchronously reload the workspace when notified of the first on-disk change, and so may theoretically call packages.Load while the Go command is in the middle of the second edit. I guess this because the failing tests have the log message "no module declaration for file:///tmp/workdir/tmp/gopls-regtest-1306654604/TestEditGoDirectiveWorkspace/experimental/work/go.mod", which doesn't occur in the logs of successful test runs.

However, I still don't understand the following:

1. Don't we enforce that only one Go command is executing at any given time (including across go/packages) via the gocommand library?
2. Why don't we subsequently succeed at reloading, after the second modification.

Both of these indicate a bug in gopls, but at least there is some rational explanation for the failure.

Investigation continues.

[gopherbot]

Change https://go.dev/cl/399625 mentions this issue: internal/lsp/fake: consider mtime when polling for file changes

[findleyr]

Aha, ok I've got it.

1. Our maxInFlight go invocations is actually 10, so there's plenty of room for concurrency.
2. We were detecting file changes in regtests based only on file hash, so we don't catch the intermediate on-disk state of the modfile edit.

I've "fixed" the latter by including mtime in our file identity. We'll see if that makes the errors go away: on certain platforms (e.g. WSL) I recall that mtime is particularly coarse.

[findleyr]

Note: another "fix" is to only apply a single quick-fix. I'd prefer if we didn't have to make that accomodation: the regtest framework should be able to handle multiple quick-fixes being applied in succession. Let's see if the flakes go to zero after the CL above.