php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #81510 Zend/tests/bug74093.phpt does not always trigger hard_timeout
Submitted: 2021-10-07 05:56 UTC Modified: 2021-10-30 17:30 UTC
From: ryan at arctype dot co Assigned:
Status: Closed Package: Testing related
PHP Version: master-Git-2021-10-07 (Git) OS: GNU Guix (Linux 5.14.3)
Private report: No CVE-ID: None
 [2021-10-07 05:56 UTC] ryan at arctype dot co
Description:
------------
On my machine (CPU: AMD Ryzen 5900X), this test case consistently fails. The test tries to induce a hard_timeout, but it does not get triggered and php exits normally under a max_execution_timeout.

I can get this test case to PASS by running other CPU intensive jobs (for example, by compiling gcc) concurrently, which slows down the timing enough to trigger the hard_timeout.

Naive attempts to fix the test program at Zend/tests/bug74093.phpt by increasing the range() sizes passed into array_intersect() did not yield any success.

Output pasted below:


$ ./sapi/cli/php run-tests.php -v Zend/tests/bug74093.phpt
=====================================================================
PHP         : /home/sundbry/projects/php-src/sapi/cli/php
PHP_SAPI    : cli
PHP_VERSION : 8.2.0-dev
ZEND_VERSION: 4.2.0-dev
PHP_OS      : Linux - Linux bb11 5.14.3 #1 SMP 1 x86_64
INI actual  : /home/sundbry/projects/php-src
More .INIs  :
---------------------------------------------------------------------
PHP         : /home/sundbry/projects/php-src/sapi/cgi/php-cgi
PHP_SAPI    : cgi-fcgi
PHP_VERSION : 8.2.0-dev
ZEND_VERSION: 4.2.0-dev
PHP_OS      : Linux - Linux bb11 5.14.3 #1 SMP 1 x86_64
INI actual  : /home/sundbry/projects/php-src
More .INIs  :
---------------------------------------------------------------------
---------------------------------------------------------------------
PHP         : /home/sundbry/projects/php-src/sapi/phpdbg/phpdbg
PHP_SAPI    : phpdbg
PHP_VERSION : 8.2.0-dev
ZEND_VERSION: 4.2.0-dev
PHP_OS      : Linux - Linux bb11 5.14.3 #1 SMP 1 x86_64
INI actual  : /home/sundbry/projects/php-src
More .INIs  :
---------------------------------------------------------------------
CWD         : /home/sundbry/projects/php-src
Extra dirs  :
VALGRIND    : Not used
=====================================================================
Running selected tests.

=================
TEST /home/sundbry/projects/php-src/Zend/tests/bug74093.phpt
TEST 1/1 [Zend/tests/bug74093.phpt]
CONTENT_LENGTH  =
CONTENT_TYPE    =
PATH_TRANSLATED = /home/sundbry/projects/php-src/Zend/tests/bug74093.php
QUERY_STRING    =
REDIRECT_STATUS = 1
REQUEST_METHOD  = GET
SCRIPT_FILENAME = /home/sundbry/projects/php-src/Zend/tests/bug74093.php
HTTP_COOKIE     =
COMMAND /home/sundbry/projects/php-src/sapi/cli/php    -d "output_handler=" -d "open_basedir=" -d "disable_functions=" -d "output_buffering=Off" -d "error_reporting=32767" -d "display_errors=1" -d "display_startup_errors=1" -d "log_errors=0" -d "html_errors=0" -d "track_errors=0" -d "report_memleaks=1" -d "report_zend_debug=0" -d "docref_root=" -d "docref_ext=.html" -d "error_prepend_string=" -d "error_append_string=" -d "auto_prepend_file=" -d "auto_append_file=" -d "ignore_repeated_errors=0" -d "precision=14" -d "serialize_precision=-1" -d "memory_limit=1G" -d "opcache.fast_shutdown=0" -d "opcache.file_update_protection=0" -d "opcache.revalidate_freq=0" -d "opcache.jit_hot_loop=1" -d "opcache.jit_hot_func=1" -d "opcache.jit_hot_return=1" -d "opcache.jit_hot_side_exit=1" -d "zend.assertions=1" -d "zend.exception_ignore_args=0" -d "zend.exception_string_param_max_len=15" -d "short_open_tag=0" -d "session.auto_start=0" -d "max_execution_time=1" -d "hard_timeout=1" -f "/home/sundbry/projects/php-src/Zend/tests/bug74093.php"  2>&1
FAIL Bug #74093 (Maximum execution time of n+2 seconds exceed not written in error_log) [Zend/tests/bug74093.phpt]
=====================================================================
Number of tests :    1                 1
Tests skipped   :    0 (  0.0%) --------
Tests warned    :    0 (  0.0%) (  0.0%)
Tests failed    :    1 (100.0%) (100.0%)
Tests passed    :    0 (  0.0%) (  0.0%)
---------------------------------------------------------------------
Time taken      :    2 seconds
=====================================================================

=====================================================================
FAILED TEST SUMMARY
---------------------------------------------------------------------
Bug #74093 (Maximum execution time of n+2 seconds exceed not written in error_log) [Zend/tests/bug74093.phpt]
=====================================================================


$ sapi/cli/php    -d "output_handler=" -d "open_basedir=" -d "disable_functions=" -d "output_buffering=Off" -d "error_reporting=32767" -d "display_errors=1" -d "display_startup_errors=1" -d "log_errors=0" -d "html_errors=0" -d "track_errors=0" -d "report_memleaks=1" -d "report_zend_debug=0" -d "docref_root=" -d "docref_ext=.html" -d "error_prepend_string=" -d "error_append_string=" -d "auto_prepend_file=" -d "auto_append_file=" -d "ignore_repeated_errors=0" -d "precision=14" -d "serialize_precision=-1" -d "memory_limit=1G" -d "opcache.fast_shutdown=0" -d "opcache.file_update_protection=0" -d "opcache.revalidate_freq=0" -d "opcache.jit_hot_loop=1" -d "opcache.jit_hot_func=1" -d "opcache.jit_hot_return=1" -d "opcache.jit_hot_side_exit=1" -d "zend.assertions=1" -d "zend.exception_ignore_args=0" -d "zend.exception_string_param_max_len=15" -d "short_open_tag=0" -d "session.auto_start=0" -d "max_execution_time=1" -d "hard_timeout=1" -f "Zend/tests/bug74093.php"

Fatal error: Maximum execution time of 1 second exceeded in /home/sundbry/projects/php-src/Zend/tests/bug74093.php on line 6

Test script:
---------------
./sapi/cli/php run-tests.php -v Zend/tests/bug74093.phpt

Expected result:
----------------
Expected result: hard_timeout kills php and the error message matches the expected output in the test case.

Actual result:
--------------
hard_timeout is not induced, and the test case fails.

Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2021-10-07 07:53 UTC] nikic@php.net
If you run "time sapi/cli/php -d memory_limit=-1 Zend/tests/bug74093.phpt", how much execution time do you see? For me it's at 2.2s, so close to the edge (I'm on 5950X).

If I double the ranges...

$a1 = range(1, 2000000);
$a2 = range(100000, 2999999);
array_intersect($a1, $a2);

... then I get a runtime of 4s. So I think increasing the range bounds enough should help make this test more reliable.

I couldn't come up with a function that would actually loop infinitely -- "unfortunately" InfiniteIterator is still subject to normal timeout, it does not require hard_timeout.
 [2021-10-09 05:37 UTC] ryan at arctype dot co
Hi Niki, it looks like just enlarging the ranges does in fact fix it. See below:



$ time sapi/cli/php -d memory_limit=-1 Zend/tests/bug74093.phpt
--TEST--
Bug #74093 (Maximum execution time of n+2 seconds exceed not written in error_log)
--SKIPIF--
--INI--
memory_limit=1G
max_execution_time=1
hard_timeout=1
--FILE--
--EXPECTF--
Fatal error: Maximum execution time of 1+1 seconds exceeded %s

real	0m1.864s
user	0m1.840s
sys	0m0.024s

$ git diff
diff --git a/Zend/tests/bug74093.phpt b/Zend/tests/bug74093.phpt
index 7f20285805..c5fc9da8cb 100644
--- a/Zend/tests/bug74093.phpt
+++ b/Zend/tests/bug74093.phpt
@@ -12,8 +12,8 @@ max_execution_time=1
 hard_timeout=1
 --FILE--
 <?php
-$a1 = range(1, 1000000);
-$a2 = range(100000, 1999999);
+$a1 = range(1, 2000000);
+$a2 = range(100000, 2999999);
 array_intersect($a1, $a2);
 ?>
 --EXPECTF--


$ time sapi/cli/php -d memory_limit=-1 Zend/tests/bug74093.phpt
--TEST--
Bug #74093 (Maximum execution time of n+2 seconds exceed not written in error_log)
--SKIPIF--
--INI--
memory_limit=1G
max_execution_time=1
hard_timeout=1
--FILE--
--EXPECTF--
Fatal error: Maximum execution time of 1+1 seconds exceeded %s

real	0m3.075s
user	0m3.047s
sys	0m0.028s

# With limits enabled now, it looks fixed (this is repeatable)
$ time sapi/cli/php -d memory_limit=-1 -d "max_execution_time=1" -d "hard_timeout=1" Zend/tests/bug74093.phpt
--TEST--
Bug #74093 (Maximum execution time of n+2 seconds exceed not written in error_log)
--SKIPIF--
--INI--
memory_limit=1G
max_execution_time=1
hard_timeout=1
--FILE--

Fatal error: Maximum execution time of 1+1 seconds exceeded (terminated) in /home/sundbry/projects/php-src/Zend/tests/bug74093.phpt on line 17

real	0m2.011s
user	0m1.983s
sys	0m0.028s
 [2021-10-14 03:58 UTC] hao dot sun at arm dot com
FYI

I encountered this failure on Mac Mini(macOS on Apple silicon), and the fix you mentioned previously did work for me as well.
 [2021-10-25 09:48 UTC] hao dot sun at arm dot com
This bug is fixed by nikic in https://github.com/php/php-src/commit/6974372f.
 [2021-10-30 17:30 UTC] ryan at arctype dot co
-Status: Open +Status: Closed
 [2021-10-30 17:30 UTC] ryan at arctype dot co
Fixed in 6974372fbbea4279e1e4f5c24425581208f5553
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved.
Last updated: Fri Mar 29 10:01:28 2024 UTC