PHP-FPM fails after too many restarts (#5616) · Issues · ISPConfig / ISPConfig 3

PHP-FPM fails after too many restarts

short description

I deleted some shell users. After a few seconds, php7.4-fpm stopped and remained failed.

Here is the syslog, which explains why php7.4-fpm failed.

May  8 11:49:01 myhost systemd[1]: php7.4-fpm.service: Succeeded.
May  8 11:49:01 myhost systemd[1]: php7.4-fpm.service: Succeeded.
May  8 11:49:02 myhost systemd[1]: php7.4-fpm.service: Succeeded.
May  8 11:49:02 myhost systemd[1]: php7.4-fpm.service: Succeeded.
May  8 11:49:03 myhost systemd[1]: php7.4-fpm.service: Succeeded.
May  8 11:49:03 myhost systemd[1]: php7.4-fpm.service: Succeeded.
May  8 11:49:03 myhost systemd[1]: php7.4-fpm.service: Start request repeated too quickly.
May  8 11:49:03 myhost systemd[1]: php7.4-fpm.service: Failed with result 'start-limit-hit'.
May  8 11:49:03 myhost systemd[1]: php7.4-fpm.service: Start request repeated too quickly.
May  8 11:49:03 myhost systemd[1]: php7.4-fpm.service: Failed with result 'start-limit-hit'.
May  8 11:49:04 myhost systemd[1]: php7.4-fpm.service: Start request repeated too quickly.
May  8 11:49:04 myhost systemd[1]: php7.4-fpm.service: Failed with result 'start-limit-hit'.

And here is anonymized ISPConfig log:

08.05.2020-11:49 - DEBUG - Found 9 changes, starting update process.
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_base_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web119' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: rm -rf '/var/www/clients/client1/web119/home/user1/.ssh' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web119' - return code: 0
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl stop php7.4-fpm.service
08.05.2020-11:49 - DEBUG - safe_exec cmd: killall -u 'user1' ; userdel -f 'user1' &> /dev/null - return code: 0
08.05.2020-11:49 - DEBUG - Deleted shelluser: user1
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl start php7.4-fpm.service
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_jailkit_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - Jailkit Plugin -> delete username:user1
08.05.2020-11:49 - DEBUG - Processed datalog_id 6957
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_base_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web121' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: rm -rf '/var/www/clients/client1/web121/home/user2/.ssh' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web121' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: killall -u 'user2' ; userdel -f 'user2' &> /dev/null - return code: 0
08.05.2020-11:49 - DEBUG - Deleted shelluser: user2
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_jailkit_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - Jailkit Plugin -> delete username:user2
08.05.2020-11:49 - DEBUG - Processed datalog_id 6958
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_base_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web124' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: rm -rf '/var/www/clients/client1/web124/home/user3/.ssh' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web124' - return code: 0
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl stop php7.4-fpm.service
08.05.2020-11:49 - DEBUG - safe_exec cmd: killall -u 'user3' ; userdel -f 'user3' &> /dev/null - return code: 0
08.05.2020-11:49 - DEBUG - Deleted shelluser: user3
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl start php7.4-fpm.service
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_jailkit_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - Jailkit Plugin -> delete username:user3
08.05.2020-11:49 - DEBUG - Processed datalog_id 6959
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_base_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web144' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: rm -rf '/var/www/clients/client1/web144/home/user4/.ssh' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web144' - return code: 0
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl stop php7.4-fpm.service
08.05.2020-11:49 - DEBUG - safe_exec cmd: killall -u 'user4' ; userdel -f 'user4' &> /dev/null - return code: 0
08.05.2020-11:49 - DEBUG - Deleted shelluser: user4
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl start php7.4-fpm.service
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_jailkit_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - Jailkit Plugin -> delete username:user4
08.05.2020-11:49 - DEBUG - Processed datalog_id 6960
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_base_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web163' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: rm -rf '/var/www/clients/client1/web163/home/user5/.ssh' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web163' - return code: 0
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl stop php7.4-fpm.service
08.05.2020-11:49 - DEBUG - safe_exec cmd: killall -u 'user5' ; userdel -f 'user5' &> /dev/null - return code: 0
08.05.2020-11:49 - DEBUG - Deleted shelluser: user5
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl start php7.4-fpm.service
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_jailkit_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - Jailkit Plugin -> delete username:user5
08.05.2020-11:49 - DEBUG - Processed datalog_id 6961
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_base_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web122' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: rm -rf '/var/www/clients/client1/web122/home/user6/.ssh' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web122' - return code: 0
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl stop php7.4-fpm.service
08.05.2020-11:49 - DEBUG - safe_exec cmd: killall -u 'user6' ; userdel -f 'user6' &> /dev/null - return code: 0
08.05.2020-11:49 - DEBUG - Deleted shelluser: user6
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl start php7.4-fpm.service
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_jailkit_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - Jailkit Plugin -> delete username:user6
08.05.2020-11:49 - DEBUG - Processed datalog_id 6962
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_base_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web81' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: rm -rf '/var/www/clients/client1/web81/home/user7/.ssh' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web81' - return code: 0
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl stop php7.4-fpm.service
08.05.2020-11:49 - DEBUG - safe_exec cmd: killall -u 'user7' ; userdel -f 'user7' &> /dev/null - return code: 0
08.05.2020-11:49 - DEBUG - Deleted shelluser: user7
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl start php7.4-fpm.service
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_jailkit_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - Jailkit Plugin -> delete username:user7
08.05.2020-11:49 - DEBUG - Processed datalog_id 6963
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_base_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web50' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: rm -rf '/var/www/clients/client1/web50/home/user8/.ssh' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web50' - return code: 0
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl stop php7.4-fpm.service
08.05.2020-11:49 - DEBUG - safe_exec cmd: killall -u 'user8' ; userdel -f 'user8' &> /dev/null - return code: 0
08.05.2020-11:49 - DEBUG - Deleted shelluser: user8
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl start php7.4-fpm.service
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_jailkit_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - Jailkit Plugin -> delete username:user8
08.05.2020-11:49 - DEBUG - Processed datalog_id 6964
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_base_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web166' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: rm -rf '/var/www/clients/client1/web166/home/user9/.ssh' - return code: 0
08.05.2020-11:49 - DEBUG - safe_exec cmd: chattr -i '/var/www/clients/client1/web166' - return code: 0
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl stop php7.4-fpm.service
08.05.2020-11:49 - DEBUG - safe_exec cmd: killall -u 'user9' ; userdel -f 'user9' &> /dev/null - return code: 0
08.05.2020-11:49 - DEBUG - Deleted shelluser: user9
08.05.2020-11:49 - DEBUG - Calling function 'restartPHP_FPM' from module 'web_module'.
08.05.2020-11:49 - DEBUG - Restarting php-fpm: systemctl start php7.4-fpm.service
08.05.2020-11:49 - DEBUG - Calling function 'delete' from plugin 'shelluser_jailkit_plugin' raised by event 'shell_user_delete'.
08.05.2020-11:49 - DEBUG - Jailkit Plugin -> delete username:user9
08.05.2020-11:49 - DEBUG - Processed datalog_id 6965
08.05.2020-11:49 - DEBUG - Remove Lock: /usr/local/ispconfig/server/temp/.ispconfig_lock

environment

Server OS: Debian 10 "Buster" ISPConfig version: 3.1.15p3

proposed fix

It seems tunning Systemd (https://www.freedesktop.org/software/systemd/man/systemd.unit.html#StartLimitIntervalSec=interval) could avoid this, but I don't think this is the right solution, and I don't want to edit the systemd unit for every FPM version.

I think ISPConfig should be careful not to restart the same PHP-FPM too many times in a row.

Thanks.