unicorn Ruby/Rack server user+dev discussion/patches/pulls/bugs/help
 help / color / mirror / code / Atom feed
* High number of TCP retransmits on Solaris
@ 2014-07-22 18:52 Paul Henry
  2014-07-22 18:57 ` Michael Fischer
  2014-07-22 20:56 ` Eric Wong
  0 siblings, 2 replies; 8+ messages in thread
From: Paul Henry @ 2014-07-22 18:52 UTC (permalink / raw)
  To: unicorn-public

Hello!

When using unicorn unicorn v4.8.2, we're seeing a high number of TCP
retransmits at a high connection rate.

Smartos version: 20131218T184706Z

Rackup file used:

> cat server.ru
run -> (env) { [200, {"Content-Type" => "text/plain"},
[Time.now.iso8601(6)]] }

To start unicorn:
> bundle exec unicorn -l 9292 server.ru

To benchmark unicorn:
>> Benchmark.measure { 1000.times { time=Benchmark.measure { open("http://<ip>:9292/api/v1/settings/time",
"Host" => "api.wanelo.com")}.real; p (time*1000).round(2) if time > 0.05 } }

After the total number of connections on the system goes above 8,000
(16,000 is the average number of connections), we start seeing delays of
around 1.1 seconds.

We don't see the issue over the local loopback interface, only over the
net. When using Webrick, we also don't see this issue.

Our tcp initial retransmit interval is 1 second. When the interval is
reduced, the occasional latency goes down. We also see the retransmits in
netstat, about 1 - 2 every second.

Anything that we should look at next?

Thanks!
Paul


^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: High number of TCP retransmits on Solaris
  2014-07-22 18:52 High number of TCP retransmits on Solaris Paul Henry
@ 2014-07-22 18:57 ` Michael Fischer
  2014-07-22 19:03   ` Paul Henry
  2014-07-22 20:56 ` Eric Wong
  1 sibling, 1 reply; 8+ messages in thread
From: Michael Fischer @ 2014-07-22 18:57 UTC (permalink / raw)
  To: Paul Henry; +Cc: unicorn-public

On Tue, Jul 22, 2014 at 11:52 AM, Paul Henry <paul@wanelo.com> wrote:

When using unicorn unicorn v4.8.2, we're seeing a high number of TCP
> retransmits at a high connection rate.


If you're seeing TCP retransmits on the server, it means your benchmark
client can't keep up with Unicorn's responses.

--Michael


^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: High number of TCP retransmits on Solaris
  2014-07-22 18:57 ` Michael Fischer
@ 2014-07-22 19:03   ` Paul Henry
  0 siblings, 0 replies; 8+ messages in thread
From: Paul Henry @ 2014-07-22 19:03 UTC (permalink / raw)
  To: Michael Fischer; +Cc: unicorn-public

We're seeing these retransmits on the client, which is key I guess. The
benchmark script is entirely sequential, so theoretically, it should be
able to keep up?

Paul


On Tue, Jul 22, 2014 at 11:57 AM, Michael Fischer <mfischer@zendesk.com>
wrote:

> On Tue, Jul 22, 2014 at 11:52 AM, Paul Henry <paul@wanelo.com> wrote:
>
> When using unicorn unicorn v4.8.2, we're seeing a high number of TCP
>> retransmits at a high connection rate.
>
>
> If you're seeing TCP retransmits on the server, it means your benchmark
> client can't keep up with Unicorn's responses.
>
> --Michael
>


^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: High number of TCP retransmits on Solaris
  2014-07-22 18:52 High number of TCP retransmits on Solaris Paul Henry
  2014-07-22 18:57 ` Michael Fischer
@ 2014-07-22 20:56 ` Eric Wong
  2014-07-22 21:56   ` Paul Henry
  1 sibling, 1 reply; 8+ messages in thread
From: Eric Wong @ 2014-07-22 20:56 UTC (permalink / raw)
  To: Paul Henry; +Cc: unicorn-public

Paul Henry <paul@wanelo.com> wrote:
> Hello!
> 
> When using unicorn unicorn v4.8.2, we're seeing a high number of TCP
> retransmits at a high connection rate.
> 
> Smartos version: 20131218T184706Z
> 
> Rackup file used:
> 
> > cat server.ru
> run -> (env) { [200, {"Content-Type" => "text/plain"},
> [Time.now.iso8601(6)]] }
> 
> To start unicorn:
> > bundle exec unicorn -l 9292 server.ru
> 
> To benchmark unicorn:
> >> Benchmark.measure { 1000.times { time=Benchmark.measure { open("http://<ip>:9292/api/v1/settings/time",
> "Host" => "api.wanelo.com")}.real; p (time*1000).round(2) if time > 0.05 } }

Thanks for including a small example to reproduce the problem on your
end.  Is that open call is from "open-uri" in the stdlib?
(does it attempt persistent connections?)

> After the total number of connections on the system goes above 8,000
> (16,000 is the average number of connections), we start seeing delays of
> around 1.1 seconds.

I was not able to reproduce the issue with two Linux machines over
my (pretty bad) 100Mbps LAN.

I used the script at the bottom to create a lot of client connections
from my client machine to the machine running unicorn (but this is not
connecting to unicorn, but a scalable server (e.g. nginx) with infinite
persistence).

> We don't see the issue over the local loopback interface, only over the
> net. When using Webrick, we also don't see this issue.

What's strange is the issue does not manifest under Webrick for you.
Which version of Ruby is that Webrick from?

strace-ing "rackup -s webrick server.ru" reveals several differences:

1) webrick uses a listen backlog of only 128 (unicorn uses 1024)
2) webrick does not disable Nagle's algorithm.
3) webrick does not set SO_KEEPALIVE (not really needed for unicorn)

So perhaps you can try config like the following to more closely match
what webrick does:

	listen 9292, backlog: 128, tcp_nodelay: false

On the other hand, maybe webrick is too slow.

> Our tcp initial retransmit interval is 1 second. When the interval is
> reduced, the occasional latency goes down. We also see the retransmits in
> netstat, about 1 - 2 every second.
> 
> Anything that we should look at next?

Try the above config to minimize the differences between webrick
and unicorn.

If that fails, perhaps disabling SO_KEEPALIVE will work, but I'm
a bit lost as I'm not familiar with SmartOS quirks.
(you'll need to comment it out in lib/unicorn/socket_helper.rb)

Maybe try a little mock server like this, too (should be fastest :)
---------------------------- hello_world.rb ----------------
require 'socket'
s = TCPServer.new(host, port)
# start changing knobs here:
# s.setsockopt(:SOL_SOCKET, :SO_KEEPALIVE, 1)
# s.setsockopt(:IPPROTOL_TCP, :TCP_NODELAY, 1)
res = "HTTP/1.0 200 OK\r\nContent-Length: 12\r\n\r\nhello world\n"
junk = ""
loop do
  c = s.accept
  c.readpartial(1024, junk)
  c.write(res)
  c.close
end
----------------------------- many.rb --------------------------
# opens a lot of idle connections, be careful :)
require 'socket'
pids = []
host = '10.45.14.175'
port = 7500 # not unicorn
at_exit { pids.each { |pid| Process.kill(:TERM, pid) } }

24.times do
  pid = fork do
    keep = []
    begin
      s = TCPSocket.new(host, port)
      # put something in the socket buffers
      s.write("GET / HTTP/1.1\r\nHost: example.com\r\n\r\n")
      keep << s
    rescue => e
      $stdout.syswrite("#$$ done (#{keep.size}): #{e.message}\n")
      sleep
    end while true
  end
  pids << pid
end
p Process.waitall
-- 
EW

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: High number of TCP retransmits on Solaris
  2014-07-22 20:56 ` Eric Wong
@ 2014-07-22 21:56   ` Paul Henry
  2014-07-22 22:07     ` Michael Fischer
  0 siblings, 1 reply; 8+ messages in thread
From: Paul Henry @ 2014-07-22 21:56 UTC (permalink / raw)
  To: Eric Wong; +Cc: unicorn-public

Thanks so much! It turned out to be a separate issue entirely, one that
appears only in Solaris. When you have a high rate of connections, sockets
sit around in the TIME_WAIT state for a default of 60s. Basically, there's
a bug in Solaris that causes a new connection to be routed (based on what
chooses the ephemeral port) to an existing TIME_WAIT connection. When the
new client sends a SYN, the server responds with an ACK that has an
incorrect sequence number (intended for the old client). This causes the
client to retransmit the SYN and then the server responds correctly.

You can read more about this issue in detail here:
http://lists.illumos.org/pipermail/developer/2011-April/001958.html

Cheers,
Paul


On Tue, Jul 22, 2014 at 1:56 PM, Eric Wong <e@80x24.org> wrote:

> Paul Henry <paul@wanelo.com> wrote:
> > Hello!
> >
> > When using unicorn unicorn v4.8.2, we're seeing a high number of TCP
> > retransmits at a high connection rate.
> >
> > Smartos version: 20131218T184706Z
> >
> > Rackup file used:
> >
> > > cat server.ru
> > run -> (env) { [200, {"Content-Type" => "text/plain"},
> > [Time.now.iso8601(6)]] }
> >
> > To start unicorn:
> > > bundle exec unicorn -l 9292 server.ru
> >
> > To benchmark unicorn:
> > >> Benchmark.measure { 1000.times { time=Benchmark.measure {
> open("http://<ip>:9292/api/v1/settings/time",
> > "Host" => "api.wanelo.com")}.real; p (time*1000).round(2) if time >
> 0.05 } }
>
> Thanks for including a small example to reproduce the problem on your
> end.  Is that open call is from "open-uri" in the stdlib?
> (does it attempt persistent connections?)
>
> > After the total number of connections on the system goes above 8,000
> > (16,000 is the average number of connections), we start seeing delays of
> > around 1.1 seconds.
>
> I was not able to reproduce the issue with two Linux machines over
> my (pretty bad) 100Mbps LAN.
>
> I used the script at the bottom to create a lot of client connections
> from my client machine to the machine running unicorn (but this is not
> connecting to unicorn, but a scalable server (e.g. nginx) with infinite
> persistence).
>
> > We don't see the issue over the local loopback interface, only over the
> > net. When using Webrick, we also don't see this issue.
>
> What's strange is the issue does not manifest under Webrick for you.
> Which version of Ruby is that Webrick from?
>
> strace-ing "rackup -s webrick server.ru" reveals several differences:
>
> 1) webrick uses a listen backlog of only 128 (unicorn uses 1024)
> 2) webrick does not disable Nagle's algorithm.
> 3) webrick does not set SO_KEEPALIVE (not really needed for unicorn)
>
> So perhaps you can try config like the following to more closely match
> what webrick does:
>
>         listen 9292, backlog: 128, tcp_nodelay: false
>
> On the other hand, maybe webrick is too slow.
>
> > Our tcp initial retransmit interval is 1 second. When the interval is
> > reduced, the occasional latency goes down. We also see the retransmits in
> > netstat, about 1 - 2 every second.
> >
> > Anything that we should look at next?
>
> Try the above config to minimize the differences between webrick
> and unicorn.
>
> If that fails, perhaps disabling SO_KEEPALIVE will work, but I'm
> a bit lost as I'm not familiar with SmartOS quirks.
> (you'll need to comment it out in lib/unicorn/socket_helper.rb)
>
> Maybe try a little mock server like this, too (should be fastest :)
> ---------------------------- hello_world.rb ----------------
> require 'socket'
> s = TCPServer.new(host, port)
> # start changing knobs here:
> # s.setsockopt(:SOL_SOCKET, :SO_KEEPALIVE, 1)
> # s.setsockopt(:IPPROTOL_TCP, :TCP_NODELAY, 1)
> res = "HTTP/1.0 200 OK\r\nContent-Length: 12\r\n\r\nhello world\n"
> junk = ""
> loop do
>   c = s.accept
>   c.readpartial(1024, junk)
>   c.write(res)
>   c.close
> end
> ----------------------------- many.rb --------------------------
> # opens a lot of idle connections, be careful :)
> require 'socket'
> pids = []
> host = '10.45.14.175'
> port = 7500 # not unicorn
> at_exit { pids.each { |pid| Process.kill(:TERM, pid) } }
>
> 24.times do
>   pid = fork do
>     keep = []
>     begin
>       s = TCPSocket.new(host, port)
>       # put something in the socket buffers
>       s.write("GET / HTTP/1.1\r\nHost: example.com\r\n\r\n")
>       keep << s
>     rescue => e
>       $stdout.syswrite("#$$ done (#{keep.size}): #{e.message}\n")
>       sleep
>     end while true
>   end
>   pids << pid
> end
> p Process.waitall
> --
> EW
>


^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: High number of TCP retransmits on Solaris
  2014-07-22 21:56   ` Paul Henry
@ 2014-07-22 22:07     ` Michael Fischer
  2014-07-22 22:10       ` Michael Fischer
  0 siblings, 1 reply; 8+ messages in thread
From: Michael Fischer @ 2014-07-22 22:07 UTC (permalink / raw)
  To: Paul Henry; +Cc: Eric Wong, unicorn-public

On Tue, Jul 22, 2014 at 2:56 PM, Paul Henry <paul@wanelo.com> wrote:

> Thanks so much! It turned out to be a separate issue entirely, one that
> appears only in Solaris. When you have a high rate of connections, sockets
> sit around in the TIME_WAIT state for a default of 60s. Basically, there's
> a bug in Solaris that causes a new connection to be routed (based on what
> chooses the ephemeral port) to an existing TIME_WAIT connection. When the
> new client sends a SYN, the server responds with an ACK that has an
> incorrect sequence number (intended for the old client). This causes the
> client to retransmit the SYN and then the server responds correctly.


Ah, you were simply running out of IP 4-tuples on the server.   This isn't
usually a problem in practice because client IPs are usually much more
diverse.  (IIRC the behavior on Linux and FreeBSD is to send an RST to the
client when this happens instead of not responding to the SYN.)

--Michael


^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: High number of TCP retransmits on Solaris
  2014-07-22 22:07     ` Michael Fischer
@ 2014-07-22 22:10       ` Michael Fischer
  0 siblings, 0 replies; 8+ messages in thread
From: Michael Fischer @ 2014-07-22 22:10 UTC (permalink / raw)
  To: Paul Henry; +Cc: Eric Wong, unicorn-public

On Tue, Jul 22, 2014 at 3:07 PM, Michael Fischer <mfischer@zendesk.com>
wrote:

>
> Ah, you were simply running out of IP 4-tuples on the server.   This isn't
> usually a problem in practice because client IPs are usually much more
> diverse.  (IIRC the behavior on Linux and FreeBSD is to send an RST to the
> client when this happens instead of not responding to the SYN.)
>

I just re-read the bug report.  Different issue entirely.  Incorrect ISNs!
 Ouch.

--Michael


^ permalink raw reply	[flat|nested] 8+ messages in thread

* High number of TCP retransmits on Solaris
@ 2014-07-22 18:51 Paul Henry
  0 siblings, 0 replies; 8+ messages in thread
From: Paul Henry @ 2014-07-22 18:51 UTC (permalink / raw)
  To: unicorn-public

Hello!

When using unicorn unicorn v4.8.2 and we're seeing a high number of TCP
retransmits at a high connection rate.

Smartos version: 20131218T184706Z

Rackup file used:

> cat server.ru
run -> (env) { [200, {"Content-Type" => "text/plain"},
[Time.now.iso8601(6)]] }

To start unicorn:
> bundle exec unicorn -l 9292 server.ru

To benchmark unicorn:
>> Benchmark.measure { 1000.times { time=Benchmark.measure { open("http://<ip>:9292/api/v1/settings/time",
"Host" => "api.wanelo.com")}.real; p (time*1000).round(2) if time > 0.05 } }

After the total number of connections on the system goes above 8,000
(16,000 is the average number of connections), we start seeing delays of
around 1.1 seconds.

We don't see the issue over the local loopback interface, only over the
net. When using Webrick, we don't see this issue.

Our tcp initial retransmit interval is 1 second. When the interval is
reduced, the occasional latency goes down. We also see the retransmits in
netstat, about 1 - 2 every second.

Any ideas of where to look next?

Thanks!
Paul


^ permalink raw reply	[flat|nested] 8+ messages in thread

end of thread, other threads:[~2014-07-22 22:10 UTC | newest]

Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2014-07-22 18:52 High number of TCP retransmits on Solaris Paul Henry
2014-07-22 18:57 ` Michael Fischer
2014-07-22 19:03   ` Paul Henry
2014-07-22 20:56 ` Eric Wong
2014-07-22 21:56   ` Paul Henry
2014-07-22 22:07     ` Michael Fischer
2014-07-22 22:10       ` Michael Fischer
  -- strict thread matches above, loose matches on Subject: below --
2014-07-22 18:51 Paul Henry

Code repositories for project(s) associated with this inbox:

	../../../unicorn.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).