Симптом, причина, строка в логе

Коды знаешь наизусть - листай до «Что ломается без этого»: там про поломки, которых в кодах ответа не видно.

Три строки одного лога. По какой из них видно, что до бэкенда дело не дошло?

200 ups_status=[200] ups_addr=[172.25.0.2:9000]
502 ups_status=[502] ups_addr=[127.0.0.1:9]
200 ups_status=[-]   ups_addr=[-]

Ответ неочевиден: не по второй. Там 502 и адрес - соединение пытались открыть, и это записано. Прочерк стоит в третьей строке, где nginx ответил сам и никуда не ходил.

На что это похоже

Разбор инцидента похож на разговор с диспетчером: прежде чем обсуждать, что случилось у мастера, надо выяснить, доехал ли он вообще. Половина времени теряется именно здесь - разработчиков будят из-за ошибки, которая произошла до того, как запрос покинул nginx.

Поэтому первый вопрос всегда один и тот же: кто ответил. И ответ на него уже лежит в логе - если формат лога придуман заранее, а не в момент аварии.

Механизм: кто ответил на запрос

Правило

log_format timing '$status ups_status=[$upstream_status] ups_addr=[$upstream_addr] '
                  'rt=$request_time urt=[$upstream_response_time] "$request"';

no live upstreams - это 502, а не 503: группа пуста, соединяться не с чем. Путаница возникает потому, что 503 отдают лимиты, и оба кода приходят из одного слова «недоступно».

Разбор: прочерк против 502 в upstream_status

Расхожая формулировка «$upstream_status пуст, если до бэкенда дело не дошло» неточна, и неточность стоит времени. Замер по трём маршрутам одного конфига:

Последняя строка - замер на 1.31.8: проксирование настроено, но идти к бэкенду не понадобилось. Правильная формулировка: прочерк означает, что к бэкенду не обращались - ответил return, статика, лимит, кеш или error_page без обращения к бэкенду. Как только nginx попробовал соединиться, в переменной появляется код, который он сам и назначил.

Практическое следствие: строка 502 ups_status=[502] - это не обязательно «бэкенд ответил 502»: точно так же выглядит «nginx не смог получить ответ». Отличить одно от другого можно по error_log: у настоящего 502 от приложения там ничего не будет.

Разбор: строки error_log, читаемые буквально

connect() failed (111: Connection refused) while connecting to upstream

Порт не слушает: процесс не поднялся, упал или слушает другой адрес. Самая частая причина 502 и самая быстрая в проверке - ss -ltnp.

upstream timed out (110: Operation timed out) while reading response header

Соединение есть, ответа нет: бэкенд занят, а не мёртв. Хвост строки важен: со словом header ошибка случилась, пока заголовки ответа ещё не получены целиком, и клиент получит 504. Та же строка без слова header означает, что код ответа клиенту уже ушёл, - тогда в access_log будет этот код, обычно 200, с обрезанным телом (шестой раздел).

upstream sent too big header while reading response header from upstream

Заголовки не влезли в proxy_buffer_size. Классика после жирного Set-Cookie или длинного JWT (токена авторизации, который клиент носит в заголовке): часть страниц работает, а личный кабинет отдаёт 502.

[alert] 10#10: *10 4 worker_connections are not enough while connecting to upstream

Слота не нашлось при подключении к бэкенду - в счёт входят и такие соединения, поэтому реальный запас вдвое меньше настроенного. Родственная строка на уровне warn с хвостом reusing connections означает противоположное: nginx закрыл простаивающие keepalive и справился.

Что ломается без этого

Обрыв после заголовков не виден в кодах ответа вовсе. Если бэкенд отдал заголовки и оборвался, клиент получает 200 и обрезанное тело, а в access_log кода ошибки нет. Мониторинг «доля 5xx» такой класс поломок не ловит; ловят его расхождение $body_bytes_sent с обещанным размером и строки в error_log.

Отброшенные соединения не пишутся в лог совсем. Когда слоты кончились, запроса не случилось - значит и строки в access_log нет. Единственные следы - accepts против handled в stub_status и [alert] в error_log.

Текст системной ошибки зависит от библиотеки. Один и тот же таймаут: на alpine (110: Operation timed out), на debian (110: Connection timed out). Занятый порт: (98: Address in use) против (98: Address already in use). Номер одинаков всегда - искать надо по номеру, иначе grep из чужой статьи не находит ничего, и рождается вывод «у нас другая проблема».

Зачем это в работе

Четыре правила, которых хватает, чтобы за минуту отделить «чинить nginx» от «будить разработчиков»:

• $request_time большой, $upstream_response_time маленький - тормозит не бэкенд: медленный клиент, огромный ответ, узкий канал или очередь limit_req;
• обе большие - тормозит приложение;
• в $upstream_addr несколько адресов через запятую - были повторы на другие узлы, то есть первый отказал;
• $upstream_status пуст - к бэкенду в этом запросе не ходили: ответил return, статика, лимит или кеш, смотреть конфиг nginx и кеш.

Отдельная категория - инциденты без единой строки в error_log: старые данные у части пользователей (ключ кеша), неработающая загрузка больших файлов (413 видно только в браузере), сломанный WebSocket (в логе обычный 200), отвалившиеся картинки на поддомене (сертификат не покрывает имя). Для них нужен не лог, а воспроизведение с параметрами пострадавшего: тот же Host, тот же метод, то же тело.

Теперь сам

В логе всплеск строк вида 502 ups_status=[502] ups_addr=[10.0.0.7:8000, 10.0.0.8:8000] rt=3.1. Что здесь произошло и в каком порядке смотреть?