big difference between request time and upstreams time

Igor A. Ippolitov iippolitov at nginx.com
Tue May 8 16:22:26 UTC 2018


Ruslan,

This depends on your routing nginx configuration.
If doesn't have enough buffers to contain a response completely and 
temporary files are turned off, then you will run into a situation, when 
the delay is propagated from client facing nginx to a middle layer nginx.

The fact that only client facing requests are affected proves this idea.

On 08.05.2018 18:51, Руслан Закиров wrote:
>
>
> On Tue, May 8, 2018 at 3:11 PM, Igor A. Ippolitov 
> <iippolitov at nginx.com <mailto: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
>>     <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
>>>     <http://192.168.1.44:5002>]
>>>     14:27:50 1.017 [0.017] [0.001] [192.168.1.24:9000
>>>     <http://192.168.1.24:9000>]
>>>     14:27:51 1.522 [0.021] [0.000] [192.168.1.92:9000
>>>     <http://192.168.1.92:9000>]
>>>     14:27:50 1.019 [0.019] [0.000] [192.168.1.41:9000
>>>     <http://192.168.1.41:9000>]
>>>     14:27:52 1.019 [0.018] [0.000] [192.168.1.49:9000
>>>     <http://192.168.1.49:9000>]
>>>     14:27:52 1.019 [0.018] [0.001] [192.168.1.59:9000
>>>     <http://192.168.1.59:9000>]
>>>     14:27:55 1.515 [0.014] [0.000] [192.168.1.92:9000
>>>     <http://192.168.1.92:9000>]
>>>     14:27:57 0.510 [0.010] [0.001] [192.168.1.21:9000
>>>     <http://192.168.1.21:9000>]
>>>     14:28:03 1.521 [0.021] [0.001] [192.168.1.48:9000
>>>     <http://192.168.1.48:9000>]
>>>     14:28:04 0.660 [0.007] [0.002] [192.168.1.24:5002
>>>     <http://192.168.1.24:5002>]
>>>     14:28:05 2.216 [0.018] [0.002] [192.168.1.44:5002
>>>     <http://192.168.1.44:5002>]
>>>     14:28:11 0.510 [0.010] [0.000] [192.168.1.49:9000
>>>     <http://192.168.1.49:9000>]
>>>     14:28:26 0.937 [0.008] [0.002] [192.168.1.92:5002
>>>     <http://192.168.1.92:5002>]
>>>     14:28:28 1.019 [0.019] [0.000] [192.168.1.49:9000
>>>     <http://192.168.1.49:9000>]
>>>     14:28:28 0.508 [0.007] [0.000] [192.168.1.42:9000
>>>     <http://192.168.1.42:9000>]
>>>     14:28:31 1.021 [0.019] [0.000] [192.168.1.44:9000
>>>     <http://192.168.1.44:9000>]
>>>     14:28:32 0.509 [0.008] [0.000] [192.168.1.48:9000
>>>     <http://192.168.1.48:9000>]
>>>     14:28:36 1.015 [0.015] [0.000] [192.168.1.43:9000
>>>     <http://192.168.1.43:9000>]
>>>     14:28:39 0.358 [0.007] [0.001] [192.168.1.92:5002
>>>     <http://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 list
>>>     nginx at nginx.org <mailto:nginx at nginx.org>
>>>     http://mailman.nginx.org/mailman/listinfo/nginx
>>>     <http://mailman.nginx.org/mailman/listinfo/nginx>
>>
>>
>>
>>
>>     _______________________________________________
>>     nginx mailing list
>>     nginx at nginx.org <mailto:nginx at nginx.org>
>>     http://mailman.nginx.org/mailman/listinfo/nginx
>>     <http://mailman.nginx.org/mailman/listinfo/nginx>
>
>
>
>     _______________________________________________
>     nginx mailing list
>     nginx at nginx.org <mailto:nginx at nginx.org>
>     http://mailman.nginx.org/mailman/listinfo/nginx
>     <http://mailman.nginx.org/mailman/listinfo/nginx>
>
>
>
>
> -- 
> Руслан Закиров
> Руководитель отдела разработки веб-сервисов
> +7(916) 597-92-69, ruz @ <http://www.sports.ru/>
>
>
> _______________________________________________
> nginx mailing list
> nginx at nginx.org
> http://mailman.nginx.org/mailman/listinfo/nginx


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx/attachments/20180508/6766995d/attachment.html>


More information about the nginx mailing list