Профилирование Nginx: цена метрик для архитектуры

Если Nginx отдаёт 502, а приложение уверяет, что отвечает за 40 мс, одной метрики latency недостаточно. Запрос мог ждать соединения с upstream, стоять в очереди, тратить время на TLS или задерживаться между балансировщиком и клиентом. В Nginx Open Source 1.25.x это можно разложить по фазам через access log, переменные upstream и stub_status, но каждая новая метрика влияет на дисковый ввод-вывод, формат логов и схему мониторинга. Профилирование здесь — не разовая настройка, а архитектурное решение.

Что именно нужно измерять

Nginx не профилирует бизнес-код приложения так, как профайлер для PHP, Python или Java. Он показывает путь HTTP-запроса на границе системы: получение соединения, чтение запроса, обращение к upstream, получение заголовков и тела ответа, отправку клиенту.

Минимальный набор измерений выглядит так:

• $request_time — полное время обработки запроса Nginx, от чтения первой строки запроса до завершения отправки ответа;
• $upstream_connect_time — время установления соединения с upstream;
• $upstream_header_time — время до получения первых заголовков от upstream;
• $upstream_response_time — время получения ответа от upstream;
• $upstream_status — статус, который вернул upstream;
• $status, $request_length, $bytes_sent — результат, размер входящего запроса и объём ответа.

Upstream — сервер, к которому Nginx обращается по директивам proxy_pass, fastcgi_pass, uwsgi_pass или похожим настройкам. У одного запроса может быть несколько upstream-значений, например после повторной попытки или работы с несколькими серверами.

Метрика полного времени отвечает на вопрос «как долго ждал пользователь». Метрики upstream отвечают на другой вопрос: «на каком участке запроса возникла задержка».

Четыре способа профилировать Nginx

Эти методы не заменяют друг друга. stub_status не сообщает, почему конкретный запрос занял две секунды, а access log не показывает, какой SQL вызвал задержку. Ошибка архитектуры наблюдаемости начинается с попытки получить ответ на оба вопроса одной метрикой.

Базовый профиль через access log

Для Nginx Open Source 1.25.x можно завести отдельный формат лога. Он не меняет поведение прокси и сохраняет данные на уровне завершённого запроса.

http {
    log_format request_profile
        '$time_iso8601 request_id=$request_id '
        'method=$request_method uri=$request_uri '
        'status=$status upstream_status=$upstream_status '
        'request_time=$request_time '
        'upstream_connect_time=$upstream_connect_time '
        'upstream_header_time=$upstream_header_time '
        'upstream_response_time=$upstream_response_time '
        'request_length=$request_length bytes_sent=$bytes_sent';

    access_log /var/log/nginx/request_profile.log request_profile;

    server {
        listen 80;
        server_name example.test;

        location / {
            proxy_pass http://application_backend;
        }
    }
}

Перед перезагрузкой конфигурации проверьте её командой nginx -t, затем перечитайте конфигурацию штатной командой управления вашим сервисом. В логе должна появиться строка с request_time и upstream-полями после первого завершённого запроса.

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

Почему одинаковый latency не означает одинаковую проблему

Высокий request_time и низкий upstream_response_time

Приложение быстро сформировало ответ, но клиент долго его принимал. Причины ищите в медленной сети, TLS, маленьком окне отправки, больших ответах, ограничениях bandwidth или поведении промежуточного прокси. Масштабирование backend в такой ситуации не устранит задержку.

Высокие upstream_header_time и upstream_response_time

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

Высокий upstream_connect_time

Проблема может быть в DNS, маршрутизации, исчерпании соединений, перегруженном upstream или слишком частом создании новых TCP-соединений. Важно смотреть распределение, а не только среднее значение: редкие длинные подключения часто исчезают в среднем, но попадают в p95 или p99.

Высокий request_time при пустых upstream-полях

Запрос мог обслуживаться статикой, быть отклонённым самим Nginx, ждать чтения тела от клиента или завершиться до обращения к upstream. Это архитектурно важный сигнал: один общий график latency смешивает несколько разных маршрутов.

Что меняется в архитектуре после включения профиля

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

Второе последствие — появляется договорённость о кардинальности. URI с идентификаторами заказов и случайными query-параметрами нельзя бездумно превращать в labels в системе метрик. Для логов такие значения допустимы с ограничениями, а для агрегированных метрик лучше нормализовать маршрут на уровне приложения или сборщика.

Третье — профилирование влияет на балансировку. Если вы различаете время соединения, ожидание заголовков и передачу тела, становится видно, что добавление серверов помогает только одному из участков. Иногда выгоднее держать соединения с upstream открытыми, изменить размеры ответов или вынести тяжёлые операции в очередь. Конкретный выбор зависит от версии Nginx, протокола, клиента и конфигурации upstream.

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

stub_status: состояние узла, а не профайлер

Модуль stub_status показывает счётчики и состояние соединений Nginx. Это полезно, когда нужно увидеть рост активных соединений или разницу между принятыми и обработанными запросами. Он не содержит времени ответа, URI и причины 5xx.

server {
    listen 127.0.0.1:8080;

    location = /nginx_status {
        stub_status;
        allow 127.0.0.1;
        deny all;
    }
}

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

Что ломается первым

• Логирование всех заголовков. В строки попадают cookies и персональные данные, а объём лога резко растёт. Добавляйте только поля, которые участвуют в диагностике.
• Debug на всём production-трафике. Такой режим создаёт поток данных, который трудно хранить и анализировать. Используйте короткое окно, отдельный узел или ограниченный маршрут, если это допустимо.
• Среднее вместо распределения. Среднее время скрывает хвост задержек. Считайте p50, p95 и p99 по маршрутам и статусам, не смешивая статику, API и загрузку файлов.
• Неправильная трактовка upstream_response_time. При нескольких upstream значения могут быть списком. Нельзя автоматически считать строку одним числом без правила разбора.
• Отсутствие проверки стоимости. Сравните CPU, размер логов, задержку записи и нагрузку на сборщик до и после включения профиля. Если инфраструктура наблюдаемости отстаёт, диагностика сама становится источником инцидента.

Как измерять без выдуманных цифр

Зафиксируйте версию Nginx, число worker-процессов, схему proxy, тип диска, объём и формат трафика. Сначала снимите базовую линию: долю ответов по статусам, p50/p95/p99 request_time, объём access log за час и потребление CPU. Затем включите дополнительные поля на ограниченном интервале и повторите замер при сопоставимой нагрузке.

Сравнивайте не только задержку запросов, но и цену профилирования: размер строки, скорость записи, задержку доставки логов, пропуски и рост нагрузки на индексатор. Если после включения наблюдаемости p99 изменился, нельзя сразу приписывать эффект Nginx: проверьте клиентскую нагрузку, cache hit ratio, ответы upstream и состояние диска.

Что делать дальше

Начните с отдельного access log и трёх разрезов: маршрут, статус и upstream. Затем добавьте корреляцию с приложением и настройте хранение только тех полей, которые помогают принять решение. После первого инцидента пересмотрите схему: какие значения привели к корню проблемы, какие оказались шумом, и можно ли заменить их агрегированной метрикой.

Следующий показатель для production — не «среднее время Nginx», а распределение request_time по маршрутам вместе с upstream_header_time и статусом. Если хвост растёт только у upstream, передавайте расследование команде сервиса. Если растёт разница между полным и upstream-временем, ищите проблему на границе, в сети, TLS или доставке ответа.