Home / server / Questions / 1090979
In Process
JimmyBanks
Asked: 2022-01-25 06:57:13 +0800 CST

Slow PHP-FPM startup on new VMs

  • 772

I have an Ubuntu 18.04 virtual machine that is started up automatically by an Azure VMSS.

It appears that PHP-FPM is taking up to 60 seconds to startup when the VM is turned on. I was under the impression that PHP-FPM startup should be in the low seconds at most. An issue I am running into is that Azure is swapping VMs, and the first 30 seconds I receive a 502 Bad Gateway error because Nginx is searching for php8.1-fpm.sock but the socket hasn't yet been created since FPM is still booting up. I lose a lot of requests during this transition.

My NGINX settings are as follows:

user = www-data
group = www-data
listen = /run/php/php8.1-fpm.sock
listen.owner = www-data
listen.group = www-data
listen.mode = 0660
pm = dynamic
pm.max_children = 35
pm.start_servers = 25
pm.min_spare_servers = 25
pm.max_spare_servers = 30

PHP-FPM is also enabled:

sudo apt-get update
sudo apt-get install -y --no-install-recommends php8.1
sudo apt-get install -y --no-install-recommends php8.1-fpm
sudo apt-get install -y --no-install-recommends php8.1-cli
sudo apt-get install -y --no-install-recommends php8.1-mysql
[...]
sudo systemctl enable php8.1-fpm

What am I missing here that is causing the slow startup times?

As requested in comments: PHP8.1-fpm.log

[24-Jan-2022 15:35:37] NOTICE: fpm is running, pid 12619
[24-Jan-2022 15:35:37] NOTICE: ready to handle connections
[24-Jan-2022 15:35:37] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:35:38] NOTICE: Terminating ...
[24-Jan-2022 15:35:38] NOTICE: exiting, bye-bye!
[24-Jan-2022 15:35:38] NOTICE: fpm is running, pid 12719
[24-Jan-2022 15:35:38] NOTICE: ready to handle connections
[24-Jan-2022 15:35:38] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:35:46] NOTICE: Terminating ...
[24-Jan-2022 15:35:46] NOTICE: exiting, bye-bye!
[24-Jan-2022 15:35:46] NOTICE: fpm is running, pid 13226
[24-Jan-2022 15:35:46] NOTICE: ready to handle connections
[24-Jan-2022 15:35:46] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:35:53] NOTICE: Terminating ...
[24-Jan-2022 15:35:53] NOTICE: exiting, bye-bye!
[24-Jan-2022 15:35:54] NOTICE: fpm is running, pid 14275
[24-Jan-2022 15:35:54] NOTICE: ready to handle connections
[24-Jan-2022 15:35:54] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:36:02] NOTICE: Terminating ...
[24-Jan-2022 15:36:02] NOTICE: exiting, bye-bye!
[24-Jan-2022 15:36:02] NOTICE: fpm is running, pid 15050
[24-Jan-2022 15:36:02] NOTICE: ready to handle connections
[24-Jan-2022 15:36:02] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:36:12] NOTICE: Terminating ...
[24-Jan-2022 15:36:12] NOTICE: exiting, bye-bye!
[24-Jan-2022 15:36:12] NOTICE: fpm is running, pid 17053
[24-Jan-2022 15:36:12] NOTICE: ready to handle connections
[24-Jan-2022 15:36:12] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:36:19] NOTICE: Terminating ...
[24-Jan-2022 15:36:19] NOTICE: exiting, bye-bye!
[24-Jan-2022 15:36:19] NOTICE: fpm is running, pid 17527
[24-Jan-2022 15:36:19] NOTICE: ready to handle connections
[24-Jan-2022 15:36:19] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:37:11] NOTICE: Terminating ...
[24-Jan-2022 15:37:11] NOTICE: exiting, bye-bye!
[24-Jan-2022 15:37:11] NOTICE: fpm is running, pid 20214
[24-Jan-2022 15:37:11] NOTICE: ready to handle connections
[24-Jan-2022 15:37:11] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:37:19] NOTICE: Terminating ...
[24-Jan-2022 15:37:19] NOTICE: exiting, bye-bye!
[24-Jan-2022 15:37:19] NOTICE: fpm is running, pid 20683
[24-Jan-2022 15:37:19] NOTICE: ready to handle connections
[24-Jan-2022 15:37:19] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:37:25] NOTICE: Terminating ...
[24-Jan-2022 15:37:25] NOTICE: exiting, bye-bye!
[24-Jan-2022 15:37:25] NOTICE: fpm is running, pid 21229
[24-Jan-2022 15:37:25] NOTICE: ready to handle connections
[24-Jan-2022 15:37:25] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:37:35] NOTICE: Terminating ...
[24-Jan-2022 15:37:35] NOTICE: exiting, bye-bye!
[24-Jan-2022 15:37:35] NOTICE: fpm is running, pid 21650
[24-Jan-2022 15:37:35] NOTICE: ready to handle connections
[24-Jan-2022 15:37:35] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:37:40] NOTICE: Terminating ...
[24-Jan-2022 15:37:40] NOTICE: exiting, bye-bye!
[24-Jan-2022 15:37:40] NOTICE: fpm is running, pid 22117
[24-Jan-2022 15:37:40] NOTICE: ready to handle connections
[24-Jan-2022 15:37:40] NOTICE: systemd monitor interval set to 10000ms
[24-Jan-2022 15:56:00] NOTICE: Terminating ...
[24-Jan-2022 15:56:00] NOTICE: exiting, bye-bye!
[24-Jan-2022 16:16:39] NOTICE: fpm is running, pid 1207
[24-Jan-2022 16:16:40] NOTICE: ready to handle connections
[24-Jan-2022 16:16:40] NOTICE: systemd monitor interval set to 10000ms

and systemctl status php8.1-fpm:

 php8.1-fpm.service - The PHP 8.1 FastCGI Process Manager
   Loaded: loaded (/lib/systemd/system/php8.1-fpm.service; enabled; vendor prese
   Active: active (running) since Mon 2022-01-24 16:16:41 UTC; 4h 42min ago
     Docs: man:php-fpm8.1(8)
  Process: 1846 ExecStartPost=/usr/lib/php/php-fpm-socket-helper install /run/ph
 Main PID: 1207 (php-fpm8.1)
   Status: "Processes active: 0, idle: 26, Requests: 123, slow: 0, Traffic: 0req
    Tasks: 131 (limit: 4915)
   CGroup: /system.slice/php8.1-fpm.service
           ├─1207 php-fpm: master process (/etc/php/8.1/fpm/php-fpm.conf)
           ├─1821 php-fpm: pool www
           ├─1822 php-fpm: pool www
           ├─1823 php-fpm: pool www
           ├─1824 php-fpm: pool www
           ├─1825 php-fpm: pool www
           ├─1826 php-fpm: pool www
           ├─1827 php-fpm: pool www
           ├─1828 php-fpm: pool www
           ├─1829 php-fpm: pool www
           ├─1830 php-fpm: pool www
           ├─1831 php-fpm: pool www
           ├─1832 php-fpm: pool www
           ├─1833 php-fpm: pool www
ubuntu php php-fpm

0 Answers