Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

cmd/go: timeout in TestCache* on darwin-amd64-10_12 #35278

Closed
bcmills opened this issue Oct 31, 2019 · 6 comments
Closed

cmd/go: timeout in TestCache* on darwin-amd64-10_12 #35278

bcmills opened this issue Oct 31, 2019 · 6 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-Darwin Testing An issue that has been verified to require only test changes, not just a test failure.
Milestone
Backlog

Comments

@bcmills
Copy link
Contributor

bcmills commented Oct 31, 2019

From darwin-amd64-10_12 (https://build.golang.org/log/9f4a33126668c564bf4bddb208bc9c6af1b7d149):

panic: test timed out after 9m0s
[…]
goroutine 657 [syscall]:
syscall.syscall6(0x10af9b0, 0x5204, 0xc00046ecb4, 0x0, 0xc0003945a0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/sys_darwin.go:74 +0x2e
syscall.wait4(0x5204, 0xc00046ecb4, 0x0, 0xc0003945a0, 0x90, 0x16e5c00, 0x1)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/syscall/zsyscall_darwin_amd64.go:44 +0x87
syscall.Wait4(0x5204, 0xc00046ed04, 0x0, 0xc0003945a0, 0x1c041a0, 0x1, 0x1d42b28)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/syscall/syscall_bsd.go:129 +0x51
os.(*Process).wait(0xc000504240, 0x17582e0, 0x17582e8, 0x17582d8)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/os/exec_unix.go:38 +0x7b
os.(*Process).Wait(...)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/os/exec.go:125
os/exec.(*Cmd).Wait(0xc000434580, 0x0, 0x0)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/os/exec/exec.go:501 +0x60
os/exec.(*Cmd).Run(0xc000434580, 0x6d, 0xc00041a460)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/os/exec/exec.go:341 +0x5c
cmd/go_test.(*testgoData).doRun(0xc0003a2d80, 0xc00041a460, 0x5, 0x5, 0xc00004bc00, 0x1d42b28)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/go/go_test.go:484 +0x2b7
cmd/go_test.(*testgoData).run(0xc0003a2d80, 0xc00041a460, 0x5, 0x5)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/go/go_test.go:500 +0x7d
cmd/go_test.TestCacheCoverage(0xc0000e4c00)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/go/go_test.go:5277 +0x2c3
testing.tRunner(0xc0000e4c00, 0x1757128)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/testing/testing.go:916 +0xc1
created by testing.(*T).Run
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/testing/testing.go:967 +0x351
[…]
goroutine 679 [syscall]:
syscall.syscall6(0x10af9b0, 0x5266, 0xc00060d964, 0x0, 0xc0004b0480, 0x0, 0x0, 0x0, 0x0, 0x0)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/sys_darwin.go:74 +0x2e
syscall.wait4(0x5266, 0xc00060d964, 0x0, 0xc0004b0480, 0x90, 0x16e5c00, 0x1)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/syscall/zsyscall_darwin_amd64.go:44 +0x87
syscall.Wait4(0x5266, 0xc00060d9b4, 0x0, 0xc0004b0480, 0x1c041a0, 0x1, 0x1d42460)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/syscall/syscall_bsd.go:129 +0x51
os.(*Process).wait(0xc00002c690, 0x17582e0, 0x17582e8, 0x17582d8)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/os/exec_unix.go:38 +0x7b
os.(*Process).Wait(...)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/os/exec.go:125
os/exec.(*Cmd).Wait(0xc00054c840, 0x0, 0x0)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/os/exec/exec.go:501 +0x60
os/exec.(*Cmd).Run(0xc00054c840, 0x6d, 0xc0000f9740)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/os/exec/exec.go:341 +0x5c
cmd/go_test.(*testgoData).doRun(0xc0003a3200, 0xc0000f9740, 0x3, 0x3, 0xc0002ae400, 0x1d42460)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/go/go_test.go:484 +0x2b7
cmd/go_test.(*testgoData).run(0xc0003a3200, 0xc0000f9740, 0x3, 0x3)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/go/go_test.go:500 +0x7d
cmd/go_test.TestTestCacheInputs(0xc0000e5200)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/go/go_test.go:5607 +0x2378
testing.tRunner(0xc0000e5200, 0x17577f0)
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/testing/testing.go:916 +0xc1
created by testing.(*T).Run
	/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/testing/testing.go:967 +0x351

It's not obvious to me whether this is due to a bug in cmd/go or the same underlying platform issue as #25696.

CC @jayconrod @ianlancetaylor
@bcmills bcmills added OS-Darwin NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Oct 31, 2019
@bcmills bcmills added this to the Backlog milestone Oct 31, 2019
@ianlancetaylor
Copy link
Member

The stack trace just shows the test program waiting for the invocation of go test -cover -short math strings to complete. I guess we should put a timeout on the execution of the subprogram. Maybe we could use the new t.Deadline in testgoData.doRun. Or rewrite the test to be a script test.

@bcmills
Copy link
Contributor Author

bcmills commented Nov 1, 2019

Rewriting to a script test sounds like a great idea — we already set a timeout in those.

@bcmills bcmills added help wanted Testing An issue that has been verified to require only test changes, not just a test failure. labels Nov 1, 2019
@prattmic
Copy link
Member

prattmic commented Dec 7, 2022

greplogs --dashboard -md -l -e 'FAIL: TestCacheCoverage'

2022-11-28T23:32:00-318e75b/darwin-amd64-aws-race
2022-11-23T23:15:01-920f87a/darwin-amd64-aws-race
2022-11-18T20:22:20-6fc1f4f/darwin-amd64-aws-race
2021-03-04T17:55:25-2d30c94/windows-amd64-longtest
2020-04-27T17:49:51-8af8fa9/windows-amd64-longtest
2020-03-01T21:04:30-a4f7b08/darwin-amd64-nocgo
2019-11-08T17:01:18-a762221/linux-amd64-clang

@bcmills
Copy link
Contributor Author

bcmills commented Dec 7, 2022

Hmm. The timeout suggested in #35278 (comment) was added (implicitly by (*testgoData).doRun) in CL 450697, and you can see in the SIGQUIT stack trace that it produced in the 2022-11-28 run that there were a few runnable goroutines at the time.

And the failures in 2022 are all on darwin-.*-race builders.

So I'm inclined to suspect one of two things:

  1. Maybe the darwin-amd64-race builders are just slow, and need a GO_TEST_TIMOUT_SCALE (like the one we currently have for windows-amd64-race)?
  2. Maybe there is some runtime bug on darwin-amd64-race that causes Go programs to (rarely) deadlock for some reason? (Perhaps something related to runtime: async signals not reliably delivered to Go threads under TSAN #18717?)

@prattmic
Copy link
Member

prattmic commented Dec 7, 2022

These Darwin builders moved from MacStadium to AWS, so I wouldn't be surprised if timing is a bit different there.

@bcmills
Copy link
Contributor Author

bcmills commented Apr 6, 2023

Duplicate of #58919

@bcmills bcmills marked this as a duplicate of #58919 Apr 6, 2023
@bcmills bcmills closed this as not planned Won't fix, can't repro, duplicate, stale Apr 6, 2023
@golang golang locked and limited conversation to collaborators Apr 5, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-Darwin Testing An issue that has been verified to require only test changes, not just a test failure.
Projects
None yet
Milestone
Backlog
Development

No branches or pull requests
4 participants
@prattmic @ianlancetaylor @bcmills @gopherbot