<div dir="ltr"><br><div class="gmail_extra"><br><div class="gmail_quote">On Mon, Jan 9, 2017 at 6:14 PM, Maxim Dounin <span dir="ltr"><<a href="mailto:mdounin@mdounin.ru" target="_blank">mdounin@mdounin.ru</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Hello!<br>
<span class=""><br>
On Sun, Jan 08, 2017 at 05:04:47PM +0300, Руслан Закиров wrote:<br>
<br>
> Hello,<br>
><br>
> nginx 1.10.2 [1] running on FreeBSD 10.3-RELEASE-p7<br>
><br>
> We have quite a lot of "upstream timed out" errors. For example:<br>
><br>
> 2017/01/08 16:20:54 [error] 82154#0: *494223064 upstream timed out (60:<br>
> Operation timed out) while connecting to upstream, client: 192.168.1.43,<br>
> server: <a href="http://q0.sports.ru" rel="noreferrer" target="_blank">q0.sports.ru</a>, request: "POST /pub?topic=docs HTTP/1.1", upstream: "<br>
> <a href="http://192.168.1.206:4151/pub?topic=docs" rel="noreferrer" target="_blank">http://192.168.1.206:4151/pub?<wbr>topic=docs</a>", host: "<a href="http://q0.sports.ru" rel="noreferrer" target="_blank">q0.sports.ru</a>"<br>
> Here is tcpdump:<br>
><br>
> 16:20:53.218916 IP myself-fe.28957 > q0-2.4151: Flags [S], seq 2479999411,<br>
> win 65535, options [mss 1460,nop,wscale 6,sackOK,TS val 787079162 ecr 0],<br>
> length 0<br>
> 16:20:53.219721 IP q0-2.4151 > myself-fe.28957: Flags [S.], seq 605231398,<br>
> ack 2479999412, win 28960, options [mss 1460,sackOK,TS val 352522447 ecr<br>
> 787079162,nop,wscale 7], length 0<br>
> 16:20:53.219742 IP myself-fe.28957 > q0-2.4151: Flags [.], ack 1, win 1040,<br>
> options [nop,nop,TS val 787079163 ecr 352522447], length 0<br>
> 16:20:54.572712 IP myself-fe.28957 > q0-2.4151: Flags [F.], seq 1, ack 1,<br>
> win 1040, options [nop,nop,TS val 787080516 ecr 352522447], length 0<br>
> 16:20:54.573173 IP q0-2.4151 > myself-fe.28957: Flags [F.], seq 1, ack 2,<br>
> win 227, options [nop,nop,TS val 352522786 ecr 787080516], length 0<br>
> 16:20:54.573195 IP myself-fe.28957 > q0-2.4151: Flags [.], ack 2, win 1040,<br>
> options [nop,nop,TS val 787080516 ecr 352522786], length 0<br>
><br>
> What I don't see here is a packet with HTTP request.<br>
<br>
</span>The "upstream timeout ... while connecting to upstream" suggests<br>
that nginx wasn't able to see the connect event.<br>
<br>
[...]<br></blockquote><div><br></div><div>Ok, spent whole day learning and investigating.</div><div><br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><span class="">
> Any idea where I should look next?<br>
<br>
</span>Some things to consider:<br>
<br>
- Make sure you are looking at tcpdump on the nginx host, and<br>
  there are no firewalls on the host to interfere with.<br></blockquote><div><br></div><div>These were tcpdumps from nginx host. I have dump from other end and they</div><div>are symmetrical. We have proxy_connect_timeout at 300ms at the top level of</div><div>the config. When we first started to investigate it we increased timeout to 1s for</div><div>this location. An hour ago I increased it to 5 seconds and finally couldn't reproduce</div><div>the problem with a simple "bomber" script.</div><div><br></div><div>From dumps you can see that connection was established within 10ms. What can stop nginx from receiving the event for more than a second?</div><div><br></div><div>This happens on all served domains as pretty much everywhere connect timeout is 300ms. If I tail -F error log, count this error occurrences grouped by second then I see 1-3 seconds spikes: silence or <5 errors for 20-40 seconds then ~200 errors in a few seconds. Is there anything that may block events processing nginx for quite a while?</div><div><br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
- Try collecting nginx debug logs, they should have enough<br>
  information to see if the event was reported by the kernel or<br>
  not.<br></blockquote><div><br></div><div>As you can see from above it is reported by the kernel, but with quite big delay. Not sure if delay is in kernel or nginx, no delay on the network.</div><div><br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><span class="">
> Is it some known issue?<br>
<br>
</span>No.</blockquote><div> <br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<span class="HOEnZb"><font color="#888888"><br>
--<br>
Maxim Dounin<br>
<a href="http://nginx.org/" rel="noreferrer" target="_blank">http://nginx.org/</a><br>
______________________________<wbr>_________________<br>
nginx mailing list<br>
<a href="mailto:nginx@nginx.org">nginx@nginx.org</a><br>
<a href="http://mailman.nginx.org/mailman/listinfo/nginx" rel="noreferrer" target="_blank">http://mailman.nginx.org/<wbr>mailman/listinfo/nginx</a></font></span></blockquote></div><br><br clear="all"><div><br></div>-- <br><div class="gmail_signature" data-smartmail="gmail_signature"><div dir="ltr"><div>Руслан Закиров</div><div>Руководитель отдела разработки веб-сервисов</div><div><span>+7(916) 597-92-69</span>, <span>ruz @ <a href="http://www.sports.ru/" target="_blank"><img src="http://farm7.static.flickr.com/6235/6210250811_19a888dbba_o.jpg" width="43" height="14" style="vertical-align:bottom;margin-right:0px"></a></span></div></div></div>
</div></div>