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
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: phpbugs at thequod dot de
New email:
PHP Version: OS:

 

 [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

Pull Requests

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-2024 The PHP Group
All rights reserved.
Last updated: Thu Nov 28 21:01:29 2024 UTC