PHP‑FPM slowlog на практике: ловим медленные запросы и фиксим узкие места

Если у вас крутится PHP‑приложение и периодически «плавают» задержки, slowlog в PHP‑FPM — один из самых недооценённых инструментов. Он даёт точку входа: что именно делает процесс PHP в момент, когда запрос становится «медленным». В статье разбираем включение, выбор порога, чтение стэктрейсов, корреляцию с веб‑сервером и типовые способы устранения узких мест.

Как работает slowlog в PHP‑FPM

slowlog не замеряет каждую функцию, он срабатывает, когда выполнение скрипта в воркере превышает порог request_slowlog_timeout. В этот момент FPM записывает текущий стек вызовов (PHP backtrace) в файл, указанный в параметре slowlog. Это почти не добавляет накладных расходов до наступления таймаута и безопасно для продакшена при разумном пороге.

Важно понимать, что slowlog фиксирует «где мы застряли сейчас», а не полную хронологию. Для детальной профилировки по времени есть специализированные профайлеры, но для первичной локализации узких мест slowlog часто быстрее и проще.

Где лежат конфиги и как включить slowlog

Файлы пулов PHP‑FPM в разных дистрибутивах располагаются по‑разному:

• Debian/Ubuntu: /etc/php/<версия>/fpm/pool.d/*.conf (например, /etc/php/8.2/fpm/pool.d/www.conf)
• RHEL/AlmaLinux/Rocky: /etc/php-fpm.d/*.conf (например, /etc/php-fpm.d/www.conf)

Минимальная настройка для включения slowlog в пуле:

; внутри файла пула, например www.conf
; путь к slowlog-файлу (права на каталог обязательны)
slowlog = /var/log/php-fpm/www-slow.log

; порог, после которого фиксируем стек
request_slowlog_timeout = 2s

; опционально: аварийное прерывание слишком долгих запросов
; request_terminate_timeout = 30s

Применяем изменения без даунтайма:

# Debian/Ubuntu
systemctl reload php8.2-fpm

# RHEL-семейство
systemctl reload php-fpm

Проверьте, что путь к логам существует и доступен для пользователя FPM (часто это www-data или apache). И продумайте ротацию: logrotate или встроенный механизм системы логов.

Выбор порога

Универсального ответа нет, но можно оттолкнуться от SLO вашего сервиса:

• API с SLO в 200–300 мс: ставьте request_slowlog_timeout 200–300 мс, но только на стейджинге или узких пулах, иначе будет много шума.
• Типовой сайт/CRM: 1–2 секунды для начала. Позже снижайте порог точечно (например, отдельный пул для критичных эндпоинтов).
• Плановые задачи (CLI-пул): минуты, либо включайте по требованию.

Нужны разные пороги для разных частей приложения — заведите несколько пулов с разной конфигурацией и привязывайте их через веб‑сервер по локациям/сокетам.

Проверка: провоцируем медленный запрос

Создайте временный скрипт со сном дольше порога и откройте его в браузере или через curl:

// /var/www/html/slow.php
<?php
usleep(3_000_000); // 3 секунды

После запроса slow.php в www-slow.log появится запись.

Как читать slowlog: пример и разбор

Типичный фрагмент логов:

[21-Apr-2025 10:51:35]  [pool www] pid 12345
script_filename = /var/www/site/index.php
[0x00007f1a3c0018c0] curl_exec() /var/www/site/lib/Http.php:142
[0x00007f1a3c0017b0] request() /var/www/site/lib/ApiClient.php:88
[0x00007f1a3c0016a0] getUser() /var/www/site/controllers/Profile.php:57
[0x00007f1a3c001590] include() /var/www/site/index.php:24

Читаем снизу вверх:

• index.php:24 подключает контроллер,
• в Profile.php:57 вызываем getUser(),
• тот через ApiClient.php:88 делает HTTP‑запрос,
• и «застряли» мы на curl_exec() в Http.php:142.

Это означает, что реальная причина в сетевом вызове. Смотрите таймауты, DNS, удалённую систему и кэширование.

Быстрый разбор больших slowlog

Несколько команд, чтобы подсветить частые виновники.

# Вывести все упоминания файлов/строк из backtrace
awk '/: [0-9]+$/{print $NF}' /var/log/php-fpm/www-slow.log | sort | uniq -c | sort -nr | head -50

# Топ функций, где чаще всего «застревали»
awk '/\) \/.*:[0-9]+$/{print $1}' /var/log/php-fpm/www-slow.log | sort | uniq -c | sort -nr | head -50

# Список скриптов, которые чаще всего становятся медленными
awk '/script_filename/{print $3}' /var/log/php-fpm/www-slow.log | sort | uniq -c | sort -nr | head -50

Эти срезы помогают быстро понять, куда смотреть в первую очередь: внешний HTTP, БД, файловые операции, регулярные выражения и т.д.

Связываем с веб‑сервером и системными метриками

Чтобы картина была полной, полезно коррелировать slowlog с логами веб‑сервера. Например, в Nginx используйте поля request_time и upstream_response_time в формате access‑лога. Если request_time большой и есть slowlog — задержка внутри PHP. Если request_time большой, а upstream_response_time маленький — задержка до PHP (TLS, очереди, сеть) или после (отдача больших ответов).

Иногда нужно «поймать за руку» конкретный зависший процесс из slowlog. Зная pid, можно временно посмотреть системные вызовы:

# осторожно: strace даёт накладные расходы, используйте точечно на стенде или в нерабочее время
strace -p 12345 -tt -s 200 -o /tmp/strace.12345.log

Если видите постоянные read() из сокета — ждём внешний сервис. Много stat() и openat() — возможно, файловые операции и «шторм» метаданных. Плотные futex() укажут на блокировки (например, сессии).

Облачный VDS-сервер в России

Аренда виртуальных серверов с моментальным развертыванием инфраструктуры от 195₽ / мес

Подробнее

Типовые узкие места и как их чинить

1) База данных: отсутствие индексов и тяжёлые JOIN

В slowlog вы увидите фреймы вида PDOStatement->execute() или mysqli_query(). Дальше план действий стандартный: лог медленных запросов СУБД, EXPLAIN, индексы по условиям и сортировкам, денормализация или материализованные представления для особо тяжёлых отчётов. Часто помогает банальное ограничение выборки и пагинация.

2) Внешние HTTP/SMTP/LDAP: таймауты и ретраи

Если «застряли» на curl_exec(), проверьте таймауты и распадите риски:

• Обязательно задавайте CURLOPT_CONNECTTIMEOUT и CURLOPT_TIMEOUT.
• Включайте CURLOPT_TCP_FASTOPEN и keep‑alive там, где уместно.
• Сделайте экспоненциальные ретраи, но ограничьте их по времени запроса.
• Кэшируйте ответы, если это безопасно.

Частая причина — DNS. Если в strace видите обращения к resolv.conf и долгие ожидания, проверьте резолверы и кэширование DNS на сервере.

3) Файловые операции и медленный диск

Большое число file_get_contents(), glob(), is_file() и т.п. может упираться в I/O. Проверьте:

• Включён ли OPCache и корректен ли opcache.validate_timestamps под ваши процессы деплоя.
• realpath_cache_size и realpath_cache_ttl в php.ini — помогает против «штормов» stat(). Подробности и примеры в материале про тонкую настройку PHP: настройки .user.ini и php_value.
• Избегайте glob() по большим деревьям в рантайме; индексация и кеширование списков файлов обычно лучше.

4) Сессии: блокировки

PHP по умолчанию держит эксклюзивную блокировку файла сессии до session_write_close(). Если в slowlog часто фигурируют вызовы, где ничего особо не происходит, а соседние запросы к тому же пользователю залипают — возможно, вы держите сессию слишком долго. Закрывайте её раньше, используйте альтернативные хранилища сессий и избегайте тяжёлых операций между стартом и закрытием сессии. Про перенос сессий в Redis — в разборе: сессии и объектный кеш в Redis.

5) Регулярные выражения и обработка строк

preg_match(), preg_replace() с плохими паттернами могут неожиданно «взрываться» по времени на отдельных входных данных. Если slowlog указывает на такие места, добавьте тесты с «злобными» строками и оптимизируйте паттерны, ограничивайте размер входа.

6) Очереди и межсервисные вызовы

Если фреймы показывают клиентскую библиотеку очереди или RPC — проверьте соединения, пулы, backpressure, лимиты и таймауты. Добавьте метрики на латентность вызовов и размеры очередей, чтобы потом не охотиться «вслепую». Для управления воркерами см. заметку про systemd и Supervisor.

Связь с настройками самого PHP‑FPM

Иногда «медленность» — следствие исчерпания пула, когда запросы стоят в очереди и дожидаются свободного воркера. slowlog покажет только то, что происходило уже внутри воркера, но на задержку повлияет и ожидание в очереди. Проверьте:

• pm: режим dynamic или ondemand. Для нагруженных API чаще подходит dynamic.
• pm.max_children: достаточно ли воркеров при пике, укладывается ли потребление памяти в лимиты сервера.
• pm.max_requests: помогает убирать «разбухание» воркеров со временем (утечки, фрагментация).

Тюнинг пула и slowlog идут рука об руку: увеличив pm.max_children, вы уменьшаете очереди, но если корень проблемы в медленных операциях внутри запроса, это только маскирует симптом. Если вам нужна полная изоляция пулов и гибкий контроль над сервисами, рассмотрите аренду VDS.

Безопасность и эксплуатация

• Права на slowlog: файл и каталог должны быть доступны пользователю FPM; не храните логи в общедоступных директориях сайта.
• Регулярная ротация логов: чтобы не переполнить диск. Проверьте, что ротация не ломает права и SELinux‑контекст, если он включён.
• Объём логов: при низких порогах slowlog будет многословен. Выводите его по расписанию или в отдельные пулы, чтобы не зашуметь общую картину.
• В продакшене держите разумный порог и выключайте детальный стэктрейс в моменты пиков, если наносит ущерб IO.

Чек‑лист внедрения slowlog

1. Определите целевой SLO и выберите порог request_slowlog_timeout под разные типы трафика.
2. Включите slowlog в конфиге пула, проверьте права и ротацию.
3. Перезагрузите FPM и убедитесь, что slowlog начинает пополняться при провоцируемом «медленном» запросе.
4. Добавьте быстрый парсинг и агрегацию: топ функций, топ скриптов, топ строк.
5. Сведите данные с access‑логами веб‑сервера и системными метриками (CPU, IO, сеть).
6. Поправьте очевидные проблемы: таймауты cURL, индексы в БД, сессии, кеширование, настройки OPCache.
7. Пересмотрите тюнинг пула (pm.*), чтобы убрать очереди, не прячьте системные проблемы за «наращиванием воркеров».
8. Снизьте порог точечно на отдельных пулах и повторите анализ до достижения целей по латентности.

Ответы на частые вопросы

Можно ли держать slowlog постоянно включённым в проде? Да, при адекватном пороге. Основная нагрузка — запись стэктрейса при срабатывании. Это редкое событие в здоровой системе.

Можно ли сделать разные пороги для разных урлов? Непрямо. Используйте несколько пулов и маршрутизируйте запросы к ним через веб‑сервер.

Почему в slowlog не видно аргументы функций? FPM печатает файл/строку и имя функции, этого обычно достаточно. Для глубокого анализа используйте профайлеры и трассировку на стендах.

Если в slowlog пусто, а задержки есть? Смотрите очереди к пулу (нехватка воркеров), TLS/сеть, медленные статики, лимиты ОС (например, somaxconn) и обратные прокси.

Итоги

slowlog — быстрый, надёжный и «лёгкий» способ локализовать проблемные участки в PHP. Включите его на ваших пулах, выберите реалистичный порог и автоматизируйте разбор. Чёткая картина того, где тратится время внутри запроса, экономит часы «на ощупь» и помогает сфокусироваться на исправлении настоящих причин: индексы, таймауты, кеши, блокировки и тюнинг пула. А дальше — итерации: фиксируем, снижаем порог точечно, закрепляем улучшения метриками.