記 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 spec­ified 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~

參考文檔

• php-fpm signal handler
• php-fpm init script
• killproc man page