x/tools/gopls: test timeouts on darwin longtest builder

[gopherbot]

#!watchflakes
default <- builder == "x_tools-gotip-darwin-amd64-longtest" && date < "2024-02-22"

Issue created automatically to collect these failures.

Example (log):

=== RUN   TestPostfixSnippetCompletion/forwarded/string_slice_join
    testing.go:1576: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test
--- FAIL: TestPostfixSnippetCompletion/forwarded/string_slice_join (1.96s)
#### Start Gopls Test Logs for "TestPostfixSnippetCompletion/forwarded"
[Trace - 02:25:59.234 AM] Sending request 'initialize - (1)'.
Params: {"processId":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"],"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":"/Users/swarming/.swarming/w/ir/x/t/gopls-test-2215923589/TestPostfixSnippetCompletion/forwarded/gopath","GOPROXY":"file:///Users/swarming/.swarming/w/ir/x/t/gopls-test-2215923589/TestPostfixSnippetCompletion/forwarded/proxy","GOSUMDB":"off"},"experimentalPostfixCompletions":true,"verboseWorkDoneProgress":true},"trace":"messages","workspaceFolders":[{"uri":"file:///Users/swarming/.swarming/w/ir/x/t/gopls-test-2215923589/TestPostfixSnippetCompletion/forwarded/work","name":"work"}]}


[Trace - 02:25:59.236 AM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2024/02/17 02:25:59 Handshake session update\n\tupdate_session=89\n\tdebug_address=\"\"\n\tlogfile=\"\"\n\tserver=\"30\"\n\tgopls_path=\"/Users/swarming/.swarming/w/ir/x/t/go-build782734547/b591/completion.test\"\n"}
...

[Trace - 02:26:18.514 AM] Received notification '$/progress'.
Params: {"token":"5007001450629832726","value":{"kind":"end","message":"Done."}}


[Trace - 02:26:19.938 AM] Sending notification '$/cancelRequest'.
Params: {"id":20}


#### End Gopls Test Logs for "TestPostfixSnippetCompletion/forwarded"

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "golang.org/x/tools/gopls/internal/test/integration/completion" && test == "TestPostfixSnippetCompletion/forwarded/string_slice_join"

2024-02-16 15:54 x_tools-gotip-darwin-amd64-longtest tools@0d171942 go@86a32d6d x/tools/gopls/internal/test/integration/completion.TestPostfixSnippetCompletion/forwarded/string_slice_join (log)

=== RUN   TestPostfixSnippetCompletion/forwarded/string_slice_join
    testing.go:1576: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test
--- FAIL: TestPostfixSnippetCompletion/forwarded/string_slice_join (1.96s)
#### Start Gopls Test Logs for "TestPostfixSnippetCompletion/forwarded"
[Trace - 02:25:59.234 AM] Sending request 'initialize - (1)'.
Params: {"processId":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"],"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":"/Users/swarming/.swarming/w/ir/x/t/gopls-test-2215923589/TestPostfixSnippetCompletion/forwarded/gopath","GOPROXY":"file:///Users/swarming/.swarming/w/ir/x/t/gopls-test-2215923589/TestPostfixSnippetCompletion/forwarded/proxy","GOSUMDB":"off"},"experimentalPostfixCompletions":true,"verboseWorkDoneProgress":true},"trace":"messages","workspaceFolders":[{"uri":"file:///Users/swarming/.swarming/w/ir/x/t/gopls-test-2215923589/TestPostfixSnippetCompletion/forwarded/work","name":"work"}]}


[Trace - 02:25:59.236 AM] Received notification 'window/logMessage'.
Params: {"type":3,"message":"2024/02/17 02:25:59 Handshake session update\n\tupdate_session=89\n\tdebug_address=\"\"\n\tlogfile=\"\"\n\tserver=\"30\"\n\tgopls_path=\"/Users/swarming/.swarming/w/ir/x/t/go-build782734547/b591/completion.test\"\n"}
...

[Trace - 02:26:18.514 AM] Received notification '$/progress'.
Params: {"token":"5007001450629832726","value":{"kind":"end","message":"Done."}}


[Trace - 02:26:19.938 AM] Sending notification '$/cancelRequest'.
Params: {"id":20}


#### End Gopls Test Logs for "TestPostfixSnippetCompletion/forwarded"

— watchflakes

[findleyr]

CC @mknyszek @prattmic @bcmills it looks like the longtest builder above is not actually setting -timeout, as opposed to the legacy longtest builders which set -timeout=1h40m0s. An oversight?

[bcmills]

Filed the missing -timeout flag as:

• x/build: timeout_scale parameter not applied on LUCI builders for x/ repos  #65845

[findleyr]

Thanks. Edited the watchflakes stanza to match this builder.

[findleyr]

Closing as the root cause (https://go.dev/issue/65845) should be fixed.

[bcmills]

I've also updated the watchflakes pattern with a date (to avoid spurious reopening, working around #57632).

[findleyr]

I've also updated the watchflakes pattern with a date (to avoid spurious reopening, working around #57632).

Hmm, won't that pattern still result in spurious reopening, since failures will continue to match this issue?