Bug #80728 [Com]: PHP built-in web server resets timeout when it can kill the process

From: Date: Thu, 11 Feb 2021 21:52:12 +0000
Subject: Bug #80728 [Com]: PHP built-in web server resets timeout when it can kill the process
References: 1  Groups: php.bugs 
Request: Send a blank email to php-bugs+get-232077@lists.php.net to get a copy of this message
Edit report at https://bugs.php.net/bug.php?id=80728&edit=1 ID: 80728 Comment by: calvin at cmpct dot info Reported by: calvin at cmpct dot info Summary: PHP built-in web server resets timeout when it can kill the process Status: Open Type: Bug Package: Built-in web server Operating System: Fedora 33 PHP Version: 7.4.15 Block user comment: N Private report: N New Comment: I think the problem is for the max_execution_time handler (OnUpdateTimeout) - that seems to reset it even when there's no script running if it was changed. Diff: ``` diff --git a/main/main.c b/main/main.c index 1cb50ce1dd..eedce27f8f 100644 --- a/main/main.c +++ b/main/main.c @@ -467,6 +467,7 @@ static PHP_INI_MH(OnUpdateTimeout) } zend_unset_timeout(); ZEND_ATOL(EG(timeout_seconds), ZSTR_VAL(new_value)); +fprintf(stderr, " ** Updating timeout to %d ** \n", EG(timeout_seconds)); zend_set_timeout(EG(timeout_seconds), 0); return SUCCESS; } ``` Output: ``` ** Setting real timer for 30.0 seconds ** ** UnSetting real timer ** ** Updating timeout to 45 ** ** Setting real timer for 45.0 seconds ** ** Setting real timer for 2.0 seconds ** [Thu Feb 11 16:23:02 2021] ip.address:40006 [200]: GET / - Maximum execution time of 45 seconds exceeded in /home/calvin/tmp/long/index.php on line 8 ** UnSetting real timer ** ** UnSetting real timer ** ** Updating timeout to 30 ** ** Setting real timer for 30.0 seconds ** [Thu Feb 11 16:23:02 2021] ip.address:40006 Closing [Thu Feb 11 16:23:04 2021] ip.address:40022 Accepted ** Setting real timer for 30.0 seconds ** ** Setting real timer for 2.0 seconds ** [Thu Feb 11 16:23:34 2021] ip.address:40022 [200]: GET /index2.php - Maximum execution time of 30 seconds exceeded in /home/calvin/tmp/long/index2.php on line 8 ** UnSetting real timer ** [Thu Feb 11 16:23:34 2021] ip.address:40022 Closing ``` Previous Comments: ------------------------------------------------------------------------ [2021-02-11 15:44:52] calvin at cmpct dot info FWIW, this also affects CGI. I also only believe this happens if set_time_limit is used; if it isn't, the timer seems to be unset without being set again. For example, index.php and index2.php are identical, except for the set_time_limit in index.php: ** Setting real timer for 30.0 seconds ** ** UnSetting real timer ** ** Setting real timer for 180.0 seconds ** ** Setting real timer for 2.0 seconds ** [Thu Feb 11 10:32:42 2021] ip.address:57946 [200]: GET / - Maximum execution time of 180 seconds exceeded in /home/calvin/tmp/long/index.php on line 8 ** UnSetting real timer ** ** UnSetting real timer ** ** Setting real timer for 30.0 seconds ** [Thu Feb 11 10:32:42 2021] ip.address:57946 Closing [Thu Feb 11 10:32:46 2021] ip.address:58018 Accepted ** Setting real timer for 30.0 seconds ** ** Setting real timer for 2.0 seconds ** [Thu Feb 11 10:33:17 2021] ip.address:58018 [200]: GET /index2.php - Maximum execution time of 30 seconds exceeded in /home/calvin/tmp/long/index2.php on line 8 ** UnSetting real timer ** [Thu Feb 11 10:33:17 2021] ip.address:58018 Closing [Thu Feb 11 10:35:09 2021] ip.address:58092 Accepted ** Setting real timer for 30.0 seconds ** ** Setting real timer for 2.0 seconds ** [Thu Feb 11 10:35:39 2021] ip.address:58092 [200]: GET /index2.php - Maximum execution time of 30 seconds exceeded in /home/calvin/tmp/long/index2.php on line 8 ** UnSetting real timer ** [Thu Feb 11 10:35:39 2021] ip.address:58092 Closing [Thu Feb 11 10:36:50 2021] ip.address:58134 Accepted ** Setting real timer for 30.0 seconds ** ** UnSetting real timer ** ** Setting real timer for 180.0 seconds ** ** Setting real timer for 2.0 seconds ** [Thu Feb 11 10:39:50 2021] ip.address:58134 [200]: GET / - Maximum execution time of 180 seconds exceeded in /home/calvin/tmp/long/index.php on line 8 ** UnSetting real timer ** ** UnSetting real timer ** ** Setting real timer for 30.0 seconds ** [Thu Feb 11 10:39:50 2021] ip.address:58134 Closing [Thu Feb 11 10:40:01 2021] ip.address:58218 Accepted ** Setting real timer for 30.0 seconds ** ** Setting real timer for 2.0 seconds ** [Thu Feb 11 10:40:32 2021] ip.address:58218 [200]: GET /index2.php - Maximum execution time of 30 seconds exceeded in /home/calvin/tmp/long/index2.php on line 8 ** UnSetting real timer ** [Thu Feb 11 10:40:32 2021] ip.address:58218 Closing ------------------------------------------------------------------------ [2021-02-10 17:34:41] calvin at cmpct dot info Description: ------------ When the PHP built-in development webserver finishes a request, it resets PHP's timer to defaults. On ITIMER_PROF (most) platforms, this usually isn't a problem because listening causes PHP to block on listen, stopping it from counting in execution time. On ITIMER_REAL platforms (IBM i and Cygwin), the timer will continue to count down and hit the hard timeout, killing an idle PHP development web server. (This may affect other mediums of PHP, but the development web server is the easiest case.) The attached patch will add debug output for handling the ITIMER cases and let you force ITIMER_REAL on Linux. The issue is likely reproducible on 7.3 and 8.0. Test script: --------------- <?php set_time_limit(10); // recommend setting to a large value to diagnose ITIMER_REAL $i = 0; while(true) { sleep(1); // comment if using ITIMER_PROF because it won't count echo "$i<br/>\n"; $i++; ob_flush(); flush(); } Expected result: ---------------- $ (cd ~/src/long/; /tmp/php7.4/bin/php -S 0.0.0.0:8080; date) [Wed Feb 10 13:19:30 2021] PHP 7.4.15RC1 Development Server (http://0.0.0.0:8080) started [Wed Feb 10 13:19:30 2021] 127.0.0.1:45308 Accepted ** Setting prof timer for 30.0 seconds ** ** UnSetting prof timer ** ** Setting prof timer for 10.0 seconds ** ** Setting prof timer for 2.0 seconds ** [Wed Feb 10 13:19:41 2021] 127.0.0.1:45308 [200]: GET / - Maximum execution time of 10 seconds exceeded in /home/calvin/src/long/index.php on line 11 ** UnSetting prof timer ** ** UnSetting prof timer ** ** Setting prof timer for 30.0 seconds ** [Wed Feb 10 13:19:41 2021] 127.0.0.1:45308 Closing Actual result: -------------- $ (cd ~/src/long/; /tmp/php7.4/bin/php -S 0.0.0.0:8080; date) [Wed Feb 10 13:13:34 2021] PHP 7.4.15RC1 Development Server (http://0.0.0.0:8080) started [Wed Feb 10 13:13:38 2021] 127.0.0.1:45126 Accepted ** Setting real timer for 30.0 seconds ** ** UnSetting real timer ** ** Setting real timer for 10.0 seconds ** ** Setting real timer for 2.0 seconds ** [Wed Feb 10 13:13:48 2021] 127.0.0.1:45126 [200]: GET / - Maximum execution time of 10 seconds exceeded in /home/calvin/src/long/index.php on line 8 ** UnSetting real timer ** ** UnSetting real timer ** ** Setting real timer for 30.0 seconds ** [Wed Feb 10 13:13:48 2021] 127.0.0.1:45126 Closing [Wed Feb 10 13:13:48 2021] 127.0.0.1:45128 Accepted [Wed Feb 10 13:13:48 2021] 127.0.0.1:45128 Closed without sending a request; it was probably just an unused speculative preconnection [Wed Feb 10 13:13:48 2021] 127.0.0.1:45128 Closing ** Setting real timer for 2.0 seconds ** Fatal error: Maximum execution time of 30+2 seconds exceeded (terminated) in Unknown on line 0 Wed 10 Feb 2021 01:14:20 PM AST ------------------------------------------------------------------------ -- Edit this bug report at https://bugs.php.net/bug.php?id=80728&edit=1

« previous php.bugs (#232077) next »