Падает прод. 502 сыпятся, пользователи орут, дашборд красный. Ты заходишь на шлюз и смотришь access.log. И видишь combined-формат образца 2004 года:
Код: Выделить всё
10.0.0.7 - - [17/Jun/2026:11:42:03 +0300] "POST /api/checkout HTTP/1.1" 502 167 "-" "okhttp/4.12"
Логирование - это не "включил и забыл", это твои глаза в проде. Хороший access_log отвечает на вопрос "что именно сейчас сломалось" за секунды, плохой - заставляет гадать. В этом уроке разберем nginx логирование по-взрослому: как устроены log_format и переменные, почему json логи победили текст, что обязательно класть в каждую строку, как не логировать мусор, как ротировать без потери данных и где спрятана грабля производительности, которая роняет latency под нагрузкой.
Как работает access_log и log_format: механика
Две директивы - фундамент. log_format описывает шаблон строки (что и в каком порядке писать), access_log говорит "пиши вот этим форматом вот сюда". Формат именованный, форматов может быть несколько, access_log на них ссылается по имени.
Полный синтаксис access_log важно знать целиком, потому что половина магии в опциональных параметрах:
Код: Выделить всё
access_log path [format [buffer=size] [gzip[=level]] [flush=time] [if=condition]];
Переменные - сердце формата. Их сотни, но рабочий минимум такой:
- $remote_addr - IP клиента (внимание: без модуля realip это IP ближайшего прокси, об этом ниже)
- $request - метод, URI и протокол одной строкой; чаще лучше разбить на $request_method, $uri, $server_protocol
- $status - HTTP-статус, который nginx отдал клиенту
- $body_bytes_sent - байты тела ответа
- $request_time - полное время обработки запроса nginx в секундах с миллисекундами
- $http_user_agent, $http_referer - заголовки клиента (любой заголовок доступен как $http_имя_заголовка с нижним подчеркиванием)
- $upstream_addr - адрес бэкенда, к которому реально ходили (при failover тут будет список через запятую)
- $upstream_status - статус ОТ бэкенда (может отличаться от $status, если nginx переписал, например отдал свою страницу ошибки)
- $upstream_response_time - сколько секунд бэкенд отвечал
- $upstream_connect_time, $upstream_header_time - время TCP-коннекта и время до первых заголовков (TTFB бэкенда)
- $upstream_cache_status - HIT/MISS/BYPASS/EXPIRED/STALE, статус кэша
Код: Выделить всё
log_format upstream_detail
'$remote_addr [$time_iso8601] "$request_method $uri $server_protocol" '
'$status req=$request_time up=$upstream_response_time '
'addr=$upstream_addr ustatus=$upstream_status cache=$upstream_cache_status '
'rid=$request_id';
access_log /var/log/nginx/access.log upstream_detail;
nginx json логи: почему escape=json меняет всё
Текстовый лог отлично читается глазами и отвратительно парсится машиной. Как только в User-Agent попадет кавычка или в URI пробел, твой grep-regexp в Loki разъедет, и поле уползет. А когда логи едут в ELK, Loki или ClickHouse, парсинг - это деньги и нервы. Решение появилось еще в nginx 1.11.8 и стало индустриальным стандартом: параметр escape=json у log_format.
Что он делает технически: nginx сам экранирует значения всех переменных по правилам JSON. Кавычка становится \", обратный слеш \\, перевод строки \n, управляющие символы с кодом меньше 32 уходят в \u00XX. То есть какой бы мусор клиент ни прислал в заголовке, итоговая строка останется валидным JSON. Без escape=json одна злая кавычка в Referer ломает всю строку, и парсер в Loki давится.
Сам формат ты пишешь руками как JSON-объект, склеивая строки. Ловушка номер один: значение строковых полей берем в кавычки ("$var"), а числовые поля ($status, $bytes_sent, $body_bytes_sent) пишем БЕЗ кавычек - тогда в Elasticsearch/ClickHouse они приедут числами и по ним можно считать агрегаты и фильтровать по диапазону.
В эталонном шлюзе ngx-trace-gateway этим занимается global_logging.conf, и формат там не игрушечный - это structured_log на 50+ полей. Не пугайся объема, логика простая - поля сгруппированы во вложенные объекты по смыслу: timestamp, severity, service, trace, client, network, tls, http (с подобъектами request/response/server/upstream). Вот компактная, но боевая выжимка того же подхода:
Код: Выделить всё
log_format structured_log escape=json
'{'
'"timestamp":"$time_iso8601",'
'"timestamp_msec":"$msec",'
'"severity":"$log_level",'
'"service":{"name":"api-gateway","instance":"$hostname"},'
'"trace":{'
'"request_id":"$request_id",'
'"trace_id":"$trace_request_id"'
'},'
'"client":{'
'"ip":"$remote_addr",'
'"real_ip":"$realip_remote_addr",'
'"forwarded_for":"$http_x_forwarded_for",'
'"user_agent":"$http_user_agent"'
'},'
'"tls":{'
'"protocol":"$ssl_protocol",'
'"cipher":"$ssl_cipher",'
'"session_reused":"$ssl_session_reused",'
'"sni":"$ssl_server_name"'
'},'
'"http":{'
'"method":"$request_method",'
'"uri":"$uri",'
'"args":"$args",'
'"host":"$host",'
'"protocol":"$server_protocol",'
'"status":$status,'
'"request_time":$request_time,'
'"body_bytes_sent":$body_bytes_sent,'
'"upstream":{'
'"addr":"$upstream_addr",'
'"status":"$upstream_status",'
'"cache_status":"$upstream_cache_status",'
'"connect_time":"$upstream_connect_time",'
'"header_time":"$upstream_header_time",'
'"response_time":"$upstream_response_time"'
'}'
'}'
'}';
Заметь $upstream_response_time отдельно от $request_time. Разница между ними - это время, которое съел сам nginx: чтение тела от медленного клиента, буферизация, ожидание в очереди. Если request_time большой, а upstream_response_time маленький - тормозит не бэкенд, а клиент или сеть. Эти два поля рядом в каждой строке экономят часы разбора инцидентов.
severity через map, реальный IP и условное логирование
Теперь три приема, которые отличают зрелый конфиг от учебного.
severity из статуса. Привычные лог-фреймворки пишут уровень (info/warn/error). nginx из коробки так не умеет, но severity выводится из $status через map. Это поле $log_level из формата выше:
Код: Выделить всё
map $status $log_level {
~^2 "info";
~^3 "info";
~^4 "warn";
~^5 "error";
default "info";
}
Реальный IP. Если nginx стоит за балансировщиком, CDN или другим nginx, то $remote_addr - это адрес соседнего прокси, а не клиента. Логи врут, rate-limit и geo считают не того. Лечится модулем realip: ему говоришь, каким сетям доверять, и из какого заголовка брать настоящий IP.
Код: Выделить всё
set_real_ip_from 10.0.0.0/8;
set_real_ip_from 172.16.0.0/12;
real_ip_header X-Forwarded-For;
real_ip_recursive on;
Условное логирование. Не всё стоит писать. Healthcheck от Kubernetes молотит /healthz каждые 2 секунды, статика - тысячи строк ни о чем. Раздуешь диск и зашумишь поиск. Параметр if= у access_log + map решают это:
Код: Выделить всё
map $request_uri $loggable {
~^/healthz 0;
~^/nginx_status 0;
default 1;
}
map $status $log_sampling {
~^[23] 0; # успешную статику можно не логировать поштучно
default 1; # а вот ошибки - всегда
}
server {
access_log /var/log/nginx/access.log structured_log if=$loggable;
location ~* \.(css|js|png|jpg|woff2)$ {
access_log off; # полностью выключить для статики
log_not_found off; # не плодить error_log по favicon.ico
expires 30d;
}
}
Буферизация, сжатие, syslog и error_log: эксплуатация
Грабля производительности. По умолчанию каждая строка access_log - это отдельный синхронный write() на диск. На шлюзе с десятками тысяч rps это превращается в шторм мелких операций ввода-вывода, и worker блокируется на диске вместо обработки запросов. Latency растет на ровном месте. Лечение - буферизация:
Код: Выделить всё
access_log /var/log/nginx/access.log structured_log buffer=64k flush=5s;
Код: Выделить всё
access_log /var/log/nginx/access.log structured_log gzip=5 buffer=128k flush=5s;
syslog. Вместо файла лог можно слать прямо в syslog по сети - удобно, когда сбор централизованный и не хочется ставить агент-сборщик на каждый хост:
Код: Выделить всё
access_log syslog:server=10.0.0.50:514,facility=local7,tag=nginx,severity=info structured_log;
Код: Выделить всё
error_log /var/log/nginx/error.log warn;
Практика: ротация без потери логов через USR1
Логи растут, диск кончается. Ротация - это переименовать старый файл и начать писать в новый. Но есть тонкость: nginx держит лог-файл открытым по файловому дескриптору. Если просто переименовать access.log в access.log.1, nginx продолжит писать в ТОТ ЖЕ дескриптор - то есть в переименованный файл. Новый access.log не появится, пока nginx не переоткроет файлы.
Механизм переоткрытия - сигнал USR1. По нему nginx закрывает текущие лог-файлы и открывает их заново по тем же путям (master передает сигнал воркерам). Поэтому правильная ротация всегда: сначала переименовать файлы, потом послать USR1.
Вручную:
Код: Выделить всё
mv /var/log/nginx/access.log /var/log/nginx/access.log.1
nginx -s reopen
# nginx -s reopen эквивалентен kill -USR1 $(cat /run/nginx.pid)
Код: Выделить всё
/var/log/nginx/*.log {
daily
rotate 14
missingok
notifempty
compress
delaycompress
sharedscripts
postrotate
[ -f /run/nginx.pid ] && kill -USR1 $(cat /run/nginx.pid)
endscript
}
Замечание про gzip-буферизацию и ротацию: если включил gzip у access_log, дай logrotate флаг nocompress или copytruncate-альтернативу осторожно - двойное сжатие бессмысленно. Проще не жать в nginx, а отдать сжатие logrotate.
Мини-лаба: собери боевой JSON-лог руками
Повтори по шагам на тестовом nginx (можно в Docker openresty/openresty или nginx:latest).
- Шаг 1. В http-блок добавь map $status $log_level из урока и log_format structured_log escape=json (компактная версия выше). Проверь nginx -t - частая ошибка тут несбалансированные кавычки в склейке строк.
- Шаг 2. В server подключи access_log с этим форматом и buffer=32k flush=3s. Сделай пару запросов curl, среди них один на несуществующий URL (получишь 404).
- Шаг 3. Открой лог. Прогони строку через jq: tail -1 access.log | jq . - убедись, что это валидный JSON и severity у 404 равен "warn".
- Шаг 4. Добавь map $request_uri $loggable с исключением /healthz и параметр if=$loggable. Сделай запрос на /healthz и проверь, что строка НЕ появилась в логе.
- Шаг 5. Ротация: mv access.log access.log.1, затем nginx -s reopen. Сделай новый curl и убедись, что строка ушла в новый access.log, а не в .1.
Контрольные вопросы
- 1. Зачем в log_format ставить параметр escape=json и что сломается без него, если клиент пришлет кавычку в User-Agent?
- 2. В чем разница между $request_time и $upstream_response_time, и что значит ситуация, когда первое большое, а второе маленькое?
- 3. Почему при ротации логов недостаточно переименовать файл, и какую роль играет сигнал USR1 (nginx -s reopen)?
- 4. Чем $remote_addr отличается от реального IP клиента за CDN, и почему set_real_ip_from нельзя задавать как 0.0.0.0/0?
Логи - это видимость, без которой ты слеп в инциденте. Уходи от combined к структурированному JSON через escape=json: числовые поля без кавычек, severity через map $status, реальный IP через realip, обязательно $upstream_response_time/$upstream_status/$upstream_cache_status/$request_id в каждой строке. Не логируй мусор (if= + access_log off + log_not_found off), буферизуй (buffer/flush/gzip), чтобы синхронный ввод-вывод не убивал latency, и ротируй честно - через USR1, иначе потеряешь данные. error_log держи на warn и не забывай про него отдельно от access_log. Такой лог отвечает на вопрос "что сломалось" за секунды, а не за час.
