php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #37422 FastCGI: comm with server .. aborted: idle timeout
Submitted: 2006-05-12 19:34 UTC Modified: 2006-07-24 12:22 UTC
From: phpbugs at thequod dot de Assigned: dmitry (profile)
Status: Closed Package: CGI/CLI related
PHP Version: 5.1.5CVS OS: Ubuntu Linux
Private report: No CVE-ID: None
 [2006-05-12 19:34 UTC] phpbugs at thequod dot de
Description:
------------
I'm running Apache2/mod_fastcgi/PHP5.1.5-dev (built: May 
12 2006 19:46:11).

The problem is, that without setting PHP_FCGI_CHILDREN 
children, PHP does not default to the documented value of 
8 (no source, but often read): it does not create any 
children.

This might be just a documentation issue/bug, but without 
using any children, I can reproduce crashing PHP (somehow 
after PHP_FCGI_MAX_REQUESTS), but also experience with 
PHP_FCGI_CHILDREN set to 4!

This "bogus" report seems to be related: 
http://bugs.php.net/bug.php?id=27802

Reproduce code:
---------------
In fastcgi.conf:        FastCgiServer /XXX/fcgi-scripts/XXX/php5-fcgi-starter -user phptest_codeprobe -group phptest_codeprobe -pass-header HTTP_AUTHORIZATION -flush -idle-timeout 60

php5-fcgi-starter script:
#!/bin/sh
PHPRC="/vhosts/phptest_codeprobe/conf/php5"
export PHPRC
PHP_FCGI_MAX_REQUESTS=100
export PHP_FCGI_MAX_REQUESTS
exec /bin/php5-fcgi


1. Restart Apache
2. A php5-fcgi process gets started (without any childs)
3. ab2 -n 101 url/
4. A new php5-fcgi process gets "re-spawned"
5. ab2 -n 201 url/
6. The longest request takes 4s(!), instead of 0.004.
7. ab2 -n 301 url/
8. The php5-fcgi process disappears forever!

This only seems to be an indication, because I have one server setup with PHP_FCGI_MAX_REQUESTS=100 and PHP_FCGI_CHILDREN=4 and it also dies away like this (with the same entries in the server's error log).

This is since PHP 5.1.3/5.1.4..

Expected result:
----------------
Do not crash.

Actual result:
--------------
Apache error log:
FastCGI: comm with 
server "/var/www/fcgi-scripts/phptest_codeprobe/php5-fcgi-starter" 
aborted: idle timeout (60 sec)
FastCGI: incomplete headers (0 bytes) received from 
server "/var/www/fcgi-scripts/phptest_codeprobe/php5-fcgi-starter"


Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2006-05-12 19:37 UTC] phpbugs at thequod dot de
The test script is just <?php echo 'foo'; ?>.
 [2006-05-15 11:03 UTC] dmitry@php.net
the behavior of PHP_FCGI_CHILDREN was changed about year ago. If it is not set then main PHP process doesn't fork worker processes but serve FastCGI requests by itself.

I cannot reproduce the problem with PHP_FCGI_CHILDREN is set, but it well reproducable without PHP_FCGI_CHILDREN.

BTW I can reproduce the same problem with mod_fastcgi and PHP-5.0, and cannot reproduce with PHP-5.1.4 and zend_enabler. So I assume this is mod_fastcgi bug, that cannot restart PHP properly.



 [2006-05-15 19:15 UTC] phpbugs at thequod dot de
I've tried debugging the problem a bit more (with gdb):

The main process (which was started at first) has this 
backtrace:
#0  0xb7890968 in wait () from /lib/tls/libc.so.6
#1  0x083203bb in main (argc=1, argv=0xbfdf8be4) 
at /home/XXX/cvs/php/php51dev/sapi/cgi/cgi_main.c:1285

("ps aux" says:
XXX    21201  0.0  0.7  15372  3976 ?        Ss   May14   
0:00 /bin/php5-fcgi)

Line 1285 is the while loop here:
            if (parent) {
#ifdef DEBUG_FASTCGI
                fprintf(stderr, "Wait for kids, pid %d\n", 
getpid());
#endif
                while (wait(&status) < 0) {
                }
                running--;
            }


And here are backtraces, of two php5-fcgi childs (4 
total):
(gdb) bt
#0  0xb78c4678 in poll () from /lib/tls/libc.so.6
#1  0x0827b266 in php_sockop_read (stream=0x866546c, 
buf=0xfffffffc <Address 0xfffffffc out of bounds>, 
count=4294967292)
    at php_network.h:164
#2  0x08099b5e in php_openssl_sockop_read 
(stream=0x866546c, buf=0x866557c "etting t&#65533;&#65533;\222&#65533;", 
count=8192)
    at /home/XXX/cvs/php/php51dev/ext/openssl/xp_ssl.c:229
#3  0x08271d20 in php_stream_fill_read_buffer 
(stream=0x866546c, size=1) 
at /home/XXX/cvs/php/php51dev/main/streams/streams.c:541
#4  0x08271dd2 in _php_stream_read (stream=0x866546c, 
buf=0xbfdf2187 "\b&#65533;!&#2047;&#65533;\204 \blTf\b&#65533;&#65533;&#65533;&#65533;kqI\b", size=1)
    
at /home/XXX/cvs/php/php51dev/main/streams/streams.c:584
#5  0x08271fa3 in _php_stream_getc (stream=0xfffffffc) 
at /home/XXX/cvs/php/php51dev/main/streams/streams.c:649
#6  0x082084c5 in zif_fgetc (ht=1, return_value=0x869180c, 
return_value_ptr=0x0, this_ptr=0x0, return_value_used=1)
    at /home/XXX/cvs/php/php51dev/ext/standard/file.c:1076
#7  0x082b503b in zend_do_fcall_common_helper_SPEC 
(execute_data=0xbfdf4410) at zend_vm_execute.h:200
#8  0x082b472b in execute (op_array=0x8681814) at 
zend_vm_execute.h:92
#9  0x0829c694 in zend_execute_scripts (type=8, 
retval=Variable "retval" is not available.
) at /home/XXX/cvs/php/php51dev/Zend/zend.c:1109
#10 0x08263044 in php_execute_script 
(primary_file=0xbfdf8acc) 
at /home/XXX/cvs/php/php51dev/main/main.c:1732
#11 0x08320831 in main (argc=1, argv=0xbfdf8be4) 
at /home/XXX/cvs/php/php51dev/sapi/cgi/cgi_main.c:1608


#0  0xb78c4678 in poll () from /lib/tls/libc.so.6
#1  0x0827b266 in php_sockop_read (stream=0x8668804, 
buf=0xfffffffc <Address 0xfffffffc out of bounds>, 
count=4294967292)
    at php_network.h:164
#2  0x08099b5e in php_openssl_sockop_read 
(stream=0x8668804, buf=0x865e50c "", count=8192)
    at /home/XXX/cvs/php/php51dev/ext/openssl/xp_ssl.c:229
#3  0x08271d20 in php_stream_fill_read_buffer 
(stream=0x8668804, size=8192)
    
at /home/XXX/cvs/php/php51dev/main/streams/streams.c:541
#4  0x08272183 in _php_stream_get_line (stream=0x8668804, 
buf=0x0, maxlen=0, returned_len=0xbfdf21b0)
    
at /home/XXX/cvs/php/php51dev/main/streams/streams.c:820
#5  0x0820b4ad in zif_fgets (ht=1, return_value=0x8696bf4, 
return_value_ptr=0x0, this_ptr=0x0, return_value_used=1)
    at /home/XXX/cvs/php/php51dev/ext/standard/file.c:1021
#6  0x082b503b in zend_do_fcall_common_helper_SPEC 
(execute_data=0xbfdf4410) at zend_vm_execute.h:200
#7  0x082b472b in execute (op_array=0x865228c) at 
zend_vm_execute.h:92
#8  0x0829c694 in zend_execute_scripts (type=8, 
retval=Variable "retval" is not available.
) at /home/XXX/cvs/php/php51dev/Zend/zend.c:1109
#9  0x08263044 in php_execute_script 
(primary_file=0xbfdf8acc) 
at /home/XXX/cvs/php/php51dev/main/main.c:1732
#10 0x08320831 in main (argc=1, argv=0xbfdf8be4) 
at /home/XXX/cvs/php/php51dev/sapi/cgi/cgi_main.c:1608

PHP_FCGI_CHILDREN=4
PHP_FCGI_MAX_REQUESTS=100
 [2006-05-15 19:56 UTC] edink@php.net
Please try using this CVS snapshot:

  http://snaps.php.net/php5.2-latest.tar.gz
 
For Windows:
 
  http://snaps.php.net/win32/php5.2-win32-latest.zip


 [2006-05-16 06:26 UTC] phpbugs at thequod dot de
The described problem, where PHP_FCGI_CHILDREN is set, seems rather to be a PHP application problem:
I was using fsockopen on URLs, without having set a transfer timeout through stream_set_timeout(). Therefor the FCGI process timed out on requests to URLs, which did not respond in a given time. I've setup the fastcgi-Server with a timeout of 60 seconds.
It seems to cause no more problems with current CVS (PHP 5.2.0-dev (cgi-fcgi) (built: May 15 2006 22:28:11)) and probably also not with 5.1.4, which I'll re-try now.

Having "crashes" with unset PHP_FCGI_CHILDREN is bad IMHO, nevertheless. Can it be fixed?

Can you see in my backtraces what the missing stream_set_timeout() in my script "triggered"? I find the message "buf=0xfffffffc <Address 0xfffffffc out of bounds>, 
count=4294967292" quite "unusal".

btw: please update sapi/cgi/README.FastCGI accordingly, because it still says that by default 8 childs get used!
 [2006-05-17 14:04 UTC] mike@php.net
No Bug? Bogus. Thanks.
 [2006-05-17 17:00 UTC] phpbugs at thequod dot de
I see at least three bugs here:
 - documentation is wrong (default values)
 - reproducable crash
 - occassional errors like:
[Wed May 17 18:34:35 2006] [error] [client 88.247.169.170] 
(104)Connection reset by peer: FastCGI: comm with 
server "/var/www/XXX/php5-fcgi-starter" aborted: read 
failed
[Wed May 17 18:34:35 2006] [error] [client 88.247.169.170] 
FastCGI: incomplete headers (0 bytes) received from 
server "/var/www/XXX/php5-fcgi-starter"

and

[Wed May 17 18:34:20 2006] [error] [client 72.30.111.157] 
FastCGI: comm with server "/var/www/XXX/php5-fcgi-starter" 
aborted: idle timeout (60 sec)
[Wed May 17 18:34:20 2006] [error] [client 72.30.111.157] 
FastCGI: incomplete headers (0 bytes) received from 
server "/var/www/XXX/php5-fcgi-starter"

after the server has been running some time..

I cannot reproduce it, though and don't know how I should 
debug it.

What's strange about all those timeout errors: 
max_execution_time is set to 30.

Since I've tested the 5.1.3 RCs, php-fastcgi is not usable 
anymore in production for me! I think I'll have to go back 
to 5.1.2 for now.

5.2-dev does not seem to have this problem (around them 
time the snapshot has been posted here), but I don't think 
it's a good idea to use it in production.
 [2006-05-17 18:56 UTC] phpbugs at thequod dot de
Sidenote: The cause for the "read failed" error was due to 
the exhausted memory_limit, see 
http://bugs.php.net/?id=37481

Still, there's the "idle timeout" error (when using 
PHP_FCGI_CHILDREN=4 and MAX_REQUEST=100).

It does not seem related to the "read failed"/memory_limit 
(e.g. memory leak because of it), at least I think so 
after triggering "memory exhausted" errors.
 [2006-05-29 23:00 UTC] phpbugs at thequod dot de
Here is a backtrace of a process running without 
PHP_FCGI_CHILDREN and PHP_FCGI_MAX_REQUESTS being set (so 
there's only one instance):

#0  0xb7802d2c in recv () from /lib/tls/libc.so.6
#1  0x0837cf99 in fcgi_finish_request (req=0xbff29d94) 
at /home/XXX/cvs/php/php51dev/sapi/cgi/fastcgi.c:620
#2  0x0837d760 in fcgi_accept_request (req=0xbff29d94) 
at /home/XXX/cvs/php/php51dev/sapi/cgi/fastcgi.c:633
#3  0x0837ee7c in main (argc=1, argv=0xbff2c464) 
at /home/XXX/cvs/php/php51dev/sapi/cgi/cgi_main.c:1333

It seems to hang there around for a while and all requests 
that arrive get an idle timeout error.

This is PHP 5.1.5-dev (cgi-fcgi) (built: May 29 2006 
01:33:02) (DEBUG).

It appears to be just a overload on the server/number of 
simulatneous requests, as I can reproduce it with
ab2 -n PHP_FCGI_CHILDREN+1 -c PHP_FCGI_CHILDREN+1 
www.site/
and a script that does "sleep( timeout + 1 );".

But I've never seen those errors before 5.1.3-dev and 
therefor cannot really believe that this is the only 
cause.
 [2006-07-24 12:22 UTC] dmitry@php.net
The README.FastCGI is fixed in CVS HEAD and PHP_5_2.

PHP crashes are already fixed.

The "indle timeout" error is not a bug. It may occur on high load, then requests concurrency is larger then number of running PHP processes.
 
PHP Copyright © 2001-2021 The PHP Group
All rights reserved.
Last updated: Fri Jul 23 20:01:23 2021 UTC