Bug #66255 [NEW]: PHP script exceeding max. allowed script exec. time

From: Date: Tue, 10 Dec 2013 15:03:21 +0000
Subject: Bug #66255 [NEW]: PHP script exceeding max. allowed script exec. time
Groups: php.bugs 
Request: Send a blank email to php-bugs+get-183226@lists.php.net to get a copy of this message
From: jfartak at wms dot cz Operating system: OpenSuSE 12.3 64bit PHP version: 5.4.22 Package: Scripting Engine problem Bug Type: Bug Bug description:PHP script exceeding max. allowed script exec. time Description: ------------ PHP Version 5.4.22 Apache details: -------- Server version: Apache/2.2.25 (Unix) Server built: Aug 9 2013 14:53:05 Server's Module Magic Number: 20051115:33 Server loaded: APR 1.4.6, APR-Util 1.4.1 Compiled using: APR 1.4.6, APR-Util 1.4.1 Architecture: 64-bit Server MPM: Worker threaded: yes (fixed thread count) forked: yes (variable process count) Server compiled with.... -D APACHE_MPM_DIR="server/mpm/worker" -D APR_HAS_SENDFILE -D APR_HAS_MMAP -D APR_HAVE_IPV6 (IPv4-mapped addresses enabled) -D APR_USE_PROC_PTHREAD_SERIALIZE -D APR_USE_PTHREAD_SERIALIZE -D SINGLE_LISTEN_UNSERIALIZED_ACCEPT -D APR_HAS_OTHER_CHILD -D AP_HAVE_RELIABLE_PIPED_LOGS -D DYNAMIC_MODULE_LIMIT=128 -D HTTPD_ROOT="/usr" -D SUEXEC_BIN="/usr/bin/suexec" -D DEFAULT_SCOREBOARD="logs/apache_runtime_status" -D DEFAULT_ERRORLOG="logs/error_log" -D AP_TYPES_CONFIG_FILE="/etc/httpd/mime.types" -D SERVER_CONFIG_FILE="/etc/httpd/httpd.conf" PHP configure line: #! /bin/sh # # Created by configure CFLAGS='-O2 -march=core2 -g2' \ CC='gcc' \ './configure' \ '--libdir=/usr/lib64' \ '--with-libdir=lib64' \ '--prefix=/usr' \ '--mandir=/usr/share/man' \ '--infodir=/usr/share/info' \ '--sysconfdir=/etc/httpd' \ '--with-apxs2' \ '--disable-cgi' \ '--with-config-file-path=/etc/httpd' \ '--with-config-file-scan-dir=/etc/httpd' \ '--enable-sigchild' \ '--disable-short-tags' \ '--with-openssl' \ '--with-zlib' \ '--enable-ftp' \ '--enable-bcmath' \ '--enable-calendar' \ '--enable-dbase' \ '--enable-dbx' \ '--enable-dio' \ '--enable-exif' \ '--enable-filepro' \ '--with-gd' \ '--with-jpeg-dir=/usr/lib' \ '--with-zlib-dir=/usr/lib' \ '--with-imap=/usr/include/imap' \ '--with-imap-ssl=/usr/include/openssl' \ '--with-interbase=/opt/firebird' \ '--enable-shmop' \ '--enable-sysvsem' \ '--enable-sysvshm' \ '--enable-sockets' \ '--enable-wddx' \ '--enable-mbstring' \ '--with-mysql=/usr/local/mysql' \ '--enable-zend-multibyte' \ '--with-iconv' \ '--with-mhash' \ '--with-zip' \ '--with-libxml-dir=/usr/lib' \ '--with-pdo-firebird=/opt/firebird' \ '--with-pdo-mysql=mysqlnd' \ '--with-mysqli=mysqlnd' \ '--with-zip=/usr/lib' \ '--enable-zip' \ '--with-freetype-dir=/usr/lib' \ '--with-curl' \ '--with-snmp' \ '--with-mcrypt' \ '--with-mysql-sock=/var/lib/mysql/mysql.sock' \ '--enable-soap' \ '--with-xsl' \ '--with-pspell' \ '--with-magickwand' \ '--with-ldap' \ "$@" Joomla version: 1.5.17 Backtrace (replaced real domain with <domain> string): #0 0x00007fcda9fcc31d in _int_free () from /lib64/libc.so.6 #1 0x00007fcda35cdc29 in php_error_cb (type=2, error_filename= 0x7fcd2c6f83f8 "/data/home/httpd/html/wwwroot/<domain>/libraries/tcpdf/tcpdf.php", error_lineno=3915, format=<optimized out>, args=<optimized out>) at /tmp/packages/php-5.4.22/main/main.c:980 #2 0x00007fcda34b6030 in soap_error_handler (error_num=2, error_filename= 0x7fcd2c6f83f8 "/data/home/httpd/html/wwwroot/<domain>/libraries/tcpdf/tcpdf.php", error_lineno=3915, format=0x7fcda3ba7de8 "%s%s%s() expects parameter %d to be %s, %s given", args=0x7fcd767c9400) at /tmp/packages/php-5.4.22/ext/soap/soap.c:2201 #3 0x00007fcda363cce4 in zend_error (type=type@entry=2, format=format@entry= 0x7fcda3ba7de8 "%s%s%s() expects parameter %d to be %s, %s given") at /tmp/packages/php-5.4.22/Zend/zend.c:1120 #4 0x00007fcda36460d9 in zend_parse_arg (tsrm_ls=0x7fcd2c001560, quiet=0, spec=<synthetic pointer>, va= 0x7fcd767c9608, arg=<optimized out>, arg_num=1) at /tmp/packages/php-5.4.22/Zend/zend_API.c:686 #5 zend_parse_va_args (num_args=1, num_args@entry=2, type_spec=0x7fcda3b81e98 "rl", va=va@entry= 0x7fcd767c9608, flags=flags@entry=0, tsrm_ls=tsrm_ls@entry=0x7fcd2c001560) at /tmp/packages/php-5.4.22/Zend/zend_API.c:844 #6 0x00007fcda36475d9 in zend_parse_parameters (num_args=2, tsrm_ls=tsrm_ls@entry=0x7fcd2c001560, type_spec=type_spec@entry=0x7fcda3b81e98 "rl") at /tmp/packages/php-5.4.22/Zend/zend_API.c:895 #7 0x00007fcda3536b54 in zif_fread (ht=<optimized out>, return_value=0x7fcd2cec34d8, return_value_ptr=<optimized out>, this_ptr=<optimized out>, return_value_used=<optimized out>, tsrm_ls= 0x7fcd2c001560) at /tmp/packages/php-5.4.22/ext/standard/file.c:1739 #8 0x00007fcda36f638c in zend_do_fcall_common_helper_SPEC (execute_data=<optimized out>, tsrm_ls= 0x7fcd2c001560) at /tmp/packages/php-5.4.22/Zend/zend_vm_execute.h:643 #9 0x00007fcda36a7bae in execute (op_array=0x7fcd2c8e6e68, tsrm_ls=0x7fcd2c001560) at /tmp/packages/php-5.4.22/Zend/zend_vm_execute.h:410 #10 0x00007fcda363dec0 in zend_execute_scripts (type=type@entry=8, tsrm_ls=0x7fcd2c001560, tsrm_ls@entry= 0x7fcd2cbda390, retval=retval@entry=0x0, file_count=file_count@entry=3) at /tmp/packages/php-5.4.22/Zend/zend.c:1319 #11 0x00007fcda35d1676 in php_execute_script (primary_file=primary_file@entry=0x7fcd767cbc10, tsrm_ls= 0x7fcd2c001560, tsrm_ls@entry=0x7fcd2cbdab10) at /tmp/packages/php-5.4.22/main/main.c:2502 #12 0x00007fcda36f9012 in php_handler (r=0x7fcd71d750a0) at /tmp/packages/php-5.4.22/sapi/apache2handler/sapi_apache2.c:667 #13 0x000000000043c03f in ap_run_handler () #14 0x000000000043c371 in ap_invoke_handler () #15 0x0000000000447a8f in ap_process_request () #16 0x0000000000445065 in ap_process_http_connection () #17 0x0000000000441d9d in ap_run_process_connection () #18 0x000000000044d116 in worker_thread () #19 0x00007fcdaa509e0f in start_thread () from /lib64/libpthread.so.0 #20 0x00007fcdaa0397dd in clone () from /lib64/libc.so.6 IMHO backtrace should "points" to Joomla's php script /libraries/tcpdf/tcpdf.php, function /** * Get a JPEG filename and return a structure for the PDF creator. * @param string $filename JPEG file name. * @return array structure containing the image data * @access protected */ function outputjpg($filename) { $a=getimagesize($filename); if(!isset($a['channels']) or $a['channels']==3) { $colspace='DeviceRGB'; } elseif($a['channels']==4) { $colspace='DeviceCMYK'; } else { $colspace='DeviceGray'; } $bpc=isset($a['bits']) ? $a['bits'] : 8; //Read whole file $f=fopen($filename,'rb'); $data=''; --- Begin of Loop --- while(!feof($f)) { $data.=fread($f,4096); } --- End of loop --- fclose($f); return array('w'=>$a[0],'h'=>$a[1],'cs'=>$colspace,'bpc'=>$bpc,'f'=>'DCTDecode','data'=>$data); } Full problem description: When issuing HTTP GET request on Joomla's site in form http://<domain>/index.php/en/lds?format=pdf Apache's thread (used MPM Worker) never terminates, i.e. loops forever albeit max_execution_time (= 60 sec) specified in the main php.ini and not overridden elsewhere. The looping thread eats a lot of CPU and put stress on the server. I did some debugging and found, that following loop never finish: --- Begin of Loop --- while(!feof($f)) { $data.=fread($f,4096); } --- End of loop --- I'm reporting this problem, because I thought, that even while's condition (feof())would never be false, then PHP script should terminate (not gracefully) at least when max_execution_time is reached. But this does not happen. Thread runs for hours if not killed manually. So, this GET Request can cause "DoS" on the server if issued more times. I had had one "cycle" stepped in gdb and it looks, that PHP wants to log some errors (php_error_cb etc.), however, nothing was being logged in Apache error_log (strange, other errors are being normally logged) I know, that Joomla's version is old (and customer was encouraged to upgrade it), but I think that this does not mean, that it could cause PHP VM to loop forever and get server to its knees. I considered this as PHP Core bug. I don't know how PHP VM checks running scripts not to exceed max allowed execution time (cooperative manner, designed "watchdog" thread, etc.), but script is able to bypass it. I checked for any ini_set and set_time_limit functions in Joomla installation that could have impact on this, but none found. Furthermore, the never ending "loop" pattern exceeding allowed max. script execution limit couldn't not be Joomla's specific, but general problem. I can upload one "loop" stepped in gdb as well as core of the process, if needed. Test script: --------------- Issue HTTP GET request from browser to get Joomla's article in PDF format: http://<domain>/index.php/en/lds?format=pdf Expected result: ---------------- Apache thread running PHP handler should terminate when max_execution_time reached. Actual result: -------------- Backtrace (replaced real domain with <domain> string): #0 0x00007fcda9fcc31d in _int_free () from /lib64/libc.so.6 #1 0x00007fcda35cdc29 in php_error_cb (type=2, error_filename= 0x7fcd2c6f83f8 "/data/home/httpd/html/wwwroot/<domain>/libraries/tcpdf/tcpdf.php", error_lineno=3915, format=<optimized out>, args=<optimized out>) at /tmp/packages/php-5.4.22/main/main.c:980 #2 0x00007fcda34b6030 in soap_error_handler (error_num=2, error_filename= 0x7fcd2c6f83f8 "/data/home/httpd/html/wwwroot/<domain>/libraries/tcpdf/tcpdf.php", error_lineno=3915, format=0x7fcda3ba7de8 "%s%s%s() expects parameter %d to be %s, %s given", args=0x7fcd767c9400) at /tmp/packages/php-5.4.22/ext/soap/soap.c:2201 #3 0x00007fcda363cce4 in zend_error (type=type@entry=2, format=format@entry= 0x7fcda3ba7de8 "%s%s%s() expects parameter %d to be %s, %s given") at /tmp/packages/php-5.4.22/Zend/zend.c:1120 #4 0x00007fcda36460d9 in zend_parse_arg (tsrm_ls=0x7fcd2c001560, quiet=0, spec=<synthetic pointer>, va= 0x7fcd767c9608, arg=<optimized out>, arg_num=1) at /tmp/packages/php-5.4.22/Zend/zend_API.c:686 #5 zend_parse_va_args (num_args=1, num_args@entry=2, type_spec=0x7fcda3b81e98 "rl", va=va@entry= 0x7fcd767c9608, flags=flags@entry=0, tsrm_ls=tsrm_ls@entry=0x7fcd2c001560) at /tmp/packages/php-5.4.22/Zend/zend_API.c:844 #6 0x00007fcda36475d9 in zend_parse_parameters (num_args=2, tsrm_ls=tsrm_ls@entry=0x7fcd2c001560, type_spec=type_spec@entry=0x7fcda3b81e98 "rl") at /tmp/packages/php-5.4.22/Zend/zend_API.c:895 #7 0x00007fcda3536b54 in zif_fread (ht=<optimized out>, return_value=0x7fcd2cec34d8, return_value_ptr=<optimized out>, this_ptr=<optimized out>, return_value_used=<optimized out>, tsrm_ls= 0x7fcd2c001560) at /tmp/packages/php-5.4.22/ext/standard/file.c:1739 #8 0x00007fcda36f638c in zend_do_fcall_common_helper_SPEC (execute_data=<optimized out>, tsrm_ls= 0x7fcd2c001560) at /tmp/packages/php-5.4.22/Zend/zend_vm_execute.h:643 #9 0x00007fcda36a7bae in execute (op_array=0x7fcd2c8e6e68, tsrm_ls=0x7fcd2c001560) at /tmp/packages/php-5.4.22/Zend/zend_vm_execute.h:410 #10 0x00007fcda363dec0 in zend_execute_scripts (type=type@entry=8, tsrm_ls=0x7fcd2c001560, tsrm_ls@entry= 0x7fcd2cbda390, retval=retval@entry=0x0, file_count=file_count@entry=3) at /tmp/packages/php-5.4.22/Zend/zend.c:1319 #11 0x00007fcda35d1676 in php_execute_script (primary_file=primary_file@entry=0x7fcd767cbc10, tsrm_ls= 0x7fcd2c001560, tsrm_ls@entry=0x7fcd2cbdab10) at /tmp/packages/php-5.4.22/main/main.c:2502 #12 0x00007fcda36f9012 in php_handler (r=0x7fcd71d750a0) at /tmp/packages/php-5.4.22/sapi/apache2handler/sapi_apache2.c:667 #13 0x000000000043c03f in ap_run_handler () #14 0x000000000043c371 in ap_invoke_handler () #15 0x0000000000447a8f in ap_process_request () #16 0x0000000000445065 in ap_process_http_connection () #17 0x0000000000441d9d in ap_run_process_connection () #18 0x000000000044d116 in worker_thread () #19 0x00007fcdaa509e0f in start_thread () from /lib64/libpthread.so.0 #20 0x00007fcdaa0397dd in clone () from /lib64/libc.so.6 IMHO backtrace should "points" to Joomla's php script /libraries/tcpdf/tcpdf.php, function -- Edit bug report at https://bugs.php.net/bug.php?id=66255&edit=1 -- Try a snapshot (PHP 5.4): https://bugs.php.net/fix.php?id=66255&r=trysnapshot54 Try a snapshot (PHP 5.5): https://bugs.php.net/fix.php?id=66255&r=trysnapshot55 Try a snapshot (trunk): https://bugs.php.net/fix.php?id=66255&r=trysnapshottrunk Fixed in SVN: https://bugs.php.net/fix.php?id=66255&r=fixed Fixed in release: https://bugs.php.net/fix.php?id=66255&r=alreadyfixed Need backtrace: https://bugs.php.net/fix.php?id=66255&r=needtrace Need Reproduce Script: https://bugs.php.net/fix.php?id=66255&r=needscript Try newer version: https://bugs.php.net/fix.php?id=66255&r=oldversion Not developer issue: https://bugs.php.net/fix.php?id=66255&r=support Expected behavior: https://bugs.php.net/fix.php?id=66255&r=notwrong Not enough info: https://bugs.php.net/fix.php?id=66255&r=notenoughinfo Submitted twice: https://bugs.php.net/fix.php?id=66255&r=submittedtwice register_globals: https://bugs.php.net/fix.php?id=66255&r=globals PHP 4 support discontinued: https://bugs.php.net/fix.php?id=66255&r=php4 Daylight Savings: https://bugs.php.net/fix.php?id=66255&r=dst IIS Stability: https://bugs.php.net/fix.php?id=66255&r=isapi Install GNU Sed: https://bugs.php.net/fix.php?id=66255&r=gnused Floating point limitations: https://bugs.php.net/fix.php?id=66255&r=float No Zend Extensions: https://bugs.php.net/fix.php?id=66255&r=nozend MySQL Configuration Error: https://bugs.php.net/fix.php?id=66255&r=mysqlcfg

« previous php.bugs (#183226) next »