It's interesting that the test is blocked on this subprocess in particular, because we explicitly plumb in a value for the -test.timeout flag that should be short enough to complete before the test finishes:
https://cs.opensource.google/go/go/+/master:src/os/signal/signal_test.go;l=746-748;drc=e3eaedb5cf623d0836533573db4140749da42768

Thanks for pinging me, @bcmills.
I'll try to reproduce it on a Solaris VM during this weekend.

One more this month:

greplogs --dashboard -md -l -e 'panic: test timed out .*\n(?:\ngoroutine \d+ .*:\n(.+\n)*)*^os/signal\.TestNotifyContextNotifications' --since=2022-02-08

2022-03-07T18:19:44-7dc6c5e/solaris-amd64-oraclerel

I notice that we're not actually calling t.Parallel() in the subtests. I wonder if the test is actually timing out in the first subtest, and then starting the second subtest without actually having enough time left to clean up.

It occurs to me that the os/exec changes proposed in #50436 would probably help here too: if either subtest times out, we ought to terminate the subprocess with SIGQUIT to figure out what it's stuck on.

* t.Parallel() is called in TestNotifyContextNotifications immediately after the checkNotifyContext conditional.

I was able to reproduce this (building checked out @ commit 0261fa6) when running all.bash on a SunOS solaris 5.11 11.4.0.15.0 i86pc i386 i86pc virtual machine. In my case, it's happening about once every ~20 runs or so. I wasn't able to identify cause. Weirdly, increasing the memory of the virtual machine seems to have reduced the number of times this happened.

I wasn't able to identify cause. Weirdly, increasing the memory of the virtual machine seems to have reduced the number of times this happened.

Since solaris/amd64 is not a first class port, if we can't identify the cause of the failure it would be ok to skip the test on that platform.

greplogs --dashboard -md -l -e 'panic: test timed out .*\n(?:\ngoroutine \d+ .*:\n(.+\n)*)*^os/signal\.TestNotifyContextNotifications' --since=2022-03-08

2022-03-28T19:46:07-1a9972e/solaris-amd64-oraclerel

Change https://go.dev/cl/398454 mentions this issue: os/signal: run TestNotifyContextnotifications subtests in parallel

Change https://go.dev/cl/398454 mentions this issue: os/signal: run TestNotifyContextNotifications subtests in parallel

CL 398454 might fix this. I'll keep an eye on it.

The thrilling conclusion, from https://build.golang.org/log/efc839b64c4b5ef269ecf21fa28685fbeb600e18:

--- FAIL: TestNotifyContextNotifications (0.00s)
    --- FAIL: TestNotifyContextNotifications/once (0.00s)
        signal_test.go:741: starting test with less than 22s remaining
    --- FAIL: TestNotifyContextNotifications/multiple (0.00s)
        signal_test.go:741: starting test with less than 22s remaining
FAIL
FAIL	os/signal	158.438s

The large settleTime that we had to set on solaris is just too slow. I guess for the interim we can try scaling it back, but longer term we should rework the tests not to send signals to the main test process to begin with. 🤔

Change https://go.dev/cl/403199 mentions this issue: os/signal: scale back the solaris-amd64-oraclerel settle time

Rolling forward to 1.20. Please comment if you disagree. Thanks.

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "os/signal" && test == "TestNotifyContextNotifications"

panic: test timed out after 3m0s

runtime.gopark(0xc00011bd68?, 0xc00011bdd0?, 0xe5?, 0xc8?, 0xc00011bdf8?)
	/opt/golang/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/runtime/proc.go:361 +0xd6 fp=0xc00011bd50 sp=0xc00011bd30 pc=0x436d56
runtime.chanrecv(0xc0000b0690, 0xc00011be4f, 0x1)
	/opt/golang/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/runtime/chan.go:577 +0x56c fp=0xc00011bde0 sp=0xc00011bd50 pc=0x405f2c
runtime.chanrecv1(0xc000098030?, 0x1?)
	/opt/golang/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/runtime/chan.go:440 +0x18 fp=0xc00011be08 sp=0xc00011bde0 pc=0x405958
testing.(*T).Run(0xc0000036c0, {0x5385d4?, 0x2?}, 0xc000092400)
	/opt/golang/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/testing/testing.go:1487 +0x37a fp=0xc00011bea8 sp=0xc00011be08 pc=0x4bc85a
os/signal.TestNotifyContextNotifications(0xc0001e4340?)
	/opt/golang/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/os/signal/signal_test.go:733 +0x1d1 fp=0xc00011bf70 sp=0xc00011bea8 pc=0x4cfb11
testing.tRunner(0xc0000036c0, 0x543928)

— watchflakes

Timed out in state WaitingForInfo. Closing.

(I am just a bot, though. Please speak up if this is a mistake or you have the requested information.)

Duplicate of #60152