big difference between request time and upstreams time

[Руслан Закиров]

On Tue, May 8, 2018 at 3:11 PM, Igor A. Ippolitov <iippolitov at nginx.com>
wrote:

> Sorry, didn't realize this is an English mailing list.
>
> To sum it up: the problem is most likely about clients and not the server.
> Discrepancy between request time and upstream time usually means that a
> client is slow or uses a bad connection.
> Basically, this is OK unless you have the only server out of many with
> this problem.
> This in turn may mean that the problem is with that server's network
> connection.
>


The issue affects all of our primary nginx servers.

However, they receive requests from 4 "routing" nginx servers and all
backends via haproxy. The problem affects only
requests from the routing nginxs, not backends. I would expect routing
servers pull data from upstream ASAP. So slow
clients in my mind should only affect those routing servers standing in
front.

Am I wrong?


> Regards.
>
>
> On 08.05.2018 14:50, Igor A. Ippolitov wrote:
>
> Можно я отвечу ссылкой? http://mailman.nginx.org/
> pipermail/nginx/2008-October/008025.html
> Проблема, скорее всего, в клиентах.
>
> On 08.05.2018 14:43, Руслан Закиров wrote:
>
> Hello,
>
> Some selected log records:
> 14:27:46 1.609 [0.013] [0.002] [192.168.1.44:5002]
> 14:27:50 1.017 [0.017] [0.001] [192.168.1.24:9000]
> 14:27:51 1.522 [0.021] [0.000] [192.168.1.92:9000]
> 14:27:50 1.019 [0.019] [0.000] [192.168.1.41:9000]
> 14:27:52 1.019 [0.018] [0.000] [192.168.1.49:9000]
> 14:27:52 1.019 [0.018] [0.001] [192.168.1.59:9000]
> 14:27:55 1.515 [0.014] [0.000] [192.168.1.92:9000]
> 14:27:57 0.510 [0.010] [0.001] [192.168.1.21:9000]
> 14:28:03 1.521 [0.021] [0.001] [192.168.1.48:9000]
> 14:28:04 0.660 [0.007] [0.002] [192.168.1.24:5002]
> 14:28:05 2.216 [0.018] [0.002] [192.168.1.44:5002]
> 14:28:11 0.510 [0.010] [0.000] [192.168.1.49:9000]
> 14:28:26 0.937 [0.008] [0.002] [192.168.1.92:5002]
> 14:28:28 1.019 [0.019] [0.000] [192.168.1.49:9000]
> 14:28:28 0.508 [0.007] [0.000] [192.168.1.42:9000]
> 14:28:31 1.021 [0.019] [0.000] [192.168.1.44:9000]
> 14:28:32 0.509 [0.008] [0.000] [192.168.1.48:9000]
> 14:28:36 1.015 [0.015] [0.000] [192.168.1.43:9000]
> 14:28:39 0.358 [0.007] [0.001] [192.168.1.92:5002]
>
> columns: wallclock time, request time, upstream_request_time,
> upstream_connect_time, upstream.
>
> Please, help me diagnose this problem further as I stuck. This is subset
> where request_time 50x bigger than upstream_request_time (just to make
> subset less noisy). I see request times up to 60 seconds. Can not tie it to
> some periodicity. It happens so often that don't see anything helpful in
> strace... I stuck... Any ideas?
>
> This is nginx/1.10.2 on FreeBSD 10.3-RELEASE-p7.
>
> --
> Руслан Закиров
> Руководитель отдела разработки веб-сервисов
> +7(916) 597-92-69, ruz @  <http://www.sports.ru/>
>
>
> _______________________________________________
> nginx mailing listnginx at nginx.orghttp://mailman.nginx.org/mailman/listinfo/nginx
>
>
>
>
> _______________________________________________
> nginx mailing listnginx at nginx.orghttp://mailman.nginx.org/mailman/listinfo/nginx
>
>
>
> _______________________________________________
> nginx mailing list
> nginx at nginx.org
> http://mailman.nginx.org/mailman/listinfo/nginx
>



-- 
Руслан Закиров
Руководитель отдела разработки веб-сервисов
+7(916) 597-92-69, ruz @  <http://www.sports.ru/>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx/attachments/20180508/83d48218/attachment-0001.html>