<div dir="ltr"><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"> Это совсем не похоже на таймаут. Возможно, перепутаны коннекции в дампе,<br>
 проверьте номера портов и tcp seq<br><br> А это похоже на таймаут коннекта. Вопрос в том, почему SYN+ACK от бэкенда<br>
 пришёл с такой задержкой. Возможно, бэкенд перегружен.<br>
 Возможно, свитчи по пути перегружены трафиком.</blockquote><div class="gmail_extra"><br>Дампы:<br>RST: <a href="https://ufile.io/09s7w">https://ufile.io/09s7w</a><br>FIN: <a href="https://ufile.io/0bkq5">https://ufile.io/0bkq5</a><br><span class="gmail-"><br>это вот эти два запроса<br>2017/06/15
 13:12:43 [error] 8449#8449: *729923 upstream timed out (110: Connection
 timed out) while connecting to upstream, client: 128.74.129.198, 
server: site, request: "GET /api/v1/product/58a2ed54d53f3d224a6b05c5 
HTTP/1.1", upstream: "fastcgi://<a href="http://217.69.137.168:8080">217.69.137.168:8080</a>", host: "api.site"<br>2017/06/15
 13:12:43 [error] 8471#8471: *734373 upstream timed out (110: Connection
 timed out) while connecting to upstream, client: 31.173.243.12, server:
 site, request: "GET 
/api/v1/counters/5730243396ad843510595f43?adv_id=D5D4F8D7-DEB7-4FE0-807E-143651398124&app_id=iphone%2F3782&timestamp=1497521562&uid=uid&usr_latitude=55.0252283782156&usr_longitude=82.93059721079625
 HTTP/1.1", upstream: "fastcgi://<a href="http://217.69.137.73:8080">217.69.137.73:8080</a>", host: "api.site"</span><br><br></div><div class="gmail_extra"><span class="gmail-">rtt порядка 1-2 миллисекунд, таймаут 300 миллисекунд. Время до посылки FIN и RST это величина до десятков миллисекунд. Я ожидал увидеть RST через ~ 300 миллисекунд.<br></span></div><div class="gmail_extra"><span class="gmail-">Возможно  с RST это вторая попытка отправить пакет через RTO + некоторое время, но из debug log nginx я не понял сколько было попыток, вроде одна. FIN объяснить не могу</span>. Так как запросов мало, примерно один запрос на один ip:port в секунду, то проблемые сессии легко видны в tcpdump. <br></div><div class="gmail_extra"><br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Возможно, бэкенд перегружен.<br>
Возможно, свитчи по пути перегружены трафиком. Бэкенд создал 50% от max кол-ва воркеров, там динамический пул. По остальным ресурсам тоже ок.<br><br></blockquote></div><div class="gmail_extra">Сеть на портах загружена на 5-7%, за всю сеть не скажу, но хосты раскиданы по трем ДЦ ~ хаотично и закономерности я не вижу.<br></div><div class="gmail_extra">Если бы воспроизводилась в одном месте, то я бы видел максимумы ошибок, связанные с одним хостом/дц. Ситуация была бы и на других проектах, но пока такого не замечали.<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><blockquote><span class="gmail-">
> Не понятно почему при настройке nginx fastcgi_connect_timeout 300ms; в логе</span><br><span class="gmail-">
> вижу upstream_response_time: 0.677 секунды. Есть этому объяснение?</span><br><span class="gmail-">
</span><br><span class="gmail-">
</span> Коннект это одно, а ожидание ответа бэкенда ПОСЛЕ завершения коннекта<br>
 это другое. Можно сконнектиться, послать запрос и долго ждать ответа.</blockquote></blockquote></div><div class="gmail_extra">Можно, но это в моем понимание будет уже таймаут на получение ответа после установления соединения и он равен ~ 2 мин.<br></div><div class="gmail_extra">Разве в это поле не должен подставиться +- таймаут, ведь код ответа уже есть?<br></div><div class="gmail_extra"><br><div><div class="gmail_signature"><div dir="ltr">Александр<br></div></div></div>
<br><div class="gmail_quote">15 июня 2017 г., 18:13 пользователь Evgeniy Berdnikov <span dir="ltr"><<a href="mailto:bgx@protva.ru" target="_blank">bgx@protva.ru</a>></span> написал:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><span class="gmail-">On Thu, Jun 15, 2017 at 05:21:38PM +0300, Алексанр Платонов wrote:<br>
> У меня есть ~30 хостов в 3-х разных ДЦ. Nginx принимает нагрузку и<br>
> распределяет её по алгоритму WRR на php-fpm пулы, расположенные на этих же<br>
> хостах.<br>
><br>
> Периодически, примерно 1/5000 (ошибка к общему кол-ву запросов)  на<br>
> случайном хосте получает ошибку:<br>
> front14 2017/06/15 15:37:40 [error] 13063#13063: *2446289 upstream timed<br>
> out (110: Connection timed out) while connecting to upstream, client:<br>
> 217.69.135.0, server: site, request: "GET<br>
> /files/images/1284_1284/58/b4/<wbr>58b455be4b559395714059e5.jpg<br>
> HTTP/1.0", upstream: "fastcgi://<a href="http://217.69.137.52:8081" rel="noreferrer" target="_blank">217.69.137.52:8081</a>"<wbr>, host: "site"<br>
><br>
> после получения ошибки nginx проксирует запрос на другой сервер и там все<br>
> отрабатывает нормально.<br>
><br>
> front14 217.69.135.0 - - [15/Jun/2017:15:37:41 +0300] "GET<br>
> /files/images/1284_1284/58/b4/<wbr>58b455be4b559395714059e5.jpg HTTP/1.0" 200<br>
> 139517 "-" "okhttp/3.4.1" "-" request_time: 1.660 upstream_addr:<br>
> <a href="http://217.69.137.52:8081" rel="noreferrer" target="_blank">217.69.137.52:8081</a>, <a href="http://217.69.137.51:8081" rel="noreferrer" target="_blank">217.69.137.51:8081</a> upstream_response_time: 0.677, 0.981<br>
> upstream_status: 504, 200 upstream_cache_status: - "tid:"<br>
> 13063-1497530259.494-217.69.<wbr>135.0-163-2446289<br>
</span>...<br>
<span class="gmail-">> Снимал несколько раз tcpdump и наблюдал следующую картину:<br>
> 1) хост с nginx послылает FIN на бэкенд сразу после своего же ACK бэкенду<br>
> через 13ms, не пересылая данные вообще.<br>
<br>
</span> Это совсем не похоже на таймаут. Возможно, перепутаны коннекции в дампе,<br>
 проверьте номера портов и tcp seq<br><br><span class="gmail-"><br>
> 2) хост с nginx посылает RST через 10 мкс после получения SYN, ACK от<br>
> бэкенда и через ~ 780 мкс от своего SYN.<br>
<br>
</span> А это похоже на таймаут коннекта. Вопрос в том, почему SYN+ACK от бэкенда<br>
 пришёл с такой задержкой. Возможно, бэкенд перегружен.<br>
 Возможно, свитчи по пути перегружены трафиком.<br>
<span class="gmail-"><br>
> Не понятно почему при настройке nginx fastcgi_connect_timeout 300ms; в логе<br>
> вижу upstream_response_time: 0.677 секунды. Есть этому объяснение?<br>
<br>
</span> Коннект это одно, а ожидание ответа бэкенда ПОСЛЕ завершения коннекта<br>
 это другое. Можно сконнектиться, послать запрос и долго ждать ответа.<br>
<span class="gmail-HOEnZb"><font color="#888888">--<br>
 Eugene Berdnikov<br>
</font></span><div class="gmail-HOEnZb"><div class="gmail-h5">______________________________<wbr>_________________<br>
nginx-ru mailing list<br>
<a href="mailto:nginx-ru@nginx.org">nginx-ru@nginx.org</a><br>
<a href="http://mailman.nginx.org/mailman/listinfo/nginx-ru" rel="noreferrer" target="_blank">http://mailman.nginx.org/<wbr>mailman/listinfo/nginx-ru</a></div></div></blockquote></div><br></div></div>