Освоение анализа логов Nginx для эффективной диагностики

Логи Nginx обычно являются самым быстрым способом превратить «сайт не работает» в конкретную проблему. Лог доступа сообщает, что запрашивали клиенты и какой статус они получили. Лог ошибок сообщает, что Nginx не смог сделать: подключиться к вышестоящему серверу, прочитать сертификат, открыть файл, разобрать конфигурацию или дождаться ответа от бэкенда в течение заданного времени.

Хороший анализ логов Nginx — это не разглядывание файлов в надежде заметить что-то подозрительное. Это постановка узкого вопроса, быстрая фильтрация и сопоставление лога доступа с логом ошибок и логами вышестоящего приложения. Ошибка 502 в логе доступа — это симптом. Соответствующая строка в логе ошибок обычно является началом ответа.

1. Основы логов Nginx: доступ и ошибки

Nginx ведет два различных типа логов, каждый из которых выполняет свою критически важную функцию:

1.1 Лог доступа (`access.log`)

Лог доступа записывает подробную информацию о каждом запросе, который обрабатывает Nginx. Он необходим для понимания поведения пользователей, мониторинга трафика и оценки времени ответа.

Расположение по умолчанию: Обычно /var/log/nginx/access.log

Назначение: Отслеживание взаимодействий клиентов, успешных запросов, ошибок клиента, ошибок сервера, возвращаемых через Nginx, переданных байтов, пользовательских агентов и времени выполнения запроса (если настроено).

1.2 Лог ошибок (`error.log`)

Лог ошибок отслеживает внутренние проблемы, сбои в работе и проблемы связи, возникающие в процессе обработки запросов Nginx. Этот лог является основным источником для диагностики проблем связности с бэкендом и ошибок конфигурации сервера.

Расположение по умолчанию: Обычно /var/log/nginx/error.log

Назначение: Отслеживание ошибок на стороне сервера, предупреждений и системных событий (ошибки 5xx, сбои при разборе файлов конфигурации).

Уровни серьезности лога ошибок

Nginx использует восемь уровней серьезности. При диагностике обычно следует начинать с уровня error или выше. Уровень серьезности настраивается с помощью директивы error_log:

# Установить минимальный уровень серьезности 'warn'
error_log /var/log/nginx/error.log warn;

Уровень	Описание	Приоритет
crit	Критические условия, такие как серьезный сбой во время выполнения	Наивысший
error	Произошла ошибка, которая помешала обработке запроса	Высокий
warn	Произошло что-то неожиданное, но работа продолжается	Средний
notice	Нормальное, но значимое условие (например, перезапуск сервера)	Низкий
info	Информационные сообщения	Самый низкий

Также существуют уровни emerg, alert и debug. Уровень debug может быть чрезвычайно многословным и обычно требует сборки Nginx с поддержкой отладки. Используйте его для целенаправленной диагностики, а не в качестве обычной настройки для продакшена.

2. Настройка логов доступа для анализа производительности

Формат лога доступа Nginx по умолчанию, часто называемый combined, полезен, но в нем отсутствуют критические переменные времени для анализа производительности. Чтобы эффективно диагностировать медленную работу, необходимо определить пользовательский формат, который фиксирует, сколько времени Nginx потратил на обработку запроса и сколько времени занял ответ вышестоящего сервера.

2.1 Определение формата лога для анализа производительности

Используйте директиву log_format (обычно определяется в nginx.conf) для создания пользовательского формата, например, timing_log:

log_format timing_log '$remote_addr - $remote_user [$time_local] ' 
                    '"$request" $status $body_bytes_sent ' 
                    '"$http_referer" "$http_user_agent" ' 
                    '$request_time $upstream_response_time';

server {
    listen 80;
    server_name example.com;
    
    # Применить пользовательский формат здесь
    access_log /var/log/nginx/timing_access.log timing_log;
    # ... остальная конфигурация
}

Переменная	Описание	Ценность для диагностики
$request_time	Общее время, прошедшее с момента получения первого байта до отправки последнего.	Высокие значения указывают на медленную сеть, медленный Nginx или медленный бэкенд.
$upstream_response_time	Время ожидания ответа от вышестоящего сервера (например, сервера приложений).	Высокие значения здесь указывают на бэкенд как на узкое место.
$status	Код состояния HTTP, возвращенный клиенту.	Необходим для фильтрации ошибок (4xx, 5xx).

Рассмотрите возможность использования форматирования логов в JSON, когда логи отправляются в централизованную систему. JSON сложнее читать глазами, но инструментам гораздо проще его надежно парсить. Если вы храните логи в текстовом формате, помните, что номера полей awk могут нарушиться, если пользовательские агенты, пути запросов или поля в кавычках содержат пробелы.

Также рассмотрите возможность регистрации идентификаторов запросов. Если ваш балансировщик нагрузки или приложение уже отправляют заголовок с идентификатором запроса, передавайте его и логируйте:

log_format timing_log '$remote_addr [$time_local] '
                    '"$request" $status $body_bytes_sent '
                    'request_time=$request_time '
                    'upstream_time=$upstream_response_time '
                    'request_id=$request_id '
                    'upstream=$upstream_addr';

Идентификатор запроса позволяет связать один медленный публичный запрос с одной записью в логе приложения. Без него вам придется сопоставлять по временной метке, пути и IP-адресу клиента, что возможно, но гораздо менее удобно.

3. Интерпретация записей лога доступа

Типичная запись с использованием пользовательского формата может выглядеть так (с добавленными значениями времени в конце):

192.168.1.10 - - [10/May/2024:14:30:05 +0000] "GET /api/data HTTP/1.1" 200 450 "-" "Mozilla/5.0" 0.534 0.528

Диагноз:

Код состояния (200): Успех.
Время запроса (0.534с): Общее время — полсекунды.
Время вышестоящего сервера (0.528с): Почти все время было потрачено на ожидание ответа от бэкенда (0.534 - 0.528 = 0.006с затрачено на накладные расходы Nginx).

Диагноз: Для этого запроса бэкенд, вероятно, является источником задержки в 500 мс. Накладные расходы Nginx кажутся небольшими.

Не делайте обобщений на основе одной строки. Посмотрите на выборку медленных запросов. Если у большинства медленных запросов высокое значение $upstream_response_time, сосредоточьтесь на приложении или сети вышестоящего сервера. Если $request_time высокое, а $upstream_response_time низкое, задержка может быть связана со временем загрузки клиента, медленной загрузкой клиента, поведением буферизации или работой на стороне Nginx.

Диагностика с использованием кодов состояния

Диапазон кодов состояния	Значение	Типичные действия/источник лога
4xx (Ошибки клиента)	Клиент отправил недопустимый или неавторизованный запрос.	Проверьте логи доступа на высокую частоту. Ищите `404 Not Found` (отсутствующие файлы) или `403 Forbidden` (проблемы с правами доступа).
5xx (Ошибки сервера)	Nginx или вышестоящий сервер не смогли выполнить допустимый запрос.	Немедленно проверьте лог ошибок на наличие соответствующих записей.
502 Bad Gateway	Nginx не смог получить ответ от вышестоящего приложения.	Лог ошибок покажет подробности (Отказ в соединении, Тайм-аут).
504 Gateway Timeout	Вышестоящий сервер не ответил в течение заданного времени ожидания прокси.	Лог ошибок покажет предупреждения о тайм-ауте. Исследуйте задержки бэкенда, прежде чем увеличивать тайм-ауты.

Увеличение proxy_read_timeout может скрыть симптом, в то время как пользователи все равно будут ждать слишком долго. Это допустимо для длительных конечных точек, потоковой передачи или известных медленных операций, но для обычных API-запросов это должно сначала вызвать расследование бэкенда.

4. Диагностика критических проблем в логе ошибок

Когда запрос приводит к ошибке 5xx, лог доступа сообщает только о том, что ошибка произошла. Лог ошибок сообщает почему.

Пример: 502 Bad Gateway

Ошибка 502 — одна из самых распространенных проблем при использовании Nginx в качестве обратного прокси. Она почти всегда указывает на то, что бэкенд не работает, перегружен или недоступен.

Ищите в логе ошибок следующие конкретные сообщения:

4.1 Отказ в соединении (бэкенд не работает)

Это указывает на то, что Nginx попытался подключиться к порту бэкенда, но никто не слушал, то есть сервер приложений (например, PHP-FPM, Gunicorn) остановлен или неправильно настроен.

2024/05/10 14:35:10 [error] 12345#0: *1 connect() failed (111: Connection refused) while connecting to upstream, client: 192.168.1.10, server: example.com, request: "GET /test"

Действие: Проверьте, работает ли сервис бэкенда, слушает ли он ожидаемый порт или Unix-сокет, и указывает ли Nginx на тот же адрес. Перезапускайте только после того, как поймете, почему он остановился.

4.2 Преждевременное закрытие соединения вышестоящим сервером (сбой бэкенда)

Это происходит, когда Nginx устанавливает соединение, но бэкенд разрывает его до отправки полного HTTP-ответа. Это часто указывает на фатальную ошибку или сбой в коде приложения.

2024/05/10 14:38:22 [error] 12345#0: *2 upstream prematurely closed connection while reading response header from upstream, client: 192.168.1.10, server: example.com, request: "POST /submit"

Действие: Проверьте собственные логи ошибок сервера приложений (например, логи PHP-FPM, логи Node.js) на предмет конкретной фатальной ошибки.

Предупреждение: Если Nginx не может прочитать свой файл конфигурации при запуске, ошибка часто выводится непосредственно в стандартный поток ошибок или в файл журнала начальной загрузки, а не в настроенное расположение error.log. Всегда проверяйте journalctl -xe или системные журналы, если Nginx не запускается.

Пример: 403 Forbidden

Ошибка 403 в логе доступа может быть вызвана авторизацией приложения, правилами доступа Nginx, правами доступа к файловой системе или поведением индексного каталога. Один лишь лог доступа не может сказать вам, что именно.

Ищите в логе ошибок строки, подобные этой:

2024/05/10 15:02:01 [error] 12345#0: *12 directory index of "/var/www/site/" is forbidden

Это означает, что Nginx достиг каталога, но в нем нет индексного файла для обслуживания, и список каталогов отключен. Исправление может заключаться в создании ожидаемого index.html, настройке директивы index или перенаправлении запроса в приложение.

При проблемах с правами доступа вы можете увидеть:

2024/05/10 15:04:44 [error] 12345#0: *15 open() "/var/www/site/private.txt" failed (13: Permission denied)

Проверьте права владения файлами, права на выполнение для каталогов, политики SELinux или AppArmor (где применимо), а также пользователя, от которого работают рабочие процессы Nginx.

Пример: 499 Client Closed Request

Специфичный для Nginx статус 499 означает, что клиент закрыл соединение до того, как Nginx закончил отвечать. Это часто случается, когда пользователи уходят, мобильные клиенты теряют связь или вышестоящий сервер отвечает так долго, что клиент сдается.

Не рассматривайте каждую ошибку 499 как ошибку Nginx. Посмотрите на время. Если у многих 499 высокое время запроса и они совпадают с медленными вышестоящими серверами, пользователи, возможно, отказываются от медленных запросов. Если они происходят немедленно от одного клиента или сети, это может быть поведением клиента.

5. Практические команды оболочки для анализа логов

Хотя для продакшена рекомендуются надежные системы мониторинга логов, командная строка Linux предоставляет мощные инструменты для быстрой диагностики в реальном времени.

5.1 Мониторинг в реальном времени

Отслеживайте логи по мере поступления запросов (особенно полезно после развертывания исправления или тестирования новой функции):

tail -f /var/log/nginx/access.log
# Или только ошибки
tail -f /var/log/nginx/error.log

Для ротированных и сжатых логов используйте zgrep:

zgrep '" 50[0-9] ' /var/log/nginx/access.log*.gz

Ротация логов имеет значение при анализе инцидентов. Ошибка могла произойти прямо перед полуночью или перед задачей ротации, которая сжала вчерашний файл.

5.2 Фильтрация и подсчет ошибок

Быстро найдите и подсчитайте наиболее частые ошибки 5xx за последний час или день:

# Найти все запросы с 5xx
grep '" 50[0-9] ' /var/log/nginx/access.log | less

# Подсчитать распределение ошибок 5xx (например, сколько 502 против 504)
grep '" 50[0-9] ' /var/log/nginx/access.log | awk '{print $9}' | sort | uniq -c | sort -nr

Пояснение: awk '{print $9}' извлекает код состояния HTTP (предполагается формат лога по умолчанию или combined, где статус является 9-м полем).

Если вы используете пользовательский формат лога, подтвердите номер поля, прежде чем доверять подсчету. Более безопасная быстрая проверка — вывести несколько разобранных строк:

awk '{print NR, $0; if (NR == 3) exit}' /var/log/nginx/access.log

Для логов в формате JSON используйте jq вместо номеров полей:

jq -r 'select(.status >= 500) | .status' /var/log/nginx/access.json \
  | sort | uniq -c | sort -nr

5.3 Выявление медленных запросов (требуется пользовательский формат лога)

Если вы внедрили формат timing_log (где $request_time является предпоследним полем или полем 16 в нашем примере):

# Найти 10 самых медленных запросов (например, запросы, выполняющиеся более 1 секунды)
awk '($16 > 1.0) {print $16, $7}' /var/log/nginx/timing_access.log | sort -nr | head -10

Пояснение: Эта команда выводит время запроса и URI ($7) для любого запроса, который выполнялся дольше 1,0 секунды, отсортированных по убыванию.

Более читаемый текстовый формат времени использует именованные значения, такие как request_time=0.534. Тогда вы можете искать медленные диапазоны с помощью grep менее элегантно, но с меньшим количеством сюрпризов с номерами полей. Для серьезного анализа отправляйте структурированные логи в систему логирования и запрашивайте процентили по маршрутам.

5.4 Выявление наиболее активных IP-адресов

Полезно для обнаружения потенциальных DoS-атак, всплесков трафика или подозрительной активности:

# Найти топ-20 IP-адресов, делающих запросы
awk '{print $1}' /var/log/nginx/access.log | sort | uniq -c | sort -nr | head -20

Топ IP-адресов — это отправная точка, а не доказательство злоупотребления. Корпоративный NAT, CDN-узел или балансировщик нагрузки могут сделать так, что множество пользователей будут выглядеть как один источник. Если Nginx находится за прокси, настройте и регистрируйте реальный IP-адрес клиента с помощью real_ip_header и доверенных диапазонов прокси. Никогда не доверяйте произвольным заголовкам X-Forwarded-For из открытого интернета.

Практический поток диагностики

Начните с симптома пользователя и временного окна. «Оформление заказа возвращало 502 около 14:35 UTC» гораздо полезнее, чем «Nginx сломан».

Сначала подсчитайте статусы:

grep '10/May/2024:14:3' /var/log/nginx/access.log \
  | awk '{print $9}' | sort | uniq -c | sort -nr

Фильтрация по дате в текстовых логах неудобна, и точная команда зависит от формата вашего лога. Для быстрой проверки инцидента даже грубая фильтрация может показать, была ли проблема в основном 502, 504, 403 или 404.

Затем извлеките несколько соответствующих запросов:

grep '" 502 ' /var/log/nginx/access.log | tail -20

Обратите внимание на временную метку, URI, время вышестоящего сервера и идентификатор запроса, если он есть. Затем выполните поиск в логе ошибок за тот же период времени:

grep '14:35' /var/log/nginx/error.log

Если в ошибке сказано connect() failed (111: Connection refused), проверьте сервис вышестоящего сервера и его порт. Если сказано upstream timed out, проверьте задержки бэкенда и очереди. Если сказано no live upstreams, проверьте работоспособность вышестоящего сервера, DNS или конфигурацию балансировщика нагрузки.

Наконец, проверьте логи бэкенда, используя тот же идентификатор запроса или временную метку. Nginx часто сообщает, где произошел сбой передачи, но лог бэкенда сообщает, почему приложение повело себя таким образом.

Сделайте логи полезными до сбоя

Худшее время для улучшения логирования — во время сбоя. Добавьте время запроса, время вышестоящего сервера, адрес вышестоящего сервера и идентификаторы запросов до того, как они понадобятся. Храните логи доступа и ошибок раздельно по сайтам, когда один сервер обслуживает несколько приложений. Убедитесь, что ротация сохраняет достаточно истории для инцидентов, которые вы действительно расследуете.

Когда что-то ломается, читайте логи парами: лог доступа — что произошло, лог ошибок — что Nginx не смог сделать, лог приложения — что сделал вышестоящий сервер. Эта привычка делает диагностику целенаправленной и обычно приводит к реальной причине сбоя быстрее, чем изменение тайм-аутов или случайные перезапуски сервисов.