x/net/ipv4: TestPacketConnConcurrentReadWriteUnicastUDP timeout with goroutines blocked on net.rawConn.Read #54595
Description
#!watchflakes
post <- pkg == "golang.org/x/net/ipv4" && test == "TestPacketConnConcurrentReadWriteUnicastUDP" && `^net\.\(\*rawConn\).Read`
2022-08-18T05:32:36-3211cb9-a2c2f06/freebsd-amd64-13_0
Details
panic: test timed out after 10m0s
goroutine 81 [running]:
testing.(*M).startAlarm.func1()
/tmp/workdir/go/src/testing/testing.go:2036 +0x8e
created by time.goFunc
/tmp/workdir/go/src/time/sleep.go:176 +0x32
goroutine 1 [chan receive]:
testing.(*T).Run(0xc000083040, {0x5b8345?, 0xc000058bb0?}, 0x5bb2f0)
/tmp/workdir/go/src/testing/testing.go:1494 +0x37a
testing.runTests.func1(0xc000083040?)
/tmp/workdir/go/src/testing/testing.go:1846 +0x6e
testing.tRunner(0xc000083040, 0xc000058cd8)
/tmp/workdir/go/src/testing/testing.go:1446 +0x10b
testing.runTests(0xc0000c2280?, {0x6e34e0, 0x19, 0x19}, {0x800b415b8?, 0x40?, 0x6e78e0?})
/tmp/workdir/go/src/testing/testing.go:1844 +0x456
testing.(*M).Run(0xc0000c2280)
/tmp/workdir/go/src/testing/testing.go:1726 +0x5d9
main.main()
_testmain.go:101 +0x1aa
goroutine 40 [semacquire]:
sync.runtime_Semacquire(0xc0000e1b80?)
/tmp/workdir/go/src/runtime/sema.go:62 +0x25
sync.(*WaitGroup).Wait(0x5ae420?)
/tmp/workdir/go/src/sync/waitgroup.go:139 +0x52
golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP(0xc0000f5a00)
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:322 +0x6aa
testing.tRunner(0xc0000f5a00, 0x5bb2f0)
/tmp/workdir/go/src/testing/testing.go:1446 +0x10b
created by testing.(*T).Run
/tmp/workdir/go/src/testing/testing.go:1493 +0x35f
goroutine 72 [IO wait]:
internal/poll.runtime_pollWait(0x8288bf9b8, 0x72)
/tmp/workdir/go/src/runtime/netpoll.go:305 +0x89
internal/poll.(*pollDesc).wait(0xc00012e400?, 0x48?, 0x0)
/tmp/workdir/go/src/internal/poll/fd_poll_runtime.go:84 +0x32
internal/poll.(*pollDesc).waitRead(...)
/tmp/workdir/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).RawRead(0xc00012e400, 0xc0001501e0)
/tmp/workdir/go/src/internal/poll/fd_unix.go:766 +0x145
net.(*rawConn).Read(0xc0000aa0e0, 0xc0000b6b40?)
/tmp/workdir/go/src/net/rawconn.go:43 +0x45
golang.org/x/net/internal/socket.(*Conn).recvMsg(0xc0000ea640, 0xc0000adbc0, 0x0)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/rawconn_msg.go:28 +0x179
golang.org/x/net/internal/socket.(*Conn).RecvMsg(...)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/socket.go:247
golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0xc000119b90, {0xc0000c9500, 0x80, 0x80})
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/payload_cmsg.go:32 +0x528
golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP.func2()
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:268 +0xeb
created by golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:320 +0x68f
goroutine 73 [semacquire]:
internal/poll.runtime_Semacquire(0x0?)
/tmp/workdir/go/src/runtime/sema.go:67 +0x25
internal/poll.(*fdMutex).rwlock(0xc00012e400, 0x48?)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:154 +0xd2
internal/poll.(*FD).readLock(...)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:221
internal/poll.(*FD).RawRead(0xc00012e400, 0xc000150230)
/tmp/workdir/go/src/internal/poll/fd_unix.go:755 +0x45
net.(*rawConn).Read(0xc0000aa0e0, 0xc0000b6b58?)
/tmp/workdir/go/src/net/rawconn.go:43 +0x45
golang.org/x/net/internal/socket.(*Conn).recvMsg(0xc0000ea640, 0xc0000adc80, 0x0)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/rawconn_msg.go:28 +0x179
golang.org/x/net/internal/socket.(*Conn).RecvMsg(...)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/socket.go:247
golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0xc000119b90, {0xc0000c9600, 0x80, 0x80})
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/payload_cmsg.go:32 +0x528
golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP.func2()
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:268 +0xeb
created by golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:320 +0x68f
goroutine 74 [semacquire]:
internal/poll.runtime_Semacquire(0x0?)
/tmp/workdir/go/src/runtime/sema.go:67 +0x25
internal/poll.(*fdMutex).rwlock(0xc00012e400, 0x48?)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:154 +0xd2
internal/poll.(*FD).readLock(...)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:221
internal/poll.(*FD).RawRead(0xc00012e400, 0xc000150280)
/tmp/workdir/go/src/internal/poll/fd_unix.go:755 +0x45
net.(*rawConn).Read(0xc0000aa0e0, 0xc0000b6b70?)
/tmp/workdir/go/src/net/rawconn.go:43 +0x45
golang.org/x/net/internal/socket.(*Conn).recvMsg(0xc0000ea640, 0xc0000add40, 0x0)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/rawconn_msg.go:28 +0x179
golang.org/x/net/internal/socket.(*Conn).RecvMsg(...)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/socket.go:247
golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0xc000119b90, {0xc0000c9700, 0x80, 0x80})
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/payload_cmsg.go:32 +0x528
golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP.func2()
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:268 +0xeb
created by golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:320 +0x68f
goroutine 75 [semacquire]:
internal/poll.runtime_Semacquire(0x0?)
/tmp/workdir/go/src/runtime/sema.go:67 +0x25
internal/poll.(*fdMutex).rwlock(0xc00012e400, 0x48?)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:154 +0xd2
internal/poll.(*FD).readLock(...)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:221
internal/poll.(*FD).RawRead(0xc00012e400, 0xc0001502d0)
/tmp/workdir/go/src/internal/poll/fd_unix.go:755 +0x45
net.(*rawConn).Read(0xc0000aa0e0, 0xc0000b6b88?)
/tmp/workdir/go/src/net/rawconn.go:43 +0x45
golang.org/x/net/internal/socket.(*Conn).recvMsg(0xc0000ea640, 0xc0000ade00, 0x0)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/rawconn_msg.go:28 +0x179
golang.org/x/net/internal/socket.(*Conn).RecvMsg(...)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/socket.go:247
golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0xc000119b90, {0xc0000c9800, 0x80, 0x80})
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/payload_cmsg.go:32 +0x528
golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP.func2()
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:268 +0xeb
created by golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:320 +0x68f
goroutine 76 [semacquire]:
internal/poll.runtime_Semacquire(0x0?)
/tmp/workdir/go/src/runtime/sema.go:67 +0x25
internal/poll.(*fdMutex).rwlock(0xc00012e400, 0x48?)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:154 +0xd2
internal/poll.(*FD).readLock(...)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:221
internal/poll.(*FD).RawRead(0xc00012e400, 0xc000150320)
/tmp/workdir/go/src/internal/poll/fd_unix.go:755 +0x45
net.(*rawConn).Read(0xc0000aa0e0, 0xc0000b6ba0?)
/tmp/workdir/go/src/net/rawconn.go:43 +0x45
golang.org/x/net/internal/socket.(*Conn).recvMsg(0xc0000ea640, 0xc0000adec0, 0x0)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/rawconn_msg.go:28 +0x179
golang.org/x/net/internal/socket.(*Conn).RecvMsg(...)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/socket.go:247
golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0xc000119b90, {0xc0000c9900, 0x80, 0x80})
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/payload_cmsg.go:32 +0x528
golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP.func2()
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:268 +0xeb
created by golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:320 +0x68f
goroutine 77 [semacquire]:
internal/poll.runtime_Semacquire(0x0?)
/tmp/workdir/go/src/runtime/sema.go:67 +0x25
internal/poll.(*fdMutex).rwlock(0xc00012e400, 0x48?)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:154 +0xd2
internal/poll.(*FD).readLock(...)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:221
internal/poll.(*FD).RawRead(0xc00012e400, 0xc000150370)
/tmp/workdir/go/src/internal/poll/fd_unix.go:755 +0x45
net.(*rawConn).Read(0xc0000aa0e0, 0xc0000b6bb8?)
/tmp/workdir/go/src/net/rawconn.go:43 +0x45
golang.org/x/net/internal/socket.(*Conn).recvMsg(0xc0000ea640, 0xc0000adf80, 0x0)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/rawconn_msg.go:28 +0x179
golang.org/x/net/internal/socket.(*Conn).RecvMsg(...)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/socket.go:247
golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0xc000119b90, {0xc0000c9a00, 0x80, 0x80})
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/payload_cmsg.go:32 +0x528
golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP.func2()
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:268 +0xeb
created by golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:320 +0x68f
goroutine 78 [semacquire]:
internal/poll.runtime_Semacquire(0x0?)
/tmp/workdir/go/src/runtime/sema.go:67 +0x25
internal/poll.(*fdMutex).rwlock(0xc00012e400, 0x48?)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:154 +0xd2
internal/poll.(*FD).readLock(...)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:221
internal/poll.(*FD).RawRead(0xc00012e400, 0xc0001503c0)
/tmp/workdir/go/src/internal/poll/fd_unix.go:755 +0x45
net.(*rawConn).Read(0xc0000aa0e0, 0xc0000b6bd0?)
/tmp/workdir/go/src/net/rawconn.go:43 +0x45
golang.org/x/net/internal/socket.(*Conn).recvMsg(0xc0000ea640, 0xc000160060, 0x0)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/rawconn_msg.go:28 +0x179
golang.org/x/net/internal/socket.(*Conn).RecvMsg(...)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/socket.go:247
golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0xc000119b90, {0xc0000c9b00, 0x80, 0x80})
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/payload_cmsg.go:32 +0x528
golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP.func2()
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:268 +0xeb
created by golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:320 +0x68f
goroutine 79 [semacquire]:
internal/poll.runtime_Semacquire(0x0?)
/tmp/workdir/go/src/runtime/sema.go:67 +0x25
internal/poll.(*fdMutex).rwlock(0xc00012e400, 0x48?)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:154 +0xd2
internal/poll.(*FD).readLock(...)
/tmp/workdir/go/src/internal/poll/fd_mutex.go:221
internal/poll.(*FD).RawRead(0xc00012e400, 0xc000150410)
/tmp/workdir/go/src/internal/poll/fd_unix.go:755 +0x45
net.(*rawConn).Read(0xc0000aa0e0, 0xc0000b6be8?)
/tmp/workdir/go/src/net/rawconn.go:43 +0x45
golang.org/x/net/internal/socket.(*Conn).recvMsg(0xc0000ea640, 0xc000160120, 0x0)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/rawconn_msg.go:28 +0x179
golang.org/x/net/internal/socket.(*Conn).RecvMsg(...)
/tmp/workdir/gopath/src/golang.org/x/net/internal/socket/socket.go:247
golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0xc000119b90, {0xc0000c9c00, 0x80, 0x80})
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/payload_cmsg.go:32 +0x528
golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP.func2()
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:268 +0xeb
created by golang.org/x/net/ipv4_test.TestPacketConnConcurrentReadWriteUnicastUDP
/tmp/workdir/gopath/src/golang.org/x/net/ipv4/readwrite_test.go:320 +0x68f
FAIL golang.org/x/net/ipv4 600.155s
It looks like there are many reader goroutines stuck with no writer goroutines remaining, which implies that either all of the writers succeeded, or one or more of writers failed but somehow didn't succeed in unblocking the readers by closing the PacketConn.
(I'm not able to find this failure using greplogs; it may have rolled off the end of what the dashboard is willing to serve.)
(attn @golang/freebsd, since this may be a symptom of a kernel bug)