Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing

From: schnederle at futureweb dot at Date: Fri, 16 Feb 2018 15:09:41 +0000

Subject: Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing

References: 1 Groups: php.bugs

Request: Send a blank email to php-bugs+get-213981@lists.php.net to get a copy of this message

Edit report at https://bugs.php.net/bug.php?id=70185&edit=1

 ID:                 70185
 Comment by:         schnederle at futureweb dot at
 Reported by:        kobenews at cox dot net
 Summary:            php-fpm restarts master process in a loop when
                     exec() and using ssh multiplexing
 Status:             Open
 Type:               Bug
 Package:            FPM related
 Operating System:   CentOS release 6.6 (Final)
 PHP Version:        5.4.43
 Block user comment: N
 Private report:     N

 New Comment:

we got the same issue with Centos 7.4.1708:

Latest PHP Version:

[root@localhost ~]# php -v
PHP 7.2.2 (cli) (built: Feb  1 2018 15:30:38) ( NTS )
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.2.0, Copyright (c) 1998-2018 Zend Technologies
    with Zend OPcache v7.2.2, Copyright (c) 1999-2018, by Zend Technologies

...
[16-Feb-2018 14:48:30] WARNING: [pool www] child 53778 exited on signal 15 (SIGTERM) after 0.046685
seconds from start
[16-Feb-2018 14:48:30] WARNING: [pool www] child 53782 exited on signal 15 (SIGTERM) after 0.045416
seconds from start
[16-Feb-2018 14:48:30] WARNING: [pool www] child 53785 exited on signal 15 (SIGTERM) after 0.045331
seconds from start
[16-Feb-2018 14:48:30] WARNING: [pool www] child 53787 exited on signal 15 (SIGTERM) after 0.044765
seconds from start
...

100% CPU Usage of "php-fpm: master process (/etc/php-fpm.conf)"


[root@localhost ~]# service php-fpm status
Redirecting to /bin/systemctl status php-fpm.service
â php-fpm.service - The PHP FastCGI Process Manager
   Loaded: loaded (/usr/lib/systemd/system/php-fpm.service; enabled; vendor preset: disabled)
   Active: active (running) since Fri 2018-02-16 14:50:00 CET; 1h 17min ago
 Main PID: 7869 (php-fpm)
   Status: "Processes active: 0, idle: 808593, Requests: 2319, slow: 0, Traffic:
72req/sec"
   CGroup: /system.slice/php-fpm.service
           ââ 7869 php-fpm: master process (/etc/php-fpm.conf)
           ââ43200 php-fpm: pool www
           ââ43202 php-fpm: pool www
           ââ43205 php-fpm: pool www
           ââ43206 php-fpm: pool www
           ââ43207 php-fpm: pool www

Feb 16 14:50:00 localhost.localdomain systemd[1]: Starting The PHP FastCGI Process Manager...
Feb 16 14:50:00 localhost.localdomain systemd[1]: Started The PHP FastCGI Process Manager.

Also the Traffic 72req/sec shows that something is Bogus with only 2.319 Requests within the last
1:17h ...

Really noone who cares?! :-/

thx, bye from Austria
Andreas Schnederle-Wagner


Previous Comments:
------------------------------------------------------------------------
[2017-09-21 18:07:16] mike at sagesolutionsinc dot ca

I also have this issue when calling exec()

Im using php 7.0.22 on Ubuntu 16.04


my log file is  getting flooded, and my cpu goes to 100%.

The only solution I have is to restart the php7.0-fpm service which is not ideal.

I could move my exec() into a cronjob, but would like to keep it in PHP preferably.


sudo tail -f /var/log/php7.0-fpm.log
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14682 exited with code 0 after 0.022976 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14685 started
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14683 exited with code 0 after 0.024077 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14686 started
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14684 exited with code 0 after 0.024208 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14687 started
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14685 exited with code 0 after 0.023809 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14688 started
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14686 exited with code 0 after 0.022311 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14689 started
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14687 exited with code 0 after 0.023341 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14690 started
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14688 exited with code 0 after 0.027854 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14691 started
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14689 exited with code 0 after 0.028554 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14692 started
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14690 exited with code 0 after 0.027951 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14693 started
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14691 exited with code 0 after 0.024784 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14694 started
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14692 exited with code 0 after 0.027203 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14695 started
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14693 exited with code 0 after 0.028104 seconds from
start
[21-Sep-2017 14:01:36] NOTICE: [pool www] child 14696 started
....

------------------------------------------------------------------------
[2017-07-21 09:36:41] d dot reade at reades dot co dot uk

I'm experiencing a very similar issue. My server is running CentOS 7.3, cPanel 64.0.33, Apache
2.4.27 and PHP 5.6.31 with PHP-FPM.

After much investigation, the following script reproduces my issue:

<?php
exec('/usr/bin/postcss css_from.css --use autoprefixer --autoprefixer.remove "false"
--output css_to.css');
echo 'Done';
?>

Only after the script completes does the PHP-FPM process then use 100% CPU and the PHP-FPM error.log
file does this:

root@l1vs09rcms [/opt/cpanel/ea-php56/root/usr/var/log/php-fpm]# head error.log -n 128
[21-Jul-2017 10:23:03] NOTICE: fpm is running, pid 30537
[21-Jul-2017 10:23:03] NOTICE: ready to handle connections
[21-Jul-2017 10:23:03] NOTICE: systemd monitor interval set to 10000ms
[21-Jul-2017 10:23:13] WARNING: [pool dev3_reades_local] child 30540 said into stderr: "â
Finished css_from.css (60ms)"
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30540 exited with code 0 after
1.167822 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30551 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30551 exited with code 0 after
0.007451 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30552 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30552 exited with code 0 after
0.007069 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30553 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30553 exited with code 0 after
0.007391 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30554 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30554 exited with code 0 after
0.007211 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30555 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30555 exited with code 0 after
0.007631 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30556 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30556 exited with code 0 after
0.007972 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30558 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30558 exited with code 0 after
0.007635 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30559 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30559 exited with code 0 after
0.007761 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30560 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30560 exited with code 0 after
0.007557 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30561 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30561 exited with code 0 after
0.007735 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30562 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30562 exited with code 0 after
0.008361 seconds from start
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30563 started
[21-Jul-2017 10:23:13] NOTICE: [pool dev3_reades_local] child 30563 exited with code 0 after
0.007477 seconds from start

The log file is meant to rotate as per the cPanel configuration, but when it's doing this and
constantly growing, the rotate threshold does not trigger the rotate and so the log file just keeps
getting bigger until the server runs out of disk space and crashes!

It doesn't even matter if I use shell_exec() or exec(), or if I append "> /dev/null
2>&1" to the command thinking the output is the cause. If I append the command so
there's no output, the log file doesn't show the warning, but the continuous notices still
happen regardless and so the log file just gets bigger.

The workaround for us is to not execute any scripts that contain exec() or shell_exec() and to
execute these scripts from the command line instead, which is doable as I wrote all our software,
but for others using other pre-written software packages this could be a problem.

------------------------------------------------------------------------
[2017-04-25 14:24:13] php at grindau dot com

Well, "kobenews at cox dot net" asked for additional informations to reproduce. After that
tons of input of me and others were provided but we havent got any feedback so far. I am not one of
the devs, so i am not going to change any metadata of which i dont have enough knowledge. I ll leave
this up to people who are into it and limit my input on providing feedback.

------------------------------------------------------------------------
[2017-04-25 14:04:17] merrill at oakland dot edu

This bug does effect 7.x as well

That being said, it's an open source project, with an insurmountable amount of bugs
(That's just the way big projects work). Somebody who cares will have to work on it an try to
submit a patch.

------------------------------------------------------------------------
[2017-04-25 11:35:58] spam2 at rhsoft dot net

> This happens in the latest stable php 7.1 as well!
> As everybody could have seen in my post with 
> the timestamp: 2017-03-10 20:03 UTC

then someone should change this metadata

PHP Version: 5.4.43 	
OS: CentOS release 6.6 (Final)

------------------------------------------------------------------------


The remainder of the comments for this report are too long. To view
the rest of the comments, please view the bug report online at

    https://bugs.php.net/bug.php?id=70185


--
Edit this bug report at https://bugs.php.net/bug.php?id=70185&edit=1

Thread (28 messages)

kobenews at cox dot netMon, 03 Aug 2015 02:54:44 +0000
kobenews at cox dot netMon, 03 Aug 2015 03:21:06 +0000Bug #70185 [Opn]: php-fpm restarts process forever when exec() and using ssh multiplexing
kobenews at cox dot netFri, 07 Aug 2015 20:13:58 +0000Bug #70185 [Opn]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
php at plainview dot seTue, 08 Sep 2015 20:39:32 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
kobenews at cox dot netWed, 09 Sep 2015 02:18:53 +0000Bug #70185 [Opn]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
i dot priladnyh at gmail dot comFri, 22 Jan 2016 08:06:12 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
sylvain at com-ocean dot comFri, 24 Feb 2017 13:52:10 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
php at grindau dot comFri, 10 Mar 2017 20:03:51 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
kobenews at cox dot netFri, 10 Mar 2017 23:14:06 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
php at grindau dot comMon, 13 Mar 2017 14:31:13 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
php at grindau dot comSat, 18 Mar 2017 21:35:49 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
please at forget dot me dot ukFri, 24 Mar 2017 09:36:20 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
php at grindau dot comThu, 13 Apr 2017 08:43:58 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
merrill at oakland dot eduThu, 13 Apr 2017 20:22:03 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
jlaustill at gmail dot comMon, 17 Apr 2017 20:22:04 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
php at grindau dot comThu, 20 Apr 2017 09:37:16 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
php at grindau dot comMon, 24 Apr 2017 22:49:55 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
spam2 at rhsoft dot netTue, 25 Apr 2017 05:24:06 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
php at grindau dot comTue, 25 Apr 2017 10:24:24 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
php at grindau dot comTue, 25 Apr 2017 11:28:57 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
spam2 at rhsoft dot netTue, 25 Apr 2017 11:36:00 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
merrill at oakland dot eduTue, 25 Apr 2017 14:04:20 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
php at grindau dot comTue, 25 Apr 2017 14:24:15 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
d dot reade at reades dot co dot ukFri, 21 Jul 2017 09:36:49 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
mike at sagesolutionsinc dot caThu, 21 Sep 2017 18:07:21 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
schnederle at futureweb dot atFri, 16 Feb 2018 15:09:41 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
schnederle at futureweb dot atFri, 16 Feb 2018 15:24:12 +0000Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
nikic@php.netFri, 23 Feb 2018 16:55:17 +0000Bug #70185 [Opn->Dup]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing

« previous	php.bugs (#213981)	next »

From:	schnederle at futureweb dot at	Date:	Fri, 16 Feb 2018 15:09:41 +0000
Subject:	Bug #70185 [Com]: php-fpm restarts master process in a loop when exec() and using ssh multiplexing
References:	1	Groups:	php.bugs
Request:	Send a blank email to php-bugs+get-213981@lists.php.net to get a copy of this message