When doing some load testing I encountered an issue maintaining a connection to rethinkdb

[Altonymous]

I'm not sure if this is a my code issue or an underlying problem.

I hopped on irc and jumped into the #rethinkdb channel. They recommended I start with giving you a shout.

Here's a gist of what I've got going on.

https://gist.github.com/Altonymous/f53f284ef1cecae7d435

[christopherhesse]

I will take a look at this.

[christopherhesse]

I can't confirm your exact error locally, but try opening session.go in rethinkgo and changing the maxIdleConnections to 100.

(You'll have to make sure go is using this new value somehow, maybe put a fmt.Println in the Connect() function to make sure you are changing the file used by your program)

Let me know if this fixes the problem, if so, it's probably a rethinkdb bug and the workaround is to raise that variable value. I may add a SetMaxIdleConnections() function.

[coffeemug]

We'll also prioritize rethinkdb/rethinkdb#369 on our end.

[Altonymous]

Okay so I set the value as you suggested rebuilt and ran this from 4 different servers...

siege -v "http://192.168.122.31:3000/machines POST" -c 100 -r 50 -b

The problem still exists but it takes a bit longer for it to happen. It still happens within the run though. After it starts happening it doesn't stop until the service is restarted.

[coffeemug]

Hmm, this is one of those rare cases when I really can't tell if it's a RethinkDB bug or a Go configuration issue. We'll try to bump rethinkdb/rethinkdb#369 to see if it fixes the problem. @Altonymous -- in general, we promise that this will get resolved if it's a rethinkdb bug. It's a matter of time until issues like this are ironed out.

[Altonymous]

4 load generation servers all hitting a single web server at the same time... Here is the command and the graph...

$ siege -v "http://192.168.122.31:3000/machines POST" -c 10 -r 500 -b
Graph: http://d.pr/i/TdJk (No Errors)

$ siege -v "http://192.168.122.31:3000/machines POST" -c 50 -r 100 -b
Graph: http://d.pr/i/uJIR (Errors Started At: ~4:36)

Error:
2013/05/01 16:35:59 Handler crashed with error write tcp 192.168.122.71:28015: broken pipe
2013/05/01 16:35:59 /usr/local/go/src/pkg/runtime/panic.c 229
2013/05/01 16:35:59 /home/jenkins/web_go_rethinkdb.go 93
2013/05/01 16:35:59 /home/jenkins/web_go_rethinkdb.go 46
2013/05/01 16:35:59 /usr/local/go/src/pkg/reflect/value.go 474
2013/05/01 16:35:59 /usr/local/go/src/pkg/reflect/value.go 345
2013/05/01 16:35:59 /home/jenkins/.mygo/src/github.com/hoisie/web/server.go 196
2013/05/01 16:35:59 /home/jenkins/.mygo/src/github.com/hoisie/web/server.go 305
2013/05/01 16:35:59 /home/jenkins/.mygo/src/github.com/hoisie/web/server.go 87
2013/05/01 16:35:59 /home/jenkins/.mygo/src/github.com/hoisie/web/server.go 82
2013/05/01 16:35:59 /usr/local/go/src/pkg/net/http/server.go 1416
2013/05/01 16:35:59 /usr/local/go/src/pkg/net/http/server.go 1517
2013/05/01 16:35:59 /usr/local/go/src/pkg/net/http/server.go 1096
2013/05/01 16:35:59 /usr/local/go/src/pkg/runtime/proc.c 1223

Hope this is helping.

[christopherhesse]

Thanks for all the help tracking down this bug!

So my theory is that once the go driver exhausts its pool of connections, it then attempts to connect too quickly for rethinkdb to handle. If that's the case, then you should receive ~0 errors when your concurrency limit is the same as maxIdleConnections. If you set maxIdleConnections > your number of concurrent requests, does the problem still occur?

[Altonymous]

I set maxIdleConnections to 20480 just to give it something insane.. and it's still happening.

I should also note, I've moved to Ubuntu 12.04 server (x64) to help track this down.

[Altonymous]

Just to make sure I'm doing this right here's what I'm doing...

I go into $GOPATH/src/.../session.go and change the file.

Then I $ go build web_go_rethinkdb.go. I then copy that file to the web server and run it.

Does that sound right?

[Altonymous]

Okay because I moved to new servers I remembered something I did on my Mac that I didn't do on the ubuntu servers. I didn't update the "open files" On the web server I did, but not the rethinkdb servers. So here's some more information... (This is with the maxIdleConnections still set at 20480)

web server

$ ulimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 257264
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 10240
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 257264
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited

rethinkdb server - before

$ ulimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 257264
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 1024
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 257264
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited

rethinkdb server - after

$ ulimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 257264
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 10240
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 257264
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited

$ siege -v "http://192.168.122.31:3000/machines POST" -c 50 -r 100 -b
No errors...

$ siege -v "http://192.168.122.31:3000/machines POST" -c 100 -r 100 -b
No errors... (few connection timeouts, but no errors)

$ siege -v "http://192.168.122.31:3000/machines POST" -c 150 -r 100 -b
And the errors begin again...

Again this is a single web server, with 4 load generating machines all running this command at the same time. So in essence the server is getting hit with -c 600.

[Altonymous]

Just to toss some more information into the pile...

If I only use 1 of the load generating servers, I start getting errors at -c 250.

$ siege -v "http://192.168.122.31:3000/machines POST" -c 225 -r 100 -b
No errors...

$ siege -v "http://192.168.122.31:3000/machines POST" -c 250 -r 100 -b
And the errors begin again...

Note: I try and narrow it down to within -c 25 requests.. not trying to get any more fine grained than that right now.

[christopherhesse]

Yeah, you're doing it correctly, another thing to try might be to limit the rate of connections to the server, I should make a branch that does this so you can try it out.

[Altonymous]

I'm not sure how to get a specific branch, but if you give me the go comment I'll give it a shot.

[christopherhesse]

I've done some testing locally, and decided that the best thing to try next would be to give you a custom version of rethinkdb with issue rethinkdb/rethinkdb#369 fixed, and see if your problem goes away. I don't have a copy of ubuntu, but it just involves changing "const int RDB_LISTEN_BACKLOG = 5;" to "const int RDB_LISTEN_BACKLOG = 128;". I asked one of the rethinkdb guys to provide a binary, so maybe that's a possibility.

For testing purposes it might be a good idea to set maxIdleConnections to the maximum number of concurrent connections you use in your tests.