Edit report at http://bugs.php.net/bug.php?id=52501&edit=1
ID: 52501
Comment by: marekroman1 at gmail dot com
Reported by: marekroman1 at gmail dot com
Summary: Misconfigured Sendmail sends PHP-FPM into an
infinite loop
Status: Analyzed
Type: Bug
Package: FPM related
Operating System: DebianLenny2.6.26-2-openvz-amd64
PHP Version: 5.3.3
Assigned To: fat
Block user comment: N
New Comment:
Oh, thanks fat.
Previous Comments:
------------------------------------------------------------------------
[2010-07-31 17:25:58] [email protected]
the problem does not exist when using kqueue,poll or select on openbsd
(and
certainely on freebsd also).
the problem exists on linux when using epoll,poll or select.
It's all the problem of the libevent when forking.
------------------------------------------------------------------------
[2010-07-31 03:23:51] [email protected]
when calling the mail() function on unix, there is a fork to run the
sendmail command. If the sendmail does not return
quickly and FPM tries to kill the process because of
request_terminate_timeout the bug happens.
Here is a sample C code to simulate a bug sendmail config:
// sendmail_bug.c
#include <stdio.h>
int main() {
char buf[11];
while (1) {
read(0, buf, 10);
}
return 0;
}
gcc -o /tmp/sendmail_bug sendmail_bug.c
then configure your php.ini this way:
sendmail_path = /tmp/sendmail_bug
set request_terminate_timeout to a 5s and load a page with the mail
function.
------------------------------------------------------------------------
[2010-07-31 00:25:45] marekroman1 at gmail dot com
Description:
------------
(Misconfigured) Sendmail sends PHP-FPM into an infinite loop of
spawning/exiting worker processes when attempting to send an email
through the mail() function. (The php script itself just times out
without any output.)
Since this loop produces 100% cpu load and warnings AND logs these
warnings, the log file has grown to 400MB+ before I noticed the load
spike and stopped PHP-FPM master process with kill -9 PID (nothing else
worked e.g. -QUIT).
After I purge-removed the Sendmail package and installed Postfix
instead, everything is working as it should (I didn't made any changes
to nginx/php-fpm/php config files whatsoever).
Server: nginx-0.8.47
PHP ini settings related to mail: "sendmail_path = /usr/sbin/sendmail -t
-i"
Sendmail state: daemon was not running (sendmail process was called, it
did it's work i.e. nothing, then exited)
PHP configure:
./configure --prefix=/usr --enable-fpm --disable-rpath --with-pear
--disable-debug --with-openssl --with-pcre-regex --with-zlib
--enable-bcmath --with-bz2 --enable-calendar --with-curl --enable-exif
--enable-inline-optimization --with-gd --enable-gd-native-ttf
--with-gettext --with-imap --with-imap-ssl --with-kerberos --with-ldap
--enable-mbstring --enable-mbregex --with-mcrypt --with-mysql
--with-mysqli --enable-pcntl --enable-pdo --with-pdo-firebird
--with-pdo-mysql --with-pdo-pgsql --with-pgsql --enable-shmop
--enable-soap --enable-sockets --enable-sqlite-utf8 --enable-sysvmsg
--enable-sysvsem --enable-sysvshm --with-tidy --enable-wddx
--with-xmlrpc --with-xsl --enable-zip --with-pic --enable-ftp
--enable-dom --enable-xmlwriter --enable-xmlreader --enable-tokenizer
--enable-simplexml --enable-session --enable-posix --enable-phar
--enable-libxml --enable-json --with-iconv --enable-filter
--enable-fileinfo --enable-dba --enable-ctype
Dynamic extensions:
pecl apc-beta (apc.so) and rar (rar.so).
Changed PHP-FPM settings:
listen = /var/run/php-fpm/php-fpm.sock
listen.owner = www-data
listen.group = www-data
user = www-data
group = www-data
pm = dynamic
pm.max_children = 10
pm.start_servers = 4
pm.min_spare_servers = 3
pm.max_spare_servers = 6
request_terminate_timeout = 60
rlimit_files = 10240
chdir = /var/www
catch_workers_output = yes
Test script:
---------------
$to = '[email protected]';
// subject
$subject = 'Birthday Reminders for August';
// message
$message = '
<html>
<head>
<title>Birthday Reminders for August</title>
</head>
<body>
<p>Here are the birthdays upcoming in August!</p>
<table>
<tr>
<th>Person</th><th>Day</th><th>Month</th><th>Year</th>
</tr>
<tr>
<td>Joe</td><td>3rd</td><td>August</td><td>1970</td>
</tr>
<tr>
<td>Sally</td><td>17th</td><td>August</td><td>1973</td>
</tr>
</table>
</body>
</html>
';
// To send HTML mail, the Content-type header must be set
$headers = 'MIME-Version: 1.0' . "\r\n";
$headers .= 'Content-type: text/html; charset=UTF-8' . "\r\n";
// Additional headers
$headers .= 'To: Dude Dudeson <[email protected]>, Kelly <[email protected]>' .
"\r\n";
$headers .= 'From: Birthday Reminder <[email protected]>' . "\r\n";
$headers .= 'Cc: [email protected]' .
"\r\n";
// Mail it
if (mail($to, $subject, $message, $headers)) echo "OKAY!!!!!";
Expected result:
----------------
OKAY!!!!!
Actual result:
--------------
php-fpm error log:
...
Trying to run a mail script
...
Jul 28 11:42:20.169022 [WARNING] [pool www] child 6344, script
'/var/www/xyz.com/public/mail.php' execution timed out (60.095817 sec),
terminating
Jul 28 11:42:20.169719 [WARNING] [pool www] child 6344 exited on signal
15 SIGTERM after 1532.840955
seconds from start
Jul 28 11:42:20.170087 [NOTICE] [pool www] child 6409 started
Jul 28 11:42:20.170752 [WARNING] [pool www] child 6409 exited on signal
11 SIGSEGV after 0.000681 seconds from start
Jul 28 11:42:20.171011 [NOTICE] [pool www] child 6410 started
Jul 28 11:42:20.171602 [WARNING] [pool www] child 6410 exited on signal
11 SIGSEGV after 0.000605 seconds from start
...
Gazillion lines
...
I've noticed it's killing my cpus and tried to kill it
...
...
Jul 28 12:01:45.644600 [NOTICE] [pool www] child 2017 started
Jul 28 12:01:45.644615 [WARNING] [pool www] child 2011 exited on signal
6 SIGABRT after 0.002469 seconds from start
Jul 28 12:01:45.644621 [WARNING] [pool www] child 2011 said into stderr:
"php-fpm: event.c:261: event_base_free: Assertion
`(((&base->eventqueue)->tqh_first) == ((void *)0))' failed."
Jul 28 12:01:45.645047 [NOTICE] [pool www] child 2018 started
Jul 28 12:01:45.645062 [WARNING] [pool www] child 2012 exited on signal
6 SIGABRT after 0.002622 seconds from start
Jul 28 12:01:45.645071 [WARNING] [pool www] child 2012 said into stderr:
"php-fpm: event.c:261: event_base_free: Assertion
`(((&base->eventqueue)->tqh_first) == ((void *)0))' failed."
Jul 28 12:01:45.646422 [NOTICE] [pool www] child 2021 started
Jul 28 12:01:45.646438 [WARNING] [pool www] child 2013 exited on signal
6 SIGABRT after 0.003529 seconds from start
Jul 28 12:01:45.646444 [WARNING] [pool www] child 2013 said into stderr:
"php-fpm: event.c:261: event_base_free: Assertion
`(((&base->eventqueue)->tqh_first) == ((void *)0))' failed."
------------------------------------------------------------------------
--
Edit this bug report at http://bugs.php.net/bug.php?id=52501&edit=1
