PHP-FPM. Установка и настройка

01.05.2024

Теги: FastCGI • FPM • Linux • PHP • Конфигурация • Настройка • Сервер • Установка

Интерпретатор PHP может работать в связке с веб-сервером в нескольких режимах. Он может быть интегрирован в веб-сервер в виде специального модуля или использоваться как отдельный сервис PHP-FPM. Аббревиатура FPM расшифровывается как Fastcgi Process Manager. Это служба, который запускает несколько процессов, которые могут выполнять PHP-скрипты. Чтобы принимать запросы от веб-сервера, PHP-FPM может прослушивать сокет TCP/IP или UNIX сокет.

Установка службы PHP-FPM

Тут все просто, устанавливаем пакет php-fpm 

$ sudo apt install php-fpm

Файл конфигурации PHP-FPM

Файл конфигурации службы — это /etc/php/8.1/fpm/php-fpm.conf 

$ sudo nano /etc/php/8.1/fpm/php-fpm.conf
[global]
; Путь к pid-файлу службы. Префикс по умолчанию /var, значение по умолчанию none.
pid = /run/php/php8.1-fpm.pid

; Имя файла для логирования ошибок. Префикс по умолчанию /var, значение по умолчанию
; log/php-fpm.log. Допускается использовать значение syslog — для записи ошибок в
; системный лог вместо отдельного файла.
error_log = /var/log/php8.1-fpm.log

; Задает источник сообщения при записи в syslog. Многие службы имеет свой facility —
; cron, ftp, mail. Прочие службы имеют значение источника daemon. Источник (facility)
; вместе с приоритетом (severity) используется в файлах конфигурации syslog, чтобы
; составлять правила — сообщения от каких служб и с каким приоритетом в какой файл
; лога нужно записывать.
syslog.facility = daemon

; Подстрока, которая будет добавлена в каждое сообщение при записи в syslog. Если
; запущено несколько экземпляров службы PHP-FPM — можно установить индивидуальное
; значение для каждого. Значение по умолчанию — php-fpm.
syslog.ident = php-fpm

; Уровень логирования, допустимые значения — alert, error, warning, notice, debug.
; Значение по умолчанию — notice.
log_level = notice

; Максимальная длина строки одной записи в файл лога. Значение по умолчанию 1024.
log_limit = 4096

; Буферизация записи в лог. Если включена — строка добавлется в лог за одну
; операцию записи на диск. Это директива игнорируется при записи в syslog.
; Значение по умолчанию — yes.
log_buffering = yes
; Если кол-во дочерних процессов, которые завершились по сигналам SIGSEGV или
; SIGBUS, превышает указанное значение, то служба PHP-FPM будет перезапущена.
; Значение по умолчанию — 0 (ноль), что означает — выключено.
emergency_restart_threshold = 10

; Интервал времени в секундах, в течение которого должны завершиться дочерние
; процессы по сигналам SIGSEGV или SIGBUS, чтобы служба PHP-FPM была перезапущена.
; Значение по умолчанию — 0 (ноль), что означает — выключено.
emergency_restart_interval = 60

; Master-процесс управляет дочерними процессами, в том числе принимает решение, что
; какой-то из них нужно завершить. Эта директива задает интервал времени в секундах,
; в течение которого master-ппоцесс будет ждать корректного завершения рабочего
; процесса, прежде чем принудительно завершить его. Значение по умолчанию — 0 (ноль),
; то есть без ограничений.
process_control_timeout = 30

; Максимальное кол-во дочерних процессов, которое может запустить служба PHP-FPM.
; Это нужно для контроля глобального количества процессов при использовании dynamic
; в большом количестве пулов. Значение по умолчанию — 0 (ноль), т.е. без ограничений.
process.max = 100

; Указывает приоритет (nice) мастер-процесса (только если установлено). Принимает
; значения от -19 (максимальный) до 20 (минимальный) По умолчанию — не установлено.
process.priority = 0

; Запустить PHP-FPM в фоновом режиме. Чтобы запустить PHP-FPM для отладки — нужно
; установить значение no. По умолчанию — yes.
daemonize = yes

; Если PHP-FPM собран с интеграцией с Systemd, указывает интервал в секундах между
; оповещениями Systemd о своём состоянии. Для отключения — 0. По умолчанию — 10.
systemd_interval = 10

; Подключить все файлы конфигурации пулов процессов из директории pool.d
include=/etc/php/8.1/fpm/pool.d/*.conf

Файл конфигурации пула процессов

PHP-FPM позволяет запускать несколько пулов процессов с разными настройками. После установки уже есть файл конфигурации пула www.conf. 

$ sudo nano /etc/php/8.1/fpm/pool.d/www.conf
; Имя пула, должно быть обязательно задано и быть уникальным. Переменная $pool,
; значение которой равно имени пула, может быть использована в любой директиве.
[www]

; Пользователь и группа, от имени которого работают процессы
user = www-data
group = www-data

; Файл unix сокета или tcp/ip сокета для прослушивания запросов от веб-сервера
listen = 127.0.0.1:9000

; Размер очереди одновременно ожидающих подключений к сокету. Если значение большое,
; а PHP-FPM не успевает обрабатывать все запросы, то веб-сервер дождется тайм-аута и
; отключится, выкинув 504 ошибку (Gateway Timeout, Шлюз не отвечает). Если значение
; маленькое, то клиентские запросы вообще не могут попасть в очередь и веб-сервер
; сразу выдает 502 ошибку (Bad Gateway, Неправильный шлюз). Второй вариант лучше
; первого, потому что не нужно тратить ресурсы на хранение запросов в очереди. Можно
; установить значение, равное RPS (requests per second) для PHP-FPM службы. Тем самым
; мы разрешаем небольшую очередь, но запросы будут ждать обработки не больше секунды.
; Значение по умолчанию — 511.
listen.backlog = 100

; Разрешения для unix-сокета, если он используется. В Linux необходимо установить
; доступ на чтение и запись, чтобы разрешить подключение с веб-сервера. Здесь
; указываются пользователь и группа, под которым работает nginx или apache.
listen.owner = www-data
listen.group = www-data
listen.mode = 0660

; Список ip-адресов, которым разрешено подключение. Адреса разделяются запятыми.
; Имеет смысл только с tcp/ip сокетом. Значение по умолчанию — any (любой).
listen.allowed_clients = 127.0.0.1
; Выбор того, как PHP-FPM будет создавать дочерние процессов. Возможные значения —
; static, ondemand, dynamic.
; 1. Static — фиксированное число дочерних процессов.
; 2. Ondemand — процессы порождаются по требованию, когда в них есть необходимость.
; 3. Dynamic — динамически изменяющееся число дочерних процессов, управляется
;    директивами pm.max_children, pm.start_servers, pm.min_spare_servers,
;    pm.max_spare_servers.
pm = dynamic

; Число дочерних процессов, которые будут созданы, когда pm установлен в static.
; Или максимальное число процессов, которые будут созданы, когда pm установлен
; в dynamic. Устанавливает ограничение на число одновременных запросов, которые
; будут обслуживаться. Эквивалент директивы ApacheMaxClients с mpm_prefork и
; переменной окружения среды PHP_FCGI_CHILDREN в в оригинальном PHP FastCGI.
pm.max_children = 8

; Кол-во дочерних процессов, создаваемых при запуске. Используется, только когда
; pm установлен в dynamic. Значение по умолчанию рассчитывается по формуле
; min_spare_servers + (max_spare_servers - min_spare_servers) / 2.
pm.start_servers = 4

; Минимальное кол-во дочерних процессов, которые остаются работающими, даже еcли
; нет запросов от веб-сервера. Используется только для dynamic.
pm.min_spare_servers = 2

; Максимальное кол-во дочерних процессов, которые остаются работающими, даже еcли
; нет запросов от веб-сервера. Используется только для dynamic.
pm.max_spare_servers = 6

; Количество одновременных порождений дочерних процессов. Используется только для
; dynamic. Значение по умолчанию — 32.
pm.max_spawn_rate = 32

; Кол-во секунд, по истечению которых простаивающий без дела процесс будет завершён.
; Используется только для ondemand. Значение по умолчанию — 10.
pm.process_idle_timeout = 10

; После обслуживания указанного кол-ва запросов от веб-сервера — дочерний процесс
; будет завершен. Полезно для избежания утечек памяти при использовании сторонних
; библиотек. Значение по умолчанию — 0, что означает — без ограничений.
pm.max_requests = 0
; URI страницы статуса службы PHP-FPM. Если значение не установлено, то страница
; статуса отображаться не будет. Значение по умолчанию — не установлено.
pm.status_path = /php-fpm-status

; Значением может быть unix сокет или tcp/ip сокет, по которому будет приниматься
; запрос состояния. Создаёт новый невидимый пул, который может независимо обрабатывать
; запросы. Полезно, если основной пул занят долго выполняющимися запросами, так как
; всё ещё можно получить страницу состояния PHP-FPM до завершения долго выполняющихся
; запросов. Значение по умолчанию — как у директивы listen.
pm.status_listen = 127.0.0.1:9001

; URI страницы мониторинга службы PHP-FPM. Если значение не установлено, ping-страница
; отображаться не будет. Можно использовать для тестирования извне, чтобы убедиться,
; что служба PHP-FPM работает и отвечает. Значение по умолчанию — не установлено.
ping.path = /php-fpm-ping

; Директива предназначена для настройки ответа на ping-запрос. Ответ формируется как
; text/plain со кодом ответа 200. Значение по умолчанию — pong.
ping.response = pong
; Путь к файлу лога доступа. Префикс по умолчанию для относительного пути — /usr.
; Значение по умолчанию — не установлено.
access.log = /var/log/$pool.php-fpm.access.log

; Формат файла лога доступа. Значение по умолчанию — "%R - %u %t \"%m %r\" %s".
access.format = "%R - %u %t \"%m %r\" %s"

; Путь к файлу лога медленных запросов. Префикс по умолчанию при указании относительного
; пути — /usr. Значение по умолчанию — не установлено.
slowlog = /var/log/$pool.php-fpm.slow.log

; Время ожидания в секундах на обработку одного запроса, после чего PHP backtrace
; будет сохранён в файл slowlog. Значение по умолчанию — 0, что означает — выключено.
request_slowlog_timeout = 10

; Глубина трассировки стека вызовов для журнала slowlog. Значение по умолчанию — 20.
request_slowlog_trace_depth = 20
; Время ожидания в секундах на обработку одного запроса, после чего рабочий процесс будет
; принудительно завершён. Этот вариант следует использовать, когда опция max_execution_time
; в файле php.ini не останавливает выполнение скрипта по каким-то причинам. Значение по
; умолчанию — 0, что означает — выключено.
request_terminate_timeout = 20

; Время ожидания, установленное с помощью request_terminate_timeout, не включается после
; fastcgi_finish_request или когда приложение завершено и вызываются внутренние функции
; завершения работы. Эта директива позволит безоговорочно применять ограничение времени
; ожидания даже в таких случаях. Значение по умолчанию — no, что означает — выключено.
request_terminate_timeout_track_finished = no
; Перенаправляет stdout и stderr дочерних процессов в основной журнал ошибок. Если задано
; значение no — stdout/stderr будут перенаправлены в /dev/null. Значение по умолчанию — no.
catch_workers_output = yes

; Дополняет информацию от дочерних процессов для записи в основной журнал ошиблк. Имеет
; смысл только если catch_workers_output=yes. Значение по умолчанию — yes.
decorate_workers_output = yes

; Очистить переменные среды для дочерних процессов перед тем, как будут установлены env[…]
; для этого пула процессов. Установка значения «no» сделает доступными для PHP-кода все
; переменные окружения через getenv(), $_ENV и $_SERVER. Значение по умолчанию — yes.
clear_env = yes

; Ограничение на расширение имен файлов скриптов, которые PHP-FPM будет обрабатывать.
; Это может предотвратить ошибки конфигурации на стороне веб-сервера. Значение по
; умолчанию — .php.
security.limit_extensions = .php

; Передать дочерним процессам установленные ниже переменные окружения. Если не
; установлены, то будут только переданы переменные, заданные директивой clear_env.
env[TMP] = /tmp
env[TEMP] = /tmp

; Дополнительные настройки PHP для этого пула процессов, которые переопределяют
; настройки из файла php.ini.
php_flag[display_errors] = off
php_admin_flag[log_errors] = on
php_admin_value[error_log] = /var/log/$pool.fpm-php.error.log
php_admin_value[memory_limit] = 32M

Директива конфигурации pm

С помощью директивы pm можно настроить стратегию запуска дочерних процессов, возможные значения — static, dynamic, ondemand.

Значение static означает фиксированное кол-во дочерних процессов, которое устанавливается с помощью pm.max_children. Процессы всегда занимают определенный объем памяти и в случае пиковых нагрузок могут быть сложности, когда свободных процессов нет. С другой стороны — запросам не нужно ждать запуска новых процессов, что делает static самым быстрым. Такую стратегию лучше использовать, когда есть постоянная высокая нагрузка и большой объём памяти.

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

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

Директивы конфигурации pm.xxxxx

Директива pm.max_children — работает для всех трёх режимов, означает максимально возможное количество дочерних процессов. Если значение слишком маленькое — то при возрастании нагрузки лимит исчерпается и сайт начнёт тупить. Если значение слишком большое — исчерпается оперативная память и начнет тупить все подряд.

Директива pm.start_servers — кол-во процессов для пула, запускаемых при старте PHP-FPM службы. Используется только для dynamic. Рекомендуется установить значение в 50% от pm.max_children.

Директива pm.min_spare_servers — минимальное кол-во процессов, которые остаются работающими, даже еcли нет запросов от веб-сервера. Используется только для dynamic. Рекомендуется установить значение в 25% от pm.max_children.

Директива pm.max_spare_servers — максимальное кол-во процессов, которые остаются работающими, даже еcли нет запросов от веб-сервера. Используется только для dynamic. Рекомендуется установить значение в 75% от pm.max_children.

Директива pm.process_idle_timeout — кол-во секунд, по истечению которых простаивающий без дела процесс будет завершён. Используется только для ondemand. Маленькое значение поможет быстро высвободить память, но если есть скачки трафика, то лучше увеличить дефолтное значение 10 секунд.

Директива pm.max_requests — дочерний процесс будет завершен после обслуживания указанного кол-ва запросов от веб-сервера. Полезно для избежания утечек памяти при использовании сторонних библиотек. Рекомендуется для начала оставить значение по умолчанию. Если мониторинг показывает, что со временем каждый процесс начинает потреблять все больше памяти — только в этом случае изменять значение по умолчанию.

Пример настройки PHP-FPM

У меня две виртуальные машины — nginx (ip-адрес 192.168.110.10) и php-fpm (ip-адрес 192.168.110.20). На первой установлен веб-сервер Nginx, на второй — служба PHP-FPM. Веб-сервер обслуживает домены example.net и example.org.

Виртуальная машина nginx

Создаем файл конфигурации виртуального хоста example.net 

# nano /etc/nginx/sites-available/example.net
server {
    listen 80;
    server_name example.net www.example.net;

    root /var/www/example.net/html;
    index index.html index.php;

    location / {
        try_files $uri $uri/ =404;
    }

    location ~* \.(ico|css|js|html|gif|jpe?g|png|ttf|woff2?|eot)$ {
        add_header Cache-Control "public, max-age=3600";
    }

    location ~* \.php$ {
        # ждать ответа от php-fpm 15 секунд, после чего вернуть клиенту 504 ошибку
        fastcgi_read_timeout 15;
        # tcp/ip сокет для общения с php-fpm службой, которая будет выполнять php-код
        fastcgi_pass 192.168.110.20:9001;
        # рекомендуемый разработчиками nginx файл конфигурации для работы с php-fpm
        include snippets/fastcgi-php.conf;
        # отдельные файлы логов при обращении к службе php-fpm для запуска скриптов
        access_log /var/log/nginx/example-net.php-fpm.access.log;
        error_log /var/log/nginx/example-net.php-fpm.error.log error;
    }

    # страница статуса пула процессов с ограничением доступа по ip-адресу
    location = /php-fpm-stat {
        allow 127.0.0.1;
        allow 192.168.110.2;
        deny all;
        fastcgi_pass 192.168.110.20:9002;
        include fastcgi.conf;
        access_log off;
    }

    # отдельные файлы логов доступа и ошибок для этого виртуального хоста
    access_log /var/log/nginx/example-net.access.log;
    error_log /var/log/nginx/example-net.error.log error;
}

Создаем файл конфигурации виртуального хоста example.org 

# nano /etc/nginx/sites-available/example.org
server {
    listen 80;
    server_name example.org www.example.org;

    root /var/www/example.org/html;
    index index.html index.php;

    location / {
        try_files $uri $uri/ =404;
    }

    location ~* \.(ico|css|js|html|gif|jpe?g|png|ttf|woff2?|eot)$ {
        add_header Cache-Control "public, max-age=3600";
    }

    location ~* \.php$ {
        # ждать ответа от php-fpm 15 секунд, после чего вернуть клиенту 504 ошибку
        fastcgi_read_timeout 15;
        # tcp/ip сокет для общения с php-fpm службой, которая будет выполнять php-код
        fastcgi_pass 192.168.110.20:9003;
        # рекомендуемый разработчиками nginx файл конфигурации для работы с php-fpm
        include snippets/fastcgi-php.conf;
        # отдельные файлы логов при обращении к службе php-fpm для запуска скриптов
        access_log /var/log/nginx/example-org.php-fpm.access.log;
        error_log /var/log/nginx/example-org.php-fpm.error.log error;
    }

    # страница статуса пула процессов с ограничением доступа по ip-адресу
    location = /php-fpm-stat {
        allow 127.0.0.1;
        allow 192.168.110.2;
        deny all;
        fastcgi_pass 192.168.110.20:9004;
        include fastcgi.conf;
        access_log off;
    }

    # отдельные файлы логов доступа и ошибок для этого виртуального хоста
    access_log /var/log/nginx/example-org.access.log;
    error_log /var/log/nginx/example-org.error.log error;
}

Виртуальная машина php-fpm

Создаем файл конфигурации пула процессов, который будет обслуживать запросы от виртуального хоста example.net. 

# nano /etc/php/8.1/fpm/pool.d/example.net.conf
[example-net]
user = www-data
group = www-data

listen = 192.168.110.20:9001
listen.backlog = 100
listen.allowed_clients = 192.168.110.10

pm = static
pm.max_children = 5

pm.status_path = /php-fpm-stat
pm.status_listen = 192.168.110.20:9002

ping.path = /php-fpm-ping
ping.response = pong

access.log = /var/log/php-fpm/$pool.access.log
access.format = "%R - %u %t \"%m %r\" %s"

slowlog = /var/log/php-fpm/$pool.slow.log
request_slowlog_timeout = 5
request_slowlog_trace_depth = 20

request_terminate_timeout = 10
security.limit_extensions = .php

catch_workers_output = yes
decorate_workers_output = no

clear_env = yes

env[TMP] = /tmp
env[TMPDIR] = /tmp
env[TEMP] = /tmp

php_flag[display_errors] = off
php_admin_flag[log_errors] = on
php_admin_value[error_log] = /var/log/php-fpm/$pool.error.log
php_admin_value[memory_limit] = 32M

Создаем файл конфигурации пула процессов, который будет обслуживать запросы от виртуального хоста example.org. 

# nano /etc/php/8.1/fpm/pool.d/example.org.conf
[example-org]
user = www-data
group = www-data

listen = 192.168.110.20:9003
listen.backlog = 100
listen.allowed_clients = 192.168.110.10

pm = static
pm.max_children = 5

pm.status_path = /php-fpm-stat
pm.status_listen = 192.168.110.20:9004

ping.path = /php-fpm-ping
ping.response = pong

access.log = /var/log/php-fpm/$pool.access.log
access.format = "%R - %u %t \"%m %r\" %s"

slowlog = /var/log/php-fpm/$pool.slow.log
request_slowlog_timeout = 5
request_slowlog_trace_depth = 20

request_terminate_timeout = 10
security.limit_extensions = .php

catch_workers_output = yes
decorate_workers_output = no

clear_env = yes

env[TMP] = /tmp
env[TMPDIR] = /tmp
env[TEMP] = /tmp

php_flag[display_errors] = off
php_admin_flag[log_errors] = on
php_admin_value[error_log] = /var/log/php-fpm/$pool.error.log
php_admin_value[memory_limit] = 16M

Создаем директорию для хранения логов 

# mkdir /var/log/php-fpm

Переименовываем файл конфигурации пула по умолчанию — чтобы этот пул не создавался 

# mv /etc/php/8.1/fpm/pool.d/www.conf /etc/php/8.1/fpm/pool.d/www.conf.back

Файл логов службы PHP-FPM тоже будем хранить в директории /var/log/php-fpm 

# nano /etc/php/8.1/fpm/php-fpm.conf
[global]
; ...... прочие директивы конфигурации ......
error_log = /var/log/php-fpm/global.service.log
; ...... прочие директивы конфигурации ......

Перезапускаем службу PHP-FPM, чтобы применить новые настройки 

# systemctl restart php8.1-fpm.service

Синхронизация директорий /var/www

Обе виртуальные машины должны работать с одной директорией /var/www. Для этого можно одну из них сделать NFS-сервером, а другую — NFS-клиентом. Тогда клиент будет монтировать себе директорию с сервера по локальной сети. У меня это сделано проще — скрипт в cron раз в минуту синхронизирует директории /var/www с помощью утилиты rsync. 

$ nano /home/evgeniy/cron/www-sync.sh
#!/bin/bash
SOURCE='/var/www'
TARGET='/var/www'
SSHKEY='/home/evgeniy/.ssh/php-fpm-server'
T_USER='evgeniy'
T_HOST='192.168.110.20'

/usr/bin/rsync -e "ssh -i $SSHKEY" --owner --perms --times --recursive --delete $SOURCE/ $T_USER@$T_HOST:$TARGET
$ chmod ug+x /home/evgeniy/cron/www-sync.sh

На ВМ nginx создаем ssh-ключи и копируем публичный ключ на ВМ php-fpm 

$ ssh-keygen
$ ssh-copy-id -i /home/evgeniy/.ssh/php-fpm-server.pub evgeniy@192.168.110.20
$ ssh -i /home/evgeniy/.ssh/php-fpm-server evgeniy@192.168.110.20

Добавляем скрипт www-sync.sh в cron для запуска каждую минуту 

$ crontab -e
# синхронизация /var/www с сервером PHP-FPM
* * * * *    /home/evgeniy/cron/www-sync.sh

Чтобы установить права для скопированных файлов и директорий — нужны права root. То есть, утилиту rsync нужно запускать от имени root с опцией --super. Для этого в файле конфигурации ssh нужно разрешить удаленный доступ для root + разрешить доступ по паролю. После этого установить пароль для root, скопировать открытый ssh-ключ, удалить пароль. В общем, очень много хлопот — поэтому просто сделал вледельцем всех файлов и директорий пользователя evgeniy. И установил права для файлов и директорий, чтобы все могли их читать и записывать. Для боевого сервера так делать нельзя, но для тестирования — подойдет. 

# find /var/www -type d -exec chown evgeniy:evgeniy {} \; -print
# find /var/www -type f -exec chown evgeniy:evgeniy {} \; -print
# find /var/www -type d -exec chmod 777 {} \; -print
# find /var/www -type f -exec chmod 666 {} \; -print

На production сервере владельцем всех файлов и директорий можно сделать пользователя developer, в качестве группы для всех файлов и директорий использовать www-data. Для всех директорий внутри /var/www установить sgid — тогда у всех новых файлов и директорий будет группа www-data. Разработчик может создавать, изменять и удалять любые файл и директории без использования sudo. Если php-скрипт в процессе работы создает какие-то файлы — то для них владелец и группа будут www-data:www-data. Но такие файлы вряд ли потребуется изменять. 

# find /var/www -type d -exec chown developer:www-data {} \; -print
# find /var/www -type f -exec chown developer:www-data {} \; -print
# find /var/www -type d -exec chmod 2770 {} \; -print
# find /var/www -type f -exec chmod 660 {} \; -print

Можно для директорий установить права 2550 — но тогда php-скрипты, которые работают от имени www-data, не смогут в них создавать файлы. Если есть информация, в каких директориях php-скрипты сайта создают файлы, то для таких директорий нужно установить права 2770.

Ротация всех логов PHP-FPM

У нас теперь много файлов логов — нужно настроить ротацию. После установки пакета php-fpm уже существует файл конфигурации для ротации лога PHP-FPM службы. Нам нужно лишь немного его изменить. 

# nano /etc/logrotate.d/php8.1-fpm
/var/log/php-fpm/*.log {
    rotate 10
    daily
    missingok
    notifempty
    compress
    delaycompress
    postrotate
        if [ -x /usr/lib/php/php8.1-fpm-reopenlogs ]; then
            /usr/lib/php/php8.1-fpm-reopenlogs;
        fi
    endscript
}

Тестирование службы PHP-FPM

Давайте напишем небольшой скрипт, который иногда будет выполняться слишком долго. И с помощью утилиты ab (входит в пакет apache2-utils) проведем нагрузочное тестирование. 

$ nano /var/www/example.net/html/index.php # на виртуальной машине nginx
<?php
function fibonacci($n) {
    if ($n <= 1) {
        return $n;
    } else {
        return fibonacci($n - 1) + fibonacci($n - 2);
    }
}

$number = 3;
if (rand(1, 10) == 5) $number = 40;
echo fibonacci($number);

Запускаем утилиту ab — с любой виртуальной машины, у которой есть доступ по сети к веб-серверу 

$ ab -n 20 -c 10 http://example.net/index.php

Посмотрим файл лога доступа веб-сервера для виртуального хоста example.net. Здесь 20 запросов, из них 4 завершились с кодом 502. Это значит, что веб-сервер не дождался ответа от PHP-FPM службы. Несколько дочерних процессов вычисляли значение функции fibonacci(40) — и это заняло слишком много времени. 

# cat /var/log/nginx/example-net.php-fpm.access.log
192.168.110.25 - - [06/May/2024:09:11:57 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:11:57 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:11:57 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:11:57 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:11:57 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:08 +0000] "GET /index.php HTTP/1.0" 502 166 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:08 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:08 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:08 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:20 +0000] "GET /index.php HTTP/1.0" 502 166 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:20 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:20 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:31 +0000] "GET /index.php HTTP/1.0" 502 166 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:31 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:31 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:31 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:31 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:31 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:31 +0000] "GET /index.php HTTP/1.0" 200 1 "-" "ApacheBench/2.3"
192.168.110.25 - - [06/May/2024:09:12:43 +0000] "GET /index.php HTTP/1.0" 502 166 "-" "ApacheBench/2.3"
# cat /var/log/nginx/example-net.php-fpm.error.log
2024/05/06 09:12:08 [error] 4142#4142: *11 recv() failed (104: Unknown error) while reading response header from upstream,
client: 192.168.110.25, server: example.net, request: "GET /index.php HTTP/1.0", upstream: "fastcgi://192.168.110.20:9001",
host: "example.net"
2024/05/06 09:12:20 [error] 4142#4142: *19 recv() failed (104: Unknown error) while reading response header from upstream,
client: 192.168.110.25, server: example.net, request: "GET /index.php HTTP/1.0", upstream: "fastcgi://192.168.110.20:9001",
host: "example.net"
2024/05/06 09:12:31 [error] 4142#4142: *25 recv() failed (104: Unknown error) while reading response header from upstream,
client: 192.168.110.25, server: example.net, request: "GET /index.php HTTP/1.0", upstream: "fastcgi://192.168.110.20:9001",
host: "example.net"
2024/05/06 09:12:43 [error] 4142#4142: *39 recv() failed (104: Unknown error) while reading response header from upstream,
client: 192.168.110.25, server: example.net, request: "GET /index.php HTTP/1.0", upstream: "fastcgi://192.168.110.20:9001",
host: "example.net"

Похожую картину мы увидим, если посмотрим лог доступа на виртуальной машине php-fpm. Здесь нет ошибок, скрипт все 20 раз отработал успешно — просто иногда это было долго. 

# cat /var/log/php-fpm/example-net.access.log
192.168.110.10 -  06/May/2024:09:11:57 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:11:57 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:11:57 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:11:57 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:11:57 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:12:08 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:12:08 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:12:08 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:12:20 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:12:20 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:12:31 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:12:31 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:12:31 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:12:31 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:12:31 +0000 "GET /index.php" 200
192.168.110.10 -  06/May/2024:09:12:31 +0000 "GET /index.php" 200

Но при этом PHP-FPM служба добавила несколько записей в лог медленных запросов — это повод задуматься об оптимизации. 

# cat /var/log/php-fpm/example-net.slow.log
[06-May-2024 09:12:15]  [pool example-net] pid 10930
script_filename = /var/www/example.net/html/index.php
[0x00007f6d84614570] fibonacci() /var/www/example.net/html/index.php:6
[0x00007f6d846144e0] fibonacci() /var/www/example.net/html/index.php:6
[0x00007f6d84614450] fibonacci() /var/www/example.net/html/index.php:6
.......... всего 20 записей ..........

[06-May-2024 09:12:26]  [pool example-net] pid 10931
script_filename = /var/www/example.net/html/index.php
[0x00007f6d846144e0] fibonacci() /var/www/example.net/html/index.php:6
[0x00007f6d84614450] fibonacci() /var/www/example.net/html/index.php:6
[0x00007f6d846143c0] fibonacci() /var/www/example.net/html/index.php:6
.......... всего 20 записей ..........

Здесь есть имя файла скрипта, который выполнялся слишком долго. И есть стэк вызовов — 20 записей для каждого медленного скрипта. Стэк вызовов должен быть намного больше — но мы ограничили его с помощью директивы request_slowlog_trace_depth.

Очередь запросов от веб-сервера

Директива listen.backlog задает размер очереди запросов от веб-сервера, которые ожидают подключения к сокету. Вообще, если образуется очередь — желательно увеличить кол-во процессов. Но если пики высокой нагрузки возникают редко — можно обработать чуть больше запросов за счет очереди.

Если значение большое, а PHP-FPM не успевает обрабатывать все запросы, то веб-сервер дождется тайм-аута и отключится, выкинув 504 ошибку (Gateway Timeout, Шлюз не отвечает). Если значение маленькое, то клиентские запросы вообще не могут попасть в очередь и веб-сервер сразу выдает 502 ошибку (Bad Gateway, Неправильный шлюз). Второй вариант лучше первого, потому что не нужно тратить ресурсы на хранение запросов в очереди.

Можно установить значение, равное RPS (requests per second) для пула процессов. Тем самым мы разрешаем небольшую очередь, но запросы будут ждать обработки не больше секунды. Все остальные клиенты, чьи запросы не попали в очередь — получат ошибку 502 от веб-сервера.

Значение RPS (requests per second) мы можем получить из логов доступа пула процессов. Получать нужно значение за период наибольшей нагрузки. Допустим, в интернет-магазине большая часть покупателей приходят в промежуток времени с 10:00 до 18:00. 

# cat /var/log/php-fpm/example-net.access.log | egrep '06/May/2024:1[0-7]:' | wc -l
2879865

Кол-во секунд за период с 10:00 до 18:00 равно 28800. Тогда RPS (requests per second) равно 2879865/28800=99.99. 

# nano /etc/php/8.1/fpm/pool.d/example.net.conf
listen.backlog = 100
Здесь следует помнить, что есть два RPS (requests per second) — сколько запросов в секунду отправляет веб-сервер и сколько из них пул процессов способен обработать.

Страница статуса пула процессов

В файлах конфигурации виртуальных хостов мы определили местоположение /php-fpm-stat для виртуальных хостов example.net и example.org. Давайте запустим нагрузочное тестирование для example.net и посмотрим на страницу статуса. Но сперва добавим в файл /etc/hosts на виртуальной машине nginx еще одну запись, чтобы можно было смотреть страницу статуса прямо с этой машины — без браузера, используя утилиту curl. 

# nano /etc/hosts
127.0.0.1 localhost
127.0.1.1 nginx
127.0.0.1 example.net www.example.net

Изменим скрипт index.php, чтобы время выполнения все время было разным — в реальных условиях будет обращение к разным скриптам, у всех будет разное время выполнения. Тем самым приближаем условия к реальности. 

$ nano /var/www/example.net/html/index.php # на виртуальной машине nginx
<?php
function fibonacci($n) {
    if ($n <= 1) {
        return $n;
    } else {
        return fibonacci($n - 1) + fibonacci($n - 2);
    }
}

$number = rand(25, 35);
echo fibonacci($number);

Запускаем утилиту ab — с любой виртуальной машины, у которой есть доступ по сети к веб-серверу. Можно даже с виртуальной машины nginx — главное, чтобы у этой машины был прописан в /etc/hosts ip-адрес и домен веб-сервера. 

$ ab -n 200 -c 20 http://example.net/index.php

Опция -c означает, что одновременно выполняется не больше 20 запросов к веб-серверу. Другими словами, если в данный момент времени выполняются 20 запросов, то утилита ab не будет отправлять еще один, пока не будет завершен какой-то из этих двадцати.

Пока выполянются запросы — запускаем утилиту curl. Запускать можно с любой виртуальной машины, у которой есть доступ по сети к веб-серверу. Можно даже с виртуальной машины nginx — главное, чтобы у этой машины был прописан в /etc/hosts ip-адрес и домен веб-сервера. И был разрешен доступ к /php-fpm-stat в файле конфигурации виртуального хоста (у меня разрешен доступ с 127.0.0.1 и 192.168.110.2). 

$ curl http://example.net/php-fpm-stat
pool:                 example-net
process manager:      static
start time:           06/May/2024:12:08:06 +0000
start since:          84
accepted conn:        136
listen queue:         40
max listen queue:     41
listen queue len:     100
idle processes:       0
active processes:     10
total processes:      10
max active processes: 10
max children reached: 0
slow requests:        26

Здесь видно, что в настоящий момент работают 10 процессов пула из 10 доступных. При этом есть 26 запросов, которые выполнялись медленно — что говорит о необходимости оптимизации. И образовалась очередь из 40 запросов — что говорит о необходимости увеличить pm.max_children. Описание параметров на странице статуса — представлено в таблице ниже.

Параметр Описание
pool Имя пула процессов FPM
proccess manager Тип менеджера процесса — static, dynamic или ondemand
start time Дата и время последнего запуска пула процессов
start since Время в секундах с момента последнего запуска пула процессов
accepted conn Общее количество принятых соединений с момента последнего запуска пула процессов
listen queue Текущее количество запросов в очереди, ожидающих свободного процесса
max listen queue Максимальное количество запросов в очереди, которое было достигнуто за все время с момента последнего запуска пула
listen queue len Максимально допустимый размер очереди прослушивания (из файла конфигурации)
idle processes Количество процессов, которые в настоящее время простаивают без дела
active processes Количество процессов, которые в настоящее время обрабатывают запросы
total processes Текущее общее количество процессов
max active processes Максимальное количество одновременно активных процессов, которое было достигнуто за все время с момента последнего запуска пула
max children reached Было ли достигнуто максимальное количество процессов с момента последнего запуска пула — 1 (да) или 0 (нет), для dynamic и ondemand.
slow requests Общее количество запросов, которые достигли значения request_slowlog_timeout

Данные статуса пула процессов можно получить в формате html, xml, json 

$ curl http://example.net/php-fpm-stat?json
{
    "pool": "example-net",
    "process manager": "static",
    "start time": 1715256486,
    "start since": 586,
    "accepted conn": 260,
    "listen queue": 40,
    "max listen queue": 41,
    "listen queue len": 100,
    "idle processes": 0,
    "active processes": 10,
    "total processes": 10,
    "max active processes": 10,
    "max children reached": 0,
    "slow requests": 53
}

Больше данных можно получить на странице полного статуса пула процессов http://example.net/php-fpm-stat?full.

Мониторинг пула процессов

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

$ nano /home/evgeniy/cron/php-fpm-stat.sh
#!/bin/bash

TELEGRAM_API_KEY='..........'
TELEGRAM_CHAT_ID='..........'

PHP_FPM_STATUS='http://example.net/php-fpm-stat'
# Размер очереди в процентах от максимального значения,
# когда нужно отправлять сообщение в телеграм
QUEUE_SIZE_WARN=90
# Количество медленных запросов в процентах от общего
# количества, когда нужно отправлять сообщение
SLOW_VALUE_WARN=10

function telegram {
    api_url="https://api.telegram.org/bot${TELEGRAM_API_KEY}/sendMessage"
    header='Content-Type: application/json; charset=utf-8'
    message=$1
    json='{\"chat_id\":\"%s\",\"text\":\"%s\"}'
    printf -v data "$json" "$TELEGRAM_CHAT_ID" "$message"
    curl -X POST -H "$header" -d "$data" $api_url > /dev/null 2>&1
}

status=$(curl -s -i $PHP_FPM_STATUS)
http_code=$(echo "$status" | egrep 'HTTP/1.1 200 OK')
if [ -z "$http_code" ]; then
    telegram 'Ошибка! Служба PHP-FPM не отвечает!'
    exit 1
fi

# Определяем размер очереди запросов
queue_len=$(echo "$status" | egrep '^listen queue len:' | sed -r 's/listen queue len:\s+//')
queue_now=$(echo "$status" | egrep '^listen queue:' | sed -r 's/listen queue:\s+//')
queue_val=$(( 100 * $queue_now / $queue_len ))
if (( $queue_val >= $QUEUE_SIZE_WARN )); then
    telegram "Warning! Размер очереди запросов $queue_val%"
fi

# Определяем кол-во медленных запросов
conn_all=$(echo "$status" | egrep '^accepted conn:' | sed -r 's/accepted conn:\s+//')
[ $conn_all -eq 0 ] && conn_all=1 # чтобы не было деления на ноль
slow_req=$(echo "$status" | egrep '^slow requests:' | sed -r 's/slow requests:\s+//')
slow_val=$(( 100 * $slow_req / $conn_all ))
if (( $slow_val >= $SLOW_VALUE_WARN )); then
    telegram "Warning! Кол-во медленных запросов $slow_val%"
fi
$ chmod ug+x /home/evgeniy/cron/php-fpm-stat.sh
$ crontab -e
* * * * *    /home/evgeniy/cron/php-fpm-stat.sh

Как выбрать pm.max_children

Для пула example-net мы установили pm.max_children=10, но это значение «с потолка». Мы пока не знаем, какое значение нужно, чтобы пул процессов успевал обслуживать все запросы от веб-сервера. Можно на какое-то время установить нулевой размер очереди и потом посмотреть, сколько 502 ошибок будет в логах веб-сервера. 

# nano /etc/php/8.1/fpm/pool.d/example.net.conf
listen.backlog = 0

Отбираем записи за период времени с 10:00 до 11:00 

# cat /var/log/nginx/example-net.php-fpm.access.log | grep '06/May/2024:10:' | wc -l
403200
# cat /var/log/nginx/example-net.php-fpm.access.log | grep '06/May/2024:10:' | grep ' 502 ' | wc -l
41516

Веб-сервер отправляет 403200/3600=112 запросов в секунду, а пул процессов обрабатывает (403200-41516)/3600=100 запросов в секунду. Теперь можно сказать, что производительность пула процессов составляет (100/112)*100=89% от необходимой.

Прежде чем изменять pm.max_children — нужно выяснить, сколько еще процессов можно добавить к тем, что уже работают. Для этого проверим объем свободной памяти и выясним, сколько в среднем потребляет один процесс пула example-net. 

# free -m
               total        used        free      shared  buff/cache   available
Mem:            1423         368         653           3         401         902
Swap:           2047           0        2047

Посмотреть, сколько памяти используют процессы пулов example-net и example-org, можно с помощью команды 

# ps -C php-fpm8.1 -o user,pcpu,rss,cmd
USER     %CPU   RSS CMD
root      0.0 20596 php-fpm: master process (/etc/php/8.1/fpm/php-fpm.conf)
www-data  0.0  7432 php-fpm: pool example-org
www-data  0.0  7432 php-fpm: pool example-org
www-data  0.0  7432 php-fpm: pool example-org
www-data  0.0  7432 php-fpm: pool example-org
www-data  0.0  7432 php-fpm: pool example-org
www-data  0.6 26228 php-fpm: pool example-net
www-data  0.5 26224 php-fpm: pool example-net
www-data  0.5 26228 php-fpm: pool example-net
www-data  0.2 26220 php-fpm: pool example-net
www-data  0.1 26228 php-fpm: pool example-net
www-data  0.7 26228 php-fpm: pool example-net
www-data  0.2 26228 php-fpm: pool example-net
www-data  0.3 26220 php-fpm: pool example-net
www-data  0.0 27196 php-fpm: pool example-net
www-data  0.0 27188 php-fpm: pool example-net

Нам нужно вычислить среднее значение потребления памяти одним процессом пула example-net — причем, за какой-то достаточно значимый период времени. Например, получим данные по использованию памяти 10 раз с задержкой в 1 секунду. 

# for i in {1..10}; do ps -C php-fpm8.1 -o user,pcpu,rss,cmd | grep example-net; sleep 1; done
www-data  0.5 26228 php-fpm: pool example-net
www-data  0.5 26224 php-fpm: pool example-net
www-data  0.4 26228 php-fpm: pool example-net
www-data  0.2 26220 php-fpm: pool example-net
www-data  0.1 26228 php-fpm: pool example-net
www-data  0.6 26228 php-fpm: pool example-net
www-data  0.2 26228 php-fpm: pool example-net
www-data  0.3 26220 php-fpm: pool example-net
www-data  0.0 27196 php-fpm: pool example-net
www-data  0.0 27188 php-fpm: pool example-net
.......... всего 100 строк ..........

Но лучше взять период побольше — хотя для этого придется подождать 

# for i in {1..600}; do ps -C php-fpm8.1 -o rss,cmd | \
> grep example-net; sleep 1; done | \
> awk 'BEGIN { s = 0; i = 0 } { s += $1; i++ } END { print s/i }'
26418.8

Получилось 26419 Кб или 26 Мб на один процесс. Делим свободную оперативную память на память процесса 902/26=34 — и получаем, что можно увеличить значение pm.max_children с 10 до 44. Впрочем, нам так много процессов не нужно — достаточно увеличить pm.max_children до 12.

Сумма всех значений pm.max_children всех пулов процессов не должна превышать значение глобальной директивы process.max.

Теперь можно задать для listen.backlog значение, равное RPS (requests per second) пула процессов. Когда pm.max_children был равен 10 — RPS пула процессов был равен 100. Мы увеличили pm.max_children до 12 — теперь RPS пула процессов равен 120. Мы разрешаем небольшую очередь — но ожидание будет недолгим, не больше одной секунды. 

# nano /etc/php/8.1/fpm/pool.d/example.net.conf
listen.backlog = 120

Время выполнения php-скриптов

Может возникнуть задача — получить среднее время выполнения скриптов. Это может быть полезно для вычисления RPS (requests per second) пула процессов. Если среднее время выполнения скриптов 0.1 секунда, то один процесс за секунду выполнит 10 скриптов, а пул из 10 процессов выполнит 100 скриптов.

Время выполнения можно получить из лога доступа, если изменить его формат. Заполнитель %d означает время выполнения в секундах. 

access.log = /var/log/php-fpm/$pool.access.log
access.format = "%d %R - %u %t \"%m %r\" %s"
# cat /var/log/php-fpm/example-net.access.log
0.250 192.168.110.10 -  07/May/2024:13:57:20 +0000 "GET /index.php" 200
0.632 192.168.110.10 -  07/May/2024:13:57:20 +0000 "GET /index.php" 200
0.279 192.168.110.10 -  07/May/2024:13:57:20 +0000 "GET /index.php" 200
0.155 192.168.110.10 -  07/May/2024:13:57:20 +0000 "GET /index.php" 200
1.311 192.168.110.10 -  07/May/2024:13:57:19 +0000 "GET /index.php" 200
0.420 192.168.110.10 -  07/May/2024:13:57:20 +0000 "GET /index.php" 200
1.189 192.168.110.10 -  07/May/2024:13:57:20 +0000 "GET /index.php" 200
1.234 192.168.110.10 -  07/May/2024:13:57:20 +0000 "GET /index.php" 200
1.155 192.168.110.10 -  07/May/2024:13:57:20 +0000 "GET /index.php" 200
0.476 192.168.110.10 -  07/May/2024:13:57:20 +0000 "GET /index.php" 200
..........

Посчитаем среднее время выполнения php-скриптов 

# cat /var/log/php-fpm/example-net.access.log | awk 'BEGIN { s = 0; i = 0 } { s += $1; i++ } END { print s/i }'
0.27276

Еще может быть интересно найти самые медленные скрипты 

# sort -n -k 1 /var/log/php-fpm/example-net.access.log | tail -3
7.932 192.168.110.10 -  07/May/2024:10:34:36 +0000 "GET /index.php" 200
8.765 192.168.110.10 -  07/May/2024:10:34:23 +0000 "GET /index.php" 200
9.590 192.168.110.10 -  07/May/2024:10:34:48 +0000 "GET /index.php" 200

Но нужно еще найти запись в логе медленных запросов, чтобы посмотреть стэк вызовов. В логе доступа есть время начала обработки запроса %t, давайте добавим время завершения %T и идентифкатор процесса %p — так будет проще искать в логе медленных запросов. 

# nano /etc/php/8.1/fpm/pool.d/example.net.conf
access.log = /var/log/php-fpm/$pool.access.log
access.format = "%d pid %p %R - %u start %t stop %T \"%m %r\" %s"
# systemctl restart php8.1-fpm.service

Еще раз ищем в логе доступа самые медленные скрипты 

# sort -n -k 1 /var/log/php-fpm/example-net.access.log | tail -3
4.285 pid 12278 192.168.110.10 -  start 07/May/2024:10:40:21 +0000 stop 07/May/2024:10:40:26 +0000 "GET /index.php" 200
6.944 pid 12276 192.168.110.10 -  start 07/May/2024:10:40:26 +0000 stop 07/May/2024:10:40:33 +0000 "GET /index.php" 200
7.014 pid 12275 192.168.110.10 -  start 07/May/2024:10:40:14 +0000 stop 07/May/2024:10:40:21 +0000 "GET /index.php" 200

Теперь ищем запись в логе медленных запросов. Тут нужно учитывать такой момент — время в логе медленных запросов будет где-то между start и stop. Чтобы найти нужную запись — используем PID рабочего процесса, который выполнял скрипт. 

# cat /var/log/php-fpm/example-net.slow.log | grep -A 21 '07-May-2024 10:40:' | grep -A 21 'pid 12275'
[07-May-2024 10:40:20]  [pool example-net] pid 12275
script_filename = /var/www/example.net/html/index.php
[0x00007f9bfaa16000] fibonacci() /var/www/example.net/html/index.php:6
..........

Timeout для веб-сервера и PHP-FPM

Директива fastcgi_read_timeout веб-сервера Nginx задает количество секунд ожидания ответа от FastCGI-сервера. Таймаут устанавливается не на всю передачу ответа, а только между двумя операциями чтения. Если за это время FastCGI-сервер ничего не передает — соединение закрывается. По-умолчанию равно 60 секунд.

Директива request_terminate_timeout пула процессов задает количество секунд для обработки одного запроса, после чего рабочий процесс будет завершен. Этот вариант следует использовать, когда опция max_execution_time в php.ini не останавливает выполнение скрипта по каким-то причинам. Значение по умолчанию — 0, что означает — выключено.

Если PHP-FPM будет отдавать ответ более fastcgi_read_timeout секунд, то Nginx вернет клиент 504 Gateway Timeout. Если request_terminate_timeout сработает раньше fastcgi_read_timeout, то Nginx вернет клиент 502 Bad Gateway.

При подсчете времени выполнения скрипта на основе set_time_limit() в коде и max_execution_time в php.ini — PHP не учитывает время, затраченное на различные действия вне скрипта, такие как вызовы функций system(), sleep(), потоковые операции, запросы к базам данных и так далее.

Например, если max_execution_time равен 30 секунд, при этом есть вызов sleep(10), то PHP остановит выполнение скрипта только по прошествии 40 секунд. Мало того, если тайм-аут изначально был 30 секунд, и через 25 секунд после запуска скрипта будет вызвана функция set_time_limit(20), то скрипт будет работать максимум 45 секунд. Еще следует учитывать hard_timeout, которое продлевает max_execution_time на случай, если вдруг что-то застрянет.

Если посмотреть глобальный лог PHP-FPM службы — можно увидеть сообщения о записи в лог медленных запросов и завершении процессов, которые выполняются слишком долго. 

# cat /var/log/php-fpm/global.service.log
[07-May-2024 11:35:21] NOTICE: fpm is running, pid 20981
[07-May-2024 11:35:21] NOTICE: ready to handle connections
[07-May-2024 11:35:21] NOTICE: systemd monitor interval set to 10000ms
[07-May-2024 11:35:36] WARNING: [pool example-net] child 20982, script ... executing too slow (6.306719 sec), logging
..........
[07-May-2024 11:35:48] WARNING: [pool example-net] child 20983, script ... execution timed out (11.015158 sec), terminating
..........

Запись лога ошибок php-скриптов

Есть несколько директив в разных файлах конфигурации, которые отвечают за логи ошибок выполнения php-скриптов

  • в файле конфигурации php.ini директива log_errors включает запись, а директива error_log задает имя лога
  • директива error_log файла конфигурации службы PHP-FPM задает имя глобального лога для всех пулов процессов
  • директива catch_workers_output в файле конфигурации пула процессов включает перенаправление stdout/stderr
  • директива fastcgi.logging в файле конфигурации php.ini включает перенаправление ошибок к веб-серверу
  • можно запустить PHP-FPM в демонизированном виде, либо опцией --force-stderr заставить писать в stderr

Глобальный лог ошибок PHP-FPM — это лог, в который записываются сообщения master-процесса, а также сообщений от дочерних процессов при определенных настройках. Глобальный лог может быть записан в stderr, либо в файл, указанный в директиве error_log.

В ряде случаев PHP-FPM проигнорирует значение из error_log и будет писать глобальный лог в другое место. По этой причине и введен термин «глобальный лог», так как говорить «логи пишутся в error_log» будет некорректно. Может быть вовсе не в error_log.

У PHP-FPM есть опции командной строки для включения/выключения демонизации и опция force-stderr перенаправления вывода в stderr, которые определяют, чем в конечном счете будет «глобальный лог» (см. подробнее здесь). 

$ php-fpm8.1 --help
..........
-D, --daemonize     force to run in background, and ignore daemonize option from config file
-F, --nodaemonize   force to stay in foreground, and ignore daemonize option from config file
-O, --force-stderr  force output to stderr in nodaemonize even if stderr is not a TTY
..........

Если директива catch_workers_output для пула процессов включена — ошибки дочерних процессов могут быть доставлены master-процессу и записаны в глобальный лог. Если директива fastcgi.logging включена (это значение по умолчанию) — ошибки будут переданы Nginx и записаны в лог ошибок веб-сервера.

Давайте напишем два небольших скрипта, первый будет выводить текст в stdout и stderr, второй будет содержать ошибку. 

# nano /var/www/example.net/html/stdout-stderr.php
<?php
echo 'FastCGI output';
file_put_contents('php://stdout', 'To stdout');
file_put_contents('php://stderr', 'To stderr');
# nano /var/www/example.net/html/call-undef.php
<?php
function outer() {
    inner();
}
outer();

1. Первый пример конфигурации

Выполнение кода, когда директива catch_workers_output равна yes

  • записи в php://stdout и php://stderr попадут в глобальный лог
  • ошибки рабочего процесса при выполнении php-скрипта попадут в лог ошибок PHP
  • текст «FastCGI output» попадет в FastCGI сокет и будет отправлен веб-серверу
# nano /etc/php/8.1/fpm/pool.d/example.net.conf
[example-net]
catch_workers_output = yes
decorate_workers_output = no

php_flag[display_errors] = off
php_admin_flag[log_errors] = on
php_admin_value[error_log] = /var/log/php-fpm/$pool.error.log

Эта конфигурация используется чаще всего. Ошибки записываются в файл лога ошибок PHP (настройки задаются в php.ini, но могу быть перезаписан в файле конфигурации пула). При этом ошибки не попадают в глобальный лог PHP-FPM и не попадают в лог ошибок веб-сервера. 

# cat /var/log/php-fpm/global.service.log # на виртуальной машине php-fpm
[07-May-2024 15:56:41] NOTICE: fpm is running, pid 53894
[07-May-2024 15:56:41] NOTICE: ready to handle connections
[07-May-2024 15:56:41] NOTICE: systemd monitor interval set to 10000ms
To stdout
To stderr
# cat /var/log/php-fpm/example-net.error.log # на виртуальной машине php-fpm
[07-May-2024 15:58:54 UTC] PHP Fatal error:  Uncaught Error: Call to undefined function inner() in
/var/www/example.net/html/call-undef.php:3
Stack trace:
#0 /var/www/example.net/html/call-undef.php(5): outer()
#1 {main}
  thrown in /var/www/example.net/html/call-undef.php on line 3

Если для директивы decorate_workers_output устарновить значение yes — в логах будет дополнительная информация. 

# cat /var/log/php-fpm/global.service.log # на виртуальной машине php-fpm
[07-May-2024 15:56:41] NOTICE: fpm is running, pid 53894
[07-May-2024 15:56:41] NOTICE: ready to handle connections
[07-May-2024 15:56:41] NOTICE: systemd monitor interval set to 10000ms
[07-May-2024 15:57:55] WARNING: [pool example-net] child 53895 said into stdout: "To stdout"
[07-May-2024 15:57:55] WARNING: [pool example-net] child 53895 said into stderr: "To stderr"

2. Второй пример настройки

Выполнение кода, когда директива catch_workers_output равна no

  • записи в php://stdout и php://stderr попадут в /dev/null
  • ошибки рабочего процесса при выполнении php-скрипта попадут в /dev/null
  • текст «FastCGI output» попадет в FastCGI сокет и будет отправлен веб-серверу
# nano /etc/php/8.1/fpm/pool.d/example.net.conf
[example-net]
catch_workers_output = no
decorate_workers_output = no

php_flag[display_errors] = off
php_admin_flag[log_errors] = on
php_admin_value[error_log] = /var/log/php-fpm/$pool.error.log

Ошибки не записываются в файл лога ошибок PHP, не попадают в глобальный лог PHP-FPM, не попадают в лог ошибок веб-сервера. 

# cat /var/log/php-fpm/global.service.log
[07-May-2024 16:05:18] NOTICE: fpm is running, pid 56025
[07-May-2024 16:05:18] NOTICE: ready to handle connections
[07-May-2024 16:05:18] NOTICE: systemd monitor interval set to 10000ms

3. Третий пример настройки

Выполнение кода, когда директива catch_workers_output=yes и php_admin_value[error_log]=/dev/stderr

  • записи в php://stdout и php://stderr попадут в глобальный лог
  • ошибки рабочего процесса при выполнении php-скрипта попадут в глобальный лог
  • текст «FastCGI output» попадет в FastCGI сокет и будет отправлен веб-серверу
# nano /etc/php/8.1/fpm/pool.d/example.net.conf
[example-net]
catch_workers_output = yes
decorate_workers_output = no

php_flag[display_errors] = off
php_admin_flag[log_errors] = on
php_admin_value[error_log] = /dev/stderr

Файл лога ошибок PHP не создается. Но ошибки попадают в глобальный лог PHP-FPM и попадают в лог ошибок веб-сервера. 

# cat /var/log/php-fpm/global.service.log # на виртуальной машине php-fpm
[07-May-2024 16:12:52] NOTICE: fpm is running, pid 52678
[07-May-2024 16:12:52] NOTICE: ready to handle connections
[07-May-2024 16:12:52] NOTICE: systemd monitor interval set to 10000ms
To stdout
To stderr
NOTICE: PHP message: PHP Fatal error:  Uncaught Error: Call to undefined function inner() in /.../call-undef.php:3
Stack trace:
#0 /var/www/example.net/html/call-undef.php(5): outer()
#1 {main}
  thrown in /var/www/example.net/html/call-undef.php on line 3
# cat /var/log/nginx/example-net.php-fpm.error.log # на виртуальной машине nginx
2024/05/07 16:17:44 [error] 6819#6819: *1 FastCGI sent in stderr:
"PHP message: PHP Fatal error:  Uncaught Error: Call to undefined function inner() in /var/.../call-undef.php:3
Stack trace:
#0 /var/www/example.net/html/call-undef.php(5): outer()
#1 {main}
thrown in /var/www/example.net/html/call-undef.php on line 3" while reading response header from upstream,
client: 192.168.110.2, server: example.net,request:  "GET /call-undef.php HTTP/1.1", upstream:
"fastcgi://192.168.110.20:9001", host: "example.net"

Если для директивы decorate_workers_output устарновить значение yes — в логах будет дополнительная информация. 

# cat /var/log/php-fpm/global.service.log # на виртуальной машине php-fpm
[07-May-2024 16:15:52] NOTICE: fpm is running, pid 52678
[07-May-2024 16:15:52] NOTICE: ready to handle connections
[07-May-2024 16:15:52] NOTICE: systemd monitor interval set to 10000ms
[07-May-2024 16:16:35] WARNING: [pool example-net] child 76516 said into stdout: "To stdout"
[07-May-2024 16:16:35] WARNING: [pool example-net] child 76516 said into stderr: "To stderr"
[07-May-2024 16:17:44] WARNING: [pool example-net] child 76512 said into stderr: "... здесь сообщение об ошибке ..."

Дополнительно

Поиск: FastCGI • Linux • Конфигурация • Настройка • Сервер • Установка • PHP • FPM

Каталог оборудования
Lorem ipsum dolor sit amet, consectetur adipiscing elit, sed do eiusmod tempor incididunt ut labore et dolore magna aliqua.
Производители
Lorem ipsum dolor sit amet, consectetur adipiscing elit, sed do eiusmod tempor incididunt ut labore et dolore magna aliqua.
Функциональные группы
Lorem ipsum dolor sit amet, consectetur adipiscing elit, sed do eiusmod tempor incididunt ut labore et dolore magna aliqua.