Медленный сайт из-за одной строки в конфиге nginx

MAATRIX

Сайт работал нормально месяцами, а после очередного обновления конфига вдруг стал заметно медленнее — страницы грузятся на секунду-две дольше, хотя ничего «серьёзного» вроде бы не трогали. Первая реакция почти всегда одна: искать проблему в приложении или базе. И это ошибка, которая может стоить нескольких часов расследования не в том месте. Разберём типичный сценарий такого инцидента и то, как в реальности находится виновная строка в nginx.conf.

Первая версия: виноват бэкенд

Классический ход мысли: сайт медленный — значит, тормозит приложение. Смотрят нагрузку на CPU и память backend-процесса, проверяют пул соединений с базой, включают slow_query_log в MySQL или log_min_duration_statement в PostgreSQL, гоняют профилировщик по коду. Иногда даже перезапускают backend «на всякий случай» — и на пару минут действительно становится быстрее (просто потому, что прогрелся кэш приложения), что укрепляет неверную гипотезу.

Проблема в том, что при таком расследовании смотрят только на одну половину пути запроса — от nginx до приложения и обратно. А запрос идёт длиннее: клиент → nginx → backend → nginx → клиент. Если тормозит именно последний участок или сам nginx, поиск по логам приложения и базе ничего не даст — там всё будет чисто, потому что оно и правда чисто.

В типичном случае из этой статьи так и происходит: полтора часа уходит на профилирование Node.js/PHP-FPM процесса, EXPLAIN ANALYZE самых тяжёлых запросов, проверку индексов — и всё в пределах нормы. Время выполнения запросов к базе — единицы миллисенкунд, ответ приложения — десятки миллисекунд. А сайт при этом ощутимо тормозит. Значит, дело не здесь.

Находка: разрыв между временем приложения и временем ответа клиенту

Переломный момент в таком разборе — сравнение двух чисел в логах: сколько реально работало приложение и сколько всего заняло обслуживание запроса от начала до конца. В nginx для этого есть переменные $upstream_response_time (время ответа backend) и $request_time (полное время обработки запроса самим nginx, включая передачу тела клиенту).

Чтобы увидеть оба значения рядом, в nginx.conf должен быть настроен подходящий log_format:

log_format timing '$remote_addr - $time_local "$request" '
                   'status=$status bytes=$body_bytes_sent '
                   'rt=$request_time uht=$upstream_response_time '
                   'referer="$http_referer"';

server {
    access_log /var/log/nginx/access.log timing;
    ...
}

Дальше — просто читать access.log и сравнивать значения rt и uht:

tail -n 200 /var/log/nginx/access.log | grep -oE 'rt=[0-9.]+ uht=[0-9.]+'

Именно здесь и обнаруживается разрыв: uht (ответ приложения) стабильно небольшой, а rt (полное время до клиента) в разы больше. Условно, если backend отвечает за десятки миллисекунд, а rt показывает уже секунды — разница возникает не в приложении, а где-то между nginx и приложением, либо в самом nginx при формировании и отдаче ответа. Backend, получается, ни при чём: он делает свою работу быстро, а вот что происходит с этим ответом дальше — большой вопрос.

Важный нюанс: если upstream_response_time вообще не появляется в логах или показывает -, значит запрос не доходил до апстрима (ошибка на уровне nginx, DNS, лимитов) — это отдельный повод присмотреться к самому nginx ещё внимательнее.

Подозреваемый №1: резолвинг DNS на каждый запрос

Одна из самых частых и самых незаметных причин — конфигурация upstream, где backend указан доменным именем, а не IP-адресом, при этом резолвинг не закэширован. Если в конфиге вместо статичного IP используется переменная с доменным именем в proxy_pass, nginx по умолчанию не кэширует DNS-ответ так, как ожидает большинство администраторов, и может обращаться к резолверу заметно чаще, чем кажется логичным.

Типичная опасная конструкция:

resolver 127.0.0.53 valid=10s;

location /api/ {
    set $backend "api.internal.example.com";
    proxy_pass http://$backend:8080;
}

Использование переменной в proxy_pass (а не статичного upstream-блока) — это осознанный приём, чтобы получать динамическое обновление IP без перезапуска nginx. Но у него есть цена: каждый TTL резолвер снова обращается к DNS-серверу, и если резолвер медленный, перегружен или просто недоступен часть времени, каждый такой запрос добавляет задержку — вплоть до заметной паузы на отдельных запросах. Если valid= выставлен слишком коротким (или резолвер указан на нестабильный внешний DNS вместо локального кэширующего), проблема усугубляется.

Проверить гипотезу можно прямо в момент инцидента:

# Смотрим, как долго резолвится домен из конфига
time nslookup api.internal.example.com

# Проверяем, есть ли локальный кэширующий резолвер
systemctl status systemd-resolved

Решение — использовать нормальный локальный кэширующий резолвер (например, systemd-resolved, dnsmasq или unbound) с разумным valid= (30–60 секунд для внутренних сервисов, у которых IP меняется редко), либо вообще уйти от переменной в proxy_pass в пользу классического upstream со статичным IP, если backend не меняет адрес динамически:

upstream api_backend {
    server 10.0.0.15:8080;
    keepalive 32;
}

location /api/ {
    proxy_pass http://api_backend;
}

Подозреваемый №2: отключённые sendfile и tcp_nopush

Второй частый виновник — по невнимательности отключённые (или так и не включённые) директивы, отвечающие за эффективную отдачу статики. sendfile позволяет ядру передавать файл напрямую в сокет, минуя лишнее копирование данных через userspace nginx-процесса; tcp_nopush (совместно с sendfile on) заставляет систему собирать пакеты в более крупные блоки перед отправкой, вместо мелких TCP-сегментов.

Если кто-то при отладке временно поставил sendfile off; (например, чтобы посмотреть логи передачи файлов или обойти баг со старым NFS-хранилищем) и забыл вернуть обратно — статика начинает отдаваться заметно менее эффективно, особенно под нагрузкой и на файлах среднего и большого размера.

http {
    sendfile on;
    tcp_nopush on;
    tcp_nodelay on;
    ...
}

Проверить текущее состояние:

nginx -T 2>/dev/null | grep -E 'sendfile|tcp_nopush|tcp_nodelay'

Если строки не найдены — значит, действуют значения по умолчанию (у nginx sendfile по умолчанию выключен, если явно не включён), и на сервере, отдающем много статики или файлов через X-Accel-Redirect, это стоит поправить. Эффект от одной этой директивы будет разным на разных нагрузках и хранилищах — не гарантируйте себе конкретные проценты ускорения без замера на своём трафике.

Подозреваемый №3: избыточное логирование без буферизации

Ещё один классический случай — кто-то в целях отладки включил подробный log_format со множеством полей (заголовки запроса, тело, время на каждом этапе через $upstream_response_time, $upstream_connect_time и так далее) или добавил второй access_log для отдельного анализа, и оставил это в проде на длительный срок. Само по себе логирование не тяжёлое — тяжёлым его делает отсутствие буферизации, когда каждая строка лога вызывает отдельную операцию записи на диск.

По умолчанию nginx пишет лог с буферизацией уровня ОС, но если в конфиге явно стоит что-то вроде принудительного flush на каждый запрос без буфера, либо второй access_log указывает на медленный сетевой диск или смонтированный по NFS каталог — дисковая нагрузка от логирования начинает конкурировать за I/O с реальной отдачей контента.

Сравните:

# Пишет на диск синхронно, без буфера — нагружает I/O на каждый запрос
access_log /var/log/nginx/debug.log detailed;

# Буферизуется и сбрасывается пачками, раз в 5 секунд или по достижении 64k
access_log /var/log/nginx/access.log timing buffer=64k flush=5s;

Проверить, не «переросло» ли отладочное логирование в постоянное, легко по размеру и приросту файла:

ls -lh /var/log/nginx/*.log
du -sh /var/log/nginx/
watch -n1 'wc -l /var/log/nginx/access.log'

Если строк в логе за минуту прибавляется в разы больше, чем реальных запросов (например, из-за дублирующего access_log в нескольких location-блоках) — это тоже стоит проверить и убрать лишнее. Заодно не забывайте про ротацию логов, чтобы диск не забивался этими же файлами со временем.

Подозреваемый №4: gzip с неоптимальным уровнем сжатия

Четвёртый типичный виновник — директива gzip_comp_level. Она принимает значения от 1 (минимальное сжатие, минимум CPU) до 9 (максимальное сжатие, максимум CPU), и разница между уровнями нелинейна: выигрыш в размере файла от 6 к 9 обычно небольшой, а рост нагрузки на CPU — куда заметнее, особенно при высоком трафике на слабом сервере.

Если при правке конфига кто-то решил «сжать посильнее для экономии трафика» и поставил gzip_comp_level 9; вместо разумных 4–6, каждый запрос к текстовому/JSON/HTML-ответу начинает заметно дольше обрабатываться именно на этапе сжатия — и на сервере с несколькими vCPU под нагрузкой это может проявляться как рост $request_time при абсолютно нормальном $upstream_response_time, потому что сжатие происходит уже на стороне nginx, после получения ответа от backend.

gzip on;
gzip_comp_level 5;
gzip_min_length 256;
gzip_types text/plain text/css application/json application/javascript text/xml application/xml;
gzip_proxied any;

Проверить нагрузку на CPU в момент запроса:

top -bn1 | grep nginx
nginx -T 2>/dev/null | grep gzip_comp_level

Если сервер и так работает на пределе CPU (что видно через top или графики в мониторинге), а gzip_comp_level стоит на 8–9 — это первый кандидат на снижение до 4–6 с последующим замером эффекта на реальном трафике, а не на синтетическом тесте.

Как локализовать: диффы и откат по частям

Когда подозреваемых несколько (DNS, sendfile, логирование, gzip — а бывает, что и не один сразу), самый надёжный метод — не гадать, а сравнить текущий конфиг с рабочей версией до инцидента и откатывать изменения по одному, проверяя эффект после каждого шага.

Если конфиг под git (а он должен быть — конфиги веб-сервера стоит версионировать так же, как код приложения):

cd /etc/nginx
git log --oneline -- nginx.conf conf.d/
git diff HEAD~1 -- nginx.conf conf.d/

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

diff -u /etc/nginx/nginx.conf.bak /etc/nginx/nginx.conf

Дальше — методичный откат по одной директиве за раз, с проверкой синтаксиса и перечитыванием конфига после каждого изменения:

nginx -t && systemctl reload nginx

После каждого отката снова смотрим на rt и uht в access log на свежих запросах (несколько минут наблюдения, а не один запрос — чтобы не спутать случайный выброс с системной проблемой). Директива, после отката которой $request_time возвращается к норме, и есть виновник. Если под рукой staging-окружение с похожим трафиком — локализовать там безопаснее, чем экспериментировать на проде.

Если конфликтующих факторов несколько (например, и gzip перегружен, и логирование без буфера) — откатывайте по одному, а не всё сразу: иначе легко решить, что виновата одна директива, хотя на деле вклад вносили две.

Частые вопросы