x/tools/gopls/internal/regtest/misc: timeout in TestRenamePackageWithDifferentDirectoryPath

[gopherbot]

#!watchflakes
post <- pkg == "golang.org/x/tools/gopls/internal/regtest/misc" && test == "TestRenamePackageWithDifferentDirectoryPath" && log ~ `panic: test timed out`

Issue created automatically to collect these failures.

Example (log):

serve.go:434: debug server listening at http://localhost:49257
serve.go:434: debug server listening at http://localhost:49258
panic: test timed out after 10m0s
running tests:
	TestRenamePackageWithDifferentDirectoryPath (6m49s)
	TestRenamePackageWithDifferentDirectoryPath/default (6m49s)

testing.(*T).Run(0xc002bf81a0, {0x1b890df?, 0x1ba62bf?}, 0xc0035f3ef0)
	/tmp/buildlet/go/src/testing/testing.go:1649 +0x3c8
golang.org/x/tools/gopls/internal/lsp/regtest.(*Runner).Run(0xc00031afa0, 0xc002bf81a0, {0x1bfae3a, 0xf2}, 0x1d0fbd8, {0x0, 0x0, 0xc000336f60?})
	/tmp/buildlet/gopath/src/golang.org/x/tools/gopls/internal/lsp/regtest/runner.go:169 +0x491
golang.org/x/tools/gopls/internal/lsp/regtest.Run(...)
	/tmp/buildlet/gopath/src/golang.org/x/tools/gopls/internal/lsp/regtest/regtest.go:54
golang.org/x/tools/gopls/internal/regtest/misc.TestRenamePackageWithDifferentDirectoryPath(0xc002fc8d00?)
	/tmp/buildlet/gopath/src/golang.org/x/tools/gopls/internal/regtest/misc/rename_test.go:264 +0x55
testing.tRunner(0xc002bf81a0, 0x1d0fbe0)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "golang.org/x/tools/gopls/internal/regtest/misc" && test == "TestRenamePackageWithDifferentDirectoryPath"

2023-04-10 20:09 darwin-amd64-nocgo tools@40fb89cd go@a5c79283 x/tools/gopls/internal/regtest/misc.TestRenamePackageWithDifferentDirectoryPath (log)

serve.go:434: debug server listening at http://localhost:49257
serve.go:434: debug server listening at http://localhost:49258
panic: test timed out after 10m0s
running tests:
	TestRenamePackageWithDifferentDirectoryPath (6m49s)
	TestRenamePackageWithDifferentDirectoryPath/default (6m49s)

testing.(*T).Run(0xc002bf81a0, {0x1b890df?, 0x1ba62bf?}, 0xc0035f3ef0)
	/tmp/buildlet/go/src/testing/testing.go:1649 +0x3c8
golang.org/x/tools/gopls/internal/lsp/regtest.(*Runner).Run(0xc00031afa0, 0xc002bf81a0, {0x1bfae3a, 0xf2}, 0x1d0fbd8, {0x0, 0x0, 0xc000336f60?})
	/tmp/buildlet/gopath/src/golang.org/x/tools/gopls/internal/lsp/regtest/runner.go:169 +0x491
golang.org/x/tools/gopls/internal/lsp/regtest.Run(...)
	/tmp/buildlet/gopath/src/golang.org/x/tools/gopls/internal/lsp/regtest/regtest.go:54
golang.org/x/tools/gopls/internal/regtest/misc.TestRenamePackageWithDifferentDirectoryPath(0xc002fc8d00?)
	/tmp/buildlet/gopath/src/golang.org/x/tools/gopls/internal/regtest/misc/rename_test.go:264 +0x55
testing.tRunner(0xc002bf81a0, 0x1d0fbe0)

— watchflakes

[bcmills]

Looks like it deadlocked during shutdown:

goroutine 39892 [semacquire, 6 minutes]:
sync.runtime_Semacquire(0x170b876?)
	/tmp/buildlet/go/src/runtime/sema.go:62 +0x25
sync.(*WaitGroup).Wait(0xc000f07380?)
	/tmp/buildlet/go/src/sync/waitgroup.go:116 +0x48
golang.org/x/tools/gopls/internal/lsp/cache.(*View).shutdown(0xc000f07380)
	/tmp/buildlet/gopath/src/golang.org/x/tools/gopls/internal/lsp/cache/view.go:587 +0xff
golang.org/x/tools/gopls/internal/lsp/cache.(*Session).Shutdown(0xc002d4d080, {0x1e368c0, 0xc00ba1aed0})
	/tmp/buildlet/gopath/src/golang.org/x/tools/gopls/internal/lsp/cache/session.go:71 +0x154
golang.org/x/tools/gopls/internal/lsp.(*Server).shutdown(0xc000133340, {0x1e36850?, 0xc00b24ab40?})
	/tmp/buildlet/gopath/src/golang.org/x/tools/gopls/internal/lsp/general.go:604 +0x145
golang.org/x/tools/gopls/internal/lsp.(*Server).Shutdown(0x0?, {0x1e36850?, 0xc00b24ab40?})
	/tmp/buildlet/gopath/src/golang.org/x/tools/gopls/internal/lsp/server_gen.go:256 +0x1d

[findleyr]

No, it's not deadlocked. Everything is waiting for a Go command invocation:

goroutine 39939 [chan receive, 6 minutes]:
golang.org/x/tools/internal/gocommand.runCmdContext({0x1e36888, 0xc0001929a0}, 0xc0013b2c60)
	/tmp/buildlet/gopath/src/golang.org/x/tools/internal/gocommand/invoke.go:305 +0x4d9

[findleyr]

Following https://go.dev/cl/483215, we don't panic with "detected a hanging Go command" when we encounter this Kernel bug where the process is done but cmd.Wait() does not return.

So we hang indefinitely.

CC @adonovan

[bcmills]

Oh, interesting! I had thought that was just a longer-than-expected delay, but I agree that looks like an actual kernel bug. That's unfortunate. 😕

[bcmills]

#19314 may be related.

[findleyr]

I think we put back the "detected a hanging Go command" panic in this case, albeit without the useless process dump, so that this failure will continue to get aggregated into #54461. Otherwise, we'll continue to get flakes for random tests that encounter this bug.

I'll send a CL.

[gopherbot]

Change https://go.dev/cl/484742 mentions this issue: internal/gocommand: panic on hanging Go command that are done