ID: 31558 Comment by: tlamay at cte1 dot com Reported By: jdw at nearlyfreespeech dot net Status: Open Bug Type: Reproducible crash Operating System: FreeBSD PHP Version: 4CVS-2005-01-21 New Comment:
I'm getting extremely similar errors on my platform. It seems to occur and 4.3.8, 4.3.9, 4.3.10 and the latest CVS (4.3.11). Actually, using 4.3.11 makes it worse, ie, the errors occur more frequently. 4.3.6 & 4.3.7 dont seem to show this bug in my apache error.log but I get other crummy bugs with those versions. Im on a Windows 2003 platform, Apache 2.052. The errors happen at fairly consistent intervals, and this interval changes consistently based on what version of PHP I actually install. 4.3.10 restarts Apache every 30-45m, 4.3.11 restarts it every 5-15m. On windows this really sucks cause the single child process dies and takes out ALL of my threads. Its like fully restarting the webserver every half-hour. Heres a snippet from error.log: [Mon Feb 14 13:17:55 2005] [notice] Parent: Created child process 2372 [Mon Feb 14 13:17:55 2005] [notice] Disabled use of AcceptEx() WinSock2 API [Mon Feb 14 13:18:02 2005] [notice] Child 2372: Child process is running [Mon Feb 14 13:18:02 2005] [notice] Child 2372: Acquired the start mutex. [Mon Feb 14 13:18:02 2005] [notice] Child 2372: Starting 750 worker threads. [Mon Feb 14 13:18:03 2005] [notice] Child 2372: Listening on port 443. [Mon Feb 14 13:18:03 2005] [notice] Child 2372: Listening on port 443. [Mon Feb 14 13:18:03 2005] [notice] Child 2372: Listening on port 80. [Mon Feb 14 13:18:03 2005] [notice] Child 2372: Listening on port 80. FATAL: erealloc(): Unable to allocate 360448 bytes [Mon Feb 14 13:53:26 2005] [notice] Parent: child process exited with status 1 -- Restarting. [Mon Feb 14 13:53:27 2005] [notice] Parent: Created child process 3632 [Mon Feb 14 13:53:27 2005] [notice] Disabled use of AcceptEx() WinSock2 API [Mon Feb 14 13:53:34 2005] [notice] Child 3632: Child process is running [Mon Feb 14 13:53:34 2005] [notice] Child 3632: Acquired the start mutex. [Mon Feb 14 13:53:34 2005] [notice] Child 3632: Starting 750 worker threads. [Mon Feb 14 13:53:34 2005] [notice] Child 3632: Listening on port 443. [Mon Feb 14 13:53:34 2005] [notice] Child 3632: Listening on port 443. [Mon Feb 14 13:53:34 2005] [notice] Child 3632: Listening on port 80. [Mon Feb 14 13:53:34 2005] [notice] Child 3632: Listening on port 80. FATAL: erealloc(): Unable to allocate 22528 bytes [Mon Feb 14 14:27:07 2005] [notice] Parent: child process exited with status 1 -- Restarting. [Mon Feb 14 14:27:08 2005] [notice] Parent: Created child process 2956 [Mon Feb 14 14:27:08 2005] [notice] Disabled use of AcceptEx() WinSock2 API [Mon Feb 14 14:27:17 2005] [notice] Child 2956: Child process is running [Mon Feb 14 14:27:17 2005] [notice] Child 2956: Acquired the start mutex. [Mon Feb 14 14:27:17 2005] [notice] Child 2956: Starting 750 worker threads. [Mon Feb 14 14:27:17 2005] [notice] Child 2956: Listening on port 443. [Mon Feb 14 14:27:17 2005] [notice] Child 2956: Listening on port 443. [Mon Feb 14 14:27:17 2005] [notice] Child 2956: Listening on port 80. [Mon Feb 14 14:27:17 2005] [notice] Child 2956: Listening on port 80. FATAL: erealloc(): Unable to allocate 360448 bytes [Mon Feb 14 15:20:23 2005] [notice] Parent: child process exited with status 1 -- Restarting. [Mon Feb 14 15:20:25 2005] [notice] Parent: Created child process 2740 [Mon Feb 14 15:20:26 2005] [notice] Disabled use of AcceptEx() WinSock2 API [Mon Feb 14 15:20:33 2005] [notice] Child 2740: Child process is running [Mon Feb 14 15:20:33 2005] [notice] Child 2740: Acquired the start mutex. [Mon Feb 14 15:20:33 2005] [notice] Child 2740: Starting 750 worker threads. [Mon Feb 14 15:20:33 2005] [notice] Child 2740: Listening on port 443. [Mon Feb 14 15:20:33 2005] [notice] Child 2740: Listening on port 443. [Mon Feb 14 15:20:33 2005] [notice] Child 2740: Listening on port 80. [Mon Feb 14 15:20:33 2005] [notice] Child 2740: Listening on port 80. I tried increasing my PHP memory limit to 40m but this has little effect. Oddly, the allocation size that fails should be perfectly fine for my settings, and routinely matches the errors I see elesewhere on the net, so it looks like some internal 'chunk' going awry somewhere (I cant imagine why the values would be so similar otherwise). Previous Comments: ------------------------------------------------------------------------ [2005-01-22 06:55:13] jdw at nearlyfreespeech dot net I also looked at the source code. Without a detailed understanding of zend_hash_*, it isn't clear that all the per_dir_info malloc() cases in sapi/apache/mod_php4.c (particularly php_value_handler_ex() ) are being properly freed by php_destroy_per_dir_info(). That's just a WAG, but it might be something to look into as a possible cause. ------------------------------------------------------------------------ [2005-01-22 06:48:32] jdw at nearlyfreespeech dot net This test has been completed. I believe this graph of the results pretty much speaks for itself: http://example.nfshost.com/ApacheGracefulMem.png Results: - With PHP enabled, "graceful" leak averages 903,000 bytes - With PHP disabled, "graceful" leak averages 8,900 bytes - "No PHP" test memory usage *converges* (leaks are front-loaded and poorly represented by the linear fit -- hard to see because of the scale of the graph) - "PHP" test memory usage *diverges* (increases linearly until process limits intervene) Methodology: - Apache 1.3.33 - PHP version php4-STABLE-200501210130 - same Apache binary, same server, same conditions - same conf file (with "LoadModule php4_module" "php_admin_value" and "php_value" lines removed for the "No HP" test) - 200 consecutive "graceful" restarts of Apache process - considering only "master" process - no requests issued during test ------------------------------------------------------------------------ [2005-01-21 01:04:16] jdw at nearlyfreespeech dot net Keep in mind that this is happen in the "master" Apache process, a context in which no PHP scripts are ever executed. In fact, very little happens other than parsing config files. That should severely constrain the influence of libraries & extensions. Apache obviously won't parse its configs with PHP disabled, and our customers will (justifiably) riot if we turn it off. There are quite a large number of PHP-specific conf lines in a proportional number of files (the reason I suspect our setup is finding this earlier than the general population), so I'm not sure how feasible your suggestion is. But I'm happy to see if I can rig something up on a test server to explore it. More to follow. It would be more direct if there were a means to instrument the amount of memory allocated at start vs. the amount freed at restart. It would also be handy if there's someone around who can point me in the right direction as to where in the PHP Apache SAPI code to find the relevant setup/cleanup code. Also, I now have a second backtrace, but I am hestitant to post it here because it's even larger than the first one. It's similar: died on a "php_admin_value open_basedir" instead of "php_admin_value max_execution_time." ------------------------------------------------------------------------ [2005-01-21 00:36:57] [EMAIL PROTECTED] Disable PHP from Apache and see if the problem persists. It is possible that one the libraries used by PHP is leaking etc... Right now all we know is that your PHP is failing to allocate memory and you are claiming that PHP leaks. Well, that does not say a whole lot. ------------------------------------------------------------------------ [2005-01-20 23:41:47] jdw at nearlyfreespeech dot net As previously indicated, the system limits are not in play. Or rather, if they are, they shouldn't be. I've said that a couple of times now in attempt to avoid a quick "you're out of memory" reaction. Unfortunately, that strategy does not appear to be a winner. The per-process allocation limits are currently set to 512M. That is a very savvy observation that the process size grows to 512M and then allocations fail. I checked out the size of the core dump file, and it confirms your theory. Whatever random PHP script, large or small, is running at that point gets hosed (obviously). Good catch! But it is a little hasty to jump from that to "bogus." The "steady state" size of Apache processes on this system should be about 30M. Where did the other 480M come from? Further research today has shown that Apache leaks about 1mb of RAM on every "graceful" (SIGUSR1) restart. If it's something else leaking, fine, but so far the stack trace says it's PHP. Perhaps instead of rushing to "bogus," you could suggest some ways I could prove or disprove the theory that PHP leaks memory when Apache is reconfigured. That would be very helpful, and I would very much appreciate help from any corner with this problem. (State changed to "open." If investigation reveals that the leak is not in PHP I'll be the first one to change it to bogus.) Thanks! ------------------------------------------------------------------------ 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 http://bugs.php.net/31558 -- Edit this bug report at http://bugs.php.net/?id=31558&edit=1
