背景和初步排查

• 訂單業(yè)務(wù)對(duì)賬時(shí)報(bào)警了，有筆訂單在我們自己的mongo庫(kù)里沒(méi)有找到
• 業(yè)務(wù)接口  /3/xx/vgift/send 調(diào)用禮物系統(tǒng)  sendPresent 接口完成送禮， 之后寫(xiě)mongo，但是php error log 里卻查不到任何mongo異常日志
• 寫(xiě)mongo沒(méi)有異常，但是庫(kù)里卻沒(méi)記錄,推斷只有2個(gè)可能

1是error log 丟日志了
2是程序執(zhí)行過(guò)程中操作完sendPresent后down掉了，導(dǎo)致沒(méi)寫(xiě)入mongo
-第一個(gè)情況工作多年的經(jīng)驗(yàn)來(lái)看應(yīng)該不至于，那就先根據(jù)第二種情況繼續(xù)查吧

• 那就去看下php-fpm 的日志，看對(duì)應(yīng)的時(shí)間點(diǎn)有沒(méi)有什么異常

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

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

熟悉下 php-fpm 的管理

php-fpm 是通過(guò) php-fpm這個(gè)命令進(jìn)行管理的，我們先看下這個(gè)命令

man php-fpm

這里有提到，php-fpm then responds to several POSIX signals php-fpm 會(huì)對(duì)下面幾個(gè)信號(hào)作（自己的）處理

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

動(dòng)手驗(yàn)證下

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

從驗(yàn)證結(jié)果推斷

在 05:28:01這個(gè)時(shí)間有人給php-fpm 發(fā)送了SIGTERM信號(hào)，在這個(gè)點(diǎn)發(fā)生很可能是個(gè)定時(shí)任務(wù)， 確認(rèn)果然是這樣 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, 顯然從日志結(jié)果來(lái)個(gè)是kill -TERM  . 文檔里也說(shuō)了默認(rèn)信號(hào)就是TERMkillproc sends signals to all processes that use the spec­ified executable. If no signal name is specified, the signal SIGTERM is sent.

看下這個(gè)情況下nginx的反應(yīng)

總結(jié)原因

• 業(yè)務(wù)請(qǐng)求時(shí)執(zhí)行完 sendPresent這個(gè)動(dòng)作后 ， 還沒(méi)來(lái)得及寫(xiě)mongo庫(kù)， php-fpm就剛好被 terminate 了，....  剛好趕上了

替代方案

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

與sa 的問(wèn)答

sa 說(shuō)了3點(diǎn)意見(jiàn)

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

我回復(fù)

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

尾聲

改成 SIGQUIT 信號(hào)nginx里還是有 104: Connection reset by peer， 看來(lái)手冊(cè)里說(shuō)SIGQUIT: graceful stop 也不能保證一次請(qǐng)求里的所有動(dòng)作都執(zhí)行完啊

最終結(jié)果 去掉這個(gè)定時(shí)重啟php-fpm 的任務(wù), 已經(jīng)3個(gè)多月了，沒(méi)發(fā)現(xiàn)問(wèn)題，oh yeah~

參考文檔

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

總結(jié)

以上就是這篇文章的全部?jī)?nèi)容了，希望本文的內(nèi)容對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值，謝謝大家對(duì)腳本之家的支持。