ID: 31749 Updated by: [EMAIL PROTECTED] Reported By: phpbug2 at mailinator dot com -Status: Open +Status: Assigned Bug Type: Scripting Engine problem Operating System: Linux 2.4.28, 2.4.21-SMP PHP Version: 5.0.3, 4.3.10 -Assigned To: +Assigned To: andi New Comment:
Andi, please take a look. I remember some talk in the past about going this route, but I don't recall the arguments against it. Similarly, I'm not sure that this is really a problem for PHP to fix; given that the time() function is officially not thread-safe, it seems wrong for the libc to mutex internally. Previous Comments: ------------------------------------------------------------------------ [2005-02-19 22:28:32] phpbug2 at mailinator dot com I've created a patch against 5.0.3 to implement my "soft timeout" idea above. It will try to soft-break execution after the timeout period elapses and then hard-break after another timeout period. There seem to be a lot of calls to the zend_set_timeout and zend_unset_timeout functions that I'm not too sure are helping the situation. Here's what happens using the CLI PHP and printing whenever certain functions are hit: $ sapi/cli/php /www/htdocs/time.php zend_unset_timeout() zend_set_timeout (0) zend_set_timeout (0) zend_set_timeout (0) zend_unset_timeout() zend_set_timeout (5) Array 2005 2217696508 Jan-01-1998 Jan 01 1998 05:00:00 Array 2005 2217696508 Jan-01-1998 Jan 01 1998 05:00:00 Array 2005 2217696510 Jan-01-1998 Jan 01 1998 05:00:00 Array 2005 2217696512 Jan-01-1998 Jan 01 1998 05:00:00 Array 2005 2217696516 Jan-01-1998 Jan 01 1998 05:00:00 Array 2005 2217696516 Jan-01-1998 Jan 01 1998 05:00:00 zend_soft_timeout() zend_set_timeout (5) zend_timeout() zend_set_timeout (5) Fatal error: Maximum execution time of 5 seconds exceeded in /www/htdocs/time.php on line 10 zend_unset_timeout() zend_set_timeout (30) zend_unset_timeout() And the patch to 5.0.3 to implement the "zend_soft_timeout" that "works for me" in that I'm not getting any more deadlocked Apache children: http://www.r1hosting.net/zend_timeout.patch ------------------------------------------------------------------------ [2005-02-17 16:33:31] phpbug2 at mailinator dot com Hi, Unfortunately that snapshot did not fix the problem. The child processes still deadlock. #0 0x401c10a4 in __pthread_sigsuspend () from /lib/i686/libpthread.so.0 #1 0x401c0a58 in __pthread_wait_for_restart_signal () from /lib/i686/libpthread.so.0 #2 0x401c2600 in __pthread_alt_lock () from /lib/i686/libpthread.so.0 #3 0x401bf2e7 in pthread_mutex_lock () from /lib/i686/libpthread.so.0 #4 0x4027caba in free () from /lib/i686/libc.so.6 #5 0x4043d9b8 in shutdown_scanner () at Zend/zend_language_scanner.c:2881 #6 0x40450aa5 in zend_deactivate () at /home/r1ch/php4-STABLE-200502171330/Zend/zend.c:689 #7 0x40427d46 in php_request_shutdown (dummy=0x0) at /home/r1ch/php4-STABLE-200502171330/main/main.c:997 #8 0x404639c7 in php_handler (r=0x81a9628) at /home/r1ch/php4-STABLE-200502171330/sapi/apache2handler/sapi_apache2.c:567 #9 0x08089d35 in ap_run_handler (r=0x81a9628) at config.c:152 #10 0x0808a340 in ap_invoke_handler (r=0x81a9628) at config.c:364 #11 0x0806eefa in ap_process_request (r=0x81a9628) at http_request.c:249 #12 0x0806a38d in ap_process_http_connection (c=0x819f418) at http_core.c:251 #13 0x08094ec5 in ap_run_process_connection (c=0x819f418) at connection.c:43 #14 0x08088334 in child_main (child_num_arg=-4) at prefork.c:610 #15 0x08088487 in make_child (s=0x401c8398, slot=0) at prefork.c:704 #16 0x080885a8 in startup_children (number_to_start=5) at prefork.c:722 #17 0x08088e1a in ap_mpm_run (_pconf=0x80cb818, plog=0x81038f8, s=0x80d0168) at prefork.c:941 #18 0x0808f36d in main (argc=3, argv=0xbffff284) at main.c:618 This backtrace is from a separate Apache 2 server (prefork) since I cannot test a PHP4 on my production server as it may break a number of PHP5 features I am using. However it still shows that the libc mutexes are not getting released, this time in the free() call. A few additional runs also reveal the gmtime() mutex as the earlier reports show: (gdb) bt #0 0x401c10a4 in __pthread_sigsuspend () from /lib/i686/libpthread.so.0 #1 0x401c0a58 in __pthread_wait_for_restart_signal () from /lib/i686/libpthread.so.0 #2 0x401c2600 in __pthread_alt_lock () from /lib/i686/libpthread.so.0 #3 0x401bf2e7 in pthread_mutex_lock () from /lib/i686/libpthread.so.0 #4 0x402a0c05 in __tz_convert () from /lib/i686/libc.so.6 #5 0x4029ed5e in gmtime_r () from /lib/i686/libc.so.6 #6 0x40136f47 in explode_time (xt=0xbfffeb70, t=1108654539401728, offset=0, use_localtime=0) at time.c:91 #7 0x40136f82 in apr_time_exp_tz (result=0xbfffeb70, input=4619712010928521212, offs=0) at time.c:114 #8 0x40136fd3 in apr_time_exp_gmt (result=0xfffffffc, input=4619712010928521212) at time.c:122 #9 0x080947d4 in cached_explode (xt=0xbfffeb70, t=1108654262423791, cache=0xfffffffc, use_gmt=1) at util_time.c:117 #10 0x08094891 in ap_explode_recent_gmt (tm=0xfffffffc, t=4619712010928521212) at util_time.c:143 #11 0x08094a95 in ap_recent_rfc822_date (date_str=0x81a7018 "", t=4619712010928521212) at util_time.c:200 #12 0x0806c1a0 in basic_http_header (r=0x81a5618, bb=0x81a6ff8, protocol=0xfffffffc <Address 0xfffffffc out of bounds>) at http_protocol.c:1248 #13 0x0806ca90 in ap_http_header_filter (f=0x81a6298, b=0x81a6f78) at http_protocol.c:1642 #14 0x080978b1 in ap_pass_brigade (next=0x401c8398, bb=0x8) at util_filter.c:512 #15 0x08099fef in ap_content_length_filter (f=0x81a6280, b=0x81a6f78) at protocol.c:1232 #16 0x080978b1 in ap_pass_brigade (next=0x401c8398, bb=0x8) at util_filter.c:512 #17 0x0806e6b5 in ap_byterange_filter (f=0x81a6268, bb=0x81a6f78) at http_protocol.c:3031 #18 0x080978b1 in ap_pass_brigade (next=0x401c8398, bb=0x8) at util_filter.c:512 #19 0x080978b1 in ap_pass_brigade (next=0x401c8398, bb=0x8) at util_filter.c:512 #20 0x40463a19 in php_handler (r=0x81a5618) at /home/r1ch/php4-STABLE-200502171330/sapi/apache2handler/sapi_apache2.c:572 #21 0x08089d35 in ap_run_handler (r=0x81a5618) at config.c:152 #22 0x0808a340 in ap_invoke_handler (r=0x81a5618) at config.c:364 #23 0x0806eefa in ap_process_request (r=0x81a5618) at http_request.c:249 #24 0x0806a38d in ap_process_http_connection (c=0x819f418) at http_core.c:251 #25 0x08094ec5 in ap_run_process_connection (c=0x819f418) at connection.c:43 #26 0x08088334 in child_main (child_num_arg=-4) at prefork.c:610 #27 0x08088487 in make_child (s=0x401c8398, slot=5) at prefork.c:704 #28 0x08088719 in perform_idle_server_maintenance (p=0x80cb818) at prefork.c:839 #29 0x08088e05 in ap_mpm_run (_pconf=0x0, plog=0x81038f8, s=0x3bc) at prefork.c:1040 #30 0x0808f36d in main (argc=3, argv=0xbffff284) at main.c:618 Please let me know if you need any additional information. ------------------------------------------------------------------------ [2005-02-17 13:44:27] [EMAIL PROTECTED] Please try using this CVS snapshot: http://snaps.php.net/php4-STABLE-latest.tar.gz For Windows: http://snaps.php.net/win32/php4-win32-STABLE-latest.zip ------------------------------------------------------------------------ [2005-02-07 11:01:26] phpbug2 at mailinator dot com Reproduced on PHP 4.3.10 with Apache 2 prefork on 2.4.21-4.0.1.ELsmp #1. Updated summary with clearer description of the problem and I believe this applies to the Zend Engine rather than the Scripting Engine. ------------------------------------------------------------------------ [2005-02-03 12:10:41] phpbug2 at mailinator dot com I believe this is the buggy code. It is setting a signal handler for SIGPROF that immediately dumps a timeout error message when the signal is received. However if the signal is delivered whilst PHP is processing a libc call to time(), a pthread mutex within libc is not released, causing a deadlock when Apache tries to call time() for the output. A fix would be to have PHP set some flag such as "processing time exceeded" for the request and to then abort the request at the next available opporunity from within PHP instead of jumping out and leaving libc in a potentially unstable or dangerous state. Obviously this reduces the effectiveness of the maximum execution timeout as a blocking libc call could cause the timeout to be greatly exceeded, but I see no other safe way of handling this without leaving libc in a potentially dangerous state. Perhaps two signals could be used, the first one to break execution if possible at the next available opportunity and then the current "hard" break if no response within 15 seconds or something. ZEND_API void zend_timeout(int dummy) { TSRMLS_FETCH(); if (zend_on_timeout) { zend_on_timeout(EG(timeout_seconds) TSRMLS_CC); } zend_error(E_ERROR, "Maximum execution time of %d second%s exceeded", EG(timeout_seconds), EG(timeout_seconds) == 1 ? "" : "s"); } ... t_r.it_value.tv_sec = seconds; t_r.it_value.tv_usec = t_r.it_interval.tv_sec = t_r.it_interval.tv_usec = 0; setitimer(ITIMER_PROF, &t_r, NULL); signal(SIGPROF, zend_timeout); sigemptyset(&sigset); sigaddset(&sigset, SIGPROF); sigprocmask(SIG_UNBLOCK, &sigset, NULL); } ------------------------------------------------------------------------ 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
