Welcome! Log In Create A New Profile

Advanced

Nginx+Mongrel slowness on 302's

Posted by rich l 
Nginx+Mongrel slowness on 302's
June 19, 2009 08:30PM
Hi,
I'm a big fan of nginx and have migrated some of my appservers to use nginx, while leaving some on apache 2.2 for comparison. I'm running ruby/rails on mongrels behind the nginx/apache frontend webserver. (Note: i'm not using passenger on either.) I have one problem to resolve before I can switch over to nginx completely. Hopefully someone here can help!

I've noticed that the average response times for certain requests on nginx are slower than on the apache server. Nginx is beating apache for all response codes (that appear frequently enough) except for 302 redirects, where nginx averages about 140% of the apache mean.

In particular, for a certain simple request where mongrel's average response time is <3ms, the nginx logs report an average response time of well over 100ms, while the apache logs report an average response time of about 60ms.

On apache (using mod_proxy_balancer), i know sometimes the request gets queued on a mongrel tied up with a long request, adding latency because the scheduler is not smart enough to send it to an idle mongrel. Looking at a histogram of response times, almost all are very fast (~10-20ms) with a small number being much higher.

On nginx, I am using the fair balancer module so the issue is not requests going to a busy mongrel. The distribution of response times looks much different than on the apache server. It is multi-modal, with the biggest peak around 20ms, but other significant peaks at 70ms and 150ms, with a few % of requests taking more than 500ms.

Examining a few specific requests to nginx that took a long time (from the nginx log) i see that the mongrels still completed in 2ms, but finished several seconds before nginx reported the request to complete.

So, i'm left wondering what could cause nginx to delay completing the request? Any suggestions on either the possible cause or how to debug this would be much appreciated.

NOTE: i realize that the time reported by rails to complete the request does not include the time needed to commit the session (in my case, to the db). But, i checked my slow query log for mysql at the times in question and it did not report any slow queries (and the threshold is set low enough that if the session accounted for the nginx slowness then i would have seen it.)

I'm running this version (on centos 5 x86_64):
nginx version: nginx/0.6.34
built by gcc 4.1.2 20071124 (Red Hat 4.1.2-42)
configure arguments: --prefix=/usr/local/nginx --add-module=/root/packages/nginx-upstream-fair/ --with-http_stub_status_module --with- http_ssl_module
I'm also running mongrel 1.1.5

thanks in advance!
rich
Re: Nginx+Mongrel slowness on 302's
June 21, 2009 03:14AM
As I've now done some more investigation, i wanted to post the additional information i've collected.

First, i want to note that this happens on a server without significant load and that is definitely not swapping.

Second, i've modified the logging to collect the $upstream_response_time as well as the $request_time. I see numerous cases where the upstream_response time is approximately 20ms, while the request_time is 2-5 seconds. And, as before, i have verified that the upstream request is not being delayed - that is, the delay is not BEFORE the request is proxied to one of the mongrels, but afterwards.

Finally, i forgot to mention that the request and response are both approximately 100 bytes. So, i don't see how a slow client could be a factor here.

what could possibly cause nginx to take more than a second after completing the upstream request - especially for a response that is a 110 byte redirect?

thanks in advance for any help/suggestions!

rich
Re: Nginx+Mongrel slowness on 302's
June 22, 2009 02:08PM
Ok, after upgrading to the latest stable release and building/deploying the debug version (with a few small modifications to the debug logging to make it easier to track the time in msecs of various log statements), I determined that the issue is the lingering close. Apparently, the $request_time variable that i had relied upon to know how long nginx took to process the request is misleading, because it includes the time for the lingering close. To the user, this extra time is irrelevant.

However, i am still stuck wondering why my signup rate is lower on my nginx server than on the otherwise identical apache servers.
Sorry, only registered users may post in this forum.

Click here to login

Online Users

Guests: 112
Record Number of Users: 6 on February 13, 2018
Record Number of Guests: 421 on December 02, 2018
Powered by nginx      Powered by FreeBSD      PHP Powered      Powered by MariaDB      ipv6 ready