# теория · шаг 1 из 5
Симптом, причина, строка в логе
Коротко
Первый вопрос инцидента - кто ответил: бэкенд или nginx вместо него. Отвечает
$upstream_status, но не так, как обычно пишут: прочерк там стоит, только если
похода к бэкенду не было вовсе; отказ в соединении даёт 502 прямо в этой
переменной вместе с адресом. Дальше коды читаются буквально: 502 - соединения
не было или ответ негоден, 504 - не дождались, 503 - твой лимит, 499 - ушёл
клиент, 500 - у nginx кончились слоты соединений. Строки error_log называют
причину дословно, но текст системной ошибки зависит от библиотеки.
Коды знаешь наизусть - листай до «Что ломается без этого»: там про поломки, которых в кодах ответа не видно.
Три строки одного лога. По какой из них видно, что до бэкенда дело не дошло?
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"';
| Код | Что произошло | Куда смотреть |
|---|---|---|
| 502 | соединения не было либо ответ негоден; сюда же no live upstreams |
жив ли процесс, error_log со словом upstream |
| 504 | бэкенд принял запрос и не ответил вовремя | proxy_read_timeout, медленные запросы приложения |
| 503 | сработал твой limit_req или limit_conn |
зоны лимитов, строка limiting requests |
| 500 | кончились слоты worker_connections либо ошибка в конфиге фазы |
[alert] в error_log |
| 499 | клиент ушёл, не дождавшись | $upstream_response_time - стало медленно |
| 413 | тело больше client_max_body_size |
загрузка файлов |
| 414 / 400 | длинный URI или заголовок | large_client_header_buffers |
no live upstreams - это 502, а не 503: группа пуста, соединяться не с
чем. Путаница возникает потому, что 503 отдают лимиты, и оба кода приходят из
одного слова «недоступно».
Разбор: прочерк против 502 в upstream_status
Расхожая формулировка «$upstream_status пуст, если до бэкенда дело не дошло»
неточна, и неточность стоит времени. Замер по трём маршрутам одного конфига:
| маршрут | $status |
$upstream_status |
$upstream_addr |
|---|---|---|---|
| прокси к живому бэкенду | 200 | 200 |
172.25.0.2:9000 |
| прокси к закрытому порту | 502 | 502 |
127.0.0.1:9 |
return 200 без прокси |
200 | - |
- |
Правильная формулировка: прочерк означает, что обработчик апстрима не
запускался - ответил 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маленький - тормозит не бэкенд: медленный клиент, огромный ответ, узкий канал;- обе большие - тормозит приложение;
- в
$upstream_addrнесколько адресов через запятую - были повторы на другие узлы, то есть первый отказал; $upstream_statusпуст - до похода к бэкенду не дошло, причина внутри 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. Что здесь произошло и в каком порядке смотреть?
Ответ: два адреса через запятую означают, что запрос повторили на второй узел
после отказа первого, и оба не ответили - это proxy_next_upstream в работе.
ups_status=[502] при этом поставил сам nginx, значит ответа от приложения не
было ни от одного узла. Смотреть: error_log рядом по времени - там будет
connect() failed (порт не слушает) или upstream timed out (занят); затем
жив ли процесс приложения на обоих узлах; и только потом - не слишком ли
строгие max_fails, из-за которых узлы могли быть выключены после единичных
таймаутов. Три секунды в rt при этом подсказывают, что время ушло на попытки
соединиться, а не на ожидание ответа.
Главное
Сначала определи, кто ответил. $upstream_status пуст только когда похода к
бэкенду не было (ответил return, статика, лимит, error_page); отказ в
соединении даёт там 502 вместе с адресом. 502 - соединения не было или ответ
негоден (сюда же no live upstreams), 504 - не дождались ответа, 503 - твои
лимиты, 500 - кончились слоты worker_connections, 499 - ушёл клиент. Строки
error_log читаются буквально, но хвост важен: while reading response header
значит «до кода ответа», без слова header - «код уже ушёл, тело обрезано», и
такой инцидент в кодах ответа не виден. Текст системной ошибки различается
между libc - ищи по номеру. Пара $request_time и $upstream_response_time за
минуту отделяет медленный бэкенд от медленного клиента.
Комментарии
Пока нет комментариев. Будь первым!
Оставить комментарий