Конспект раздела: логи и отладка

Раздел про то, как узнать, что произошло на самом деле, вместо того чтобы гадать по конфигу.

Два лога и разделение труда

access_log  →  ЧТО происходило: коды, время, объёмы, кто и куда. Пишется ПОСЛЕ ответа.
error_log   →  ПОЧЕМУ не получилось: причина строкой. Пишется по ходу дела.

Разбор начинается с кода в access_log и заканчивается причиной в error_log. Между ними стоит фильтр по уровню, и он решает, будет ли вторая половина вообще записана:

debug  info  notice  |  warn  error  crit  alert  emerg
       ↑ здесь 400 и 499     ↑ типовая черта

Свой формат лога окупается сразу

log_format main escape=json '{"time":"$time_iso8601","status":$status,'
    '"uri":"$request_uri","rt":$request_time,"urt":"$upstream_response_time",'
    '"us":"$upstream_status","cache":"$upstream_cache_status",'
    '"id":"$request_id","ip":"$remote_addr"}';

Что добавили	Что теперь видно
`$request_time` + `$upstream_response_time`	тормозит бэкенд или отдача клиенту
`$upstream_status` + `$upstream_addr`	кто ответил, каким кодом, с какой попытки
`$upstream_cache_status`	работает ли кеш вообще
`$request_id`	связать nginx и лог приложения по одному запросу

Все upstream-поля - в кавычках: без них строка ломается на каждом запросе, который не ушёл на бэкенд.

Дерево решений при разборе

код в access_log
├─ upstream = «-»           → решение принял nginx, смотри его конфиг
│   ├─ 413 → client_max_body_size (умолчание 1 МБ)
│   ├─ 403 → строка: нет прав / нет index / deny
│   ├─ 404 → путь в кавычках: как сложились root и alias
│   └─ 400 → уровень info: длинный заголовок или нет Host
└─ upstream = адрес         → запрос дошёл
    ├─ us = код бэкенда      → разбираться в приложении
    ├─ us = «-», код 502/504 → бэкенд не ответил, причина в error_log
    ├─ запятая в полях       → была повторная попытка
    └─ код 200, тело короче обещанного → обрыв ПОСЛЕ заголовков

Карта «код → куда смотреть»

Код	Первое подозрение
404	путь в кавычках в `error_log`: как сложились root/alias
403	одна из трёх причин - смотреть строку
413	`client_max_body_size` в нужном location
499	клиент ушёл: смотреть время ответа бэкенда
502	бэкенд не слушает, умер до заголовков, слишком большой заголовок
503	свои же лимиты: `limiting requests` в `error_log`
504	таймаут; этап написан в строке
500	цикл `rewrite`/`try_files` либо ошибка самого бэкенда

Команды раздела

$ команда

nginx -T | grep -E "access_log|error_log"
tail -f /var/log/nginx/error.log
tail -n 10000 access.log | awk '{print $9}' | sort | uniq -c | sort -rn
grep "upstream timed out" error.log | tail

Чек-лист: что ты должен уметь объяснить

Чем $request_time отличается от $upstream_response_time и что означает большая разница.
Почему при уровне warn половина причин в error_log не пишется и какие именно.
Почему $remote_addr за CDN бесполезен и что с этим делать.
Три причины 403 и как отличить их друг от друга.
Что означает 499 и почему это не проблема nginx.
Почему обрыв ответа после заголовков не даёт 502 и как его тогда заметить.
Зачем нужен $request_id и как он связывает два лога.