利用php-fpm的慢日志定位故障

利用php-fpm的慢日志定位故障

    今天上午，開(kāi)發(fā)小哥向我反映一臺(tái)開(kāi)發(fā)機(jī)訪問(wèn)時(shí)速度非常慢，讓我?guī)退乙幌略颍缓笪揖烷_(kāi)始了一個(gè)排錯(cuò)的過(guò)程，當(dāng)時(shí)我的思路是這樣的：判斷網(wǎng)絡(luò)是否有問(wèn)題，判斷開(kāi)發(fā)機(jī)資源是否耗盡，判斷各服務(wù)是否正常運(yùn)行，判斷代碼問(wèn)題。

    網(wǎng)絡(luò)問(wèn)題較為簡(jiǎn)單了，ping一下，traceroute一下，發(fā)現(xiàn)沒(méi)有問(wèn)題，網(wǎng)絡(luò)很正常。排除了網(wǎng)絡(luò)問(wèn)題以后就要判斷是否是服務(wù)器資源耗盡了，然后我ssh登陸到開(kāi)發(fā)機(jī)上，使用top命令，看到的結(jié)果如下：

從這個(gè)結(jié)果來(lái)看，服務(wù)器資源還是很富裕的，問(wèn)題不在這里。那接下來(lái)就要查找是不是各服務(wù)的問(wèn)題了。

    訪問(wèn)速度慢，最大的可能是緩存的問(wèn)題，memcached是否掛了，memcached的內(nèi)存是否夠用，于是，我先查看了一下memcached的運(yùn)行狀態(tài)，發(fā)現(xiàn)其運(yùn)行十分正常，然后又重新啟動(dòng)并增加了memcached的內(nèi)存，但是訪問(wèn)速度依然很慢，看來(lái)故障并不是在這里，接著排錯(cuò)。

    既然不是緩存的問(wèn)題，那我又在想，會(huì)不會(huì)是php進(jìn)程開(kāi)啟的少了呢？然后我查了一下php的進(jìn)程池：

從結(jié)果我們也可以看出來(lái)，php的進(jìn)程是很多的，基本排除了php進(jìn)程問(wèn)題，那現(xiàn)在我的排錯(cuò)就進(jìn)入了一個(gè)瓶頸，這時(shí)就感到自己知識(shí)的饋乏性了，最后還是在大牛的提醒下，讓我查一下php的慢日志。由于本屌是一個(gè)新手，經(jīng)驗(yàn)與技術(shù)都有所欠缺，所以對(duì)慢日志并沒(méi)有多大的映像，畢竟在自己學(xué)習(xí)的過(guò)程中是很少用到這個(gè)日志的。

    既然查找慢日志，那么我做的第一步是開(kāi)啟php-fpm的慢日志功能，在php-fpm.conf配置文件中找到如下兩條配置：

; The timeout for serving a single request after which a PHP backtrace will be
; dumped to the 'slowlog' file. A value of '0s' means 'off'.
; Available units: s(econds)(default), m(inutes), h(ours), or d(ays)
; Default Value: 0
request_slowlog_timeout = 5
; The log file for slow requests
; Default Value: not set
; Note: slowlog is mandatory if request_slowlog_timeout is set
slowlog = /var/log/php-fpm/www-slow.log

其中，request_slowlog_timeout = 5 這條配置表示，將執(zhí)行時(shí)間超過(guò)5秒的php進(jìn)程記錄進(jìn)入慢日志，為什么要設(shè)置為5秒呢？這是因?yàn)槲也榭戳宋揖W(wǎng)頁(yè)的請(qǐng)求時(shí)間，響應(yīng)時(shí)間大概在13秒左右；

slowlog = /var/log/php-fpm/www-slow.log 這條配置指定慢日志的位置。

    開(kāi)啟慢日志后，使用命令tail -F /var/log/php-fpm/www-slow.log來(lái)實(shí)時(shí)動(dòng)態(tài)的查看日志內(nèi)容，同時(shí)再繼續(xù)訪問(wèn)該服務(wù)器，然后發(fā)現(xiàn)，在慢日志的輸出中，有多個(gè)函數(shù)的執(zhí)行時(shí)間超過(guò)了5秒，看來(lái)問(wèn)題就出在這里了。然后我找了開(kāi)發(fā)人員，反映了這個(gè)執(zhí)行較慢的腳本和函數(shù)，經(jīng)過(guò)他們的查找，發(fā)現(xiàn)是代碼中有一個(gè)配置沒(méi)有更新導(dǎo)致的，修改代碼后問(wèn)題解決。

    從這個(gè)運(yùn)維事件中，我又積累到了一些實(shí)際生產(chǎn)環(huán)境中的運(yùn)維經(jīng)驗(yàn)，這一點(diǎn)是我值得記錄的地方，可能這篇文章在許多大牛的眼里就是渣渣，但解決這個(gè)問(wèn)題的過(guò)程與經(jīng)驗(yàn)對(duì)于我來(lái)說(shuō)是真正的寶貴財(cái)富，我也相信，只要我一點(diǎn)一滴的記錄、積累，我也會(huì)變成一只大牛的。