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.

Sign up for GitHub

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

Jump to bottom

Deadlock detected by TestConnReaperDeadlock #149

Closed
egorse opened this issue Dec 15, 2023 · 2 comments · Fixed by #150
Closed

Deadlock detected by TestConnReaperDeadlock #149

egorse opened this issue Dec 15, 2023 · 2 comments · Fixed by #150

Comments

@egorse
Copy link
Contributor

egorse commented Dec 15, 2023

Running while go test -timeout 30s -run ^TestConnReaperDeadlock$; do echo .; done with v0.16.0 eventually may get test failed by timeout

The output is next:

panic: test timed out after 30s
running tests:
	TestConnReaperDeadlock (30s)

goroutine 42 [running]:
testing.(*M).startAlarm.func1()
	/usr/local/go/src/testing/testing.go:2259 +0x3b9
created by time.goFunc
	/usr/local/go/src/time/sleep.go:176 +0x2d

goroutine 1 [chan receive]:
testing.(*T).Run(0xc00020d380, {0x5f1463?, 0x4d20bc?}, 0x5fe1e8)
	/usr/local/go/src/testing/testing.go:1649 +0x3c8
testing.runTests.func1(0x770c60?)
	/usr/local/go/src/testing/testing.go:2054 +0x3e
testing.tRunner(0xc00020d380, 0xc0000c3c48)
	/usr/local/go/src/testing/testing.go:1595 +0xff
testing.runTests(0xc0000a0140?, {0x76b8c0, 0x21, 0x21}, {0x414a85?, 0xc0000c3d08?, 0x770440?})
	/usr/local/go/src/testing/testing.go:2052 +0x445
testing.(*M).Run(0xc0000a0140)
	/usr/local/go/src/testing/testing.go:1925 +0x636
main.main()
	_testmain.go:115 +0x19c

goroutine 19 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc0000fa3d0, 0x0)
	/usr/local/go/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0xc0000dc640?)
	/usr/local/go/src/sync/cond.go:70 +0x85
github.com/go-zeromq/zmq4.(*pubMWriter).run(0xc0000a4480)
	/home/egorse/projects/public/zmq4-tag/pub.go:245 +0x225
created by github.com/go-zeromq/zmq4.newPubMWriter in goroutine 1
	/home/egorse/projects/public/zmq4-tag/pub.go:237 +0x15a

goroutine 20 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc0000fa610, 0x0)
	/usr/local/go/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0x0?)
	/usr/local/go/src/sync/cond.go:70 +0x85
github.com/go-zeromq/zmq4.(*pubMWriter).run(0xc0000a47e0)
	/home/egorse/projects/public/zmq4-tag/pub.go:245 +0x225
created by github.com/go-zeromq/zmq4.newPubMWriter in goroutine 1
	/home/egorse/projects/public/zmq4-tag/pub.go:237 +0x15a

goroutine 21 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc0000fa850, 0x0)
	/usr/local/go/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0x0?)
	/usr/local/go/src/sync/cond.go:70 +0x85
github.com/go-zeromq/zmq4.(*pubMWriter).run(0xc0000a4b40)
	/home/egorse/projects/public/zmq4-tag/pub.go:245 +0x225
created by github.com/go-zeromq/zmq4.newPubMWriter in goroutine 1
	/home/egorse/projects/public/zmq4-tag/pub.go:237 +0x15a

goroutine 23 [select]:
github.com/go-zeromq/zmq4.(*repWriter).run(0xc0000fab40)
	/home/egorse/projects/public/zmq4-tag/rep.go:272 +0xf4
created by github.com/go-zeromq/zmq4.newRepWriter in goroutine 1
	/home/egorse/projects/public/zmq4-tag/rep.go:232 +0xd6

goroutine 24 [select]:
github.com/go-zeromq/zmq4.(*repWriter).run(0xc0000facc0)
	/home/egorse/projects/public/zmq4-tag/rep.go:272 +0xf4
created by github.com/go-zeromq/zmq4.newRepWriter in goroutine 1
	/home/egorse/projects/public/zmq4-tag/rep.go:232 +0xd6

goroutine 25 [select]:
github.com/go-zeromq/zmq4.(*repWriter).run(0xc0000fae40)
	/home/egorse/projects/public/zmq4-tag/rep.go:272 +0xf4
created by github.com/go-zeromq/zmq4.newRepWriter in goroutine 1
	/home/egorse/projects/public/zmq4-tag/rep.go:232 +0xd6

goroutine 27 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc0000faf90, 0x0)
	/usr/local/go/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0xc0000dd680?)
	/usr/local/go/src/sync/cond.go:70 +0x85
github.com/go-zeromq/zmq4.(*pubMWriter).run(0xc0000a52c0)
	/home/egorse/projects/public/zmq4-tag/pub.go:245 +0x225
created by github.com/go-zeromq/zmq4.newPubMWriter in goroutine 1
	/home/egorse/projects/public/zmq4-tag/pub.go:237 +0x15a

goroutine 28 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc0000fb1d0, 0x0)
	/usr/local/go/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0x0?)
	/usr/local/go/src/sync/cond.go:70 +0x85
github.com/go-zeromq/zmq4.(*pubMWriter).run(0xc0000a5620)
	/home/egorse/projects/public/zmq4-tag/pub.go:245 +0x225
created by github.com/go-zeromq/zmq4.newPubMWriter in goroutine 1
	/home/egorse/projects/public/zmq4-tag/pub.go:237 +0x15a

goroutine 29 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc0000fb410, 0x0)
	/usr/local/go/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0x0?)
	/usr/local/go/src/sync/cond.go:70 +0x85
github.com/go-zeromq/zmq4.(*pubMWriter).run(0xc0000a5980)
	/home/egorse/projects/public/zmq4-tag/pub.go:245 +0x225
created by github.com/go-zeromq/zmq4.newPubMWriter in goroutine 1
	/home/egorse/projects/public/zmq4-tag/pub.go:237 +0x15a

goroutine 30 [semacquire]:
sync.runtime_Semacquire(0x454ebc?)
	/usr/local/go/src/runtime/sema.go:62 +0x25
sync.(*WaitGroup).Wait(0x20?)
	/usr/local/go/src/sync/waitgroup.go:116 +0x48
golang.org/x/sync/errgroup.(*Group).Wait(0xc000238200)
	/home/egorse/go/pkg/mod/golang.org/x/sync@v0.3.0/errgroup/errgroup.go:53 +0x25
github.com/go-zeromq/zmq4.(*routerMWriter).write(0xc0000fbf00, {0x633598, 0xc0000f43f0}, {{0xc000212820, 0x3, 0x3}, 0x0, 0x0, {0x0, 0x0}})
	/home/egorse/projects/public/zmq4-tag/router.go:242 +0x2ed
github.com/go-zeromq/zmq4.(*routerSocket).Send(0xc000092408, {{0xc000212820, 0x3, 0x3}, 0x0, 0x0, {0x0, 0x0}})
	/home/egorse/projects/public/zmq4-tag/router.go:40 +0xdb
github.com/go-zeromq/zmq4_test.TestConnReaperDeadlock(0xc00020d520)
	/home/egorse/projects/public/zmq4-tag/socket_test.go:217 +0x77f
testing.tRunner(0xc00020d520, 0x5fe1e8)
	/usr/local/go/src/testing/testing.go:1595 +0xff
created by testing.(*T).Run in goroutine 1
	/usr/local/go/src/testing/testing.go:1648 +0x3ad

goroutine 32 [IO wait]:
internal/poll.runtime_pollWait(0x7fb11099ce38, 0x72)
	/usr/local/go/src/runtime/netpoll.go:343 +0x85
internal/poll.(*pollDesc).wait(0xc0000f6380?, 0xc000139d50?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Accept(0xc0000f6380)
	/usr/local/go/src/internal/poll/fd_unix.go:611 +0x2ac
net.(*netFD).accept(0xc0000f6380)
	/usr/local/go/src/net/fd_unix.go:172 +0x29
net.(*TCPListener).accept(0xc0000c02a0)
	/usr/local/go/src/net/tcpsock_posix.go:152 +0x1e
net.(*TCPListener).Accept(0xc0000c02a0)
	/usr/local/go/src/net/tcpsock.go:315 +0x30
github.com/go-zeromq/zmq4.(*socket).accept(0xc00020da00)
	/home/egorse/projects/public/zmq4-tag/socket.go:207 +0xa9
created by github.com/go-zeromq/zmq4.(*socket).Listen in goroutine 30
	/home/egorse/projects/public/zmq4-tag/socket.go:193 +0x145

goroutine 33 [sync.Mutex.Lock]:
sync.runtime_SemacquireMutex(0x7fb11011a530?, 0x18?, 0x415132?)
	/usr/local/go/src/runtime/sema.go:77 +0x25
sync.(*Mutex).lockSlow(0xc0000fbf10)
	/usr/local/go/src/sync/mutex.go:171 +0x15d
sync.(*Mutex).Lock(...)
	/usr/local/go/src/sync/mutex.go:90
github.com/go-zeromq/zmq4.(*routerMWriter).rmConn(0xc0000fbf00, 0xc000100320)
	/home/egorse/projects/public/zmq4-tag/router.go:211 +0x5a
github.com/go-zeromq/zmq4.(*socket).rmConn(0xc00020da00, 0xc000100320)
	/home/egorse/projects/public/zmq4-tag/socket.go:323 +0x223
github.com/go-zeromq/zmq4.(*socket).connReaper(0xc00020da00)
	/home/egorse/projects/public/zmq4-tag/socket.go:387 +0x16b
created by github.com/go-zeromq/zmq4.(*socket).Listen in goroutine 30
	/home/egorse/projects/public/zmq4-tag/socket.go:194 +0x187

goroutine 10 [sync.Mutex.Lock]:
sync.runtime_SemacquireMutex(0x48f5e0?, 0x0?, 0xc000056c68?)
	/usr/local/go/src/runtime/sema.go:77 +0x25
sync.(*Mutex).lockSlow(0xc0000b8840)
	/usr/local/go/src/sync/mutex.go:171 +0x15d
sync.(*Mutex).Lock(0x52fc65?)
	/usr/local/go/src/sync/mutex.go:90 +0x32
github.com/go-zeromq/zmq4.(*socket).scheduleRmConn(0xc00020da00, 0xc0000a0960)
	/home/egorse/projects/public/zmq4-tag/socket.go:328 +0x33
github.com/go-zeromq/zmq4.(*Conn).notifyOnCloseError(...)
	/home/egorse/projects/public/zmq4-tag/conn.go:500
github.com/go-zeromq/zmq4.(*Conn).SetClosed(0xc000014298?)
	/home/egorse/projects/public/zmq4-tag/conn.go:472 +0x3c
github.com/go-zeromq/zmq4.(*Conn).checkIO(0x632660?, {0x632300, 0x764000})
	/home/egorse/projects/public/zmq4-tag/conn.go:486 +0xa5
github.com/go-zeromq/zmq4.(*Conn).read(0xc0000a0960)
	/home/egorse/projects/public/zmq4-tag/conn.go:385 +0x671
github.com/go-zeromq/zmq4.(*routerQReader).listen(0xc000212500, {0x633528, 0xc000212460}, 0xc0000a0960)
	/home/egorse/projects/public/zmq4-tag/router.go:161 +0x172
created by github.com/go-zeromq/zmq4.(*routerQReader).addConn in goroutine 32
	/home/egorse/projects/public/zmq4-tag/router.go:122 +0xa5

goroutine 11 [sync.Mutex.Lock]:
sync.runtime_SemacquireMutex(0x48f5e0?, 0x80?, 0xc000057c68?)
	/usr/local/go/src/runtime/sema.go:77 +0x25
sync.(*Mutex).lockSlow(0xc0000b8840)
	/usr/local/go/src/sync/mutex.go:171 +0x15d
sync.(*Mutex).Lock(0x52fc65?)
	/usr/local/go/src/sync/mutex.go:90 +0x32
github.com/go-zeromq/zmq4.(*socket).scheduleRmConn(0xc00020da00, 0xc000100e60)
	/home/egorse/projects/public/zmq4-tag/socket.go:328 +0x33
github.com/go-zeromq/zmq4.(*Conn).notifyOnCloseError(...)
	/home/egorse/projects/public/zmq4-tag/conn.go:500
github.com/go-zeromq/zmq4.(*Conn).SetClosed(0xc000014318?)
	/home/egorse/projects/public/zmq4-tag/conn.go:472 +0x3c
github.com/go-zeromq/zmq4.(*Conn).checkIO(0x632660?, {0x632300, 0x764000})
	/home/egorse/projects/public/zmq4-tag/conn.go:486 +0xa5
github.com/go-zeromq/zmq4.(*Conn).read(0xc000100e60)
	/home/egorse/projects/public/zmq4-tag/conn.go:385 +0x671
github.com/go-zeromq/zmq4.(*routerQReader).listen(0xc000212500, {0x633528, 0xc000212460}, 0xc000100e60)
	/home/egorse/projects/public/zmq4-tag/router.go:161 +0x172
created by github.com/go-zeromq/zmq4.(*routerQReader).addConn in goroutine 32
	/home/egorse/projects/public/zmq4-tag/router.go:122 +0xa5

goroutine 71 [IO wait]:
internal/poll.runtime_pollWait(0x7fb11099c298, 0x72)
	/usr/local/go/src/runtime/netpoll.go:343 +0x85
internal/poll.(*pollDesc).wait(0xc000288180?, 0xc000284268?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc000288180, {0xc000284268, 0x2, 0x2})
	/usr/local/go/src/internal/poll/fd_unix.go:164 +0x27a
net.(*netFD).Read(0xc000288180, {0xc000284268?, 0x0?, 0x0?})
	/usr/local/go/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc00028c078, {0xc000284268?, 0x7fb11011a488?, 0x7fb158f4cf18?})
	/usr/local/go/src/net/net.go:179 +0x45
io.ReadAtLeast({0x632660, 0xc00028c078}, {0xc000284268, 0x2, 0x2}, 0x2)
	/usr/local/go/src/io/io.go:335 +0x90
io.ReadFull(...)
	/usr/local/go/src/io/io.go:354
github.com/go-zeromq/zmq4.(*Conn).read(0xc000290f00)
	/home/egorse/projects/public/zmq4-tag/conn.go:383 +0xf0
github.com/go-zeromq/zmq4.(*routerQReader).listen(0xc000212500, {0x633528, 0xc000212460}, 0xc000290f00)
	/home/egorse/projects/public/zmq4-tag/router.go:161 +0x172
created by github.com/go-zeromq/zmq4.(*routerQReader).addConn in goroutine 32
	/home/egorse/projects/public/zmq4-tag/router.go:122 +0xa5

goroutine 35 [sync.Mutex.Lock]:
sync.runtime_SemacquireMutex(0x48f5e0?, 0x80?, 0xc000055c68?)
	/usr/local/go/src/runtime/sema.go:77 +0x25
sync.(*Mutex).lockSlow(0xc0000b8840)
	/usr/local/go/src/sync/mutex.go:171 +0x15d
sync.(*Mutex).Lock(0x52fc65?)
	/usr/local/go/src/sync/mutex.go:90 +0x32
github.com/go-zeromq/zmq4.(*socket).scheduleRmConn(0xc00020da00, 0xc0001ba000)
	/home/egorse/projects/public/zmq4-tag/socket.go:328 +0x33
github.com/go-zeromq/zmq4.(*Conn).notifyOnCloseError(...)
	/home/egorse/projects/public/zmq4-tag/conn.go:500
github.com/go-zeromq/zmq4.(*Conn).SetClosed(0xc00019c178?)
	/home/egorse/projects/public/zmq4-tag/conn.go:472 +0x3c
github.com/go-zeromq/zmq4.(*Conn).checkIO(0x632660?, {0x632300, 0x764000})
	/home/egorse/projects/public/zmq4-tag/conn.go:486 +0xa5
github.com/go-zeromq/zmq4.(*Conn).read(0xc0001ba000)
	/home/egorse/projects/public/zmq4-tag/conn.go:385 +0x671
github.com/go-zeromq/zmq4.(*routerQReader).listen(0xc000212500, {0x633528, 0xc000212460}, 0xc0001ba000)
	/home/egorse/projects/public/zmq4-tag/router.go:161 +0x172
created by github.com/go-zeromq/zmq4.(*routerQReader).addConn in goroutine 32
	/home/egorse/projects/public/zmq4-tag/router.go:122 +0xa5

goroutine 36 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc000238110, 0x0)
	/usr/local/go/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0x0?)
	/usr/local/go/src/sync/cond.go:70 +0x85
github.com/go-zeromq/zmq4.(*socket).connReaper(0xc0002304e0)
	/home/egorse/projects/public/zmq4-tag/socket.go:379 +0x107
created by github.com/go-zeromq/zmq4.(*socket).Dial in goroutine 30
	/home/egorse/projects/public/zmq4-tag/socket.go:269 +0x3db

goroutine 38 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc0001b4450, 0x0)
	/usr/local/go/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0x0?)
	/usr/local/go/src/sync/cond.go:70 +0x85
github.com/go-zeromq/zmq4.(*socket).connReaper(0xc0001b6b60)
	/home/egorse/projects/public/zmq4-tag/socket.go:379 +0x107
created by github.com/go-zeromq/zmq4.(*socket).Dial in goroutine 30
	/home/egorse/projects/public/zmq4-tag/socket.go:269 +0x3db

goroutine 72 [IO wait]:
internal/poll.runtime_pollWait(0x7fb11099c0a8, 0x72)
	/usr/local/go/src/runtime/netpoll.go:343 +0x85
internal/poll.(*pollDesc).wait(0xc000288200?, 0xc000014330?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc000288200, {0xc000014330, 0x2, 0x2})
	/usr/local/go/src/internal/poll/fd_unix.go:164 +0x27a
net.(*netFD).Read(0xc000288200, {0xc000014330?, 0x0?, 0x0?})
	/usr/local/go/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc00028c080, {0xc000014330?, 0x7fb158f55280?, 0x7fb158f4c108?})
	/usr/local/go/src/net/net.go:179 +0x45
io.ReadAtLeast({0x632660, 0xc00028c080}, {0xc000014330, 0x2, 0x2}, 0x2)
	/usr/local/go/src/io/io.go:335 +0x90
io.ReadFull(...)
	/usr/local/go/src/io/io.go:354
github.com/go-zeromq/zmq4.(*Conn).read(0xc000291360)
	/home/egorse/projects/public/zmq4-tag/conn.go:383 +0xf0
github.com/go-zeromq/zmq4.(*routerQReader).listen(0xc000212500, {0x633528, 0xc000212460}, 0xc000291360)
	/home/egorse/projects/public/zmq4-tag/router.go:161 +0x172
created by github.com/go-zeromq/zmq4.(*routerQReader).addConn in goroutine 32
	/home/egorse/projects/public/zmq4-tag/router.go:122 +0xa5

goroutine 40 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc0001b4510, 0x0)
	/usr/local/go/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0x0?)
	/usr/local/go/src/sync/cond.go:70 +0x85
github.com/go-zeromq/zmq4.(*socket).connReaper(0xc0001b6ea0)
	/home/egorse/projects/public/zmq4-tag/socket.go:379 +0x107
created by github.com/go-zeromq/zmq4.(*socket).Dial in goroutine 30
	/home/egorse/projects/public/zmq4-tag/socket.go:269 +0x3db

goroutine 73 [IO wait]:
internal/poll.runtime_pollWait(0x7fb1100d7e90, 0x72)
	/usr/local/go/src/runtime/netpoll.go:343 +0x85
internal/poll.(*pollDesc).wait(0xc000288280?, 0xc0000b8a68?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc000288280, {0xc0000b8a68, 0x2, 0x2})
	/usr/local/go/src/internal/poll/fd_unix.go:164 +0x27a
net.(*netFD).Read(0xc000288280, {0xc0000b8a68?, 0x0?, 0x0?})
	/usr/local/go/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc00028c088, {0xc0000b8a68?, 0x7fb110999658?, 0x7fb158f4c5b8?})
	/usr/local/go/src/net/net.go:179 +0x45
io.ReadAtLeast({0x632660, 0xc00028c088}, {0xc0000b8a68, 0x2, 0x2}, 0x2)
	/usr/local/go/src/io/io.go:335 +0x90
io.ReadFull(...)
	/usr/local/go/src/io/io.go:354
github.com/go-zeromq/zmq4.(*Conn).read(0xc0002917c0)
	/home/egorse/projects/public/zmq4-tag/conn.go:383 +0xf0
github.com/go-zeromq/zmq4.(*routerQReader).listen(0xc000212500, {0x633528, 0xc000212460}, 0xc0002917c0)
	/home/egorse/projects/public/zmq4-tag/router.go:161 +0x172
created by github.com/go-zeromq/zmq4.(*routerQReader).addConn in goroutine 32
	/home/egorse/projects/public/zmq4-tag/router.go:122 +0xa5

goroutine 12 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc0001b45d0, 0x0)
	/usr/local/go/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0x0?)
	/usr/local/go/src/sync/cond.go:70 +0x85
github.com/go-zeromq/zmq4.(*socket).connReaper(0xc0001b71e0)
	/home/egorse/projects/public/zmq4-tag/socket.go:379 +0x107
created by github.com/go-zeromq/zmq4.(*socket).Dial in goroutine 30
	/home/egorse/projects/public/zmq4-tag/socket.go:269 +0x3db

goroutine 74 [IO wait]:
internal/poll.runtime_pollWait(0x7fb1100d7ca0, 0x72)
	/usr/local/go/src/runtime/netpoll.go:343 +0x85
internal/poll.(*pollDesc).wait(0xc000288300?, 0xc00019c398?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc000288300, {0xc00019c398, 0x2, 0x2})
	/usr/local/go/src/internal/poll/fd_unix.go:164 +0x27a
net.(*netFD).Read(0xc000288300, {0xc00019c398?, 0x0?, 0x0?})
	/usr/local/go/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc00028c090, {0xc00019c398?, 0x7fb1101179e0?, 0x7fb158f4ca68?})
	/usr/local/go/src/net/net.go:179 +0x45
io.ReadAtLeast({0x632660, 0xc00028c090}, {0xc00019c398, 0x2, 0x2}, 0x2)
	/usr/local/go/src/io/io.go:335 +0x90
io.ReadFull(...)
	/usr/local/go/src/io/io.go:354
github.com/go-zeromq/zmq4.(*Conn).read(0xc000291c20)
	/home/egorse/projects/public/zmq4-tag/conn.go:383 +0xf0
github.com/go-zeromq/zmq4.(*routerQReader).listen(0xc000212500, {0x633528, 0xc000212460}, 0xc000291c20)
	/home/egorse/projects/public/zmq4-tag/router.go:161 +0x172
created by github.com/go-zeromq/zmq4.(*routerQReader).addConn in goroutine 32
	/home/egorse/projects/public/zmq4-tag/router.go:122 +0xa5

goroutine 55 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc000016250, 0x0)
	/usr/local/go/src/runtime/sema.go:527 +0x159
sync.(*Cond).Wait(0x0?)
	/usr/local/go/src/sync/cond.go:70 +0x85
github.com/go-zeromq/zmq4.(*socket).connReaper(0xc000126d00)
	/home/egorse/projects/public/zmq4-tag/socket.go:379 +0x107
created by github.com/go-zeromq/zmq4.(*socket).Dial in goroutine 30
	/home/egorse/projects/public/zmq4-tag/socket.go:269 +0x3db

goroutine 75 [IO wait]:
internal/poll.runtime_pollWait(0x7fb1100d7ab0, 0x72)
	/usr/local/go/src/runtime/netpoll.go:343 +0x85
internal/poll.(*pollDesc).wait(0xc000288500?, 0xc000284408?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc000288500, {0xc000284408, 0x2, 0x2})
	/usr/local/go/src/internal/poll/fd_unix.go:164 +0x27a
net.(*netFD).Read(0xc000288500, {0xc000284408?, 0x0?, 0x0?})
	/usr/local/go/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc00028c098, {0xc000284408?, 0x7fb11011a488?, 0x7fb158f4cf18?})
	/usr/local/go/src/net/net.go:179 +0x45
io.ReadAtLeast({0x632660, 0xc00028c098}, {0xc000284408, 0x2, 0x2}, 0x2)
	/usr/local/go/src/io/io.go:335 +0x90
io.ReadFull(...)
	/usr/local/go/src/io/io.go:354
github.com/go-zeromq/zmq4.(*Conn).read(0xc0002b40a0)
	/home/egorse/projects/public/zmq4-tag/conn.go:383 +0xf0
github.com/go-zeromq/zmq4.(*routerQReader).listen(0xc000212500, {0x633528, 0xc000212460}, 0xc0002b40a0)
	/home/egorse/projects/public/zmq4-tag/router.go:161 +0x172
created by github.com/go-zeromq/zmq4.(*routerQReader).addConn in goroutine 32
	/home/egorse/projects/public/zmq4-tag/router.go:122 +0xa5

goroutine 57 [sync.Mutex.Lock]:
sync.runtime_SemacquireMutex(0x5c0f00?, 0x0?, 0xc000051dd0?)
	/usr/local/go/src/runtime/sema.go:77 +0x25
sync.(*Mutex).lockSlow(0xc0000b8840)
	/usr/local/go/src/sync/mutex.go:171 +0x15d
sync.(*Mutex).Lock(0x10?)
	/usr/local/go/src/sync/mutex.go:90 +0x32
github.com/go-zeromq/zmq4.(*socket).scheduleRmConn(0xc00020da00, 0xc000290000)
	/home/egorse/projects/public/zmq4-tag/socket.go:328 +0x33
github.com/go-zeromq/zmq4.(*Conn).notifyOnCloseError(...)
	/home/egorse/projects/public/zmq4-tag/conn.go:500
github.com/go-zeromq/zmq4.(*Conn).SetClosed(0x632640?)
	/home/egorse/projects/public/zmq4-tag/conn.go:472 +0x3c
github.com/go-zeromq/zmq4.(*Conn).checkIO(0x0?, {0x632640, 0xc000212a00})
	/home/egorse/projects/public/zmq4-tag/conn.go:492 +0xfe
github.com/go-zeromq/zmq4.(*Conn).send(0xc000290000, 0xa0?, {0x0, 0x0, 0x0}, 0x8?)
	/home/egorse/projects/public/zmq4-tag/conn.go:362 +0x13c
github.com/go-zeromq/zmq4.(*Conn).SendMsg(0xc000290000, {{0xc000212838, 0x2, 0x2}, 0x0, 0x0, {0x0, 0x0}})
	/home/egorse/projects/public/zmq4-tag/conn.go:190 +0x137
github.com/go-zeromq/zmq4.(*routerMWriter).write.func1()
	/home/egorse/projects/public/zmq4-tag/router.go:239 +0x34
golang.org/x/sync/errgroup.(*Group).Go.func1()
	/home/egorse/go/pkg/mod/golang.org/x/sync@v0.3.0/errgroup/errgroup.go:75 +0x56
created by golang.org/x/sync/errgroup.(*Group).Go in goroutine 30
	/home/egorse/go/pkg/mod/golang.org/x/sync@v0.3.0/errgroup/errgroup.go:72 +0x96
exit status 2
FAIL	github.com/go-zeromq/zmq4	30.044s

go-zeromq/zmq4 v0.16.0
go version 1.21.5
@egorse
Copy link
Contributor Author

egorse commented Dec 30, 2023

Seems that func (w *routerMWriter) write(ctx context.Context, msg Msg)
under w.mu.Lock()
when calling ww.SendMsg
and getting error can reap connection which ends up in
func (mw *routerMWriter) rmConn(w *Conn)
which requires already locked mw.mu.Lock()
and locks connection reaper forever.

Then next call to func (sck *socket) scheduleRmConn(c *Conn) stuck trying to sck.reaperCond.L.Lock(), i.e. by read error.

@egorse egorse changed the title Deadlock detected by TestConnReaperDeadlock? Deadlock detected by TestConnReaperDeadlock Dec 30, 2023
@egorse
Copy link
Contributor Author

egorse commented Dec 30, 2023

Synthetic test hard to make but its enough to have two clients dialed to server and then close those clients. Not even needs 5/10 as in TestConnReaperDeadlock. Then you need to make either multiple runs or artificial delays to ensure sequence in prev message.

@egorse egorse mentioned this issue Jan 10, 2024
Merged
sbinet added a commit that referenced this issue Jan 24, 2024
@egorse @sbinet
zmq4: fix another connection reaper deadlock
e75c615 
Fixes #149

Co-authored-by: Sergey Egorov <sergey.egorov@teleste.com>
Co-authored-by: Sebastien Binet <binet@cern.ch>
@egorse egorse mentioned this issue May 16, 2024
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix connection reaper deadlock. egorse/zmq4
1 participant
@egorse