1. 1
  2. 2
  3. 3
  4. 4
  5. 5

# теория · шаг 1 из 5

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

Коротко

Первый вопрос инцидента - кто ответил: бэкенд или nginx вместо него. Отвечает $upstream_status, но не так, как обычно пишут: прочерк там стоит, только если похода к бэкенду не было вовсе; отказ в соединении даёт 502 прямо в этой переменной вместе с адресом. Дальше коды читаются буквально: 502 - соединения не было или ответ негоден, 504 - не дождались, 503 - твой лимит, 499 - ушёл клиент, 500 - у nginx кончились слоты соединений. Строки error_log называют причину дословно, но текст системной ошибки зависит от библиотеки.

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

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

↳  вывод/var/log/nginx/access.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.

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

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

строка лога ups_status пуст ответил сам nginx ups_status заполнен поход к бэкенду был 502 в ups_status ставит сам nginx: соединения не было
Прочерк означает «никуда не ходили», а не «не дошли»

Правило

/etc/nginx/nginx.confhttp
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, читаемые буквально

↳  вывод/var/log/nginx/error.log
connect() failed (111: Connection refused) while connecting to upstream

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

↳  вывод/var/log/nginx/error.log
upstream timed out (110: Operation timed out) while reading response header

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

↳  вывод/var/log/nginx/error.log
upstream sent too big header while reading response header from upstream

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

↳  вывод/var/log/nginx/error.log
[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 за минуту отделяет медленный бэкенд от медленного клиента.

Комментарии

Пока нет комментариев. Будь первым!

Оставить комментарий

Комментарий появится после проверки. Email не публикуется. Войти, чтобы не вводить имя каждый раз.