Да upstream завершает запрос. Клиенту в итоге приходит корректный ответ.
Никаких ошибок нигде нет. Мне кажется врядли это связанно с upstream-ом,
т.к. тоже самое проявляется и на статике.
И по логам tcpdump видно, что интересующие нас 130 миллисекунд
находятся между отправкой запроса с клиента и до отправки запроса в upstream.

Dmitry Wrote:
-------------------------------------------------------
> Странно это. 300-400 запросов в минуту это порядка 5-7 в секунду,
> т.е. не
> много. Upstream запрос завершает или как? Например для php
> fastcgi_finish_request? Нет ли ошибок выполнения, которые как-то
> обрабатываются? Ожидания закрытия каких-то соединений, буферов и
> т.п.?
> 19 авг. 2014 г. 16:10 пользователь "yury_y" <nginx-forum@nginx.us>
> написал:
>
> > Добрый день,
> >
> > столкнулся со следующей проблемой. Сервер работает под нагрузкой
> порядка
> > 300-400 запросов в минуту.
> > Из статистики времени выполнения запросов видно, что в некоторых
> случаях
> > "быстрые" запросы, которые обычно занимают несколько миллисекунд,
> могут
> > выполняться по несколько секунд.
> > Для иллюстрации проблемы можно рассмотреть такой пример.
> >
> > Выполняется GET запрос "http://127.0.0.1:777/fcgi/auth..."(без ssl,
> без
> > поиска в dns, сервер слушает на localhost) с локального клиента(на
> том же
> > сервере).
> > Запрос, который обычно занимает меньше миллисекунды, в данном
> случае
> > занимает 130 миллисекунд.
> >
> > Здесь краткая хронология событий из tcpdump-а:
> > 16:18:43.095716 - клиент отправляет запрос nginx-у
> > 16:18:43.225903 - nginx отправляет запрос upstream-у
> > 16:18:43.226178 - upstream отвечает nginx-у
> > 16:18:43.226235 - nginx отвечает клиенту
> >
> > Таким образом upstream отвечает по запрос менее чем за миллисекунду,
> но 130
> > миллисекунд уходит на то чтобы прочесть клиентский запрос и
> переслать его в
> > upstream.
> > Такое же поведение наблюдается и при отдаче статики.
> >
> > Кто-нибудь сталкивался с подобными проблемами? В каком направлении
> можно
> > копать?
> >
> >
> > С уважением,
> > Юрий
> >
> >
> > <--nginx to client tcpdump--------------------->
> > 2014-08-15 16:18:43.095653 IP 127.0.0.1.17573 > 127.0.0.1.777: Flags
> [S],
> > seq 2328271692, win 65535, options [mss 16344,nop,wscale 6,sackOK,TS
> val
> > 2588746027 ecr 0], length 0
> > 2014-08-15 16:18:43.095673 IP 127.0.0.1.777 > 127.0.0.1.17573: Flags
> [S.],
> > seq 1912981495, ack 2328271693, win 65535, options [mss
> 16344,nop,wscale
> > 6,sackOK,TS val 858797424 ecr 2588746027], length 0
> > 2014-08-15 16:18:43.095687 IP 127.0.0.1.17573 > 127.0.0.1.777: Flags
> [.],
> > ack 1, win 1275, options [nop,nop,TS val 2588746027 ecr 858797424],
> length
> > 0
> > 2014-08-15 16:18:43.095716 IP 127.0.0.1.17573 > 127.0.0.1.777: Flags
> [P.],
> > seq 1:133, ack 1, win 1275, options [nop,nop,TS val 2588746027 ecr
> > 858797424], length 132
> > 2014-08-15 16:18:43.195641 IP 127.0.0.1.777 > 127.0.0.1.17573: Flags
> [.],
> > ack 133, win 1273, options [nop,nop,TS val 858797524 ecr
> 2588746027],
> > length
> > 0
> > 2014-08-15 16:18:43.226235 IP 127.0.0.1.777 > 127.0.0.1.17573: Flags
> [P.],
> > seq 1:250, ack 133, win 1275, options [nop,nop,TS val 858797554 ecr
> > 2588746027], length 249
> > 2014-08-15 16:18:43.226412 IP 127.0.0.1.17573 > 127.0.0.1.777: Flags
> [F.],
> > seq 133, ack 250, win 1275, options [nop,nop,TS val 2588746157 ecr
> > 858797554], length 0
> > 2014-08-15 16:18:43.226440 IP 127.0.0.1.777 > 127.0.0.1.17573: Flags
> [.],
> > ack 134, win 1275, options [nop,nop,TS val 858797554 ecr
> 2588746157],
> > length
> > 0
> > 2014-08-15 16:18:43.226450 IP 127.0.0.1.777 > 127.0.0.1.17573: Flags
> [F.],
> > seq 250, ack 134, win 1275, options [nop,nop,TS val 858797554 ecr
> > 2588746157], length 0
> > 2014-08-15 16:18:43.455652 IP 127.0.0.1.777 > 127.0.0.1.17573: Flags
> [F.],
> > seq 250, ack 134, win 1275, options [nop,nop,TS val 858797784 ecr
> > 2588746157], length 0
> > 2014-08-15 16:18:43.715642 IP 127.0.0.1.777 > 127.0.0.1.17573: Flags
> [F.],
> > seq 250, ack 134, win 1275, options [nop,nop,TS val 858798044 ecr
> > 2588746157], length 0
> > 2014-08-15 16:18:44.035649 IP 127.0.0.1.777 > 127.0.0.1.17573: Flags
> [F.],
> > seq 250, ack 134, win 1275, options [nop,nop,TS val 858798364 ecr
> > 2588746157], length 0
> > <------------------------------------------------------------->
> >
> > <--nginx to upstream tcpdump------------------->
> > 2014-08-15 16:18:43.225762 IP 127.0.0.1.17591 > 127.0.0.1.1300:
> Flags [S],
> > seq 1606422700, win 65535, options [mss 16344,nop,wscale 6,sackOK,TS
> val
> > 2588746157 ecr 0], length 0
> > 2014-08-15 16:18:43.225785 IP 127.0.0.1.1300 > 127.0.0.1.17591:
> Flags [S.],
> > seq 212542195, ack 1606422701, win 65535, options [mss
> 16344,nop,wscale
> > 6,sackOK,TS val 3738538996 ecr 2588746157], length 0
> > 2014-08-15 16:18:43.225793 IP 127.0.0.1.17591 > 127.0.0.1.1300:
> Flags [.],
> > ack 1, win 1275, options [nop,nop,TS val 2588746157 ecr 3738538996],
> length
> > 0
> > 2014-08-15 16:18:43.225903 IP 127.0.0.1.17591 > 127.0.0.1.1300:
> Flags [P.],
> > seq 1:577, ack 1, win 1275, options [nop,nop,TS val 2588746157 ecr
> > 3738538996], length 576
> > 2014-08-15 16:18:43.226178 IP 127.0.0.1.1300 > 127.0.0.1.17591:
> Flags [P.],
> > seq 1:121, ack 577, win 1275, options [nop,nop,TS val 3738538996
> ecr
> > 2588746157], length 120
> > 2014-08-15 16:18:43.226187 IP 127.0.0.1.1300 > 127.0.0.1.17591:
> Flags [F.],
> > seq 121, ack 577, win 1275, options [nop,nop,TS val 3738538996 ecr
> > 2588746157], length 0
> > 2014-08-15 16:18:43.226198 IP 127.0.0.1.17591 > 127.0.0.1.1300:
> Flags [.],
> > ack 122, win 1274, options [nop,nop,TS val 2588746157 ecr
> 3738538996],
> > length 0
> > 2014-08-15 16:18:43.226222 IP 127.0.0.1.17591 > 127.0.0.1.1300:
> Flags [F.],
> > seq 577, ack 122, win 1275, options [nop,nop,TS val 2588746157 ecr
> > 3738538996], length 0
> > 2014-08-15 16:18:43.455643 IP 127.0.0.1.17591 > 127.0.0.1.1300:
> Flags [F.],
> > seq 577, ack 122, win 1275, options [nop,nop,TS val 2588746387 ecr
> > 3738538996], length 0
> > 2014-08-15 16:18:43.455661 IP 127.0.0.1.1300 > 127.0.0.1.17591:
> Flags [R],
> > seq 212542317, win 0, length 0
> > <--------------------------------------------------->
> >
> > <--server info---------------------------------->
> > os: FreeBSD 9.2-RELEASE-p3
> > arch: amd64
> > number of cores: 48
> > ram merory size: 32GB
> > nginx verson: 1.6.0
> > nginx workers count: 32
> > <---------------------------------------------------->
> >
> > <---nginx.conf---------------------------------->
> > user datauser;
> > daemon off;
> > worker_processes 32;
> >
> > events
> > {
> > worker_connections 1024;
> > }
> >
> > http
> > {
> > include .../mime.types;
> >
> > gzip on;
> > gzip_http_version 1.0;
> > gzip_comp_level 2;
> > gzip_proxied any;
> > gzip_min_length 1100;
> > gzip_buffers 16 8k;
> > gzip_types text/plain text/css application/x-javascript
> text/xml
> > application/xml application/xml+rss text/javascript;
> > gzip_disable "MSIE [1-6].(?!.*SV1)";
> > gzip_vary on;
> >
> > client_max_body_size 65m;
> > client_body_buffer_size 128k;
> > client_body_temp_path /tmp/nginx/client_body_temp;
> > default_type application/octet-stream;
> > sendfile on;
> >
> > ...
> > upstreams
> > ...
> >
> > ...
> > servers
> > ...
> >
> > server
> > {
> > listen 127.0.0.1:777;
> >
> > location ~* ^/fcgi/(.*)$ {
> > fastcgi_pass 127.0.0.1:1300;
> > include fastcgi_params;
> > rewrite ^/fcgi/(.*)$ /$1 break;
> > }
> > }
> > <---------------------------------------------->
> >
> > Posted at Nginx Forum:
> > http://forum.nginx.org/read.php?21,252669,252669#msg-252669
> >
> > _______________________________________________
> > nginx-ru mailing list
> > nginx-ru@nginx.org
> > http://mailman.nginx.org/mailman/listinfo/nginx-ru
> _______________________________________________
> nginx-ru mailing list
> nginx-ru@nginx.org
> http://mailman.nginx.org/mailman/listinfo/nginx-ru