Closed spikebike closed 9 years ago
You're not the first person complaining about it, but I can't reproduce it. Could you send it a SIGQUIT and show the resulting goroutines trace?
Here are my stack traces for the same problem on my machine:
[0:zond@zond-macbookair ~/go/src/github.com/nictuku/dht]$go test -v
=== RUN TestDHTLocal
SIGQUIT: quit
PC=0x40603
goroutine 0 [idle]:
runtime.kevent(0x7fff00000005, 0x0, 0x7fff00000000, 0x7fff5fbff208, 0x40, 0x0, 0x0, 0x59c000, 0x1, 0x0, ...)
/usr/local/go/src/runtime/sys_darwin_amd64.s:493 +0x23
runtime.netpoll(0x524001, 0x0)
/usr/local/go/src/runtime/netpoll_kqueue.go:76 +0xcb
findrunnable(0xc208012000)
/usr/local/go/src/runtime/proc.c:1472 +0x485
schedule()
/usr/local/go/src/runtime/proc.c:1575 +0x151
runtime.park_m(0xc208094900)
/usr/local/go/src/runtime/proc.c:1654 +0x113
runtime.mcall(0x33e14)
/usr/local/go/src/runtime/asm_amd64.s:186 +0x5a
goroutine 1 [chan receive]:
testing.RunTests(0x41be50, 0x521040, 0xa, 0xa, 0xb92d5f50c87e801)
/usr/local/go/src/testing/testing.go:556 +0xad6
testing.(*M).Run(0xc20802e320, 0x51c4a0)
/usr/local/go/src/testing/testing.go:485 +0x6c
main.main()
github.com/nictuku/dht/_test/_testmain.go:78 +0x1d5
goroutine 5 [chan receive]:
github.com/golang/glog.(*loggingT).flushDaemon(0x524020)
/Users/zond/go/src/github.com/golang/glog/glog.go:879 +0x78
created by github.com/golang/glog.init·1
/Users/zond/go/src/github.com/golang/glog/glog.go:410 +0x2a7
goroutine 17 [syscall, locked to thread]:
runtime.goexit()
/usr/local/go/src/runtime/asm_amd64.s:2232 +0x1
goroutine 7 [semacquire]:
sync.(*WaitGroup).Wait(0xc20800aec0)
/usr/local/go/src/sync/waitgroup.go:132 +0x169
github.com/nictuku/dht.TestDHTLocal(0xc208042090)
/Users/zond/go/src/github.com/nictuku/dht/dht_test.go:159 +0xa0f
testing.tRunner(0xc208042090, 0x521040)
/usr/local/go/src/testing/testing.go:447 +0xbf
created by testing.RunTests
/usr/local/go/src/testing/testing.go:555 +0xa8b
goroutine 8 [select]:
github.com/nictuku/nettools.(*ClientThrottle).cleanup(0xc20800a4e0)
/Users/zond/go/src/github.com/nictuku/nettools/ratelimit.go:76 +0x288
created by github.com/nictuku/nettools.NewThrottler
/Users/zond/go/src/github.com/nictuku/nettools/ratelimit.go:20 +0xd7
goroutine 11 [IO wait]:
net.(*pollDesc).Wait(0xc208010220, 0x72, 0x0, 0x0)
/usr/local/go/src/net/fd_poll_runtime.go:84 +0x47
net.(*pollDesc).WaitRead(0xc208010220, 0x0, 0x0)
/usr/local/go/src/net/fd_poll_runtime.go:89 +0x43
net.(*netFD).readFrom(0xc2080101c0, 0xc20808f000, 0x1000, 0x1000, 0x0, 0x0, 0x0, 0x711df0, 0xc2080caaf0)
/usr/local/go/src/net/fd_unix.go:269 +0x4a1
net.(*UDPConn).ReadFromUDP(0xc20802c070, 0xc20808f000, 0x1000, 0x1000, 0x5f, 0x0, 0x0, 0x0)
/usr/local/go/src/net/udpsock_posix.go:67 +0x124
github.com/nictuku/dht.readFromSocket(0xc20802c070, 0xc208030660, 0xc2080306c0, 0xc2080302a0)
/Users/zond/go/src/github.com/nictuku/dht/krpc.go:219 +0xed
created by github.com/nictuku/dht.(*DHT).Run
/Users/zond/go/src/github.com/nictuku/dht/dht.go:296 +0x1d8
goroutine 10 [select]:
github.com/nictuku/dht.(*DHT).Run(0xc208001b00, 0x0, 0x0)
/Users/zond/go/src/github.com/nictuku/dht/dht.go:329 +0x13cf
created by github.com/nictuku/dht.startNode
/Users/zond/go/src/github.com/nictuku/dht/dht_test.go:89 +0x1ac
goroutine 12 [select]:
github.com/nictuku/nettools.(*ClientThrottle).cleanup(0xc20800a900)
/Users/zond/go/src/github.com/nictuku/nettools/ratelimit.go:76 +0x288
created by github.com/nictuku/nettools.NewThrottler
/Users/zond/go/src/github.com/nictuku/nettools/ratelimit.go:20 +0xd7
goroutine 15 [IO wait]:
net.(*pollDesc).Wait(0xc208010300, 0x72, 0x0, 0x0)
/usr/local/go/src/net/fd_poll_runtime.go:84 +0x47
net.(*pollDesc).WaitRead(0xc208010300, 0x0, 0x0)
/usr/local/go/src/net/fd_poll_runtime.go:89 +0x43
net.(*netFD).readFrom(0xc2080102a0, 0xc208096000, 0x1000, 0x1000, 0x0, 0x0, 0x0, 0x711df0, 0xc2080cab00)
/usr/local/go/src/net/fd_unix.go:269 +0x4a1
net.(*UDPConn).ReadFromUDP(0xc20802c098, 0xc208096000, 0x1000, 0x1000, 0x5e, 0x0, 0x0, 0x0)
/usr/local/go/src/net/udpsock_posix.go:67 +0x124
github.com/nictuku/dht.readFromSocket(0xc20802c098, 0xc208030cc0, 0xc208030d20, 0xc208030960)
/Users/zond/go/src/github.com/nictuku/dht/krpc.go:219 +0xed
created by github.com/nictuku/dht.(*DHT).Run
/Users/zond/go/src/github.com/nictuku/dht/dht.go:296 +0x1d8
goroutine 14 [select]:
github.com/nictuku/dht.(*DHT).Run(0xc208094120, 0x0, 0x0)
/Users/zond/go/src/github.com/nictuku/dht/dht.go:329 +0x13cf
created by github.com/nictuku/dht.startNode
/Users/zond/go/src/github.com/nictuku/dht/dht_test.go:89 +0x1ac
goroutine 16 [select]:
github.com/nictuku/nettools.(*ClientThrottle).cleanup(0xc20800ace0)
/Users/zond/go/src/github.com/nictuku/nettools/ratelimit.go:76 +0x288
created by github.com/nictuku/nettools.NewThrottler
/Users/zond/go/src/github.com/nictuku/nettools/ratelimit.go:20 +0xd7
goroutine 20 [IO wait]:
net.(*pollDesc).Wait(0xc208010450, 0x72, 0x0, 0x0)
/usr/local/go/src/net/fd_poll_runtime.go:84 +0x47
net.(*pollDesc).WaitRead(0xc208010450, 0x0, 0x0)
/usr/local/go/src/net/fd_poll_runtime.go:89 +0x43
net.(*netFD).readFrom(0xc2080103f0, 0xc2080a3000, 0x1000, 0x1000, 0x0, 0x0, 0x0, 0x711df0, 0xc2080cab60)
/usr/local/go/src/net/fd_unix.go:269 +0x4a1
net.(*UDPConn).ReadFromUDP(0xc20802c0c0, 0xc2080a3000, 0x1000, 0x1000, 0x5f, 0x0, 0x0, 0x0)
/usr/local/go/src/net/udpsock_posix.go:67 +0x124
github.com/nictuku/dht.readFromSocket(0xc20802c0c0, 0xc2080313e0, 0xc208031440, 0xc208031080)
/Users/zond/go/src/github.com/nictuku/dht/krpc.go:219 +0xed
created by github.com/nictuku/dht.(*DHT).Run
/Users/zond/go/src/github.com/nictuku/dht/dht.go:296 +0x1d8
goroutine 19 [select]:
github.com/nictuku/dht.(*DHT).Run(0xc2080946c0, 0x0, 0x0)
/Users/zond/go/src/github.com/nictuku/dht/dht.go:329 +0x13cf
created by github.com/nictuku/dht.startNode
/Users/zond/go/src/github.com/nictuku/dht/dht_test.go:89 +0x1ac
goroutine 21 [select]:
github.com/nictuku/dht.drainResults(0xc208094120, 0xc20800a0e0, 0x14, 0x1, 0x2540be400, 0x0, 0x0)
/Users/zond/go/src/github.com/nictuku/dht/dht_test.go:98 +0x4f6
github.com/nictuku/dht.func·003()
/Users/zond/go/src/github.com/nictuku/dht/dht_test.go:148 +0x69
created by github.com/nictuku/dht.TestDHTLocal
/Users/zond/go/src/github.com/nictuku/dht/dht_test.go:152 +0x92e
goroutine 22 [select]:
github.com/nictuku/dht.drainResults(0xc2080946c0, 0xc20800a0e0, 0x14, 0x1, 0x2540be400, 0x0, 0x0)
/Users/zond/go/src/github.com/nictuku/dht/dht_test.go:98 +0x4f6
github.com/nictuku/dht.func·004()
/Users/zond/go/src/github.com/nictuku/dht/dht_test.go:154 +0x69
created by github.com/nictuku/dht.TestDHTLocal
/Users/zond/go/src/github.com/nictuku/dht/dht_test.go:158 +0x9fc
rax 0x4
rbx 0x0
rcx 0x7fff5fbff1a0
rdx 0x0
rdi 0x5
rsi 0x0
rbp 0x524200
rsp 0x7fff5fbff1a0
r8 0x40
r9 0x0
r10 0x7fff5fbff208
r11 0x246
r12 0x4ecd938acc20
r13 0x5c916891e0a0
r14 0x13b7924f97785c00
r15 0x10
rip 0x40603
rflags 0x247
cs 0x7
fs 0x0
gs 0x80d0000
exit status 2
FAIL github.com/nictuku/dht 13.648s
[1:zond@zond-macbookair ~/go/src/github.com/nictuku/dht]$
The client throttler had very aggressive defaults and caused problems. When I bumped logging, I would see this:
I0117 10:06:46.176141 05436 dht.go:448] Node exceeded rate limiter. Dropping packet.
My local 'nettools' repository had a patch that essentially disabled this, which is why I couldn't reproduce it.
I've added two settings to the DHT library now:
// ClientPerMinuteLimit protects against spammy clients. Ignore their requests if exceeded // this number of packets per minute. Default value: 50. ClientPerMinuteLimit int // ThrottlerTrackedClients is the number of hosts the client throttler remembers. An LRU is used to // track the most interesting ones. Default value: 1000. ThrottlerTrackedClients int64
I've also bumped the default value of ClientPerMinuteLimit from 10 to 50. Ideally this should be higher during bootstrapping and searching, but lower for other kinds of requests. Let's see how this goes.
Unless there's something that needs setup, go test doesn't work as I'd expect:
$ go test -v === RUN TestDHTLocal
It just hangs, or at least runs for a very long time.