x/tools/gopls/internal/test/integration/workspace: TestCreateModule_Interdependent failures

[gopherbot]

#!watchflakes
default <- pkg == "golang.org/x/tools/gopls/internal/test/integration/workspace" && test == "TestCreateModule_Interdependent"

Issue created automatically to collect these failures.

Example (log):

#### Start Gopls Test Logs for "TestCreateModule_Interdependent/default"
[Trace - 00:12:28.041 AM] Sending request 'initialize - (1)'.
Params: {"processId":0,"clientInfo":{"name":"fake.Editor","version":"v1.0.0"},"rootUri":"","capabilities":{"workspace":{"workspaceEdit":{"resourceOperations":["rename"]},"didChangeConfiguration":{},"didChangeWatchedFiles":{"dynamicRegistration":true},"configuration":true},"textDocument":{"completion":{"completionItem":{"snippetSupport":true,"tagSupport":{"valueSet":[1]}}},"documentSymbol":{"hierarchicalDocumentSymbolSupport":true},"codeAction":{"codeActionLiteralSupport":{"codeActionKind":{"valueSet":null}}},"publishDiagnostics":{},"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","label"],"tokenModifiers":["declaration","definition","readonly","static","deprecated","abstract","async","modification","documentation","defaultLibrary"],"formats":null}},"window":{"workDoneProgress":true}},"initializationOptions":{"completionBudget":"0s","diagnosticsDelay":"10ms","env":{"GO111MODULE":"","GOMODCACHE":"","GOPACKAGESDRIVER":"off","GOPATH":"/tmp/buildlet/tmp/gopls-test-2855048953/TestCreateModule_Interdependent/default/gopath","GOPROXY":"file:///tmp/buildlet/tmp/gopls-test-2855048953/TestCreateModule_Interdependent/default/proxy","GOSUMDB":"off"},"verboseWorkDoneProgress":true},"trace":"messages","workspaceFolders":[{"uri":"file:///tmp/buildlet/tmp/gopls-test-2855048953/TestCreateModule_Interdependent/default/work","name":"work"}]}

[Trace - 00:12:28.042 AM] Received response 'initialize - (1)' in 0ms.
Result: {"capabilities":{"textDocumentSync":{"openClose":true,"change":2,"save":{}},"completionProvider":{"triggerCharacters":["."]},"hoverProvider":true,"signatureHelpProvider":{"triggerCharacters":["(",","]},"definitionProvider":true,"typeDefinitionProvider":true,"implementationProvider":true,"referencesProvider":true,"documentHighlightProvider":true,"documentSymbolProvider":true,"codeActionProvider":true,"codeLensProvider":{},"documentLinkProvider":{},"workspaceSymbolProvider":true,"documentFormattingProvider":true,"renameProvider":true,"foldingRangeProvider":true,"selectionRangeProvider":true,"executeCommandProvider":{"commands":["gopls.add_dependency","gopls.add_import","gopls.add_telemetry_counters","gopls.apply_fix","gopls.change_signature","gopls.check_upgrades","gopls.diagnose_files","gopls.doc","gopls.edit_go_directive","gopls.fetch_vulncheck_result","gopls.gc_details","gopls.generate","gopls.go_get_package","gopls.list_imports","gopls.list_known_packages","gopls.maybe_prompt_for_telemetry","gopls.mem_stats","gopls.regenerate_cgo","gopls.remove_dependency","gopls.reset_go_mod_diagnostics","gopls.run_go_work_command","gopls.run_govulncheck","gopls.run_tests","gopls.start_debugging","gopls.start_profile","gopls.stop_profile","gopls.test","gopls.tidy","gopls.toggle_gc_details","gopls.update_go_sum","gopls.upgrade_dependency","gopls.vendor","gopls.views","gopls.workspace_stats"]},"callHierarchyProvider":true,"semanticTokensProvider":{"legend":{"tokenTypes":["namespace","type","class","enum","interface","struct","typeParameter","parameter","variable","property","enumMember","event","function","method","macro","keyword","modifier","comment","string","number","regexp","operator","label"],"tokenModifiers":["declaration","definition","readonly","static","deprecated","abstract","async","modification","documentation","defaultLibrary"]},"range":true,"full":true},"inlayHintProvider":{},"workspace":{"workspaceFolders":{"supported":true,"changeNotifications":"workspace/didChangeWorkspaceFolders"}}},"serverInfo":{"name":"gopls","version":"{\"GoVersion\":\"go1.22.2\",\"Path\":\"\",\"Main\":{\"Path\":\"\",\"Version\":\"\",\"Sum\":\"\",\"Replace\":null},\"Deps\":null,\"Settings\":null,\"Version\":\"(unknown)\"}"}}

[Trace - 00:12:28.043 AM] Sending notification 'initialized'.
...
--- FAIL: TestCreateModule_Interdependent (1.71s)
    --- FAIL: TestCreateModule_Interdependent/default (1.71s)
        workspace_test.go:453: waiting on:
            Unmeetable: once "All of:\ncompleted work \"diagnosing opened files\" at least 2 time(s)\ncompleted work \"diagnosing files changed on disk\" at least 1 time(s)\ncompleted work \"diagnosing close files\" at least 1 time(s)" is met, must have:
            any diagnostics at the first position (3:5) matching `x` in "modb/b/b.go"

            err:condition has final verdict Unmeetable

            state:
            #### log messages (see RPC logs for full text):
...
                    7:5 [compiler]: x declared and not used

            #### outstanding work:
            #### completed work:
                diagnosing initial workspace load: 1
                Setting up workspace: 1
                Checking telemetry prompt: 1
                diagnosing opened files: 2
                diagnosing close files: 1
                diagnosing files changed on disk: 1

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "golang.org/x/tools/gopls/internal/test/integration/workspace" && test == "TestCreateModule_Interdependent"

2024-04-10 17:04 darwin-amd64-12_0 tools@6f92c839 go@a65a2bbd x/tools/gopls/internal/test/integration/workspace.TestCreateModule_Interdependent (log)

#### Start Gopls Test Logs for "TestCreateModule_Interdependent/default" [Trace - 00:12:28.041 AM] Sending request 'initialize - (1)'. Params: {"processId":0,"clientInfo":{"name":"fake.Editor","version":"v1.0.0"},"rootUri":"","capabilities":{"workspace":{"workspaceEdit":{"resourceOperations":["rename"]},"didChangeConfiguration":{},"didChangeWatchedFiles":{"dynamicRegistration":true},"configuration":true},"textDocument":{"completion":{"completionItem":{"snippetSupport":true,"tagSupport":{"valueSet":[1]}}},"documentSymbol":{"hierarchicalDocumentSymbolSupport":true},"codeAction":{"codeActionLiteralSupport":{"codeActionKind":{"valueSet":null}}},"publishDiagnostics":{},"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","label"],"tokenModifiers":["declaration","definition","readonly","static","deprecated","abstract","async","modification","documentation","defaultLibrary"],"formats":null}},"window":{"workDoneProgress":true}},"initializationOptions":{"completionBudget":"0s","diagnosticsDelay":"10ms","env":{"GO111MODULE":"","GOMODCACHE":"","GOPACKAGESDRIVER":"off","GOPATH":"/tmp/buildlet/tmp/gopls-test-2855048953/TestCreateModule_Interdependent/default/gopath","GOPROXY":"file:///tmp/buildlet/tmp/gopls-test-2855048953/TestCreateModule_Interdependent/default/proxy","GOSUMDB":"off"},"verboseWorkDoneProgress":true},"trace":"messages","workspaceFolders":[{"uri":"file:///tmp/buildlet/tmp/gopls-test-2855048953/TestCreateModule_Interdependent/default/work","name":"work"}]} [Trace - 00:12:28.042 AM] Received response 'initialize - (1)' in 0ms. Result: {"capabilities":{"textDocumentSync":{"openClose":true,"change":2,"save":{}},"completionProvider":{"triggerCharacters":["."]},"hoverProvider":true,"signatureHelpProvider":{"triggerCharacters":["(",","]},"definitionProvider":true,"typeDefinitionProvider":true,"implementationProvider":true,"referencesProvider":true,"documentHighlightProvider":true,"documentSymbolProvider":true,"codeActionProvider":true,"codeLensProvider":{},"documentLinkProvider":{},"workspaceSymbolProvider":true,"documentFormattingProvider":true,"renameProvider":true,"foldingRangeProvider":true,"selectionRangeProvider":true,"executeCommandProvider":{"commands":["gopls.add_dependency","gopls.add_import","gopls.add_telemetry_counters","gopls.apply_fix","gopls.change_signature","gopls.check_upgrades","gopls.diagnose_files","gopls.doc","gopls.edit_go_directive","gopls.fetch_vulncheck_result","gopls.gc_details","gopls.generate","gopls.go_get_package","gopls.list_imports","gopls.list_known_packages","gopls.maybe_prompt_for_telemetry","gopls.mem_stats","gopls.regenerate_cgo","gopls.remove_dependency","gopls.reset_go_mod_diagnostics","gopls.run_go_work_command","gopls.run_govulncheck","gopls.run_tests","gopls.start_debugging","gopls.start_profile","gopls.stop_profile","gopls.test","gopls.tidy","gopls.toggle_gc_details","gopls.update_go_sum","gopls.upgrade_dependency","gopls.vendor","gopls.views","gopls.workspace_stats"]},"callHierarchyProvider":true,"semanticTokensProvider":{"legend":{"tokenTypes":["namespace","type","class","enum","interface","struct","typeParameter","parameter","variable","property","enumMember","event","function","method","macro","keyword","modifier","comment","string","number","regexp","operator","label"],"tokenModifiers":["declaration","definition","readonly","static","deprecated","abstract","async","modification","documentation","defaultLibrary"]},"range":true,"full":true},"inlayHintProvider":{},"workspace":{"workspaceFolders":{"supported":true,"changeNotifications":"workspace/didChangeWorkspaceFolders"}}},"serverInfo":{"name":"gopls","version":"{\"GoVersion\":\"go1.22.2\",\"Path\":\"\",\"Main\":{\"Path\":\"\",\"Version\":\"\",\"Sum\":\"\",\"Replace\":null},\"Deps\":null,\"Settings\":null,\"Version\":\"(unknown)\"}"}} [Trace - 00:12:28.043 AM] Sending notification 'initialized'. ... --- FAIL: TestCreateModule_Interdependent (1.71s) --- FAIL: TestCreateModule_Interdependent/default (1.71s) workspace_test.go:453: waiting on: Unmeetable: once "All of:\ncompleted work \"diagnosing opened files\" at least 2 time(s)\ncompleted work \"diagnosing files changed on disk\" at least 1 time(s)\ncompleted work \"diagnosing close files\" at least 1 time(s)" is met, must have: any diagnostics at the first position (3:5) matching `x` in "modb/b/b.go" err:condition has final verdict Unmeetable state: #### log messages (see RPC logs for full text): ... 7:5 [compiler]: x declared and not used #### outstanding work: #### completed work: diagnosing initial workspace load: 1 Setting up workspace: 1 Checking telemetry prompt: 1 diagnosing opened files: 2 diagnosing close files: 1 diagnosing files changed on disk: 1

— watchflakes

[adonovan]

This suggests a race in the test, which asserts that after a WriteFiles and then a Diagnostics, there must be a diagnostic about variable x in the updated file's location--but in fact it reports the diagnostic at x's location in the original file. Looking at onFileChanges, I don't see how it can be correct that it fires off a goroutine but doesn't wait for anything to get started. That means the didChangedWatchedFiles could occur arbitrarily late, which would explain the race.