Edit report at https://bugs.php.net/bug.php?id=61558&edit=1
ID: 61558
Comment by: kobenews at cox dot net
Reported by: phpbug2012 at tgabber dot mine dot nu
Summary: Runaway spawning of children after pipe error
Status: Assigned
Type: Bug
Package: FPM related
Operating System: Debian Linux
PHP Version: 5.3.10
Assigned To: tony2001
Block user comment: N
Private report: N
New Comment:
I think this issue is related to a bug I just posted. Same behavior where php-fpm restarts the
process over and over again, causing php-fpm master to use 100% cpu. The test script is a little bit
simpler, though requires exec() and running a SSH command using multiplexing.
https://bugs.php.net/bug.php?id=70185&edit=2
Previous Comments:
------------------------------------------------------------------------
[2014-07-25 13:07:22] Danack at basereality dot com
I'd recommend being inspired by aka copying the behaviour of Supervisord.
http://supervisord.org/subprocess.html
Basically it does what it probably the best behaviour of:
i) If child processes exist too quickly, put them in a 'back off' state, to rate limit the
number of processes attempting to be started.
ii) If they still fail to start after a reasonable number of retries stop trying to start it for
now.
Admittedly, sounds like a big task for something that should be a rare event.
------------------------------------------------------------------------
[2014-07-25 09:06:12] tony2001@php.net
Ok, so FPM basically starts the children, but they die immediately (for a reason) and FPM master
process starts the new ones.
I can think of adding some option that would limit the number of children spawned per second, or
probably abort the whole process if N children were created in the last N seconds, but that kind of
solution looks quite hacky to me.
------------------------------------------------------------------------
[2014-07-24 19:44:00] Danack at basereality dot com
I think there is an easier way to trigger this (and probably something that I'll open as a
separate bug):
i) Include a library function in an extension.
ii) Don't include the library in the linking step for php-fpm.
iii) Watch the error log fill up with:
[24-Jul-2014 18:58:27] NOTICE: [pool www] child 22710 started
[24-Jul-2014 18:58:27] WARNING: [pool www] child 22710 exited with code 127 after 0.044963 seconds
from start
[24-Jul-2014 18:58:27] WARNING: [pool www] child 22710 said into stderr: "php-fpm: pool www:
symbol lookup error: /usr/local/lib/php/extensions/no-debug-zts-20131226/imagick.so: undefined
symbol: GetMagickVersion"
Once this happens you need to kill -9 the php-fpm master process to stop it spawning pool workers.
Obviously there shouldn't be errors like this in an extension, but also PHP-FPM shouldn't
become unresponsive and start spawning workers like crazy.
------------------------------------------------------------------------
[2013-05-23 13:44:24] pavel at stack dot ee
PHP 5.3.23 with Suhosin-Patch (cli) (built: Mar 26 2013 14:07:09)
Copyright (c) 1997-2013 The PHP Group
Zend Engine v2.3.0, Copyright (c) 1998-2013 Zend Technologies
FPM POOL CONFIG:
[storage]
listen = /tmp/fpm_storage.sock
listen.owner = storage
listen.group = storage
listen.mode = 0666
user = storage
group = storage
pm = dynamic
pm.max_children = 50
pm.start_servers = 10
pm.min_spare_servers = 5
pm.max_spare_servers = 35
NGINX:
location ~ \.php$ {
fastcgi_pass unix:/tmp/fpm_storage.sock;
fastcgi_index index.php;
include fastcgi_params;
fastcgi_param DEVENV on;
fastcgi_intercept_errors on;
fastcgi_ignore_client_abort off;
fastcgi_connect_timeout 60;
fastcgi_send_timeout 180;
fastcgi_read_timeout 180;
fastcgi_buffer_size 128k;
fastcgi_buffers 4 256k;
fastcgi_busy_buffers_size 256k;
fastcgi_temp_file_write_size 256k;
}
~/.ssh/config:
Host *
ConnectTimeout 2
TCPKeepAlive yes
Port 22
Identityfile ~/.ssh/server1000
ControlMaster no
ControlPath ~/.ssh/master-%r@%h:%p
Host server1000
Hostname 192.168.2.2
Creating connection to remote server:
# ssh -o "ServerAliveInterval 15" -o "ServerAliveCountMax 1" -MN user@server1000
# ls -la ~/.ssh/
srw------- 1 storage storage 0 Mar 26 15:46 master-root@192.168.2.2:22
# ssh server1000 whoami
root
and this simple script for which was run from browser and i'm getting same behaviour in Debian
and FreeBSD
<?php
for ($i = 0; $i < 100; ++$i) {
echo exec("ssh root@192.168.2.2 ls -la");
}
?>
[26-Mar-2013 15:57:00] NOTICE: configuration file /etc/php5/fpm/php-fpm.conf test is successful
[26-Mar-2013 15:57:00] NOTICE: fpm is running, pid 20053
[26-Mar-2013 15:57:00] NOTICE: ready to handle connections
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20054 exited with code 0 after 92.745193 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20324 started
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20324 exited with code 0 after 0.005245 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20325 started
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20325 exited with code 0 after 0.005121 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20326 started
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20326 exited with code 0 after 0.005202 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20327 started
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20327 exited with code 0 after 0.005543 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20328 started
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20328 exited with code 0 after 0.004935 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20329 started
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20329 exited with code 0 after 0.005255 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20330 started
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20330 exited with code 0 after 0.005239 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20331 started
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20331 exited with code 0 after 0.005134 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20332 started
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20332 exited with code 0 after 0.005162 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20333 started
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20333 exited with code 0 after 0.004950 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20334 started
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20334 exited with code 0 after 0.005066 seconds
from start
[26-Mar-2013 15:58:33] NOTICE: [pool storage] child 20335 started
............
............
------------------------------------------------------------------------
[2012-10-25 13:57:40] adrian dot siminiceanu at gmail dot com
Hello,
I have the same behavior on my test machine using Red Hat Enterprise Linux Server release 5.3
(Tikanga) Update 3 using the following:
- nginx-1.2.4-1.ngx.x86_64
- php-fpm-5.3.10-2.x86_64 (built from the github php-src tag 5.1.30 - https://github.com/php/php-src/tree/php-5.3.10)
The php-fpm configuration is the following:
[www]
listen = /tmp/fastcgi.socket
;listen.backlog = -1
listen.allowed_clients = 127.0.0.1
;listen.owner = nobody
;listen.group = nobody
;listen.mode = 0666
user = apache
group = apache
pm = dynamic
pm.max_children = 300
pm.start_servers = 100
pm.min_spare_servers = 100
pm.max_spare_servers = 300
pm.max_requests = 500
;pm.status_path = /status
;ping.path = /ping
;ping.response = pong
;request_terminate_timeout = 0
;request_slowlog_timeout = 0
;slowlog = /var/log/php-fpm.log.slow
;rlimit_files = 1024
;rlimit_core = 0
;chroot =
;chdir = /var/www
;catch_workers_output = yes
;env[HOSTNAME] = $HOSTNAME
;env[PATH] = /usr/local/bin:/usr/bin:/bin
;env[TMP] = /tmp
;env[TMPDIR] = /tmp
;env[TEMP] = /tmp
;php_admin_value[sendmail_path] = /usr/sbin/sendmail -t -i -f www@my.domain.com
;php_flag[display_errors] = off
php_admin_value[error_log] = /var/log/php-fpm/www-error.log
php_admin_flag[log_errors] = on
;php_admin_value[memory_limit] = 32M
I am receiving at a rate of over 250/300 requests per seconds and for some reasons the number of
opened fd are increasing at a very high
rate. There is only one PHP script executed for each request that is not doing anything fancy and
that is really fast in doing what it
supposed to do.
If I look at the one of the php-fpm processes on the platform (e.g. pid = 12258) I can see the
following in /proc/<pid>/smaps:
2b9cbbb49000-2b9cbbb4a000 rw-s 00000000 00:09 346827919 /dev/zero (deleted)
Size: 4 kB
Rss: 4 kB
Shared_Clean: 0 kB
Shared_Dirty: 4 kB
Private_Clean: 0 kB
Private_Dirty: 0 kB
Swap: 0 kB
2b9cbbb4a000-2b9cbbb4b000 rw-s 00000000 00:09 346827920 /dev/zero (deleted)
Size: 4 kB
Rss: 4 kB
Shared_Clean: 0 kB
Shared_Dirty: 4 kB
Private_Clean: 0 kB
Private_Dirty: 0 kB
Swap: 0 kB
2b9cbbb4b000-2b9cbbb4c000 rw-s 00000000 00:09 346827921 /dev/zero (deleted)
Size: 4 kB
Rss: 4 kB
Shared_Clean: 0 kB
Shared_Dirty: 4 kB
Private_Clean: 0 kB
Private_Dirty: 0 kB
Swap: 0 kB
2b9cbbb4c000-2b9cbbb4d000 rw-s 00000000 00:09 346827922 /dev/zero (deleted)
Size: 4 kB
Rss: 4 kB
Shared_Clean: 0 kB
Shared_Dirty: 4 kB
Private_Clean: 0 kB
Private_Dirty: 0 kB
Swap: 0 kB
2b9cbbb4d000-2b9cbbb4e000 rw-s 00000000 00:09 346827923 /dev/zero (deleted)
Size: 4 kB
Rss: 4 kB
Shared_Clean: 0 kB
Shared_Dirty: 4 kB
Private_Clean: 0 kB
Private_Dirty: 0 kB
Swap: 0 kB
The number of opened fd is really high and does not gow down when things calm down on the machine or
even when the php-fpm processes are
dyeing.
root@bench:/etc/php-fpm.d # ps aux | grep php-fpm | wc -l
134
root@bench:/etc/php-fpm.d # lsof | grep php-fpm | grep DEL | wc -l
40299
root@bench:/etc/php-fpm.d # lsof | grep php-fpm | wc -l
53270
root@bench6 [P/S] :/etc/php-fpm.d # /etc/init.d/php-fpm restart
Stopping php-fpm: [ OK ]
Starting php-fpm: [ OK ]
root@bench:/etc/php-fpm.d # ps aux | grep php-fpm | wc -l
102
root@bench:/etc/php-fpm.d # lsof | grep php-fpm | grep DEL | wc -l
30603
root@bench:/etc/php-fpm.d # lsof | grep php-fpm | wc -l
38970
As you see, even after a restart of the php-fpm daemon the DEL fd are not removed.
------------------------------------------------------------------------
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=61558
--
Edit this bug report at https://bugs.php.net/bug.php?id=61558&edit=1