|
|
php.net | support | documentation | report a bug | advanced search | search howto | statistics | random bug | login |
[2015-08-03 02:54 UTC] kobenews at cox dot net
Description:
------------
Ok bear with me, this bug is a bit obscure and takes some setup. However, it is consistent, and causes php-fpm to continue to restart the process over and over again using 100% of the CPU on the php-fpm master process.
It only occurs with SSH controlMaster which basically allows SSH connection multiplexing.
Here is an example code:
<?php
$command = 'ssh -o "ControlMaster=auto" -o "ControlPersist=2m" -S /home/justin/.ssh/sockets/justin.sock justin@1.2.3.4';
$output = exec($command, $output_array, $return_code);
If you remove the options -o "ControlMaster=auto" -o "ControlPersist=2m" -S /home/justin/.ssh/sockets/justin.sock this works without crashing over and over again.
Test script:
---------------
<?php
$command = 'ssh -o "ControlMaster=auto" -o "ControlPersist=2m" -S /home/justin/.ssh/sockets/justin.sock justin@1.2.3.4';
$output = exec($command, $output_array, $return_code);
Expected result:
----------------
php-fpm master process should not restart the process over and over again. Nothing is crashing here.
Actual result:
--------------
php-fpm continues to restart the process over and over again using 100% of the CPU on the php-fpm master process.
PatchesPull RequestsHistoryAllCommentsChangesGit/SVN commits
|
|||||||||||||||||||||||||||||||||||||
Copyright © 2001-2024 The PHP GroupAll rights reserved. |
Last updated: Thu Apr 25 19:01:33 2024 UTC |
Sorry, the script I provided is incorrect. I forgot a command at the end. It should be: <?php $command = 'ssh -o "ControlMaster=auto" -o "ControlPersist=2m" -S /home/justin/.ssh/sockets/justin.sock justin@1.2.3.4 uptime'; $output = exec($command, $output_array, $return_code); die($output);Finally, someone else with the same bug! I have been dealing with it for years and, until I read this, used a separate php-fastcgi to deal with the constant child spamming. My previous setup was a Debian 7 with 5.4.4-14+deb7u14. My current setup is a Debian 8 with 5.6.9+dfsg-0+deb8u1. Both exhibit the exact same behaviour: when a multiplexed SSH is exec()ed it goes spawn crazy, with children dying left and right: [08-Sep-2015 21:32:36] NOTICE: [pool www] child 30721 exited with code 0 after 0.011428 seconds from start [08-Sep-2015 21:32:36] NOTICE: [pool www] child 30722 exited with code 0 after 0.011916 seconds from start [08-Sep-2015 21:32:36] NOTICE: [pool www] child 30723 exited with code 0 after 0.011527 seconds from start [08-Sep-2015 21:32:36] NOTICE: [pool www] child 30724 exited with code 0 after 0.012399 seconds from start [08-Sep-2015 21:32:36] NOTICE: [pool www] child 30725 exited with code 0 after 0.011333 seconds from start [08-Sep-2015 21:32:36] NOTICE: [pool www] child 30726 exited with code 0 after 0.010918 seconds from start [08-Sep-2015 21:32:36] NOTICE: [pool www] child 30727 exited with code 0 after 0.010977 seconds from start [08-Sep-2015 21:32:36] NOTICE: [pool www] child 30728 exited with code 0 after 0.011124 seconds from start The result is 100% CPU load and a sluggish system. The source of the problem is, as kobenews says, multiplexing SSH. I do it via a series of bash scripts that are execed by PHP. Original script: #!/bin/bash CONTROLPATH=/var/www/mail_scripts/master-mail_scripts MAIL_SCRIPTS_COMMAND="ssh -o StrictHostKeyChecking=no -l mail_scripts -o ControlPath=$CONTROLPATH -i /var/www/mail_scripts/mail_scripts TARGET.COM" # If the socket doesn't exist, create it. if [ ! -e $CONTROLPATH* ] ; then $MAIL_SCRIPTS_COMMAND -fNM fi # Execute the requested command. $MAIL_SCRIPTS_COMMAND /home/mail_scripts/the_command $@ What I did was I moveed -f in front of TARGET.COM and started the master manually, outside of PHP. After that PHP seems fine with running the script without spawnflooding.I am having the same issue! It took me ages to find out whats the reason. I am running the latest php-7.1.2 under archx64. Executing this command: shell_exec('/usr/lib/node_modules/csso/bin/csso '.ROOT_PATH.'/tmp/style-critical-unoptimized.css --output '.ROOT_PATH.'/tmp/style-critical.css'); which should just easily grap a normal css file and compress it down causes the master process to restart itself hundred times a second or even more causing 100% cpu load on the server.I am running into this same issue on php 5.6.30 running on Ubuntu 16.04. I'm trying to call minify(node.js library). Here's the exact call I'm making. public function minifyJsFile($source, $dest) { $result = exec('minify ' . $source . ' > ' . $dest); if ($result) { return false; } else { return filemtime($dest); } } I have been unable to find a workaround. But I'm not a php expert by any stretch. My background is c/c++/C#/javascript mainly.My only working workaround looks as the follows: $cwd='/tmp'; $descriptorspec = array( 0 => array("pipe", "r"), 1 => array("pipe", "w"), 2 => array("file", "/tmp/error-output.txt", "a") ); $process = proc_open('csso '.ROOT_PATH.'/tmp/style-'.$type.'-uncritical-unoptimized.css '.ROOT_PATH.'/tmp/style-'.$type.'-uncritical.css --comments none', $descriptorspec, $pipes, '/tmp'); stream_get_contents($pipes[1]); fclose($pipes[1]);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.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