PHP执行时间那点事

说起php的执行时间，相信每一个phper都遇到过这方面的问题，特别是在CGI模式下，一般我们都会通过修改max_execution_time或者在代码开头添加set_time_limit(0)来解决问题，但下面这个场景大家可能也曾经遇到过：
我们先将php.ini的执行时间设置为60S

max_execution_time = 60

再在代码的开头设置执行时间为60S，让两者统一
然后运行sleep让程序模拟运行20S：

set_time_limit(60);
sleep(20);
echo 1;

会发现程序在执行到第16S的时候就报出了502 Bad Gateway

说好的可以执行60S呢？江湖规矩报错先翻看日志，查看php-fpm.log，可以发现有这么一段信息

[06-Dec-2019 12:44:13] WARNING: [pool www] child 19910, script '/home/wwwroot/public/index.php' (request: "GET /index.php") execution timed out (16.120721 sec), terminating
[06-Dec-2019 12:44:13] WARNING: [pool www] child 19910 exited on signal 15 (SIGTERM) after 2573.443300 seconds from start
[06-Dec-2019 12:44:13] NOTICE: [pool www] child 21861 started

这三行日志分别告诉了我们三个信息
1.子进程19910的执行时间超过了16S被终结了
2.子进程19910在启动了2573.44S后被关闭了
3.子进程19910在关闭后的同一秒子进程child 21861被fork出来开始运行

也就是说，PHP-CGI在执行的过程中，除去我们之前已经设置好的两个参数，应该还有另外一个参数限制了这个进程的执行时间，打开php目录下的php-fpm.conf看看有无异常

...
pm.min_spare_servers = 16
pm.max_spare_servers = 60
request_terminate_timeout = 15
request_slowlog_timeout = 0
slowlog = var/log/slow.log
...

可以看到有一个参数request_terminate_timeout = 15 和我们的超时阈值非常接近，翻看注释找到关于这个参数的解释：

; The timeout for serving a single request after which the worker process will
; be killed. This option should be used when the 'max_execution_time' ini option
; does not stop script execution for some reason. A value of '0' means 'off'.

大概的意思是这个参数的设置是当max_execution_time启用时，为了防止php子进程因为某些原因无法停止运行而设置的一个保护措施，当然这个保护措施比较简单粗暴，就是直接kill超时的子进程，然后直接fork一个新的

结合解释，我们就很好理解前面日志中出现的三条信息了：因为执行时间超过了max_execution_time设置的阈值，子进程19910被直接kill了，然后又生成了一个新的子进程21861

于是我们将php-fpm.conf中的request_terminate_timeout改为30，重启php，再次执行之前的代码，不再报502了

看到这里，可能会有小伙伴会说，PHP的执行执行时间影响的参数有点多，真的记不住应该改那个才真正的有效，我们不妨从php运行的架构来梳理一下，不太清楚php运行架构的小伙伴可以看看我之前写的《浅析PHP-FPM、CGI、Fast CGI的关系》

PHP-FPM的程序架构是由一个master进程来进行管理一个PHP-CGI的子进程池，当一个请求由master进程转发到worker时，master进程便会开始计时，当超过设定的执行时间时master进程，便会直接kill掉超时的worker进程（程序的世界也不好混），而我们设置max_execution_time设置的时间是对于workder进程而言的，所以无论单个worker进程的执行时间设置多少，都不得超过fpm中的request_terminate_timeout，否则一律kill

---

文末，再补充两条在翻看手册时翻到的知识点：

在代码中使用set_time_limit()会从零开始重新启动超时计数器

换句话说，如果超时默认是30秒，在脚本运行了了25秒时调用 set_time_limit(20)，那么，脚本在超时之前可运行总时间为45秒。
这个相对简单，就不上测试代码了，大家有空可以验证一下

set_time_limit()函数和配置指令max_execution_time只影响脚本本身执行的时间

其他发生在诸如使用system()的系统调用，流操作，数据库操作等的脚本执行的最大时间不包括其中。也就是说，比如sleep或者file_get_contents等操作消耗的时间是不会计入max_execution_time的超时时间中的

所以其实我前文写的代码即使把sleep设置为999也不会报执行超时的错误
，用代码验证下：

set_time_limit(10);
sleep(20);

可以发现程序确实没有报超时的错误，接着我们再编写一段代码，让php执行非系统调用和数据流等操作的耗时任务

set_time_limit(10); //将计数器清零，允许执行时间为10S
sleep(10);
$json[] = str_repeat("123456789,",10000);   //生成一个内容量较大的数组
$count = 1000000;
//循环执行1000000次数据，json_encode和json_decode在对于长字符串的转化效率不高，所以比较耗时
while ($count--){
    $string = json_encode($json);
    json_decode($string,true);
}

结果如上图，程序一共执行了20S，其中有10S是在sleep也就是系统调用不算入执行超时时间，另外10s执行的是一段cpu密集型的操作，符合算入max_execution_time超时时间的要求，于是符合条件抛出错误

文末总结：有空可以多翻翻手册，每天都有新发现