文章編寫計劃
待完成: 詳細(xì)介紹用到的各個工具
作者: 萬千鈞(祝星)
適合閱讀人群
文中的調(diào)優(yōu)思路無論是php, java, 還是其他任何語言都是用. 如果你有php使用經(jīng)驗, 那肯定就更好了
業(yè)務(wù)背景
框架及相應(yīng)環(huán)境
- laravel5.7, mysql5.7, redis5, nginx1.15
- centos 7.5 bbr
- docker, docker-compose
- 阿里云 4C和8G
問題背景
php已經(jīng)開啟opcache, laravel也運行了optimize命令進(jìn)行優(yōu)化, composer也進(jìn)行過dump-autoload命令.
首先需要聲明的是, 系統(tǒng)的環(huán)境中是一定有小問題的(沒有問題也不可能能夠提升如此大的性能), 但是這些問題, 如果不通過使用合適的工具, 可能一輩子也發(fā)現(xiàn)不出來.
本文關(guān)注的就是如何發(fā)現(xiàn)這些問題, 以及發(fā)現(xiàn)問題的思路.
我們首先找到系統(tǒng)中一個合適的API或函數(shù), 用來放大問題.
這個api設(shè)計之初是給nginx負(fù)載均衡做健康檢查的. 使用ab -n 100000 -c 1000 進(jìn)行壓測, 發(fā)現(xiàn)qps只能到140個每秒.
我們知道Laravel的性能是出了名的不好, 但是也不至于到這個程度, 從api的編寫來看不應(yīng)該這么低. 所以決定一探究竟.
public function getActivateStatus()
{
try {
$result = \DB::select('select 1');
$key = 1;
if ($result[0]->$key !== 1) {
throw new \Exception("mysql 檢查失敗");
}
} catch (\Exception $exception) {
\Log::critical("數(shù)據(jù)庫連接失敗: {$exception->getMessage()}", $exception->getTrace());
return \response(null, 500);
}
try {
Cache::getRedis()->connection()->exists("1");
} catch (\Exception $exception) {
\Log::critical("緩存連接失敗: {$exception->getMessage()}", $exception->getTrace());
return \response(null, 500);
}
return \response(null, 204);
}
問題表現(xiàn)以及排查思路
top
top命令發(fā)現(xiàn)系統(tǒng)CPU占用100% 其中用戶態(tài)占80%, 內(nèi)核態(tài)占20%, 看起來沒什么大問題. 有一個地方看起來很奇怪, top命令的運行結(jié)果
<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>
就是有一部分php-fpm進(jìn)程處在Sleep狀態(tài), 但CPU占用還是達(dá)到了近30%. 當(dāng)一個進(jìn)程處于Sleep狀態(tài)的時候, 任然占用了不少CPU, 先不要懷疑是不是進(jìn)程的問題, 我們看一下Ttop命令的man page.
%CPU -- CPU usage
The task's share of the elapsed CPU time since the last screen update, expressed as a percentage of total CPU time.
大致意思是這個占用是最后一次屏幕刷新的時候, 進(jìn)程CPU的占用. 由于top命令收集信息的時候, 可能linux把這個進(jìn)程強(qiáng)制調(diào)度了 ( 比如用于top收集進(jìn)程信息 ), 所以在這一瞬間(屏幕刷新的這一瞬間)某些php-fpm進(jìn)程處于sleep狀態(tài), 可以理解, 所以應(yīng)該不是php-fpm的問題.
pidstat
首先選出一個php-fpm進(jìn)程, 然后使用pidstat查看進(jìn)程詳細(xì)的運行情況
<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>
過程中也沒發(fā)現(xiàn)什么異樣, 并且和top命令的運行結(jié)果也基本一致.
vmstat
保持壓測壓力, 運行vmstate查看, 除了context switch (上下文切換)有點高之外, 并沒有看到太多異常. 由于我們使用的docker, redis, mysql都運行在同一臺機(jī)器上, 7000左右的CS還是一個合理的范圍, 但是這個IN(中斷)就有點太高了, 達(dá)到了1.4萬左右. 一定有什么東西觸發(fā)了中斷.
<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>
我們知道中斷有硬中斷和軟中斷, 硬中斷是由網(wǎng)卡, 鼠標(biāo)等硬件發(fā)出中斷信號, cpu馬上停下在做的事情, 處理中斷信號. 軟中斷是由操作系統(tǒng)發(fā)出的, 常用于進(jìn)程的強(qiáng)制調(diào)度.
不管是vmstat還是pidstat都只是新能探測工具, 我們無法看到具體的中斷是由誰發(fā)出的. 我們通過/proc/interrupts 這個只讀文件中讀取系統(tǒng)的中斷信息, 獲取到底是什么導(dǎo)致的中斷升高. 通過watch -d命令, 判斷變化最頻繁的中斷.
watch -d cat /proc/interrupts
<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>
我們發(fā)現(xiàn)其中Rescheduling interrupts變化的最快, 這個是重調(diào)度中斷（RES）雾鬼，這個中斷類型表示金刁，喚醒空閑狀態(tài)的CPU 來調(diào)度新的任務(wù)運行挤悉。這是多處理器系統(tǒng)（SMP）中，調(diào)度器用來分散任務(wù)到不同 CPU的機(jī)制撩穿，通常也被稱為處理器間中斷（Inter-Processor Interrupts，IPI）。 結(jié)合vmstat中的命令, 我們可以確定造成qps不高的原因之一是過多的進(jìn)程爭搶CPU導(dǎo)致的, 我們現(xiàn)在還不能確定具體是什么, 所以還需要進(jìn)一步的排查.
strace
strace可以查看系統(tǒng)調(diào)用, 我們知道, 當(dāng)使用系統(tǒng)調(diào)用的時候, 系統(tǒng)陷入內(nèi)核態(tài), 這個過程是會產(chǎn)生軟中斷的, 通過查看php-fpm的系統(tǒng)調(diào)用, 驗證我們的猜想
<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>
果然, 發(fā)現(xiàn)大量的stat系統(tǒng)調(diào)用, 我們猜想, 是opcache在檢查文件是否過期導(dǎo)致的. 我們通過修改opcache的配置, 讓opcache更少的檢查文件timestamp, 減少這種系統(tǒng)調(diào)用
opcache.validate_timestamps="60"
opcache.revalidate_freq="0"
再次執(zhí)行ab命令進(jìn)行壓測
<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>
果然qps直接漲到了205, 提升非常明顯, 有接近 46% 的提升
perf
現(xiàn)在任然不滿足這個性能, 希望在更多地方找到突破口. 通過
perf record -g
perf report -g
看到系統(tǒng)的分析報告
<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>
我們看到, 好像這里面有太多tcp建立相關(guān)的系統(tǒng)調(diào)用(具體是不是我還不清楚, 請大神指正, 但是看到send, ip, tcp啥的我就懷疑可能是tcp/ip相關(guān)的問題). 我們懷疑兩種情況
- 與mysql, redis重復(fù)大量的建立TCP連接, 消耗資源
- 大量請求帶來的tcp連接
先說第一個, 經(jīng)過檢查, 發(fā)現(xiàn)數(shù)據(jù)庫連接使用了php-fpm的連接池, 但是redis連接沒有, redis用的predis, 這個是一個純PHP實現(xiàn), 性能不高, 換成了phpredis:
打開laravel的config/database.php文件, 修改redis的driver為phpredis, 確保本機(jī)已安裝php的redis擴(kuò)展. 另外由于Laravel自己封裝了一個Redis門面, 而恰好redis擴(kuò)展帶來的對象名也叫Redis. 所以需要修改Laravel的Redis門面為其他名字, 如RedisL5.
再次進(jìn)行壓測
<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>
達(dá)到了喜人的286qps, 雖然和其他主打高性能的框架或者原生php比, 還有很高的提升空間(比如Swoole), 但是最終達(dá)到了104%的提升, 還是很有意義的
總結(jié)
我們通過top, 發(fā)現(xiàn)系統(tǒng)CPU占用高, 且發(fā)現(xiàn)確實是php-fpm進(jìn)程占用了CPU資源, 判斷系統(tǒng)瓶頸來自于PHP.
接著我們通過pidstat, vmstat發(fā)現(xiàn)壓測過程中, 出現(xiàn)了大量的系統(tǒng)中斷, 并通過 watch -d cat /proc/interrupts 發(fā)現(xiàn)主要的中斷來自于重調(diào)度中斷（RES)
通過strace查看具體的系統(tǒng)調(diào)用, 發(fā)現(xiàn)大量的系統(tǒng)調(diào)用來自于stat, 猜測可能是opcache頻繁的檢查時間戳, 判斷文件修改. 通過修改配置項, 達(dá)到了46%的性能提升
最后再通過perf, 查看函數(shù)調(diào)用棧, 分析得到, 可能是大量的與redis的TCP連接帶來不必要的資源消耗. 通過安裝redis擴(kuò)展, 以及使用phpredis來驅(qū)動Laravel的redis緩存, 提升性能, 達(dá)到了又一次近50%的性能提升.
最終我們完成了我們的性能提升104%的目標(biāo)
