ID: 31749
User updated by: phpbug2 at mailinator dot com
-Summary: pthread deadlock after script execution finishes
Reported By: phpbug2 at mailinator dot com
Status: Open
Bug Type: Scripting Engine problem
Operating System: Linux 2.4.28
PHP Version: 5.0.3
New Comment:
Updated summary with new findings.
Previous Comments:
------------------------------------------------------------------------
[2005-01-30 07:01:56] phpbug2 at mailinator dot com
Test case, this almost 100% guarantees a deadlock for me with the
following BT:
(gdb) bt
#0 0x001cf666 in sigsuspend () from /lib/libc.so.6
#1 0x00d0bc28 in __pthread_wait_for_restart_signal () from
/lib/libpthread.so.0
#2 0x00d0def0 in __pthread_alt_lock () from /lib/libpthread.so.0
#3 0x00d0a170 in pthread_mutex_lock () from /lib/libpthread.so.0
#4 0x0023f125 in __tz_convert () from /lib/libc.so.6
#5 0x0023d2a1 in gmtime () from /lib/libc.so.6
#6 0x080801fa in ap_gm_timestr_822 (p=0xfffffffc, sec=1107064749) at
util.c:153
#7 0x0807b7ac in ap_basic_http_header (r=0x2dd1c0) at
http_protocol.c:1585
#8 0x0807b938 in ap_send_http_header (r=0x819ca44) at
http_protocol.c:1852
#9 0x00a74337 in sapi_apache_send_headers (sapi_headers=0xbb0fd8) at
/root/php5cvs/php-src/sapi/apache/mod_php5.c:217
#10 0x009b9923 in sapi_send_headers () at
/root/php5cvs/php-src/main/SAPI.c:760
#11 0x0096741a in php_header () at
/root/php5cvs/php-src/ext/standard/head.c:54
#12 0x009c0764 in php_ub_body_write (str=0xfffffffc <Address 0xfffffffc
out of bounds>, str_length=4294967292)
at /root/php5cvs/php-src/main/output.c:707
#13 0x009bfac6 in php_end_ob_buffer (send_buffer=1 '\001', just_flush=0
'\0') at /root/php5cvs/php-src/main/output.c:297
#14 0x009bfd13 in php_end_ob_buffers (send_buffer=252 'ü') at
/root/php5cvs/php-src/main/output.c:336
#15 0x009b3021 in php_request_shutdown (dummy=0x0) at
/root/php5cvs/php-src/main/main.c:1183
#16 0x00a74112 in apache_php_module_main (r=0x819ca44,
display_source_mode=0)
at /root/php5cvs/php-src/sapi/apache/sapi_apache.c:60
#17 0x00a7490a in send_php (r=0x819ca44, display_source_mode=0,
filename=0x0)
at /root/php5cvs/php-src/sapi/apache/mod_php5.c:631
#18 0x00a74bd7 in send_parsed_php (r=0x819ca44) at
/root/php5cvs/php-src/sapi/apache/mod_php5.c:646
#19 0x0806c842 in ap_invoke_handler (r=0x819ca44) at http_config.c:475
#20 0x0807edb3 in process_request_internal (r=0x819ca44) at
http_request.c:1298
#21 0x0807ef27 in ap_process_request (r=0x819ca44) at
http_request.c:1314
#22 0x080762d0 in child_main (child_num_arg=-1073743648) at
http_main.c:4786
#23 0x08076644 in make_child (s=0x80a929c, slot=4, now=0) at
http_main.c:4956
#24 0x08076704 in startup_children (number_to_start=8) at
http_main.c:4983
#25 0x08077819 in standalone_main (argc=-4, argv=0x0) at
http_main.c:5315
#26 0x080789a7 in main (argc=1, argv=0xbffffed4) at http_main.c:5657
<?php
set_time_limit (10);
header ('Content-Type: text/plain');
while (TRUE)
{
$date = date ('Y');
$time = time ();
$time += time();
$foo = localtime();
$then = date("M-d-Y", mktime(0, 0, 0, 12, 32, 1997));
$something = gmdate("M d Y H:i:s", mktime(0, 0, 0, 1,
1, 1998));
if (time() != $oldtime)
{
$oldtime = time();
print "$foo $date $time $then $something\n";
}
}
?>
------------------------------------------------------------------------
[2005-01-29 18:55:13] phpbug2 at mailinator dot com
I am using Apache 1.3.33 which isn't threaded to my knowledge.
# ./httpd -V
Server version: Apache/1.3.33 (Unix)
Server built: Nov 11 2004 07:16:41
Server's Module Magic Number: 19990320:16
Server compiled with....
-D HAVE_MMAP
-D HAVE_SHMGET
-D USE_SHMGET_SCOREBOARD
-D USE_MMAP_FILES
-D HAVE_FCNTL_SERIALIZED_ACCEPT
-D HAVE_SYSVSEM_SERIALIZED_ACCEPT
-D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
-D DYNAMIC_MODULE_LIMIT=64
-D HARD_SERVER_LIMIT=256
-D HTTPD_ROOT="/www"
-D SUEXEC_BIN="/www/bin/suexec"
-D DEFAULT_PIDLOG="logs/httpd.pid"
-D DEFAULT_SCOREBOARD="logs/httpd.scoreboard"
-D DEFAULT_LOCKFILE="logs/httpd.lock"
-D DEFAULT_ERRORLOG="logs/error_log"
-D TYPES_CONFIG_FILE="conf/mime.types"
-D SERVER_CONFIG_FILE="conf/httpd.conf"
-D ACCESS_CONFIG_FILE="conf/access.conf"
-D RESOURCE_CONFIG_FILE="conf/srm.conf"
# ./httpd -l
Compiled-in modules:
http_core.c
mod_env.c
mod_log_config.c
mod_mime.c
mod_negotiation.c
mod_status.c
mod_include.c
mod_autoindex.c
mod_dir.c
mod_cgi.c
mod_imap.c
mod_actions.c
mod_alias.c
mod_rewrite.c
mod_access.c
mod_auth.c
mod_so.c
mod_setenvif.c
suexec: enabled; valid wrapper /www/bin/suexec
I am also using the latest versions of mod_security, mod_dav and
mod_throttle. Using non-tls glibc 2.3.2.
Following additional testing it appears the script output DOES NOT get
sent to the client. No data is transferred and eventually the browser
gives a 'Request timed out' message or similar.
I have rebuilt using PHP 5 CVS with -g. Here is the new backtrace after
a child froze:
(gdb) bt
#0 0x001cf666 in sigsuspend () from /lib/libc.so.6
#1 0x00d0bc28 in __pthread_wait_for_restart_signal () from
/lib/libpthread.so.0
#2 0x00d0def0 in __pthread_alt_lock () from /lib/libpthread.so.0
#3 0x00d0a170 in pthread_mutex_lock () from /lib/libpthread.so.0
#4 0x0023f125 in __tz_convert () from /lib/libc.so.6
#5 0x0023d2a1 in gmtime () from /lib/libc.so.6
#6 0x08086ce0 in ap_gm_timestr_822 ()
Since this is a calendar module I guess there may be a lot of libc
calls to time related functions which may explain why gmtime is
deadlocking.
A subsequent request froze in PHP flock() on the session file, which to
me would indicate that the first request is still in processing
somewhere by PHP, even though the backtrace seems to indicate
elsewhere.
(gdb) bt
#0 0x0027cca1 in flock () from /lib/libc.so.6
#1 0x008f365c in ps_files_open (data=0x8b86044, key=0x8bfd0dc
"155e331d3c7ad7493906808d89dae388")
at /root/php5cvs/php-src/ext/session/mod_files.c:166
#2 0x008f3900 in ps_read_files (mod_data=0xfffffe00, key=0x8bfd0fc "",
val=0xbfffb770, vallen=0xfffffe00)
at /root/php5cvs/php-src/ext/session/mod_files.c:322
#3 0x008f1029 in php_session_start () at
/root/php5cvs/php-src/ext/session/session.c:746
#4 0x008f2999 in zif_session_start (ht=1, return_value=0x82d8c6c,
this_ptr=0x0, return_value_used=0)
at /root/php5cvs/php-src/ext/session/session.c:1660
#5 0x00a0bf25 in zend_do_fcall_common_helper_SPEC
(execute_data=0xbfffbfa0) at zend_vm_execute.h:175
#6 0x00a10245 in ZEND_DO_FCALL_SPEC_CONST_HANDLER
(execute_data=0xbfffbfa0) at zend_vm_execute.h:1534
#7 0x00a0b96f in execute (op_array=0x82dcde4) at zend_vm_execute.h:78
#8 0x00a0bb86 in zend_do_fcall_common_helper_SPEC
(execute_data=0xbfffd0a0) at zend_vm_execute.h:204
#9 0x00a0b96f in execute (op_array=0x82c65ec) at zend_vm_execute.h:78
#10 0x009ebc14 in zend_execute_scripts (type=8, retval=0x0,
file_count=3) at /root/php5cvs/php-src/Zend/zend.c:1058
#11 0x009b3b38 in php_execute_script (primary_file=0xbffff400) at
/root/php5cvs/php-src/main/main.c:1636
#12 0x00a7404f in apache_php_module_main (r=0x81ac084,
display_source_mode=0)
at /root/php5cvs/php-src/sapi/apache/sapi_apache.c:54
#13 0x00a7490a in send_php (r=0x81ac084, display_source_mode=0,
filename=0x0)
at /root/php5cvs/php-src/sapi/apache/mod_php5.c:631
#14 0x00a74bd7 in send_parsed_php (r=0x81ac084) at
/root/php5cvs/php-src/sapi/apache/mod_php5.c:646
#15 0x080701e7 in ap_invoke_handler ()
#16 0x00b17016 in zend_vm_decode.0 () from /www/libexec/libphp5.so
#17 0x00000017 in ?? ()
#18 0x0000001b in ?? ()
Restarting Apache and then accessing the same URL results in the page
loading. After using a few more calendar functions in phpWebSite, I
encounted these errors after 30 seconds of 100% CPU usage (looks like a
few PEAR scripts ship with phpWebSite):
Fatal error: Maximum execution time of 30 seconds exceeded in
/home/----/public_html/test/lib/pear/Date/Calc.php on line 1236
1236:
return(Date_Calc::dateFormat($day,$month,$century.$year,$format));
Fatal error: Maximum execution time of 30 seconds exceeded in
/home/----/public_html/test/lib/pear/Date/TimeZone.php on line 117
117: $this->dstlongname = $this->longname;
Fatal error: Maximum execution time of 30 seconds exceeded in
/home/----/public_html/test/lib/pear/Date.php on line 586
586: list($this->year, $this->month, $this->day) =
sscanf(Date_Calc::daysToDate($d), "%04s%02s%02s");
Continuing to reload the page after the execution timeout error
eventually results in a deadlock:
(gdb) bt
#0 0x001cf666 in sigsuspend () from /lib/libc.so.6
#1 0x00d0bc28 in __pthread_wait_for_restart_signal () from
/lib/libpthread.so.0
#2 0x00d0def0 in __pthread_alt_lock () from /lib/libpthread.so.0
#3 0x00d0a170 in pthread_mutex_lock () from /lib/libpthread.so.0
#4 0x0023f125 in __tz_convert () from /lib/libc.so.6
#5 0x0023d2a1 in gmtime () from /lib/libc.so.6
#6 0x08086ce0 in ap_gm_timestr_822 ()
It looks like I may have to rebuild Apache to see where these calls are
coming from. After doing so:
#0 0x001cf666 in sigsuspend () from /lib/libc.so.6
#1 0x00d0bc28 in __pthread_wait_for_restart_signal () from
/lib/libpthread.so.0
#2 0x00d0def0 in __pthread_alt_lock () from /lib/libpthread.so.0
#3 0x00d0a170 in pthread_mutex_lock () from /lib/libpthread.so.0
#4 0x0023f125 in __tz_convert () from /lib/libc.so.6
#5 0x0023d2a1 in gmtime () from /lib/libc.so.6
#6 0x080801fa in ap_gm_timestr_822 (p=0xfffffffc, sec=1107020917) at
util.c:153
#7 0x0807b7ac in ap_basic_http_header (r=0x2dd1c0) at
http_protocol.c:1585
#8 0x0807b938 in ap_send_http_header (r=0x819ca44) at
http_protocol.c:1852
#9 0x00a74337 in sapi_apache_send_headers (sapi_headers=0xbb0fd8) at
/root/php5cvs/php-src/sapi/apache/mod_php5.c:217
#10 0x009b9923 in sapi_send_headers () at
/root/php5cvs/php-src/main/SAPI.c:760
#11 0x0096741a in php_header () at
/root/php5cvs/php-src/ext/standard/head.c:54
#12 0x009c0764 in php_ub_body_write (str=0xfffffffc <Address 0xfffffffc
out of bounds>, str_length=4294967292)
at /root/php5cvs/php-src/main/output.c:707
#13 0x009bfac6 in php_end_ob_buffer (send_buffer=1 '\001', just_flush=0
'\0') at /root/php5cvs/php-src/main/output.c:297
#14 0x009bfd13 in php_end_ob_buffers (send_buffer=252 'ü') at
/root/php5cvs/php-src/main/output.c:336
#15 0x009b3021 in php_request_shutdown (dummy=0x0) at
/root/php5cvs/php-src/main/main.c:1183
#16 0x00a74112 in apache_php_module_main (r=0x819ca44,
display_source_mode=0)
at /root/php5cvs/php-src/sapi/apache/sapi_apache.c:60
#17 0x00a7490a in send_php (r=0x819ca44, display_source_mode=0,
filename=0x0)
at /root/php5cvs/php-src/sapi/apache/mod_php5.c:631
#18 0x00a74bd7 in send_parsed_php (r=0x819ca44) at
/root/php5cvs/php-src/sapi/apache/mod_php5.c:646
#19 0x0806c842 in ap_invoke_handler (r=0x819ca44) at http_config.c:475
#20 0x0807edb3 in process_request_internal (r=0x819ca44) at
http_request.c:1298
#21 0x0807ef27 in ap_process_request (r=0x819ca44) at
http_request.c:1314
#22 0x080762d0 in child_main (child_num_arg=-1073743616) at
http_main.c:4786
#23 0x08076644 in make_child (s=0x80a929c, slot=18, now=0) at
http_main.c:4956
#24 0x08077b09 in standalone_main (argc=-4, argv=0x0) at
http_main.c:5141
#25 0x080789a7 in main (argc=1, argv=0xbffffed4) at http_main.c:5657
(gdb) bt full
#0 0x001cf666 in sigsuspend () from /lib/libc.so.6
No symbol table info available.
#1 0x00d0bc28 in __pthread_wait_for_restart_signal () from
/lib/libpthread.so.0
No symbol table info available.
#2 0x00d0def0 in __pthread_alt_lock () from /lib/libpthread.so.0
No symbol table info available.
#3 0x00d0a170 in pthread_mutex_lock () from /lib/libpthread.so.0
No symbol table info available.
#4 0x0023f125 in __tz_convert () from /lib/libc.so.6
No symbol table info available.
#5 0x0023d2a1 in gmtime () from /lib/libc.so.6
No symbol table info available.
#6 0x080801fa in ap_gm_timestr_822 (p=0xfffffffc, sec=1107020917) at
util.c:153
tms = (struct tm *) 0xfffffffc
#7 0x0807b7ac in ap_basic_http_header (r=0x2dd1c0) at
http_protocol.c:1585
protocol = 0x0
#8 0x0807b938 in ap_send_http_header (r=0x819ca44) at
http_protocol.c:1852
i = 135914004
zero = 0
#9 0x00a74337 in sapi_apache_send_headers (sapi_headers=0xbb0fd8) at
/root/php5cvs/php-src/sapi/apache/mod_php5.c:217
No locals.
#10 0x009b9923 in sapi_send_headers () at
/root/php5cvs/php-src/main/SAPI.c:760
nm_zlib_get_coding_type = {value = {lval = -1073746799, dval =
1.5914943852473662e-314, str = {val = 0xbfffec91 "",
len = 0}, ht = 0xbfffec91, obj = {handle = 3221220497, handlers =
0x0}}, refcount = 1255, type = 0 '\0',
is_ref = 0 '\0'}
uf_result = (zval *) 0x9f80ab
retval = -4
ret = -1
#11 0x0096741a in php_header () at
/root/php5cvs/php-src/ext/standard/head.c:54
No locals.
#12 0x009c0764 in php_ub_body_write (str=0xfffffffc <Address 0xfffffffc
out of bounds>, str_length=4294967292)
at /root/php5cvs/php-src/main/output.c:707
result = 0
#13 0x009bfac6 in php_end_ob_buffer (send_buffer=1 '\001', just_flush=0
'\0') at /root/php5cvs/php-src/main/output.c:297
final_buffer = 0x834b8b4 "\n\n\n<br />\n<b>Fatal error</b>:
Maximum execution time of 30 seconds exceeded in
<b>/home/----/public_html/test/lib/pear/Date/TimeZone.php</b> on line
<b>251</b><br />\n"
final_buffer_length = 169
alternate_buffer = (zval *) 0x0
to_be_destroyed_handler_name = 0x82b89dc "default output
handler"
to_be_destroyed_handled_output = The value of variable
'to_be_destroyed_handled_output' is distributed across several
locations, and GDB cannot access its value.
Is it possible the execution timeout handler is interrupting an
existing gmtime call from the PHP code, and then causing a deadlock
when trying to write the header?
Please let me know what additional information is needed.
------------------------------------------------------------------------
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/31749
--
Edit this bug report at http://bugs.php.net/?id=31749&edit=1
