# 一起線上事故引發的對PHP超時控制的思考 幾周以前我們的一個線上服務nginx請求日志里突然出現大量499、500、502的錯誤，于此同時發現php-fpm的worker進程不斷的退出，新啟動的worker幾乎過幾十秒就死掉了，在php-fpm.log里發現如下錯誤： ``` [28-Dec-2016 23:21:02] WARNING: [pool www] child 6528, script '/home/qinpeng/sofa/site/sofa/htdocs/test.php' (request: "GET /test.php") execution timed out (15.028107 sec), terminating [28-Dec-2016 23:21:02] WARNING: [pool www] child 6528 exited on signal 15 (SIGTERM) after 53.265943 seconds from start [28-Dec-2016 23:21:02] NOTICE: [pool www] child 26594 started ``` 從日志里也可以看出fpm worker進程因為執行超時(超過15s)而被kill掉了。 最終經過排查確定是因為訪問redis沒有設置讀寫超時，后端redis實例掛了導致請求阻塞而引發的故障，事故造成的影響非常嚴重，在故障期間整個服務完全不可用。 事后一直不解為什么超時會導致fpm的退出？php-fpm.conf配置里有個：`request_terminate_timeout`，正是它導致fpm的退出，此配置項的注釋中寫的很清楚：如果一個request的執行時間超過request_terminate_timeout，worker進程將被killed。 此次事故引發我對PHP超時機制的進一步探究，fpm的處理方式太過暴力，那么除了`request_terminate_timeout`還有沒有別的超時控制項可以避免這類問題？下面將根據PHP中幾個涉及超時的配置分析內核是如何處理的。(版本:php-7.0.12) ## 1、PHP的超時配置 ### 1.1 max_input_time 這個配置在php.ini中，含義是PHP解析請求數據的最大耗時，如解析GET、POST參數等，這個參數控制的PHP從解析請求到執行PHP腳本的超時，也就是從php_request_startup()到php_execute_script()之間的耗時。 此配置默認值為60s，cli模式下被強制設為-1，關于這個參數沒有什么可說的，不再展開分析，下面重點分析`max_execution_time`。 ### 1.2 max_execution_time 此配置也在php.ini中，也就是說它是php的配置而不是fpm的，從源碼注釋上看這個配置的含義是：每個PHP腳本的最長執行時間。 默認值為30s，cli模式下為0(即cli下此配置不生效)。 從字面意義上猜測這個配置控制的是整個PHP腳本的最大執行耗時，也就是超過這個值PHP就不再執行了。我們用下面的例子測試下(max_execution_time = 10s)： ``` //test.php <?php sleep(20); echo "hello~"; ?> ``` `max_execution_time`配置的是10s，按照上面的猜測，瀏覽器請求test.php將因為超時不會有任何輸出，并可能返回某個500以上的錯誤，我們來實際操作下（不要用cli執行）： ``` curl http://127.0.0.1:8000/test.php ``` 結果輸出： ``` hello~ ``` 很遺憾，結果不是預期的那樣，腳本執行的很順利，并沒有中斷，難道`max_execution_time`配置對fpm無效？網上有些文章認為"如果php-fpm中設置了 request_terminate_timeout 的話，那么 max_execution_time 就不生效"，事實上這是錯誤的，這倆值是沒有任何關聯的，下面我們就從內核看下`max_execution_time`具體的實現。 `max_execution_time`在`php_execute_script()`函數中使用的： ``` //main/main.c #line:2400 PHPAPI int php_execute_script(zend_file_handle *primary_file) { ... //注意zend_try，后面會用到 zend_try { ... if (PG(max_input_time) != -1) { //非cli模式 ... zend_set_timeout(INI_INT("max_execution_time"), 0); } ... zend_execute_scripts(...); }zend_end_try(); } ``` 之前的一篇文章[《一張圖看PHP框架的整體執行流程》](http://x.xiaojukeji.com/article.html?id=3906)畫的一幅圖已經介紹過`php_execute_script()`函數的先后調用順序：`php_module_startup` -> `php_request_startup` -> `php_execute_script` -> `php_request_shutdown` -> `php_module_shutdown`，它是PHP腳本的具體解析、執行的入口，`max_execution_time`在這個位置設置的可以進一步確定它控制的是PHP的執行時長，我們再到`zend_set_timeout()`中看下（去除了一些windows的無關代碼）： ``` //Zend/zend_execute_API.c #line:1222 void zend_set_timeout(zend_long seconds, int reset_signals) { EG(timeout_seconds) = seconds; ... { struct itimerval t_r; /* timeout requested */ int signo; if(seconds) { t_r.it_value.tv_sec = seconds; t_r.it_value.tv_usec = t_r.it_interval.tv_sec = t_r.it_interval.tv_usec = 0; setitimer(ITIMER_PROF, &t_r, NULL); //設定一個定時器，seconds秒后觸發，到達時間后將發出ITIMER_PROF信號 } signo = SIGPROF; if (reset_signals) { # ifdef ZEND_SIGNALS zend_signal(signo, zend_timeout); # else sigset_t sigset; signal(signo, zend_timeout); //設置信號處理函數，這個例子中就是設置ITIMER_PROF信號由zend_timeout()處理 sigemptyset(&sigset); sigaddset(&sigset, signo); sigprocmask(SIG_UNBLOCK, &sigset, NULL); # endif } } } ``` 如果你用過C語言里面的定時器看到這里應該明白`max_execution_time`的含義了吧？`zend_set_timeout`設定了一個間隔定時器(itimer)，類型為`ITIMER_PROF`，問題就出在這，這個類型計算的程序在用戶態、內核態下的`執行`時長，下面簡單介紹下linux幾種不同類型的定時器。 #### a. 間隔定時器itimer 間隔定時器設定的接口setitimer定義如下，setitimer()為Linux的API，并非C語言的Standard Library，setitimer()有兩個功能，一是指定一段時間后，才執行某個function，二是每間格一段時間就執行某個function。 ``` int setitimer(int which, const struct itimerval *value, struct itimerval *ovalue)); struct itimerval { struct timeval it_interval; //it_value時間后每隔it_interval執行 　　struct timeval it_value; //it_value時間后將開始執行 }; struct timeval { long tv_sec; 　　long tv_usec; }; ``` which為定時器類型： * __ITIMER_REAL__ : 以__系統真實時間__來計算，它送出SIGALRM信號 * __ITIMER_VIRTUAL__ : 以該進程在__用戶態__下花費的時間來計算，它送出SIGVTALRM信號 * __ITIMER_PROF__ : 以該進程在__用戶態__下和__內核態__下所費的時間來計算，它送出SIGPROF信號 it_interval指定間隔時間，it_value指定初始定時時間。如果只指定it_value，就是實現一次定時；如果同時指定 it_interval，則超時后，系統會重新初始化it_value為it_interval，實現重復定時；兩者都清零，則會清除定時器。 #### b. 內核態、用戶態 操作系統的很多操作會消耗系統的物理資源，例如創建一個新進程時，要做很多底層的細致工作，如分配物理內存，從父進程拷貝相關信息，拷貝設置頁目錄、頁表等，這些操作顯然不能隨便讓任何程序都可以做，于是就產生了特權級別的概念，與系統相關的一些特別關鍵性的操作必須由高級別的程序來完成，這樣可以做到集中管理，減少有限資源的訪問和使用沖突。Intel的X86架構的CPU提供了0到3四個特權級，而在我們Linux操作系統中則主要采用了0和3兩個特權級，也就是我們通常所說的內核態和用戶態。 每個進程都有一個4G大小的虛擬地址空間，其中0~3G為用戶空間，3~4G為內核空間，每個進程都有一各用戶棧、內核棧，程序從用戶空間開始執行，當發生`系統調用`、`發生異常`、`外設產生中斷`時就從用戶空間切換到內核空間，`系統調用`都有哪些呢？可以從kernal源碼中查到：linux-4.9/arch/x86/entry/syscalls/syscall_xx.tbl，比如讀寫文件read/write、socket等。 PHP本質就是普通的C程序，所以我們直接按照C語言程序分析就行了，內核態、用戶態的區分簡單講就是如果cpu當前執行在用戶棧還是內核棧上，比如程序里寫的if、for、+/-等都在用戶態下執行，而讀寫文件、請求數據庫則將切換到內核態。 #### c. linux IO模式 PHP中操作最多的就是IO，比如訪問數據、rpc調用等等，因此這里單獨分析下IO操作引起的進程掛起。 對于一次IO訪問（以read舉例），數據會先被拷貝到操作系統內核的緩沖區中，然后才會從操作系統內核的緩沖區拷貝到應用程序的地址空間，linux系統產生了下面五種網絡模式： * 阻塞 I/O（blocking IO） * 非阻塞 I/O（nonblocking IO） * I/O 多路復用（ IO multiplexing） * 信號驅動 I/O（ signal driven IO） * 異步 I/O（asynchronous IO）: linux下很少用 阻塞IO下當用戶進程調用了recvfrom這個系統調用，kernel就開始了IO的第一個階段：準備數據（對于網絡IO來說，很多時候數據在一開始還沒有到達。比如，還沒有收到一個完整的UDP包。這個時候kernel就要等待足夠的數據到來）。這個過程需要等待，也就是說數據被拷貝到操作系統內核的緩沖區中是需要一個過程的。而在用戶進程這邊，整個進程會被阻塞、休眠。當kernel一直等到數據準備好了，它就會將數據從kernel中拷貝到用戶內存，然后kernel返回結果，用戶進程才解除block的狀態，重新運行起來。通過ps命令我們也可出fpm等待io響應時的狀態: ``` [qinpeng@kvm980199 ~]$ ps aux|grep fpm xiaoju 26700 0.0 0.2 207812 5340 ? S Dec28 0:16 php-fpm: pool www ``` ps命令進程的狀態：R 正在運行或可運行 S 可中斷睡眠 (休眠中, 受阻, 在等待某個條件的形成或接受到信號)。 最后我們回到PHP，總結一下： `ITIMER_VIRTUAL`定時器只會在`用戶態`下倒計時，在內核態下將停止倒計時，`ITIMER_PROF`在兩種狀態下都倒計時，`ITIMER_REAL`則以系統實際時間倒計時，因為除了這兩種狀態，程序還有一種狀態:`掛起`，也就是說`ITIMER_REAL`之外的兩種定時器記錄的都是進程的活躍狀態，也就是cpu忙碌的狀態，而讀寫文件、sleep、socket等操作因為等待時間發生而掛起的時間則不包括。這就是為什么上面測試腳本執行的時間比`max_execution_time`長的原因。這個時間限制的是__執行__時間，不含io阻塞、sleep等等進程掛起的時長，所以PHP腳本的實際執行時間遠遠大于`max_execution_time`的設定。 所以如果PHP里的定時器`setitimer`用的是`ITIMER_REAL`或者用下面的代碼測試，上面的例子結果就是我們預期了。 ``` <?php while(1){ } ?> ``` 將返回: 500 Internal Server Error。 現在可以清楚上面測試例子為什么不是預期結果的原因了，文章開始提到的故障也是因為等待redis響應而導致fpm的worker進程掛起，等待redis響應的時間并不在`ITIMER_PROF`計時內，所以即使我們配的`max_execution_time < request_terminate_timeout`，也無法因為IO阻塞的原因而命中`max_execution_time`的限制，除非類似死循環這類導致長時間占用cpu的情況。 我們接著從源碼看下`max_execution_time`超時時PHP是如何中斷執行、返回錯誤的。 `zend_set_timeout()`函數中設定的`ITIMER_PROF`定時器超時信號處理函數為`zend_timeout()`： ``` //Zend/zend_execute_API.c #line:1181 ZEND_API void zend_timeout(int dummy) { if (zend_on_timeout) { ... zend_on_timeout(EG(timeout_seconds)); } zend_error_noreturn(E_ERROR, "Maximum execution time of %pd second%s exceeded", EG(timeout_seconds), EG(timeout_seconds) == 1 ? "" : "s"); } ``` 不要著急去`zend_on_timeout`里看，注意這個函數__zend_error_noreturn()__，從函數名稱可以猜測它拋出了一個error錯誤，實際這就是將PHP中斷執行的操作： ``` //Zend/zend.c ZEND_COLD void zend_error_noreturn(int type, const char *format, ...) __attribute__ ((alias("zend_error"),noreturn)); ZEND_API ZEND_COLD void zend_error(int type, const char *format, ...) { ... /* if we don't have a user defined error handler */ if (Z_TYPE(EG(user_error_handler)) == IS_UNDEF || !(EG(user_error_handler_error_reporting) & type) || EG(error_handling) != EH_NORMAL) { zend_error_cb(type, error_filename, error_lineno, format, args); } else switch (type) { ... } ... } ``` `zend_error_cb`是一個函數指針，它在`php_module_startup()`中定義： ``` //main/main.c #line:2011 int php_module_startup(sapi_module_struct *sf, zend_module_entry *additional_modules, uint num_additional_modules) { ... zuf.error_function = php_error_cb; ... zend_startup(&zuf, NULL); ... } //Zend/zend.c #line:632 int zend_startup(zend_utility_functions *utility_functions, char **extensions) { ... zend_error_cb = utility_functions->error_function; //即：zend_error_cb = php_error_cb ... } ``` 最終調用的是`php_error_cb()`： ``` //main/main.c #line:973 static ZEND_COLD void php_error_cb(int type, const char *error_filename, const uint error_lineno, const char *format, va_list args) { ... switch (type) { ... case E_ERROR: case E_RECOVERABLE_ERROR: case E_PARSE: case E_COMPILE_ERROR: case E_USER_ERROR: ... /* the parser would return 1 (failure), we can bail out nicely */ if (type == E_PARSE) { CG(parse_error) = 0; } else { /* restore memory limit */ zend_set_memory_limit(PG(memory_limit)); efree(buffer); zend_objects_store_mark_destructed(&EG(objects_store)); zend_bailout(); //終止執行，try-catch return; } ... } ... } ``` 再展開__zend_bailout()__： ``` //zend.h #define zend_bailout() _zend_bailout(__FILE__, __LINE__) //zend.c #line:893 ZEND_API ZEND_COLD void _zend_bailout(char *filename, uint lineno) { if (!EG(bailout)) { zend_output_debug_string(1, "%s(%d) : Bailed out without a bailout address!", filename, lineno); exit(-1); } CG(unclean_shutdown) = 1; CG(active_class_entry) = NULL; CG(in_compilation) = 0; EG(current_execute_data) = NULL; LONGJMP( *EG(bailout), FAILURE); } //zend_portability.h # define SETJMP(a) sigsetjmp(a, 0) # define LONGJMP(a,b) siglongjmp(a, b) # define JMP_BUF sigjmp_buf ``` 還記得上面`php_execute_script()`中在PHP腳本執行函數外的`zend_try{...}`嗎？ 實際這是PHP里面實現的C語言層面的`try-catch`機制，try時利用__sigsetjmp()__將當前執行位置保存到__EG(bailout)__，中間執行拋出異常時利用__siglongjmp()__跳回到try保存的位置__EG(bailout)__，展開來看`php_execute_script`： ``` PHPAPI int php_execute_script(zend_file_handle *primary_file) { ... JMP_BUF *__orig_bailout = EG(bailout); JMP_BUF __bailout; EG(bailout) = &__bailout; if (SETJMP(__bailout)==0) { //初次設置時值為0，當執行LONGJMP時將跳回到這個位置，且值不為0，即從if之外的操作執行 ... if (PG(max_input_time) != -1) { ... zend_set_timeout(INI_INT("max_execution_time"), 0); } ... zend_execute_scripts(...); //parse -> execute } //zend_bailout()將接著從這里執行 EG(bailout) = __orig_bailout; ... } ``` 更多siglongjmp、sigsetjmp的說明可以自行查下，[https://github.com/pangudashu/anywork/tree/master/try_catch](https://github.com/pangudashu/anywork/tree/master/try_catch) 現在你應該清楚`max_execution_time`的實現機制及用法了吧? 最后總結一下__max_execution_time__的內核處理：PHP從執行`php_execute_script`開始活躍時間累計達到`max_execution_time`時，系統送出`SIGPROF`信號，此信號由__zend_timeout()__處理，最終內核調用__zend_bailout()__，回到開始執行的位置，結束`php_execute_script`執行，進入`php_request_shutdown`階段。 - - - ### 1.3 request_terminate_timeout 上一節我們詳細分析了PHP自身`max_execution_time`的實現原理，這一節我們再簡單看下fpm退出主因：`request_terminate_timeout`。 這個配置屬于php-fpm，注釋寫的是：一個request執行的最長時間，超過這個時間worker進程將被killed。 php-fpm是多進程模型，與nginx類似，master負責管理worker進程，worker為進程阻塞模型，每個worker同一時刻只能處理一個請求。master與worker之間可以進行通信，master可以啟動、殺掉worker。 這里不再對fpm詳細說明，只簡單看下`request_terminate_timeout`的處理： ``` //fpm_process_ctl.c void fpm_pctl_heartbeat(struct fpm_event_s *ev, short which, void *arg) { ... if (which == FPM_EV_TIMEOUT) { fpm_clock_get(&now); fpm_pctl_check_request_timeout(&now); return; } ... fpm_event_set_timer(&heartbeat, FPM_EV_PERSIST, &fpm_pctl_heartbeat, NULL); fpm_event_add(&heartbeat, fpm_globals.heartbeat); } static void fpm_pctl_check_request_timeout(struct timeval *now) { ... int terminate_timeout = wp->config->request_terminate_timeout; //php-fpm.conf中的request_terminate_timeout配置 int slowlog_timeout = wp->config->request_slowlog_timeout; ... fpm_request_check_timed_out(child, now, terminate_timeout, slowlog_timeout); ... } ``` 再看下`fpm_request_check_timed_out`: ``` //fpm_request.c void fpm_request_check_timed_out(struct fpm_child_s *child, struct timeval *now, int terminate_timeout, int slowlog_timeout) { ... if (terminate_timeout && tv.tv_sec >= terminate_timeout) { ... fpm_pctl_kill(child->pid, FPM_PCTL_TERM); //kill worker zlog(...); } } ``` 可以看到，master如果發現worker處理一個request時間超過了`request_terminate_timeout`將發送TERM信號給worker，直接導致worker退出,而這個時間是從worker接到請求開始計時的，是系統時間。 ---- ## 2、優化思路 上面分析了`request_terminate_timeout`及`max_execution_time`，兩者在PHP腳本執行超時的控制上都有一些欠缺，首先fpm的處理，雖然直接kill調進程是最簡單的方式，但對于業務而言成本太高，個別接口超時嚴重這種處理方式將直接導致所有的worker進程處于不斷的重啟狀態，每一個進程只處理一個請求就被干掉了；另外`max_execution_time`的限制實際沒有太大意義。 當然業務層面的優化才是根本解決之道，這里說的只是最后的一層防護，避免因為代碼的疏漏導致業務雪崩，出現問題的時候盡量減小影響、盡快定位出現問題的地方。 最容易想到的優化就是將上面提到的超時定時器類型改為：`ITIMER_REAL`，關于這個方案我用PHP擴展實現了一個，通過callback回調機制控制一個函數的執行時間，有興趣的具體可以翻下代碼：[https://github.com/pangudashu/timeout](https://github.com/pangudashu/timeout)，因為同一種定時器，linux下每個進程同一時刻只支持一個，所以目前不支持嵌套調用，可以適當修改支持多定時器。