tcp-info
tcp-info copied to clipboard
eventsocket unit tests flaky
Before merging https://github.com/m-lab/tcp-info/pull/113 one of the travis builds failed as a result of test hanging in github.com/m-lab/tcp-info/eventsocket
.
However, this can occur on earlier versions as late as v1.3.0.
Running the tcp-info unit tests repeatedly will eventually hang on these tests.
while go test -timeout 2m -count=1 -v ./... ; do echo $? ; done
After timeout, the test panics and dumps a stack trace, like below:
=== RUN TestClient
2019/12/20 18:32:56 Adding new TCP event client &{{0xc0000c6500}}
panic: test timed out after 10m0s
goroutine 5 [running]:
testing.(*M).startAlarm.func1()
/golang/src/testing/testing.go:1392 +0xdf
created by time.goFunc
/golang/src/time/sleep.go:168 +0x44
goroutine 1 [chan receive]:
testing.(*T).Run(0xc0000c8100, 0x624772, 0xa, 0x62f8b8, 0x483fb6)
/golang/src/testing/testing.go:961 +0x377
testing.runTests.func1(0xc0000c8000)
/golang/src/testing/testing.go:1204 +0x78
testing.tRunner(0xc0000c8000, 0xc00004cdc0)
/golang/src/testing/testing.go:909 +0xc9
testing.runTests(0xc0000a6060, 0x7ad420, 0x4, 0x4, 0x0)
/golang/src/testing/testing.go:1202 +0x2a7
testing.(*M).Run(0xc0000c6000, 0x0)
/golang/src/testing/testing.go:1119 +0x176
main.main()
_testmain.go:50 +0x135
goroutine 20 [semacquire]:
sync.runtime_Semacquire(0xc0000ce078)
/golang/src/runtime/sema.go:56 +0x42
sync.(*WaitGroup).Wait(0xc0000ce070)
/golang/src/sync/waitgroup.go:130 +0x64
github.com/m-lab/tcp-info/eventsocket.TestClient(0xc0000c8100)
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/client_test.go:62 +0x66d
testing.tRunner(0xc0000c8100, 0x62f8b8)
/golang/src/testing/testing.go:909 +0xc9
created by testing.(*T).Run
/golang/src/testing/testing.go:960 +0x350
goroutine 21 [IO wait]:
internal/poll.runtime_pollWait(0x7ffbfc5d2f98, 0x72, 0x0)
/golang/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc0000c6098, 0x72, 0x0, 0x0, 0x623b1d)
/golang/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/golang/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc0000c6080, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/golang/src/internal/poll/fd_unix.go:384 +0x1f8
net.(*netFD).accept(0xc0000c6080, 0x5aac8e, 0x0, 0x0)
/golang/src/net/fd_unix.go:238 +0x42
net.(*UnixListener).accept(0xc00008e810, 0xc000098038, 0x5d2560, 0x65e390)
/golang/src/net/unixsock_posix.go:162 +0x32
net.(*UnixListener).Accept(0xc00008e810, 0x0, 0x0, 0x0, 0x0)
/golang/src/net/unixsock.go:260 +0x47
github.com/m-lab/tcp-info/eventsocket.(*server).Serve(0xc0000ba0a0, 0x664e80, 0xc00009c6c0, 0x0, 0x0)
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/server.go:152 +0x1d1
created by github.com/m-lab/tcp-info/eventsocket.TestClient
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/client_test.go:40 +0x2ac
goroutine 22 [IO wait]:
internal/poll.runtime_pollWait(0x7ffbfc5d2ec8, 0x72, 0xffffffffffffffff)
/golang/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc0000c6298, 0x72, 0x1000, 0x1000, 0xffffffffffffffff)
/golang/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/golang/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc0000c6280, 0xc0000e4000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/golang/src/internal/poll/fd_unix.go:169 +0x1cf
net.(*netFD).Read(0xc0000c6280, 0xc0000e4000, 0x1000, 0x1000, 0xc00004ece8, 0x44706c, 0x1000)
/golang/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc000098030, 0xc0000e4000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/golang/src/net/net.go:184 +0x68
bufio.(*Scanner).Scan(0xc00004eed8, 0x666480)
/golang/src/bufio/scan.go:213 +0xa4
github.com/m-lab/tcp-info/eventsocket.MustRun(0x664e80, 0xc00009c800, 0xc0000d0080, 0x32, 0x662ec0, 0xc0000ce060)
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/client.go:48 +0x276
github.com/m-lab/tcp-info/eventsocket.TestClient.func1(0x664e80, 0xc00009c680, 0xc000096030, 0x23, 0xc0000ce060, 0xc0000942b0)
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/client_test.go:47 +0x99
created by github.com/m-lab/tcp-info/eventsocket.TestClient
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/client_test.go:46 +0x386
goroutine 23 [chan receive]:
github.com/m-lab/tcp-info/eventsocket.MustRun.func1(0x664e80, 0xc00009c800, 0x666480, 0xc000098030)
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/client.go:42 +0x48
created by github.com/m-lab/tcp-info/eventsocket.MustRun
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/client.go:39 +0x1d0
goroutine 24 [chan receive]:
github.com/m-lab/tcp-info/eventsocket.(*server).notifyClients(0xc0000ba0a0, 0x664e80, 0xc00009c840)
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/server.go:99 +0xdb
created by github.com/m-lab/tcp-info/eventsocket.(*server).Serve
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/server.go:135 +0x11e
goroutine 25 [chan receive]:
github.com/m-lab/tcp-info/eventsocket.(*server).Serve.func1(0x664e80, 0xc00009c840, 0xc0000ba0a0)
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/server.go:143 +0x4c
created by github.com/m-lab/tcp-info/eventsocket.(*server).Serve
/home/soltesz/src/github.com/m-lab/tcp-info/eventsocket/server.go:142 +0x174
FAIL github.com/m-lab/tcp-info/eventsocket 600.033s