<pre>Hi,
I'm using nginx as a reverse proxy to my backends. I see sometimes the request time is too big while the upstream response time is quite small:</pre><pre>211.139.145.99 - - [26/Oct/2012:10:49:55 +0800] 5.287 "POST /service/3/app_components/?screen_type=iphone_2x&device_platform=iphone&channel=App%20Store&app_name=news_article&device_type=iPhone%205&os_version=6.0&version_code=1.2&uuid=27506e0c4c09b881f44e1a458f471f3de165cc34 HTTP/1.1" 200 6916 "-" "-" "<a href="http://i.snssdk.com">i.snssdk.com</a>" "uuid=27506e0c4c09b881f44e1a458f471f3de165cc34" upstream_response_time: 0.287</pre>
<pre>As I analyze the access log, I see sometimes there are many logs like above which the request time is 5 or more bigger than upstream response time. </pre><pre>For find out the big difference between the request time and request respons time, i use tcpdump to get packages on nginx server 80 port like :</pre>
<pre>As I analyze the packages£¬ I find many Strange phenomenon below:</pre><pre>219.234.82.78 - - [26/Oct/2012:10:52:48 +0800] 5.260 "POST /service/2/app_alert/?uuid=4960614f474b0990f3dcb83c12bde42e55eb42b1&lang=zh-Hans&access=mobile&carrier=%E4%B8%AD%E5%9B%BD%E7%A7%BB%E5%8A%A8&mcc_mnc=46002&device_platform=iphone&channel=App%20Store&app_name=joke_essay&device_type=iPhone%204&os_version=6.0&version_code=1.3 HTTP/1.1" 200 49 "-" "\xE5\x86\x85\xE6\xB6\xB5\xE6\xAE\xB5\xE5\xAD\x90 1.3 (iPhone; iPhone OS 6.0; zh_CN)" "<a href="http://i.snssdk.com">i.snssdk.com</a>" "uuid=4960614f474b0990f3dcb83c12bde42e55eb42b1" upstream_response_time: 0.260

tcpdump:

10:52:43.099494 IP 219.234.82.78.57120 > 60.29.255.91.80: Flags [S], seq 599253512, win 5840, options [mss 1460], length 0
10:52:43.099526 IP 60.29.255.91.80 > 219.234.82.78.57120: Flags [S.], seq 1300382255, ack 599253513, win 14600, options [mss 1460], length 0
10:52:43.110052 IP 219.234.82.78.57120 > 60.29.255.91.80: Flags [.], ack 1, win 5840, length 0
10:52:43.614325 IP 219.234.82.78.57120 > 60.29.255.91.80: Flags [P.], seq 1:553, ack 1, win 5840, length 552 
E..P..@.1.....RN<..[. .P#.. M.B0P.......POST /service/2/app_alert/?uuid=4960614f474b0990f3dcb83c12bde42e55eb42b1&lang=zh-Hans&access=mobile&carrier=%E4%B8%AD%E5%9B%BD%E7%A7%BB%E5%8A%A8&mcc_mnc=46002&device_platform=iphone&channel=App%20Store&app_name=joke_essay&device_type=iPhone%204&os_version=6.0&version_code=1.3 HTTP/1.1^M
Host: <a href="http://i.snssdk.com">i.snssdk.com</a>^M
Accept-Encoding: gzip^M
Content-Length: 0^M 
Cookie: uuid=4960614f474b0990f3dcb83c12bde42e55eb42b1^M
User-Agent: ............ 1.3 (iPhone; iPhone OS 6.0; zh_CN)^M
Via: 1.1 dxt_2_168 (squid/3.1.16)^M
Cache-Control: max-age=0^M
Connection: keep-alive^M
<br></pre><pre>10:52:46.613596 IP 219.234.82.78.57120 > 60.29.255.91.80: Flags [P.], seq 1:553, ack 1, win 5840, length 552 
10:52:52.614245 IP 219.234.82.78.57120 > 60.29.255.91.80: Flags [P.], seq 1:553, ack 1, win 5840, length 552 
10:53:03.048953 IP 219.234.82.78.57120 > 60.29.255.91.80: Flags [F.], seq 553, ack 1, win 5840, length 0
10:53:28.987395 IP 60.29.255.91.80 > 219.234.82.78.57120: Flags [P.], seq 1:229, ack 554, win 15456, length 228 
</pre><pre>10:53:28.997888 IP 219.234.82.78.57120 > 60.29.255.91.80: Flags [R], seq 599254066, win 0, length 0</pre><pre>I analyze many nginx access log with tcpdump packages. I find sometimes the nginx server does not response ack on the client in time, when the client post request to server, and in some cases the server does not send any package more after The three handshake with client.</pre>
<pre>I fell quite puzzled why nginx log the request time 5.260 seconds while the nginx server send the ack package 40 seconds later.</pre><pre>And I try debug the nginx, I find the request time logged after <span style="font-family:arial">the ngx_http_finalize_request, which call the sendfile to write the reseult the tcp sk_buffer.</span></pre>
<pre>I guess there is some thing wrong with my system or network, but i use </pre><pre>netstat -s -t, i find no packages dropped outgoing:</pre><pre>    2922 ICMP packets dropped because they were out-of-window
    73 ICMP packets dropped because socket was locked
    927337 SYNs to LISTEN sockets dropped</pre><pre>Any idea what's happening and how to resolve this problem ?</pre><pre>Thanks.</pre><div><br></div>-- <br>thanks<div>rockybai</div><br>