Nginx TCP Delays

We are using Nginx on this web server. Look at the # of reading &
writing
requests. a curl http://localhost/test.html can take up to 45 seconds.
Can anyone help?

Using telnet I can see that basically the Nginx server is taking time to
get
to the TCP connection that I initiated.

This happens only during peak times of the web site.

Active connections: 8467
server accepts handled requests
380771 380771 835836
Reading: 75 Writing: 1497 Waiting: 6895
http://67.159.60.59/status 45.03 seconds

I’ve attached the nginx.conf

user www-data www-data;
worker_processes 32;

error_log /var/www/log/nginx_error.log;
pid /var/run/nginx.pid;

events {
worker_connections 10024;
}

http {
include /etc/nginx/mime.types;
default_type application/octet-stream;

sendfile on;
tcp_nopush on;
tcp_nodelay on;

server {
listen 80;
server_name xs.to;
root /var/www/xs;
error_page 404 index.php;
error_page 500 502 503 504 index.php;
access_log off;

location / {
  root   /var/www/xs;
  index  index.php default.php;
  rewrite  ^/albums/(.*)$  /albums/showalbum.php?$1?  last;
  rewrite  ^/community/(.*)$  /community.php?$1?  last;
  error_page  404 index.php;
  error_page   500 502 503 504  index.php;
}

location /status {
  stub_status on;
  access_log off;
}

location ~ .php$ {
  fastcgi_pass 127.0.0.1:8888;
  fastcgi_index index.php;
  fastcgi_intercept_errors on;
  error_page  404 index.php;
  error_page   500 502 503 504  index.php;
  fastcgi_param  SCRIPT_FILENAME 

/var/www/xs/$fastcgi_script_name;
include /etc/nginx/fastcgi_params;
}

location ~* ^.+.(jpg|jpeg|gif|tiff|png|bmp|ico|fav|html)$ {
  access_log        off;
  expires           30d;
}

}

nginx version: nginx/0.8.15
Debian GNU/Linux 5.0 \n \l

What are the specs of this machine? What is your load during this time?

From: [email protected] [mailto:[email protected]] On Behalf Of
Khalid Shaikh
Sent: Sunday, September 20, 2009 11:47 PM
To: [email protected]
Subject: Nginx TCP Delays

We are using Nginx on this web server. Look at the # of reading &
writing
requests. a curl http://localhost/test.html can take up to 45 seconds.

Can anyone help?

Using telnet I can see that basically the Nginx server is taking time to
get
to the TCP connection that I initiated.

This happens only during peak times of the web site.

Active connections: 8467

server accepts handled requests

380771 380771 835836

Reading: 75 Writing: 1497 Waiting: 6895

http://67.159.60.59/status http://67.159.60.59/status 45.03
seconds

I’ve attached the nginx.conf

user www-data www-data;

worker_processes 32;

error_log /var/www/log/nginx_error.log;

pid /var/run/nginx.pid;

events {

worker_connections 10024;

}

http {

include /etc/nginx/mime.types;

default_type application/octet-stream;

sendfile on;

tcp_nopush on;

tcp_nodelay on;

server {

listen       80;

server_name  xs.to;

root   /var/www/xs;

error_page  404 index.php;

error_page   500 502 503 504  index.php;

access_log off;



location / {

  root   /var/www/xs;

  index  index.php default.php;

  rewrite  ^/albums/(.*)$  /albums/showalbum.php?$1?  last;

  rewrite  ^/community/(.*)$  /community.php?$1?  last;

  error_page  404 index.php;

  error_page   500 502 503 504  index.php;

}



location /status {

  stub_status on;

  access_log off;

}



location ~ .php$ {

  fastcgi_pass 127.0.0.1:8888;

  fastcgi_index index.php;

  fastcgi_intercept_errors on;

  error_page  404 index.php;

  error_page   500 502 503 504  index.php;

  fastcgi_param  SCRIPT_FILENAME 

/var/www/xs/$fastcgi_script_name;

  include /etc/nginx/fastcgi_params;

}



location ~* ^.+.(jpg|jpeg|gif|tiff|png|bmp|ico|fav|html)$ {

  access_log        off;

  expires           30d;

}

}

Le dimanche 20 septembre 2009 à 22:47 -0700, Khalid Shaikh a écrit :

worker_processes 32;

That’s way too much, try to keep the number of workers sticked to the
number of cores (eg: 4).

events {
worker_connections 10024;

  • use epoll ;

}

BTW what’s the result of an ulimit -n and results for a netstat -t?

Best regards

Overall seems like 3GB of RAM, with a very near 0 load.

I get the delay in one out of 10 requests. I’d love to help someone SSH
and
look at it!

model name : Intel® Core™2 Quad CPU Q8300 @ 2.50GHz
s

00:39:34 up 16:41, 1 user, load average: 0.40, 0.60, 0.70

Tasks: 132 total, 1 running, 131 sleeping, 0 stopped, 0 zombie
Cpu(s): 1.0%us, 1.8%sy, 0.0%ni, 90.6%id, 1.8%wa, 0.0%hi, 4.8%si,
0.0%st
Mem: 3099008k total, 2970148k used, 128860k free, 207052k buffers
Swap: 2650684k total, 64k used, 2650620k free, 2385632k cached

violet2:~# ulimit -n
65536

Done the changes. 4 processes and epoll. I cannot reproduce. Give me
24
hours.

Thank you at the moment.

Best,
Khalid

On Mon, Sep 21, 2009 at 1:02 AM, François Battail

Hello!

On Sun, Sep 20, 2009 at 10:47:21PM -0700, Khalid Shaikh wrote:

We are using Nginx on this web server. Look at the # of reading & writing
requests. a curl http://localhost/test.html can take up to 45 seconds.
Can anyone help?

Using telnet I can see that basically the Nginx server is taking time to get
to the TCP connection that I initiated.

This happens only during peak times of the web site.

Looks like either nginx has no CPU time due to fastcgi sitting on
the same machine, or nginx workers are blocked on disk. You may find
out actual reason by examining state of nginx worker processes in
top.

If the problem is CPU time you shuld just add some to nginx, e.g.
by using worker_priority directive. Reducing load on fastcgi
(e.g. by using fastcgi_cache) may help too.

If the problem is disk load, you may try the following:

  1. Set sendfile_max_chunk to something like 128k or 256k. This
    should prevent fast clients from blocking nginx in sendfile() for
    too long.

  2. Don’t use sendfile at all and use small number of big
    output_buffers (e.g. output_buffers 1 256k;). This should reduce
    number of disk accesses (and seeks) at cost of not using
    sendfile() - e.g. some additional CPU usage.

  3. If fastcgi returns big responses that are buffered to disk, try
    raising fastcgi_buffers and/or setting fastcgi_max_temp_file_size
    0;. This should prevent nginx from going to disk at cost of not
    releasing fastcgi connection as early as possible. Also you
    should consider finding the source of such responses and using
    X-Accel-Redirect instead if it’s possible.

  4. Consider using aio. Though aio on Linux isn’t something
    generally usable, but it may help anyway. Note that some bugs may
    be still here, it’s expiremental feature.

Maxim D.

Maxim,
Great advice. Give me 24 hours to test it out.

The specific requests I am doing /test.html and /status do not hit
php-fpm
and I verified that by turning it off and hitting those URLs for
responses.

I do not think CPU is the issue, but I still value the advice and will
go
through the variables and see if I get improvements.

Best,
Khalid

Spoke too soon.
9 second response

Active connections: 6987
server accepts handled requests
11659 11659 18780
Reading: 64 Writing: 1174 Waiting: 5749
http://67.159.60.59/status 9.02 seconds

netstat -t -n

tcp 0 0 67.159.60.59:80 117.82.34.11:1535
ESTABLISHED
tcp 0 0 67.159.60.59:80 211.100.62.157:4580
ESTABLISHED
tcp 0 0 67.159.60.59:80 119.125.137.202:1169
ESTABLISHED
tcp 0 0 67.159.60.59:80 222.50.97.40:1406
ESTABLISHED
tcp 0 0 67.159.60.59:80 71.132.222.153:8988
FIN_WAIT2
tcp 0 11520 67.159.60.59:80 121.24.99.183:2029
ESTABLISHED
tcp 0 0 67.159.60.59:80 61.90.8.47:4676
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:58729
TIME_WAIT
tcp 0 0 67.159.60.59:80 114.103.15.21:2257
ESTABLISHED
tcp 0 14400 67.159.60.59:80 220.165.174.78:2408
ESTABLISHED
tcp 0 27588 67.159.60.59:80 60.31.32.160:1186
ESTABLISHED
tcp 0 18720 67.159.60.59:80 218.201.195.36:28173
ESTABLISHED
tcp 0 0 67.159.60.59:80 114.245.195.118:11982
ESTABLISHED
tcp 0 0 67.159.60.59:80 125.88.8.62:26011
ESTABLISHED
tcp 0 14400 67.159.60.59:80 221.4.152.228:9277
ESTABLISHED
tcp 0 0 67.159.60.59:80 117.15.167.138:1975
ESTABLISHED
tcp 0 0 67.159.60.59:80 123.11.41.60:2142
FIN_WAIT2
tcp 0 0 67.159.60.59:80 119.40.201.46:4350
ESTABLISHED
tcp 0 0 67.159.60.59:80 120.11.152.161:48949
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:58926
TIME_WAIT
tcp 0 0 67.159.60.59:80 124.110.60.86:60537
FIN_WAIT2
tcp 0 0 67.159.60.59:80 116.1.38.35:1837
ESTABLISHED
tcp 0 0 67.159.60.59:80 58.209.143.83:1367
ESTABLISHED
tcp 0 0 67.159.60.59:80 222.135.76.132:4367
ESTABLISHED
tcp 0 0 67.159.60.59:80 124.227.50.67:1645
ESTABLISHED
tcp 1 42341 67.159.60.59:80 122.96.58.37:48830
LAST_ACK
tcp 0 0 67.159.60.59:80 114.93.140.247:4519
FIN_WAIT2
tcp 0 0 67.159.60.59:80 119.128.42.242:1682
ESTABLISHED
tcp 0 13068 67.159.60.59:80 211.162.2.121:6398
ESTABLISHED
tcp 0 0 67.159.60.59:80 123.97.37.177:1293
ESTABLISHED
tcp 0 0 67.159.60.59:80 219.94.239.126:62599
ESTABLISHED
tcp 0 0 67.159.60.59:80 117.92.184.120:3672
ESTABLISHED
tcp 0 0 67.159.60.59:80 61.50.138.225:65386
ESTABLISHED
tcp 0 0 67.159.60.59:80 61.19.52.6:5747
FIN_WAIT2
tcp 0 0 67.159.60.59:80 222.181.204.108:48073
ESTABLISHED
tcp 0 0 67.159.60.59:80 219.232.53.162:13166
ESTABLISHED
tcp 0 12726 67.159.60.59:80 60.177.44.18:1782
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:58624
TIME_WAIT
tcp 0 0 67.159.60.59:80 113.66.215.199:52656
ESTABLISHED
tcp 0 0 67.159.60.59:80 60.166.205.82:4782
TIME_WAIT
tcp 0 0 67.159.60.59:80 218.170.143.169:50838
ESTABLISHED
tcp 0 0 67.159.60.59:80 114.139.147.41:3189
ESTABLISHED
tcp 0 0 67.159.60.59:80 222.216.160.169:51695
ESTABLISHED
tcp 0 64801 67.159.60.59:80 60.168.211.206:2528
FIN_WAIT1
tcp 0 0 67.159.60.59:80 60.24.127.246:1276
ESTABLISHED
tcp 0 1 67.159.60.59:80 125.86.86.210:1530
LAST_ACK
tcp 0 0 67.159.60.59:80 121.232.5.0:1562
TIME_WAIT
tcp 0 0 67.159.60.59:80 123.169.76.124:3261
ESTABLISHED
tcp 0 0 67.159.60.59:80 58.48.127.114:4321
ESTABLISHED
tcp 0 0 67.159.60.59:80 115.58.70.57:44170
ESTABLISHED
tcp 0 0 67.159.60.59:80 218.83.159.27:20978
ESTABLISHED
tcp 0 0 67.159.60.59:80 117.82.34.11:1536
ESTABLISHED
tcp 0 0 67.159.60.59:80 116.233.98.184:51505
ESTABLISHED
tcp 0 0 67.159.60.59:80 92.50.56.232:1691
ESTABLISHED
tcp 0 0 67.159.60.59:80 92.50.56.232:1691
ESTABLISHED
tcp 0 0 67.159.60.59:80 119.129.193.248:50947
ESTABLISHED
tcp 0 0 67.159.60.59:80 123.12.133.82:4568
ESTABLISHED
tcp 0 0 67.159.60.59:80 60.184.168.119:1081
ESTABLISHED
tcp 0 0 67.159.60.59:80 125.75.66.227:2213
ESTABLISHED
tcp 0 0 67.159.60.59:80 221.214.27.252:50954
FIN_WAIT2
tcp 0 0 67.159.60.59:80 116.114.151.17:3455
ESTABLISHED
tcp 0 0 67.159.60.59:80 123.128.69.132:1697
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:58853
TIME_WAIT
tcp 0 0 67.159.60.59:80 85.248.177.67:62149
ESTABLISHED
tcp 0 11775 67.159.60.59:80 59.175.138.23:61678
LAST_ACK
tcp 0 0 67.159.60.59:80 94.199.64.122:62616
ESTABLISHED
tcp 0 0 67.159.60.59:80 118.117.183.66:4089
ESTABLISHED
tcp 0 0 67.159.60.59:80 218.211.190.77:51443
ESTABLISHED
tcp 0 0 67.159.60.59:80 125.126.206.177:4726
ESTABLISHED
tcp 0 0 67.159.60.59:80 125.87.42.161:2607
ESTABLISHED
tcp 0 0 67.159.60.59:80 122.92.202.219:20826
FIN_WAIT2
tcp 0 1 67.159.60.59:80 121.23.193.145:54343
FIN_WAIT1
tcp 0 0 67.159.60.59:80 61.180.31.246:54534
ESTABLISHED
tcp 0 0 67.159.60.59:80 60.2.171.194:6036
ESTABLISHED
tcp 0 0 67.159.60.59:80 120.8.91.128:1416
ESTABLISHED
tcp 0 0 67.159.60.59:80 119.134.26.56:20514
ESTABLISHED
tcp 0 0 67.159.60.59:80 122.4.74.74:34171
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:59091
TIME_WAIT
tcp 0 0 67.159.60.59:80 61.178.121.202:21775
ESTABLISHED
tcp 0 0 67.159.60.59:80 218.249.171.66:59990
ESTABLISHED
tcp 0 0 67.159.60.59:80 222.170.44.147:6922
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:58414
TIME_WAIT
tcp 0 1 67.159.60.59:80 122.88.100.94:2551
FIN_WAIT1
tcp 0 0 67.159.60.59:80 60.163.58.207:3499
TIME_WAIT
tcp 0 0 67.159.60.59:80 123.233.56.129:6895
ESTABLISHED
tcp 0 0 67.159.60.59:80 210.176.56.135:3342
ESTABLISHED
tcp 0 0 67.159.60.59:80 120.8.91.128:1418
ESTABLISHED
tcp 0 128370 67.159.60.59:80 221.208.129.207:44742
ESTABLISHED
tcp 0 1 67.159.60.59:80 60.51.0.11:18636
LAST_ACK
tcp 0 0 67.159.60.59:80 58.17.218.36:32444
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:58467
TIME_WAIT
tcp 0 34560 67.159.60.59:80 122.159.63.171:4878
ESTABLISHED
tcp 0 0 67.159.60.59:80 59.37.160.126:4174
ESTABLISHED
tcp 0 0 67.159.60.59:80 219.159.236.86:3394
ESTABLISHED
tcp 0 0 67.159.60.59:80 121.235.174.70:1264
ESTABLISHED
tcp 0 0 67.159.60.59:80 217.218.42.252:43719
ESTABLISHED
tcp 0 19008 67.159.60.59:80 125.77.54.194:59397
ESTABLISHED
tcp 0 0 67.159.60.59:80 58.213.15.212:61406
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:58437
TIME_WAIT
tcp 0 0 127.0.0.1:8888 127.0.0.1:58413
TIME_WAIT
tcp 0 0 67.159.60.59:80 58.208.183.16:62097
FIN_WAIT2
tcp 0 0 67.159.60.59:80 219.68.112.123:62231
ESTABLISHED
tcp 0 0 67.159.60.59:80 121.232.63.54:3108
ESTABLISHED
tcp 0 0 67.159.60.59:80 93.110.82.204:42349
ESTABLISHED
tcp 0 0 67.159.60.59:80 68.149.62.179:2153
ESTABLISHED
tcp 0 0 67.159.60.59:80 119.98.149.117:5489
ESTABLISHED
tcp 0 1 67.159.60.59:80 117.80.24.112:41012
LAST_ACK
tcp 0 10080 67.159.60.59:80 121.235.180.213:1671
ESTABLISHED
tcp 0 10080 67.159.60.59:80 121.235.180.213:1671
ESTABLISHED
tcp 0 0 67.159.60.59:80 222.211.148.148:2664
ESTABLISHED
tcp 0 0 67.159.60.59:80 119.99.240.106:1785
ESTABLISHED
tcp 0 10220 67.159.60.59:80 61.184.25.99:4860
ESTABLISHED
tcp 0 1 67.159.60.59:80 116.226.69.101:56958
LAST_ACK
tcp 0 0 67.159.60.59:80 114.224.166.26:4496
ESTABLISHED
tcp 0 0 67.159.60.59:80 68.149.62.179:2150
ESTABLISHED
tcp 0 0 67.159.60.59:80 119.51.243.209:5952
ESTABLISHED
tcp 0 0 67.159.60.59:80 220.249.111.99:2316
TIME_WAIT
tcp 0 0 67.159.60.59:80 114.36.183.15:1482
ESTABLISHED
tcp 0 62737 67.159.60.59:80 61.192.233.14:2219
ESTABLISHED
tcp 0 1 67.159.60.59:80 124.164.103.210:44978
FIN_WAIT1
tcp 0 0 67.159.60.59:80 222.74.231.133:63607
ESTABLISHED
tcp 0 0 67.159.60.59:80 60.169.51.199:1123
ESTABLISHED
tcp 0 0 67.159.60.59:80 119.32.81.9:1856
ESTABLISHED
tcp 0 0 67.159.60.59:80 218.8.130.28:12247
TIME_WAIT
tcp 0 0 67.159.60.59:80 218.87.219.57:1188
ESTABLISHED
tcp 0 0 67.159.60.59:80 125.110.225.77:5000
TIME_WAIT
tcp 0 0 67.159.60.59:80 120.82.50.9:1959
ESTABLISHED
tcp 0 0 67.159.60.59:80 61.53.134.242:4413
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:58534
TIME_WAIT
tcp 0 13068 67.159.60.59:80 123.7.51.43:8057
ESTABLISHED
tcp 0 0 67.159.60.59:80 61.183.251.3:33373
ESTABLISHED
tcp 0 0 67.159.60.59:80 119.142.222.51:2588
ESTABLISHED
tcp 0 12960 67.159.60.59:80 124.224.57.22:3831
ESTABLISHED
tcp 0 0 67.159.60.59:80 119.128.97.47:2968
ESTABLISHED
tcp 0 1 67.159.60.59:80 123.133.15.167:11534
FIN_WAIT1
tcp 0 129228 67.159.60.59:80 124.135.253.42:24657
ESTABLISHED
tcp 0 0 67.159.60.59:80 119.145.12.51:61043
ESTABLISHED
tcp 0 0 67.159.60.59:80 123.6.231.235:28603
ESTABLISHED
tcp 0 13140 67.159.60.59:80 113.18.3.226:29028
ESTABLISHED
tcp 0 0 67.159.60.59:80 94.66.12.40:53535
ESTABLISHED
tcp 0 1 67.159.60.59:80 117.8.169.234:23688
LAST_ACK
tcp 0 0 67.159.60.59:80 219.135.54.155:3290
ESTABLISHED
tcp 0 39420 67.159.60.59:80 218.9.29.197:15631
ESTABLISHED
tcp 0 0 67.159.60.59:80 116.17.54.43:2081
ESTABLISHED
tcp 0 0 67.159.60.59:80 98.157.213.82:32884
ESTABLISHED
tcp 0 0 67.159.60.59:80 75.22.38.158:3196
ESTABLISHED
tcp 0 0 67.159.60.59:80 221.236.102.92:2691
ESTABLISHED
tcp 0 25920 67.159.60.59:80 58.16.255.234:8333
ESTABLISHED
tcp 0 0 67.159.60.59:80 220.249.99.240:4588
ESTABLISHED
tcp 0 0 67.159.60.59:80 120.195.54.73:4058
FIN_WAIT2
tcp 0 0 67.159.60.59:80 218.25.19.182:3275
ESTABLISHED
tcp 0 0 67.159.60.59:80 114.95.48.35:12094
ESTABLISHED
tcp 0 0 67.159.60.59:80 219.146.142.14:2025
ESTABLISHED
tcp 0 0 67.159.60.59:80 123.179.80.114:2800
ESTABLISHED
tcp 0 0 67.159.60.59:80 222.90.211.222:3554
ESTABLISHED
tcp 0 0 67.159.60.59:80 222.217.86.82:2009
ESTABLISHED
tcp 0 12961 67.159.60.59:80 58.22.255.48:32575
FIN_WAIT1
tcp 0 0 67.159.60.59:80 221.234.151.209:2349
ESTABLISHED
tcp 0 8951 67.159.60.59:80 221.235.83.142:3886
ESTABLISHED
tcp 0 0 67.159.60.59:80 221.238.69.42:52375
ESTABLISHED
tcp 0 1 67.159.60.59:80 125.114.148.250:1908
FIN_WAIT1
tcp 0 0 67.159.60.59:80 59.48.156.213:3422
ESTABLISHED
tcp 0 0 67.159.60.59:80 221.238.69.42:52375
ESTABLISHED
tcp 0 1 67.159.60.59:80 125.114.148.250:1908
FIN_WAIT1
tcp 0 0 67.159.60.59:80 59.48.156.213:3422
ESTABLISHED
tcp 0 0 67.159.60.59:80 117.15.86.61:3553
TIME_WAIT
tcp 0 0 67.159.60.59:80 124.226.233.191:3964
ESTABLISHED
tcp 0 0 67.159.60.59:80 125.88.146.96:28525
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:58609
TIME_WAIT
tcp 0 0 67.159.60.59:80 220.140.17.243:4414
ESTABLISHED
tcp 0 0 67.159.60.59:80 123.87.145.142:2028
ESTABLISHED
tcp 0 0 67.159.60.59:80 110.164.18.179:2714
FIN_WAIT2
tcp 0 0 67.159.60.59:80 60.191.161.162:4563
ESTABLISHED
tcp 0 6269 67.159.60.59:80 60.13.54.107:2483
ESTABLISHED
tcp 0 0 67.159.60.59:80 117.74.31.54:56578
ESTABLISHED
tcp 0 0 67.159.60.59:80 60.1.212.113:14161
ESTABLISHED
tcp 0 8280 67.159.60.59:80 60.191.116.171:64665
ESTABLISHED
tcp 0 0 67.159.60.59:80 219.144.113.172:4742
ESTABLISHED
tcp 0 0 67.159.60.59:80 222.170.45.13:1193
FIN_WAIT2
tcp 0 0 67.159.60.59:80 117.88.145.221:2217
ESTABLISHED
tcp 0 13069 67.159.60.59:80 124.77.11.102:3239
FIN_WAIT1
tcp 0 0 67.159.60.59:80 114.45.171.33:2377
ESTABLISHED
tcp 0 0 67.159.60.59:80 125.70.195.58:4728
TIME_WAIT
tcp 0 0 127.0.0.1:8888 127.0.0.1:58375
TIME_WAIT
tcp 0 0 67.159.60.59:80 123.87.145.142:2031
ESTABLISHED
tcp 0 0 67.159.60.59:80 122.225.226.138:29639
ESTABLISHED
tcp 0 0 67.159.60.59:80 219.232.53.162:12526
ESTABLISHED
tcp 0 1 67.159.60.59:80 218.78.205.50:2841
LAST_ACK
tcp 0 0 67.159.60.59:80 119.98.149.117:5490
ESTABLISHED
tcp 0 0 67.159.60.59:80 60.185.180.189:1725
ESTABLISHED
tcp 0 12960 67.159.60.59:80 116.226.93.15:3911
ESTABLISHED
tcp 0 0 67.159.60.59:80 123.139.39.186:1820
ESTABLISHED
tcp 0 0 67.159.60.59:80 122.117.145.93:2464
ESTABLISHED
tcp 0 143353 67.159.60.59:80 218.83.159.6:14970
FIN_WAIT1
tcp 0 10164 67.159.60.59:80 210.203.31.142:3070
ESTABLISHED
tcp 0 0 67.159.60.59:80 122.138.11.143:51691
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:58743
TIME_WAIT
tcp 0 0 127.0.0.1:8888 127.0.0.1:58336
TIME_WAIT
tcp 0 0 67.159.60.59:80 202.104.3.242:17588
ESTABLISHED
tcp 0 12727 67.159.60.59:80 116.233.251.150:4373
FIN_WAIT1
tcp 0 1 67.159.60.59:80 122.193.146.250:2888
FIN_WAIT1
tcp 0 0 67.159.60.59:80 221.210.88.204:3602
ESTABLISHED
tcp 0 1 67.159.60.59:80 122.141.171.23:3052
FIN_WAIT1
tcp 0 0 67.159.60.59:80 61.19.52.6:40716
FIN_WAIT2
tcp 0 0 67.159.60.59:80 58.38.81.251:2992
ESTABLISHED
tcp 0 13769 67.159.60.59:80 219.234.81.64:45322
ESTABLISHED
tcp 0 0 67.159.60.59:80 60.162.220.172:2033
ESTABLISHED
tcp 0 0 67.159.60.59:80 116.30.202.70:54700
ESTABLISHED
tcp 0 0 67.159.60.59:80 124.134.41.105:2084
ESTABLISHED
tcp 0 0 67.159.60.59:80 117.39.55.183:1621
ESTABLISHED
tcp 0 1 67.159.60.59:80 116.24.216.78:17922
LAST_ACK
tcp 0 1 67.159.60.59:80 116.30.225.101:19140
LAST_ACK
tcp 0 0 127.0.0.1:8888 127.0.0.1:58302
TIME_WAIT
tcp 0 0 127.0.0.1:8888 127.0.0.1:58840
TIME_WAIT
tcp 0 0 67.159.60.59:80 125.37.119.162:18576
ESTABLISHED
tcp 0 0 67.159.60.59:80 61.145.246.105:43110
ESTABLISHED
tcp 0 0 67.159.60.59:80 60.210.236.205:14509
ESTABLISHED
tcp 0 0 67.159.60.59:80 116.19.70.19:9278
ESTABLISHED
tcp 0 0 67.159.60.59:80 59.46.80.241:9444
ESTABLISHED
tcp 0 11521 67.159.60.59:80 58.247.192.147:43432
FIN_WAIT1
tcp 0 33120 67.159.60.59:80 220.170.179.43:4414
ESTABLISHED
tcp 0 12960 67.159.60.59:80 114.103.2.166:4308
ESTABLISHED
tcp 0 0 67.159.60.59:80 60.188.197.90:1549
ESTABLISHED
tcp 0 0 67.159.60.59:80 222.50.97.40:1527
ESTABLISHED
tcp 0 0 67.159.60.59:80 59.50.66.2:9690
ESTABLISHED
tcp 0 0 67.159.60.59:80 221.205.27.239:64003
FIN_WAIT2
tcp 0 13140 67.159.60.59:80 117.136.9.43:22164
ESTABLISHED
tcp 0 0 127.0.0.1:8888 127.0.0.1:58714
TIME_WAIT
tcp 0 10164 67.159.60.59:80 81.34.33.64:2523
ESTABLISHED
tcp 0 0 67.159.60.59:80 58.20.123.103:1141
ESTABLISHED
tcp 0 1 67.159.60.59:80 116.22.69.79:27633
LAST_ACK
tcp 0 0 67.159.60.59:80 222.95.216.42:2016
ESTABLISHED
tcp 0 0 67.159.60.59:80 218.249.171.66:59992
ESTABLISHED
tcp 0 0 67.159.60.59:80 68.225.195.210:62639
ESTABLISHED
tcp 0 0 67.159.60.59:56080 66.90.104.80:3306
TIME_WAIT
tcp 0 0 67.159.60.59:80 60.183.111.145:2923
ESTABLISHED
tcp 0 0 67.159.60.59:80 117.42.244.235:2834
ESTABLISHED
tcp 0 11520 67.159.60.59:80 60.164.40.244:3876
ESTABLISHED
tcp 0 0 67.159.60.59:80 220.165.170.120:2051
ESTABLISHED
tcp 0 0 67.159.60.59:80 79.127.30.239:3762
ESTABLISHED
tcp 0 0 67.159.60.59:80 119.119.61.52:11781
ESTABLISHED
tcp 0 12960 67.159.60.59:80 220.173.186.108:7466
ESTABLISHED
tcp 0 0 67.159.60.59:80 221.207.231.235:3777
ESTABLISHED
tcp 0 0 67.159.60.59:80 124.77.179.223:3692
ESTABLISHED
tcp 0 1 67.159.60.59:80 58.19.176.130:5028
FIN_WAIT1
tcp 0 0 67.159.60.59:80 121.13.210.124:21375
ESTABLISHED
violet2:~#

Salut Francois,
Excellent suggestion.

Even in the test that passed, 11 seconds is not really acceptable. If
i
conduct a telnet localhost 80, sometimes it takes many seconds before
showing you

Check out these results with curl. Over 90 seconds of ‘waiting’
http://screencast.com/t/g5uvshJY25Ty

You can see near the end of the video when I start and restart nginx and
do
a number of tests, some respond instantly, some take a while.

Results

Test #1
Benchmarking localhost (be patient)…apr_poll: The timeout specified
has
expired (70007)

Test #2
violet2:~# ab -k -n 100 -c 10 http://localhost/test.html
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient)…done

Server Software: nginx/0.8.15
Server Hostname: localhost
Server Port: 80

Document Path: /test.html
Document Length: 17 bytes

Concurrency Level: 10
Time taken for tests: 0.015 seconds
Complete requests: 100
Failed requests: 0
Write errors: 0
Keep-Alive requests: 100
Total transferred: 30400 bytes
HTML transferred: 1700 bytes
Requests per second: 6544.50 [#/sec] (mean)
Time per request: 1.528 [ms] (mean)
Time per request: 0.153 [ms] (mean, across all concurrent
requests)
Transfer rate: 1942.90 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.1 0 0
Processing: 0 1 3.1 0 11
Waiting: 0 1 3.1 0 11
Total: 0 1 3.2 0 11

Percentage of the requests served within a certain time (ms)
50% 0
66% 1
75% 1
80% 1
90% 11
95% 11
98% 11
99% 11
100% 11 (longest request)

Test #3
Benchmarking localhost (be patient)…apr_poll: The timeout specified
has
expired (70007)

Best,
Khalid

On Mon, Sep 21, 2009 at 1:54 AM, François Battail

Team,
Here is another sample point. See the 9 second delay on the server I
keep
speaking about. This problem shows across multiple servers. The one we
are
investigating is http://67.159.60.59/status. Same nginx.conf across
all.

root@pa:~# clear; ./status.rb
Active connections: 17442
server accepts handled requests
291457 291457 499538
Reading: 242 Writing: 3838 Waiting: 13362
http://208.53.158.42/status 0.07 seconds

Active connections: 11545
server accepts handled requests
8720635 8720635 13904180
Reading: 154 Writing: 1370 Waiting: 10021
http://67.159.60.37/status 0.03 seconds

Active connections: 3807
server accepts handled requests
3758087 3758087 27448407
Reading: 44 Writing: 213 Waiting: 3550
http://66.90.101.97/status 0.04 seconds

Active connections: 8855
server accepts handled requests
6865763 6865763 10978021
Reading: 133 Writing: 988 Waiting: 7734
http://208.53.158.75/status 0.03 seconds

Active connections: 10571
server accepts handled requests
194174 194174 467424
Reading: 106 Writing: 2147 Waiting: 8318
http://67.159.60.59/status 9.03 seconds

Active connections: 8354
server accepts handled requests
4314517 4314517 6679147
Reading: 195 Writing: 1954 Waiting: 6205
http://208.53.158.200/status 0.03 seconds

Le lundi 21 septembre 2009 à 01:20 -0700, Khalid Shaikh a écrit :

Spoke too soon.
9 second response

Can you try:

ab -k -n 100 -c 10 http://localhost/test.html

(It’s Apache Bench from Debian’s apache2-utils package, it will give us
a more precise idea of the timings)

Best regards

Hello!

On Mon, Sep 21, 2009 at 09:26:22AM -0700, Khalid Shaikh wrote:

http://208.53.158.42/status 0.07 seconds
Reading: 44 Writing: 213 Waiting: 3550
194174 194174 467424
Reading: 106 Writing: 2147 Waiting: 8318
http://67.159.60.59/status 9.03 seconds

After looking closely on timings you provide - it’s
suspiciously rounded delays. Looks like packet
drops/retransmissions. This may be due to some network resource
shortage on the host in question or some problems on the wire.

First of all, try tcpdump to see what actually happens on the
wire.

Also it’s probably a good idea to examine your backlog size and
status. AFAIK Linux by default just drops incoming SYN packets on
listen queue overflows, so this may be the reason.

Maxim D.

I like your analysis of the SYN packets. The tests are specifically
localhost, so it cannot be network for those connections.

I will investigate based on your analysis.

Best,
Khalid

Maxim,
You may be a genius.

I see the backlog is only 1024, so I upped that
echo 10024 > /proc/sys/net/ipv4/tcp_max_syn_backlog

Things feel responsive, but I will only know more in 24 hours when we
hit
peak loads.

Best,
Khalid

Team,
I’ve applied almost every suggestion given to me and still cannot
resolve
the delays.

Is there anyone whom is willing to log into the server and take a look?
I
can compensate if needed!

Please email me!

Active connections: 7506
server accepts handled requests
173367 173367 443669
Reading: 82 Writing: 1721 Waiting: 5703
http://67.159.60.59/status 21.03 seconds

Best,
Khalid
[email protected]

On Sep 21, 2009, at 1:02, François Battail [email protected]
wrote:

Le dimanche 20 septembre 2009 à 22:47 -0700, Khalid Shaikh a écrit :

worker_processes 32;

That’s way too much, try to keep the number of workers sticked to the
number of cores (eg: 4).

Surely you should have more?
Eg with 4 cores have 8 workers.

If workers block serving a request, this means you don’t have CPU
sitting idle.

On Mon, Sep 21, 2009 at 9:25 PM, Khalid Shaikh
[email protected] wrote:

http://67.159.60.59/status 21.03 seconds
Best,
Khalid
[email protected]

does not seem to be an nginx issue, server side issue due to high
amount of connections being tracked by nf_conntrack aka iptables
modifying that value to something of power of 2 will solve the
issue… you can set the number safely around 1048576 as well as your
hash bucket size

Active connections: 12558
server accepts handled requests
192560 192560 747535
Reading: 152 Writing: 2661 Waiting: 9745

also enabling linux syncookie helps a lot so you dont have to deal
with stupid bogus traffic :slight_smile:
[201926.711051] possible SYN flooding on port 80. Sending cookies.

cheers

Le mercredi 23 septembre 2009 à 01:45 -0700, Avleen Vig a écrit :

On Sep 21, 2009, at 1:02, François Battail [email protected]
wrote:

Surely you should have more?
Eg with 4 cores have 8 workers.

If workers block serving a request, this means you don’t have CPU
sitting idle.

Well, according to the nginx.conf provided there is also a fastcgi
server on the same server…

From my tests you don’t gain anything by rising the number of nginx’s
workers over the number of cores and I’am not convinced that the
“hyperthreading” scheme can be useful in that case.

Best regards

Avleen Vig wrote:

Surely you should have more?
Eg with 4 cores have 8 workers.

If workers block serving a request, this means you don’t have CPU
sitting idle.
Generally no. If you are doing everything properly event driven (even
more so if you shift from a polling model to an AIO model), then any
time you are busy serving a request, that means your CPU isn’t sitting
idle. The only time it should be idle is when there literally aren’t any
requests/events to process (at which point extra processes isn’t going
to help).

–Chris