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.

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

runtime: apparent deadlock in TestFakeTime on solaris-amd64-oraclerel starting 2021-11-05 #49614

Closed
bcmills opened this issue Nov 16, 2021 · 6 comments
Labels
NeedsInvestigation okay-after-beta1 OS-Solaris release-blocker
Milestone

Comments

@bcmills
Copy link
Member

@bcmills bcmills commented Nov 16, 2021

goroutine 252574 [syscall, 1 minutes]:
runtime.syscall_wait4(0x5944, 0xc0006d6000, 0x0, 0xc0006d8000)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/runtime/syscall_solaris.go:312 +0x86 fp=0xc000075d50 sp=0xc000075cf8 pc=0x46db26
syscall.Wait4(0x5944?, 0xc0006d6000?, 0x0?, 0xc0006d8000?)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/syscall/syscall_solaris.go:245 +0x2c fp=0xc000075d98 sp=0xc000075d50 pc=0x47b5ec
os.(*Process).wait(0xc00017e000)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/os/exec_unix.go:43 +0x85 fp=0xc000075df0 sp=0xc000075d98 pc=0x494aa5
os.(*Process).Wait(...)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/os/exec.go:132
os/exec.(*Cmd).Wait(0xc00012e580)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/os/exec/exec.go:507 +0x54 fp=0xc000075e68 sp=0xc000075df0 pc=0x4ea614
os/exec.(*Cmd).Run(0xc00012e580?)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/os/exec/exec.go:341 +0x39 fp=0xc000075e88 sp=0xc000075e68 pc=0x4e9779
runtime_test.TestFakeTime(0xc0003ab520)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/runtime/time_test.go:39 +0x16f fp=0xc000075f70 sp=0xc000075e88 pc=0x5dc70f
testing.tRunner(0xc0003ab520, 0x662910)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/testing/testing.go:1410 +0x102 fp=0xc000075fc0 sp=0xc000075f70 pc=0x4dd042
testing.(*T).Run.func1()
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/testing/testing.go:1457 +0x2a fp=0xc000075fe0 sp=0xc000075fc0 pc=0x4ddeea
runtime.goexit()
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/runtime/asm_amd64.s:1579 +0x1 fp=0xc000075fe8 sp=0xc000075fe0 pc=0x470fe1
created by testing.(*T).Run
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/testing/testing.go:1457 +0x35f

greplogs --dashboard -md -l -e 'goroutine \d+ \[.*, \d+ minutes\]:\n(?:.+\n\t.+\n)*os/exec.*\n\t.+\nruntime_test\.TestFakeTime'

2021-11-15T23:01:05-d156101/solaris-amd64-oraclerel
2021-11-15T21:22:18-c8d7c5f/solaris-amd64-oraclerel
2021-11-13T02:30:25-c546052/solaris-amd64-oraclerel
2021-11-12T23:34:09-fdee1b2/solaris-amd64-oraclerel
2021-11-12T18:14:22-8b66b3d/solaris-amd64-oraclerel
2021-11-11T21:27:05-c3c4a2b/solaris-amd64-oraclerel
2021-11-11T19:44:13-d60a4e6/solaris-amd64-oraclerel
2021-11-09T22:58:24-578ada4/solaris-amd64-oraclerel
2021-11-09T22:14:26-1c86bee/solaris-amd64-oraclerel
2021-11-09T21:26:25-b93220c/solaris-amd64-oraclerel
2021-11-08T22:05:00-67e2294/solaris-amd64-oraclerel
2021-11-06T19:41:15-61d789d/solaris-amd64-oraclerel
2021-11-06T16:43:43-3544082/solaris-amd64-oraclerel
2021-11-05T22:56:55-2f71c86/solaris-amd64-oraclerel
2021-11-05T19:48:29-c353f1b/solaris-amd64-oraclerel
(Note the ~1-year gap here.)
2020-11-30T20:08:34-a45e12f/darwin-amd64-race
(Note the ~1-year gap here too.)
2019-11-06T15:08:19-cf3be9b/openbsd-amd64-62
2019-11-06T13:55:04-6dc250f/darwin-amd64-nocgo
2019-11-06T09:08:53-6108998/darwin-386-10_14
2019-11-06T02:52:51-f71bd51/linux-arm

@bcmills bcmills added okay-after-beta1 release-blocker NeedsInvestigation labels Nov 16, 2021
@bcmills bcmills added this to the Go1.18 milestone Nov 16, 2021
@bcmills
Copy link
Member Author

@bcmills bcmills commented Nov 16, 2021

The symptom here is very similar to #44422. This issue may be a duplicate of that one.

@ianlancetaylor
Copy link
Contributor

@ianlancetaylor ianlancetaylor commented Nov 17, 2021

I can totally recreate this on Solaris with go test -test.short -test.run=TestFakeTime -test.count=100 -test.timeout=30s runtime. Interesting. On my Linux laptop that command takes 0.345 seconds, on Solaris it invariably times out.

@ianlancetaylor
Copy link
Contributor

@ianlancetaylor ianlancetaylor commented Nov 17, 2021

It's the test program itself that is hanging.

(The runTestProg function puts a timeout on each test, so this failure may be causing #44422 by taking so long that it pushes the overall test into timeout. Maybe.)

@ianlancetaylor
Copy link
Contributor

@ianlancetaylor ianlancetaylor commented Nov 17, 2021

If I set GOGC=off the test consistently completes. CC @mknyszek

@ianlancetaylor
Copy link
Contributor

@ianlancetaylor ianlancetaylor commented Nov 17, 2021

I have a patch.

@gopherbot
Copy link

@gopherbot gopherbot commented Nov 17, 2021

Change https://golang.org/cl/364757 mentions this issue: runtime: make faketime more robust against GC

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
NeedsInvestigation okay-after-beta1 OS-Solaris release-blocker
Projects
None yet
Development

No branches or pull requests

3 participants