php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #43105 PHP seems to fail to close open files.
Submitted: 2007-10-25 15:03 UTC Modified: 2007-12-27 02:13 UTC
Votes:9
Avg. Score:4.9 ± 0.3
Reproduced:9 of 9 (100.0%)
Same Version:6 (66.7%)
Same OS:1 (11.1%)
From: ian at onlineloop dot com Assigned: bjori (profile)
Status: Closed Package: Apache2 related
PHP Version: 5.2.5RC2-dev OS: Solaris, Linux, Mac OS X
Private report: No CVE-ID: None
Welcome back! If you're the original bug submitter, here's where you can edit the bug or add additional notes.
If you forgot your password, you can retrieve your password here.
Password:
Status:
Package:
Bug Type:
Summary:
From: ian at onlineloop dot com
New email:
PHP Version: OS:

 

 [2007-10-25 15:03 UTC] ian at onlineloop dot com
Description:
------------
Working with PHP 5.2.5-RC2, build from php5.2-200710241430, problem also occurred in php5.2-200710171030.

PHP for what ever reason is occasionally unable to execute the mail program that we have installed, ssmtp. I am able to run the script below 15-20 times, and 1 or 2 times the mail program fails, every other time it is successful. This problem seesm to occur only when there is a higher system load, apache needs to be serving 60-80 requests before this problem shows itself. Suspicion was in the maximum number of open files, however that can be ruled out as our system (Sun V440, 16Gb RAM, 4 x SPARC 1.6Ghz) allows up to 10240 open files at any one time.

Additionally, there are sometimes problems creating files. Although the errors would point to a system problem, this is definately not the case as other processes on the system do not have problems (proftpd, for example), and everything was OK with PHP 5.1.6.

A log file extract and system messages are:
# Oct 25 16:28:01 www-walda mod_evasive[21333]: [ID 869489 daemon.alert] Couldn't open logfile /var/apache2/logs/mod_evasive-log/dos-86.56.222.150: Bad file number

[25-Oct-2007 16:39:48] [UseBB Error] [Thu Oct 25 14:39:48 2007] [E_WARNING - mb_send_mail() [<a href='function.mb-send-mail'>function.mb-send-mail</a>]: Could not execute mail delivery program '/usr/bin/ssmtp -t'] [./sources/functions.php:1164]

[25-Oct-2007 16:30:03] PHP Warning:  mail() [<a href='function.mail'>function.mail</a>]: Could not execute mail delivery program '/usr/bin/ssmtp -t' in /ftp/usr/ian/mailtest.php on line 12

These problems have appeared only since we changed from PHP 5.1.6 to PHP 5.2.x (note that we have had many problems with PHP 5.2.x). We are currently using the PHP CVS version mentioned above, as up until and including PHP 5.2.4, bug numbers 41822, 41899 were blocking us.

Reproduce code:
---------------
<?php
// Mail addresses have been removed because of spam concerns!
 $to      = '<enter your mail address here';
 $subject = 'the testmail';
 $message = 'Testmail' ;
 $headers = 'From: <senders mail address>' . "\r\n" .
    'Reply-To: <senders mail address>' . "\r\n" .
    'X-Mailer: PHP/' . phpversion();

$date= date("d M y, G:i:s");

if ( mail($to, $subject, $message, $headers) == TRUE)
        echo "OK: $date, mail($to, $subject, $message, $headers)";
else
        echo "False";
?>


Expected result:
----------------
The code should run correctly every time, delivering a mail.

Actual result:
--------------
The mail is sent most times, but occasionally I get an error message back saying that the sending failed:

Browser:
Warning: mail() [function.mail]: Could not execute mail delivery program '/usr/bin/ssmtp -t' in /ftp/usr/ian/mailtest.php on line 12
 False

Logs:
[25-Oct-2007 16:56:58] PHP Warning:  mail() [<a href='function.mail'>function.mail</a>]: Could not execute mail delivery program '/usr/bin/ssmtp -t' in /ftp/usr/ian/mailtest.php on line 12


Patches

Pull Requests

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2007-11-06 11:19 UTC] ian at onlineloop dot com
Changing this whole report as I have now more information.

After further examining the problem, it is clear that PHP is sometimes failing to close the files it opens, and is generally failing to cleanly exit, if it exits at all.  It is running with Apache 2.0.61.  As time passes, PHP has more and more files open, the apache child processes do not exit, the status of the child processes stays on "W", writing, for long periods of time although the network status on the server itsel clearly shows that all connections to the remote address have closed.  The memory usage also climbs constantly until the apache child process dies, if the child process dies at all.  

In the system, this is noticable by the number of open files, in the last 24 hours, this has changed from 4.2Gb and 30,711 open files to now 6.6Gb and 48,462 open files.  This increase in memory consumption and the number of open files is continuous.  Additionally, there are more and more apache child processes that simply do not exit.  It is this behaviour that is clearly responsible for the problems of opening other files, and for the failure to be able to execute some system calls, such as sending mail and writing log files.

The cause for this behaviour is unclear, however it is definately PHP 5.2.x related as under PHP 5.1.6, everything is ok.
 [2007-11-11 19:03 UTC] jani@php.net
So, how can we reproduce this?
 [2007-11-11 19:18 UTC] ab5602@php.net
1) What file(s) are being held open? (lsof/ptree may help).
2) Is 'ssmtp -t' successfully opening, delivering the email and closing it's own network connections under this condition?  Every open network connection requires 2 file descriptors.
3) Does this happen without sending mail()?
4) Does this happen with other delivery programs such as 'sendmail -t'? 

Thanks,
-Rob
 [2007-11-12 20:52 UTC] ian at onlineloop dot com
Hi,

I don't want to post the attahced file to the bug report as this may 
expose more information that I like about our web server.  It is a 
pfiles output from the apache processes.  I will send the file to you 
directly in an email.

The exact situation is difficult to reproduce, and happened most 
frequently when the server was under load.  We are typically handling 
about 100-120 requests per second, and under PHP 5.1.6 (we are back 
on it now), there was usually between 500 and 1000 open files at any 
one time between the apache processes.  

The symptom of the problem - system error messages, masses of open 
files, not being able to execute ssmtp and not being able to open 
files, also generally exists for just a couple of seconds, then goes 
away again.  The total memory usage of apache climbs constantly, 
usually hitting 6-8Gb within 24 hours of an apache restart, and 
continuing to climb if apache is not restarted.  After about 36 
hours, the ram usage is over 10Gb, at which point I restart the 
server as we need it to be available.  Since running 5.1.6 again (one 
week), the memory usage is constantly around 1.5-2Gb and there are no 
problems from 5.2.5rc-x.  I fear reproducing this will be difficult 
for you.

ssmtp is generally able to send mails, just occasionally it is hit by 
this problem.  Apache also has problems opening other files under 
this condition, apparently mainly for writing.  I have tried on the 
command line to send mails with ssmtp when the error messages start 
coming out, however that worked and the test mails came in.  "cat"ing 
files into another file, and things like this also worked.  

The problem of not being able to open files also occurs when not 
trying to send mails, as such my impression the problem is more 
general than just being connected with mail function.  I did put 
sendmail in briefly today to see what happened, the problem still 
occured.  A restart in the middle of the day for the apache process 
is not an option here as the service needs to be available.  I can 
only make changes to the system between 2 and 4am.

I will do what I can to help pinpoint this problem, please however 
understand the restrictions I have as I do this on a productive 
system.
 [2007-11-20 09:40 UTC] jani@php.net
IIRC, this is actually an Apache bug. PHP is not the only module which suffers as 3rd party of it..
 [2007-11-25 14:21 UTC] hwallenstone at gmx dot de
I think we have the same problem here. I have updated one server of a cluster of busy servers from a patched 5.2.1 to 5.2.5 . The number of apache processes is growing and as a consequence of this, the number of open files increases. We have about 50 processes running on average machines; on the 5.2.5-one the number constantly grows until it reaches my MaxClients Limit. Trying to stop apache, I get hundreds of entries like 

[Sun Nov 25 14:14:55 2007] [error] could not make child process 28546 exit, attempting to continue anyway

This problem **definitely** has come with the upgrade from 5.2.1 to 5.2.5. Nothing else was changed. So it doesn't look like this is a old apache bug.
 [2007-11-26 14:08 UTC] marcus dot mueller at grintsch dot com
I doubt this is an Apache issue since we're experiencing the same symptons as hwallenstone at gmx dot here on two debian linux boxes, one using the 64bit version of Apache's httpd 2.2.4, the other using the 32bit version of httpd 2.0.59.
httpd processes seem to hang i.e. they don't close the connection (telling from /server-status) resulting in the issues mentioned above.

I first noticed this behaviour when switching from PHP 5.2.3 to PHP 5.2.4, both self-compiled using the same configure options. PHP 5.2.3, unlike 5.2.4 and 5.2.5, does not expose this behaviour.

I hope this info might narrow down your search path a little bit.
 [2007-11-28 15:02 UTC] grknight at iwon dot com
I am also experiencing this issue.

We are running Apache 2.2.3 on Redhat EL 3 and recently tried to update to 5.2.5 from 5.2.3 to fix the security issues.   The moment 5.2.5 was activated, connections failed to close in apache and resulted in hung processes.  I also tried 5.2.4 with the same results.

No configurations were changed nor PHP scripts.

Something changed in the PHP processes that prevents the apxs2handler from exiting between 5.2.3 and 5.2.4.

Configs available on request.
 [2007-11-28 16:36 UTC] ian at onlineloop dot com
Coming back to the bug report here now.

In the meantime some private emails were exchanged, including a pfiles output from Solaris showing that PHP had over 210,000 open files after 24 hours running on our servers.  Within 48 hours (we let it go this far onyl once), apache/php eats around 12Gb of RAM and has between 170 and 220 child processes with over 230,000 open files.  Under 5.1.6 the usage is more around 1.5-2Gb ram, and 30-70 child processes, with rarely more than 100 open files (only when we are really under load do we get to more than about 800 open files at any one time).

A small patch was sent to me to try, however this has changed nothing.

I was also asked to compile with gcc if possible, however this is not feasible as too many other things would have to be recompiled.  Besides, we specifically went away from gcc because everything we had that was compiled with gcc was seg faulting all the time, however with the Sun Studio compiler suite, everything is stable.

I seriously doubt this is an apache bug, why were things working with previous versions of PHP, and not this one?
 [2007-11-29 16:03 UTC] marcus dot mueller at grintsch dot com
As I stated above we have this issue on two Linux boxes with self-compiled PHP binaries. These were compiled using gcc!
 [2007-12-23 14:08 UTC] ifeghali@php.net
Apache 1.3.33 and PHP 5.2.5 running on Darwin Kernel Version 8.11.1 (Mac OS X 10.4.11) compiled with configure command (gcc):

'./configure' '--prefix=/usr/local' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--with-apxs' '--with-kerberos' '--enable-cli' '--enable-exif' '--enable-ftp' '--enable-mbstring' '--enable-mbregex' '--enable-sockets' '--with-curl' '--with-config-file-path=/private/etc' '--sysconfdir=/private/etc' '--with-mysql=/usr/local/mysql' '--with-mysql-sock=/tmp/mysql.sock' '--without-pear' '--with-gd' '--enable-gd-native-ttf' '--with-png-dir' '--with-zlib' '--with-bz2' '--with-libxml-dir' '--with-mysqli=/usr/local/mysql/bin/mysql_config' '--enable-sqlite-utf8' '--enable-zip' '--disable-cgi'

doesn't seems to be closing open files (requires, includes etc.) which ends up with the error "Too many open files" very often. 

# apachectl restart
# lsof -u www | wc -l
> 56
# lsof -u www | grep "\.php" | wc -l
no output

After running one PHP script:

# lsof -u www | grep "\.php" | wc -l
> 22

Another page hit:

# lsof -u www | grep "\.php" | wc -l
> 104

And so on... The number of open files just keeps increasing. 

For some reason PHP 4.4.7 don't have this behavior, that is, apache keeps the number of open files somewhat constant when PHP is not running.

For phpMyAdmin the first entries of lsof looks like:
# lsof -u www | grep "\.php" | head
httpd   678  www    6r     REG      14,2    26700   915904 /Users/data/htdocs/mysql/libraries/common.inc.php
httpd   678  www    7r     REG      14,2    18504   915886 /Users/data/htdocs/mysql/libraries/core.lib.php
httpd   678  www    8r     REG      14,2     2063   915950 /Users/data/htdocs/mysql/libraries/sanitizing.lib.php
httpd   678  www    9r     REG      14,2     9447   915968 /Users/data/htdocs/mysql/libraries/Theme.class.php
httpd   678  www   10r     REG      14,2    10571   915906 /Users/data/htdocs/mysql/libraries/Theme_Manager.class.php
httpd   678  www   11r     REG      14,2     9447   915968 /Users/data/htdocs/mysql/libraries/Theme.class.php
httpd   678  www   12r     REG      14,2    33846   915974 /Users/data/htdocs/mysql/libraries/Config.class.php
httpd   678  www   13r     REG      14,2    44257   915868 /Users/data/htdocs/mysql/libraries/Table.class.php
httpd   678  www   14r     REG      14,2    79607   915957 /Users/data/htdocs/mysql/libraries/common.lib.php
httpd   678  www   18r     REG      14,2     1919   915824 /Users/data/htdocs/mysql/libraries/js_escape.lib.php
 [2007-12-26 21:34 UTC] ifeghali@php.net
I can't reproduce the bug in PHP 5.1.6 on Darwin Kernel Version 8.11.1, which makes me think its an issue of 5.2.5 only.
 [2007-12-26 22:22 UTC] ifeghali@php.net
I did some more tests:

PHP 4.4.7: couldn't reproduce
PHP 5.1.6: couldn't reproduce
PHP 5.2.4: couldn't reproduce
PHP 5.2.5: problem found
PHP 5.3-200712262130: problem found
 [2007-12-27 01:54 UTC] ifeghali@php.net
It seems that the bug was introduced here:

http://cvs.php.net/viewvc.cgi/php-src/main/fopen_wrappers.c?revision=1.175.2.3.2.14&view=markup&pathrev=PHP_5_2

(revision 1.175.2.3.2.14 of fopen_wrappers.c)
 [2007-12-27 02:13 UTC] bjori@php.net
This bug has been fixed in CVS.

Snapshots of the sources are packaged every three hours; this change
will be in the next snapshot. You can grab the snapshot at
http://snaps.php.net/.
 
Thank you for the report, and for helping us make PHP better.

Thanks to Igors awesome debugging skillz :)
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved.
Last updated: Thu Nov 21 12:01:29 2024 UTC