runtime: timeouts in TestChan on netbsd-arm64-bsiegert and openbsd-arm64-jsing

[bcmills]

SIGQUIT: quit
PC=0x81ffc m=4 sigcode=0
…

goroutine 20 [sleep]:
runtime.gopark(0x173ea30f12cd8f?, 0x1a1634?, 0xa0?, 0x4d?, 0x400000e750?)
	/var/gobuilder/buildlet/go/src/runtime/proc.go:363 +0xe4 fp=0x400004abe0 sp=0x400004abc0 pc=0x4c3f4
time.Sleep(0xf4240)
	/var/gobuilder/buildlet/go/src/runtime/time.go:195 +0x120 fp=0x400004ac20 sp=0x400004abe0 pc=0x7def0
runtime_test.TestChan(0x4000146000)
	/var/gobuilder/buildlet/go/src/runtime/chan_test.go:67 +0x35c fp=0x400004af60 sp=0x400004ac20 pc=0x1a168c
testing.tRunner(0x4000146000, 0x2c6350)
	/var/gobuilder/buildlet/go/src/testing/testing.go:1449 +0x10c fp=0x400004afb0 sp=0x400004af60 pc=0xf7e0c
testing.(*T).Run.func1()
	/var/gobuilder/buildlet/go/src/testing/testing.go:1496 +0x2c fp=0x400004afd0 sp=0x400004afb0 pc=0xf8b4c
runtime.goexit()
	/var/gobuilder/buildlet/go/src/runtime/asm_arm64.s:1155 +0x4 fp=0x400004afd0 sp=0x400004afd0 pc=0x812b4
created by testing.(*T).Run
	/var/gobuilder/buildlet/go/src/testing/testing.go:1496 +0x328

goroutine 67 [chan send]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x26?, 0x400006c898?)
	/var/gobuilder/buildlet/go/src/runtime/proc.go:363 +0xe4 fp=0x400018dee0 sp=0x400018dec0 pc=0x4c3f4
runtime.chansend(0x400005e930, 0x311cb8, 0x1, 0x812b8?)
	/var/gobuilder/buildlet/go/src/runtime/chan.go:259 +0x44c fp=0x400018df70 sp=0x400018dee0 pc=0x15cfc
runtime.chansend1(0x4000076bd0?, 0x400006c840?)
	/var/gobuilder/buildlet/go/src/runtime/chan.go:145 +0x18 fp=0x400018dfa0 sp=0x400018df70 pc=0x15898
runtime_test.TestChan.func3()
	/var/gobuilder/buildlet/go/src/runtime/chan_test.go:64 +0x30 fp=0x400018dfd0 sp=0x400018dfa0 pc=0x1a26d0
runtime.goexit()
	/var/gobuilder/buildlet/go/src/runtime/asm_arm64.s:1155 +0x4 fp=0x400018dfd0 sp=0x400018dfd0 pc=0x812b4
created by runtime_test.TestChan
	/var/gobuilder/buildlet/go/src/runtime/chan_test.go:63 +0x350

…
*** Test killed with quit: ran too long (31m0s).
FAIL	runtime	1860.134s

greplogs -l -e 'goroutine \d+ \[sleep.*\]:\n(?:.+\n\t.+\n)*runtime_test\.TestChan' --since=2021-01-01
2022-05-03T19:48:07-bccce90/netbsd-arm64-bsiegert
2021-11-13T00:26:23-bc0b98e/netbsd-arm64-bsiegert
2021-09-23T20:15:19-93f964b/netbsd-arm64-bsiegert
2021-09-08T22:47:57-bff39cf/netbsd-arm64-bsiegert

It's not clear to me whether this is a deadlock or livelock in or exposed by this particular test, or an overall timeout due to a long stall in some other test function. (Note that TestChan is not parallel.)

attn @bsiegert; CC @golang/runtime, @golang/netbsd

[bcmills]

Curiously, a timeout in the same place on openbsd/arm64 (CC @golang/openbsd, @golang/arm).

I'm not sure whether to approach this as a BSD bug, an arm64 bug, or just a runtime test that has gotten slower and happens to be slowest right around there. 😅

greplogs -l -e 'goroutine \d+ \[sleep.*\]:\n(?:.+\n\t.+\n)*runtime_test\.TestChan' --since=2022-05-04
2022-05-04T16:42:28-cf69725/openbsd-arm64-jsing

[bcmills]

One today without the goroutine in the [sleep] state:

greplogs -l -e 'goroutine \d+ \[.*\]:\n(?:.+\n\t.+\n)*runtime_test\.TestChan' --since=2022-01-01
2022-05-05T14:44:31-485a572/openbsd-arm64-jsing
2022-05-04T16:42:28-cf69725/openbsd-arm64-jsing
2022-05-03T19:48:07-bccce90/netbsd-arm64-bsiegert

[bcmills]

greplogs -l -e 'goroutine \d+ \[.*\]:\n(?:.+\n\t.+\n)*runtime_test\.TestChan' --since=2022-05-06
2022-05-08T17:27:54-dd8d425/openbsd-arm64-jsing
2022-05-06T21:51:47-d7a03da/openbsd-arm64-jsing

[bcmills]

greplogs -l -e 'goroutine \d+ \[.*\]:\n(?:.+\n\t.+\n)*runtime_test\.TestChan' --since=2022-05-09
2022-05-11T23:26:11-f2cd6d6/openbsd-arm64-jsing
2022-05-11T21:01:09-b89a194/openbsd-arm64-jsing
2022-05-11T04:25:28-4388faf/openbsd-arm64-jsing

@4a6f656c, I'm going to drop openbsd-arm64-jsing from builder triage (and consider that port broken) until there is some progress on this issue. The signal-to-noise ratio from this builder is currently too low.

[bcmills]

greplogs -l -e 'goroutine \d+ \[.*\]:\n(?:.+\n\t.+\n)*runtime_test\.TestChan' --since=2022-05-12
2022-05-18T19:52:53-c087121/openbsd-arm64-jsing
2022-05-14T00:17:10-2168095/openbsd-arm64-jsing
2022-05-13T22:18:38-845a95b/openbsd-arm64-jsing
2022-05-13T21:50:20-9e9e2a8/openbsd-arm64-jsing

[gopherbot]

Change https://go.dev/cl/408703 mentions this issue: dashboard: add known issue for openbsd-arm64-jsing

[4a6f656c]

@bcmills are there any occurrences of this on openbsd-arm64-jsing prior to 2022-05-04?

I believe this relates to an OpenBSD kernel issue, which if the answer to the above question is no, lines up with an upgrade to 7.1. I've just applied a kernel patch that should avoid the issue - hopefully we'll know in the near future.

[bcmills]

are there any occurrences of this on openbsd-arm64-jsing prior to 2022-05-04?

None that I could find. 😃

I've just applied a kernel patch that should avoid the issue - hopefully we'll know in the near future.

Great! If you'd like to send a CL to remove the KnownIssue for the builder (https://cs.opensource.google/go/x/build/+/master:dashboard/builders.go;l=2135;drc=2305360635654c3c7c875b9e5f14e56463d9634a), we can put it back into triage to check for any remaining issues.

[gopherbot]

Change https://go.dev/cl/410095 mentions this issue: dashboard: remove known issue for openbsd-arm64-jsing