[php-src] Issue #12814: `max_execution_time` reached too early

From: Date: Tue, 28 Nov 2023 13:56:30 +0000
Subject: [php-src] Issue #12814: `max_execution_time` reached too early
Groups: php.bugs 
Request: Send a blank email to php-bugs+get-245918@lists.php.net to get a copy of this message
Issue: https://github.com/php/php-src/issues/12814 Author: Muffinman ### Description Hi, I'm looking for some guidance in tracking down a very strange error with max_execution_time setting not being honoured correctly. We have an incoming JSON POST request to a Laravel backend, which does some processing and stores some data. The request is a few KB of tree data, and the controller calls a rebuildTree() method as below. Internally this makes a lot of calls to the MySQL DB and Redis DB. ```php Category::scoped(['site_key' => config('cms_scope')]) ->rebuildTree($request->data); ``` The problem I'm facing is that this fails every time after **1 second** with this error: ``` Maximum execution time of 30 seconds exceeded ``` I have added some debugging to the exception handler to try to work out why it is doing this: ```php var_dump(time() - $_SERVER['REQUEST_TIME']); var_dump(getrusage()); var_dump(ini_get('max_execution_time')); var_dump(error_get_last()); ``` ``` int(1) // Request had only been processing for ~1s before exception happened array(17) { ["ru_oublock"]=> int(0) ["ru_inblock"]=> int(0) ["ru_msgsnd"]=> int(43432) ["ru_msgrcv"]=> int(51349) ["ru_maxrss"]=> int(71073792) ["ru_ixrss"]=> int(0) ["ru_idrss"]=> int(0) ["ru_minflt"]=> int(17193) ["ru_majflt"]=> int(17) ["ru_nsignals"]=> int(15) ["ru_nvcsw"]=> int(7368) ["ru_nivcsw"]=> int(104279) ["ru_nswap"]=> int(0) ["ru_utime.tv_usec"]=> int(212295) ["ru_utime.tv_sec"]=> int(8) ["ru_stime.tv_usec"]=> int(564183) ["ru_stime.tv_sec"]=> int(1) } string(2) "30" array(4) { ["type"]=> int(1) ["message"]=> string(45) "Maximum execution time of 30 seconds exceeded" ["file"]=> string(112) "/path/to/site/vendor/laravel/framework/src/Illuminate/Redis/Connections/PhpRedisConnection.php" ["line"]=> int(405) } ``` Now for the next strange part, if I set the max_execution_time to some other far larger value, it works! ```php // set_time_limit(30); // Didn't work, same error // set_time_limit(60); // Didn't work, same error // set_time_limit(120); // Didn't work, same error set_time_limit(300); // Works. Request completed in around 3.5s! Category::scoped(['site_key' => config('cms_scope')]) ->rebuildTree($request->data); ``` ![Screenshot 2023-11-28 at 13 41 38](https://github.com/php/php-src/assets/1319568/2357b064-dfd8-4edb-8955-e6636f16be1e) ### PHP Version PHP 8.2.7 ### Operating System MacOS 14.1.1

« previous php.bugs (#245918) next »