色综合久久av,久久久亚洲一区,日韩精品电影一区亚洲

主頁 > 知識庫 > php-fpm重啟導致的程序執行中斷問題詳解

php-fpm重啟導致的程序執行中斷問題詳解

背景和初步排查

訂單業務對賬時報警了，有筆訂單在我們自己的mongo庫里沒有找到
業務接口 /3/xx/vgift/send 調用禮物系統 sendPresent 接口完成送禮，之后寫mongo，但是php error log 里卻查不到任何mongo異常日志
寫mongo沒有異常，但是庫里卻沒記錄,推斷只有2個可能

1是error log 丟日志了
2是程序執行過程中操作完sendPresent后down掉了，導致沒寫入mongo
-第一個情況工作多年的經驗來看應該不至于，那就先根據第二種情況繼續查吧

那就去看下php-fpm 的日志，看對應的時間點有沒有什么異常

[wu.daolin@web001.m6~]$ grep "2017 05:28" /var/log/php-fpm.log
[25-Jun-2017 05:28:01] NOTICE: Terminating ...

跟訂單時間剛好吻合，那肯定有必要研究下了

熟悉下 php-fpm 的管理

php-fpm 是通過 php-fpm這個命令進行管理的，我們先看下這個命令

man php-fpm

這里有提到，php-fpm then responds to several POSIX signals php-fpm 會對下面幾個信號作（自己的）處理

SIGINT, SIGTERM: immediate termination
SIGQUIT: graceful stop
SIGUSR1: re-open log file
SIGUSR2: graceful reload of all workers + reload of fpm conf/binary

動手驗證下

sudo kill -QUIT {php-fpm-pid}

[26-Jun-2017 13:58:22] NOTICE: Finishing ...            
[26-Jun-2017 13:58:22] NOTICE: exiting, bye-bye!

sudo kill -TERM {php-fpm-pid}

[26-Jun-2017 13:59:21] NOTICE: Terminating ...            
[26-Jun-2017 13:59:21] NOTICE: exiting, bye-bye!

sudo kill -USR2 12583

[26-Jun-2017 14:00:48] NOTICE: Reloading in progress ...          
[26-Jun-2017 14:00:48] NOTICE: reloading: execvp("/usr/sbin/php-fpm", {"/usr/sbin/php-fpm", "--daemonize"})    
[26-Jun-2017 14:00:48] NOTICE: using inherited socket fd=8, "10.30.60.87:9000"        
[26-Jun-2017 14:00:48] NOTICE: using inherited socket fd=8, "10.30.60.87:9000"        
[26-Jun-2017 14:00:48] NOTICE: fpm is running, pid 12696          
[26-Jun-2017 14:00:48] NOTICE: ready to handle connections

從驗證結果推斷

在 05:28:01這個時間有人給php-fpm 發送了SIGTERM信號，在這個點發生很可能是個定時任務，確認果然是這樣 28 5 * * * root /etc/init.d/php-fpm restart> /dev/null

我們的 php-fpm 管理

init script 是 /etc/init.d/php-fpm
其中stop 是 killproc -p ${pidfile} php-fpm, 顯然從日志結果來個是kill -TERM . 文檔里也說了默認信號就是TERMkillproc sends signals to all processes that use the specified executable. If no signal name is specified, the signal SIGTERM is sent.

看下這個情況下nginx的反應

總結原因

業務請求時執行完 sendPresent這個動作后，還沒來得及寫mongo庫， php-fpm就剛好被 terminate 了，.... 剛好趕上了

替代方案

雖然php-fpm 沒有解釋 terminate 跟 graceful stop 的具體含義，但猜的話前者是直接就終止程序的執行了，后者可能是溫柔點，把處理中的請求里的所有操作都執行完再殺死。。。
總之 SIGTERM terminate 調php 工作進程太粗暴了，應該要改一下比較好
改成 SIGUSER2 reload 方式
改成 SIGQUIT方式 ,把killproc -p ${pidfile} php-fpm 這句改成 killproc -p ${pidfile} php-fpm -QUIT
php-fpm 的worker 是計數n次后就會殺掉重新拉一個，如果用reload感覺功能重復了,根本沒必要定時重啟了，我還是選 graceful stop(SIGQUIT) 吧
當然還有個問題時，為啥要配置個定時重啟，將上面的內容發給sa看了

與sa 的問答

sa 說了3點意見

建議看下 -QUIT 時，Nginx的狀態碼是否正常？另外在某種情況下，可能會造成 PHP-FPM 進程退出時間比較長，會影響部署嗎？
用 reload(SIGUSER2) 而不是用SIGTERM停掉再啟動.
我們之前的測試結果看 reload 之后，nginx會報 502，并不 graceful stop。建議做好測試確認，包括部署php代碼時是不是 reload？Bug #60961 Graceful Restart (USR2) isn't very graceful
php-fpm每天定時重啟腳本這個定時腳本大概是在2012年部署的，當時是擔心 PHP-FPM 存在內存泄漏的情況而添加的。到現在是不是還適用？建議找一臺機器關掉定時腳本觀察一段較長時間看看。

我回復

SIGQUIT 是否正常還不清楚，但現在的默認 SIGTERM 是立即停掉php 進程是肯定不正常的 -- 從nginx error log 看，對于nginx 和 php-fpm已經建立好的連接，錯誤是 “104: Connection reset by peer”；準備去連的是“111: Connection refused”；
“111: Connection refused” 是還可以接受的，連不上而已，用戶稍后重試就可以；“104: Connection reset by peer” 這個就很難接受，這個錯我理解的意思是連接已經建好了，php突然terminate了，然后發了個RST分節給nginx；背后就表示當前請求可能只執行了一半動作，還有動作沒執行完，這可能就造成丟數據了。。。比如文章開頭說的這個問題
reload 那個其實就是 -USR2信號，這個bug看起來還沒解決。。。不過-USR2 應該說是偶現terminate，但 -TERM 肯定是必現terminate
現在代碼部署邏輯是同步代碼+清理opcache和yac緩存，不對php-fpm進程做操作
php-fpm 會自己對worker進程處理的請求數計數，達到一定數量就干掉再重新拉一個；所以worker進程應該沒有什么內存泄露的問題； manager 進程就不清楚了，但我想概率應該是極其低的。這個適不適用感覺很難去證偽啊。。。
所以要不找3臺機器，一臺用 -QUIT，一臺用 -USR2, 一臺去掉這個定時任務；先觀察下
sa 回復可以，我們自己看著辦

尾聲

改成 SIGQUIT 信號nginx里還是有 104: Connection reset by peer，看來手冊里說SIGQUIT: graceful stop 也不能保證一次請求里的所有動作都執行完啊

最終結果去掉這個定時重啟php-fpm 的任務, 已經3個多月了，沒發現問題，oh yeah~

參考文檔