Could also be related to #48789.

The stuck calls appear to be running go run, go tool link, etc. Since these are Go binaries, probably a good starting point would be to send the stuck processes SIGQUIT to try to get goroutine dumps, and then to send them SIGKILL if they still don't respond.

That would at least help us to determine whether the hang is in the subprocess or the parent process.

(I think @aclements and @mknyszek were working on retrofitting that logic to various tests?)

The arm and arm64 ones may be due to slow machine.

Yeah, sending a SIGQUIT at timeout is probably a good idea.

I have CL 370665 to apply timeouts to nearly every subprocess invocation in the runtime test (though wasn't planning to land that until the tree opens). These failures are all in cmd/link or cmd/link/internal/ld. I could roll a CL to use RunWithTimeout in those tests.

Looks like the same failure mode in go/internal/gcimporter too: https://build.golang.org/log/0e1b9a393109ba16005d18ff9faca47c50728a8f

goroutine 167 [syscall, 2 minutes]:
syscall.Syscall6(0x1a4b, 0x8853cf0, 0x0, 0x8d7c320, 0x0, 0x0, 0x0)
	/tmp/workdir/go/src/syscall/asm_unix_386.s:43 +0x5 fp=0x8853c9c sp=0x8853c98 pc=0x80b4015
syscall.wait4(0x1a4b, 0x8853cf0, 0x0, 0x8d7c320)
	/tmp/workdir/go/src/syscall/zsyscall_netbsd_386.go:34 +0x5b fp=0x8853cd4 sp=0x8853c9c pc=0x80b28db
syscall.Wait4(0x1a4b, 0x8853d14, 0x0, 0x8d7c320)
	/tmp/workdir/go/src/syscall/syscall_bsd.go:144 +0x3b fp=0x8853cf8 sp=0x8853cd4 pc=0x80b269b
os.(*Process).wait(0x89d1530)
	/tmp/workdir/go/src/os/exec_unix.go:43 +0x82 fp=0x8853d2c sp=0x8853cf8 pc=0x80c9d32
os.(*Process).Wait(...)
	/tmp/workdir/go/src/os/exec.go:132
os/exec.(*Cmd).Wait(0x89549a0)
	/tmp/workdir/go/src/os/exec/exec.go:507 +0x4d fp=0x8853d70 sp=0x8853d2c pc=0x8139b7d
os/exec.(*Cmd).Run(0x89549a0)
	/tmp/workdir/go/src/os/exec/exec.go:341 +0x43 fp=0x8853d80 sp=0x8853d70 pc=0x8138f63
os/exec.(*Cmd).CombinedOutput(0x89549a0)
	/tmp/workdir/go/src/os/exec/exec.go:567 +0x89 fp=0x8853d94 sp=0x8853d80 pc=0x813a049
go/internal/gcimporter_test.compile(0x8801b30, {0x88c4300, 0x1e}, {0x88aaa80, 0xe}, {0x89d1500, 0x27})
	/tmp/workdir/go/src/go/internal/gcimporter/gcimporter_test.go:50 +0x28d fp=0x8853e18 sp=0x8853d94 pc=0x822216d
go/internal/gcimporter_test.TestImportTypeparamTests.func1(0x8801b30)
	/tmp/workdir/go/src/go/internal/gcimporter/gcimporter_test.go:201 +0x406 fp=0x8853f9c sp=0x8853e18 pc=0x8223a86
testing.tRunner(0x8801b30, 0x8970ca0)
	/tmp/workdir/go/src/testing/testing.go:1440 +0x10d fp=0x8853fe4 sp=0x8853f9c pc=0x8109a0d
testing.(*T).Run.func1()
	/tmp/workdir/go/src/testing/testing.go:1487 +0x28 fp=0x8853ff0 sp=0x8853fe4 pc=0x810a7e8
runtime.goexit()
	/tmp/workdir/go/src/runtime/asm_386.s:1311 +0x1 fp=0x8853ff4 sp=0x8853ff0 pc=0x80a8a51
created by testing.(*T).Run
	/tmp/workdir/go/src/testing/testing.go:1487 +0x36e

greplogs --dashboard -md -l -e 'panic: test timed out.*\n\n(?:goroutine .*:\n(?:.+\n\t.+\n)+\n)*goroutine \d+ \[syscall, \d+ minutes\]:\n(?:.+\n\t.+\n)*os\.\(\*Process\)\.Wait(?:.*\n)+FAIL\s+cmd/link' --since=2022-01-08

2022-03-10T09:12:04-5a040c5/netbsd-amd64-9_0

Broadening the regexp to search for os.(*Process).Wait generally, since this symptom does not appear to be specific to cmd/link as far as I can see.

greplogs --dashboard -md -l -e '\Anetbsd-(.*\n)*panic: test timed out.*\n\n(?:goroutine .*:\n(?:.+\n\t.+\n)+\n)*goroutine \d+ \[syscall, \d+ minutes\]:\n(?:.+\n\t.+\n)*os\.\(\*Process\)\.Wait' --since=2022-01-01

• 2022-04-05T17:54:15-de8a882-9839668/netbsd-386-9_0
  • 9 minutes, stuck in git-codereview.TestSubmit on a git fetch to a local server hosted in the test process, and the server appears to be idle
• 2022-03-31T06:40:26-ebe624d/netbsd-arm-bsiegert
  • 29 minutes, stuck in gcimporter_test.TestImportTypeparamTests on go tool compile
• 2022-03-10T09:12:04-5a040c5/netbsd-amd64-9_0
  • 2 minutes, stuck in link.TestIssue21703 on go tool compile
• 2022-02-14T17:30:31-6c99688-3d7f836/netbsd-386-9_0
  • 9 minutes, same git fetch in git-codereview.TestSubmit
• 2022-01-13T19:25:50-ce01afe/netbsd-arm64-bsiegert
  • 29 minutes, stuck in pprof.TestMapping on go run of a test program that sleeps for 200ms before exiting
• 2022-01-11T15:28:40-c7fa661/netbsd-arm-bsiegert
  • 29 minutes, stuck in cmd/compile/internal/test.TestReproducibleBuilds on go tool compile
• 2022-01-06T21:38:57-c5540e5/netbsd-386-9_0-n2
  • 2 minutes, same go tool compile in gcimporter_test.TestImportTypeparamTests

greplogs --dashboard -md -l -e '\Anetbsd-(.*\n)*panic: test timed out.*\n\n(?:goroutine .*:\n(?:.+\n\t.+\n)+\n)*goroutine \d+ \[syscall, \d+ minutes\]:\n(?:.+\n\t.+\n)*os\.\(\*Process\)\.Wait' --since=2022-04-06

2022-04-18T22:07:54-f49e802/netbsd-arm-bsiegert

• 29 minutes, stuck in cmd/link/internal/ld.TestMemProfileCheck on go run of a test program that prints runtime.MemProfileRate and then exits.

@bsiegert, @coypoop: given that os/exec is used pervasively, I can't easily filter out these failures during dashboard triage. I also don't see how Go on NetBSD could be usable in a production setting with what appears to be a pervasive deadlock in such a fundamental API. Is there something that can be done to move this forward on the NetBSD side?

/cc @zoulasc @tklauser

The arm and arm64 ones may be due to slow machine.

Is this still a suspicion? I assume the netbsd/arm builder is extra slow.
I didn't try this, but netbsd/arm64's 32-bit compat might be sufficient for running arm32 tests.

Do you have steps to reproduce?

I'm having a little trouble following the initial report, because it seems to cover several operating systems and architectures. Does this happen every time on NetBSD, or on NetBSD/arm, or only sometimes, or what?

If it happens only sometimes, how long does it take successful test runs on the machines where it fails?

The arm and arm64 ones may be due to slow machine.

Is this still a suspicion? I assume the netbsd/arm builder is extra slow.

I can't speak for @cherrymui, but given the similar failures on the -amd64 and -386 builders I believe this is likely an architecture-independent synchronization bug in either the NetBSD kernel or the Go os implementation for NetBSD.

Do you have steps to reproduce?

Unfortunately no. The failures listed above were found organically in the Go build dashboard — the repro rate is high enough to be significant but not high enough to reproduce on demand.

I'm having a little trouble following the initial report, because it seems to cover several operating systems and architectures.

The freebsd failure in 2021-04-29T15:47:16-12eaefe was likely #46272, and hasn't been seen since that was addressed.
The linux-ppc64le failure was from 2019, and may have been an organic timeout. (It hasn't been a recurring pattern.)
The remainder AFAICT are on NetBSD, on varying architectures.

Does this happen every time on NetBSD, or on NetBSD/arm, or only sometimes, or what?

Intermittently, on NetBSD across all of the architectures for which we have builders.

(Note that we also tried to use wait6 for this on NetBSD, but had to roll it back because of other deadlocks on that OS — see #48789.)

greplogs --dashboard -md -l -e '\Anetbsd-(.*\n)*panic: test timed out.*\n\n(?:goroutine .*:\n(?:.+\n\t.+\n)+\n)*goroutine \d+ \[syscall, \d+ minutes\]:\n(?:.+\n\t.+\n)*os\.\(\*Process\)\.Wait' --since=2022-04-19

• 2022-04-22T04:42:23-1e59876/netbsd-386-9_0
  • 8 minutes, stuck in cmd/go_test.waitOrStop, which attempts to explicitly terminate the process before the observed timout occurs (see cmd/go: test timeouts waiting for os/exec copying goroutines #50187, os: on NetBSD, *Process.Wait sometimes deadlocks after cmd.Process.Signal returns "process already finished" #48789 — both of which appear to be specific to NetBSD).
• 2022-04-22T00:37:23-bf19163/netbsd-386-9_0
  • 2 minutes, stuck in runtime_test.TestLockOSThreadTemplateThreadRace on a program that spins on time.Now() on two goroutines for 10ms before locking those threads and exiting.

greplogs --dashboard -md -l -e '\Anetbsd-(.*\n)*panic: test timed out.*\n\n(?:goroutine .*:\n(?:.+\n\t.+\n)+\n)*goroutine \d+ \[syscall, \d+ minutes\]:\n(?:.+\n\t.+\n)*os\.\(\*Process\)\.Wait' --since=2022-04-23
2022-05-12T22:29:02-da0a6f4/netbsd-arm-bsiegert
2022-05-12T20:19:10-27ace7a/netbsd-arm-bsiegert

Very curious that these recent ones seem to occur in pairs. 🤔

(attn @golang/netbsd)

Then again, the pairings might just be a coincidence.

greplogs --dashboard -md -l -e '\Anetbsd-(.*\n)*panic: test timed out.*\n\n(?:goroutine .*:\n(?:.+\n\t.+\n)+\n)*goroutine \d+ \[syscall, \d+ minutes\]:\n(?:.+\n\t.+\n)*os\.\(\*Process\)\.Wait' --since=2022-05-13
2022-05-13T19:45:43-ba8310c/netbsd-amd64-9_0

greplogs -l -e '\Anetbsd-(.*\n)*panic: test timed out.*\n\n(?:goroutine .*:\n(?:.+\n\t.+\n)+\n)*goroutine \d+ \[syscall, \d+ minutes\]:\n(?:.+\n\t.+\n)*os\.\(\*Process\)\.Wait' --since=2022-05-14
2022-05-27T14:57:14-590b53f/netbsd-amd64-9_0 (on release-branch.go1.17)
2022-05-17T03:26:28-41b9d8c/netbsd-arm64-bsiegert (on the main branch)

Change https://go.dev/cl/409595 mentions this issue: dashboard: mark all current netbsd builders as affected by golang/go#50138

Change https://go.dev/cl/442575 mentions this issue: os: split wait6 syscall wrapper into per-platform files

https://go.dev/cl/442478 seems like a plausible fix for this issue. Waiting to see if there's more.

The TryBots for that change hit a deadlock that looks plausibly related to the missed fprintf wakeup from the C program I tried yesterday (#50138 (comment)). If that's all that is left I suggest that we report it as a separate issue, since it has a somewhat different symptom.

I've filed the new failure mode separately as #56180.

I left this attempt at a C reproducer running overnight on a netbsd-amd64-9_0 gomote instance, but by the morning it ended up deadlocked in fprintf instead of seeing a spurious return from wait6. Apparently there is also some kind of rare race condition in NetBSD's fprintf that causes a missed wakeup on a condition variable? 😅

The fprintf issue you hit may be a bug in the interaction between libpthread and the dynamic loader rtld which we have since fixed in HEAD and netbsd-9 (but not in netbsd-9.0):

https://nxr.netbsd.org/xref/src/lib/libpthread/pthread.c?r=1.181#418

Please let us know if you can still reproduce it on a current system.

https://go.dev/cl/442478 seems like a plausible fix for this issue. Waiting to see if there's more.

Surely that wouldn't affect the deadlock you saw with wait4, would it? If Go uses wait4 instead of wait6, do you still see the deadlock? (Forgive me if I missed something -- there have been a lot of updates in quick succession which I didn't follow all of.)

The wait4 version of the deadlock is plausibly #13987, depending how quickly NetBSD recycles PIDs.

Updating to a more recent NetBSD release is #54773.

Updating to a more recent NetBSD release is #54773.

Unfortunately the libpthread/rtld fix didn't make it into 9.3! I didn't realize it until a couple days after 9.3 went out, sorry. But if you can reproduce the C program's fprintf hang, just a regular NetBSD install on a VM without all the golang test harness, that would be helpful -- especially if you can do it on a system with the debug.tgz (or debug.tar.xz) set installed so we get full stack traces. I'll see if I can reproduce it, but half an hour of running it, both on a NetBSD<=9.3 library without the fix and on a current library with the fix, hasn't turned anything up yet.

The new failure mode in #56180 is consistent with the aforementioned libpthread bug, and the remaining failures on the builders after CL 442478 all seem to plausibly match that failure mode.

I'm going to close this issue as “one bug fixed”, with the remaining hang tracked in #56180. (If there are other failure modes after the builders are upgraded in #54773, we can open new issues for those.)

Change https://go.dev/cl/454755 mentions this issue: dashboard: remove NetBSD 9.0 builders