殺手級(jí)分析——bootchart

之前小弟一直在宣傳推廣火焰圖，結(jié)果是很多童鞋凡事都用火焰圖。說(shuō)實(shí)話，火焰圖特別適合分析運(yùn)行時(shí)熱點(diǎn)（無(wú)論是on-cpu、off-cpu、還是內(nèi)存等，火焰圖的想象力可以無(wú)窮放大），但是你要分析一個(gè)的如果是一個(gè)時(shí)序問(wèn)題，比如系統(tǒng)啟動(dòng)的慢、一個(gè)軟件啟動(dòng)的慢，用火焰圖固然可能有一點(diǎn)幫助，但是幫助肯定很微妙。

因?yàn)檫@種某個(gè)過(guò)程慢的問(wèn)題，是一個(gè)時(shí)序問(wèn)題。不是一個(gè)運(yùn)行時(shí)熱點(diǎn)的問(wèn)題，所以你最重要的是畫(huà)出來(lái)你的這個(gè)過(guò)程的時(shí)序圖。這里面說(shuō)不定有I/O的牽絆，說(shuō)不定就是狂占CPU，說(shuō)不定誰(shuí)傻不拉幾地在sleep。

Linux界有一個(gè)殺手級(jí)分析Linux本身啟動(dòng)慢的工具，叫做bootchart，它其實(shí)把啟動(dòng)過(guò)程中進(jìn)程的IO,CPU占用情況進(jìn)行了描述。注意這類(lèi)圖都有一個(gè)共同特點(diǎn)，橫軸是時(shí)間，縱軸是CPU、線程等的狀態(tài)（運(yùn)行、睡眠、IO什么的）。

bootchart確實(shí)有利于分析開(kāi)機(jī)過(guò)程，但是你平時(shí)某個(gè)軟件啟動(dòng)慢呢？或者更廣泛地說(shuō)，某個(gè)特定過(guò)程特別慢呢？或者更加更加廣泛地說(shuō)，我寫(xiě)的程序在系統(tǒng)里面是怎么在運(yùn)行，幾個(gè)線程怎么在跑？我們則要描繪出它的時(shí)序圖。

這個(gè)時(shí)候，我們可以用perf的timechart，比如，下面我們寫(xiě)一個(gè)很簡(jiǎn)單的包含了2個(gè)線程周期循環(huán)做事情和睡眠的代碼：

我們運(yùn)行上面這個(gè)a.out，下面我們用perf錄制系統(tǒng)的sched情況：

~$ sudo perf sched record -a^C[ perf record: Woken up 1 times to write data ][perfrecord:Capturedandwrote1.909MBperf.data(9039samples)]

接下來(lái)生成timechart：

~$ sudo perf timechartWritten6.4secondsoftracetooutput.svg.

我們用firefox打開(kāi)這個(gè)時(shí)序圖：

時(shí)序圖上我們看到了我的8個(gè)CPU的運(yùn)行情況，以及a.out中2個(gè)線程一會(huì)兒藍(lán)色（running）一會(huì)灰色（sleeping）的情況。我們看到，系統(tǒng)差不多在用CPU2和CPU7跑我們a.out里面的2個(gè)占用CPU比較高線程。

不過(guò)，這類(lèi)工具里面壓軸的不是perf timechart，說(shuō)實(shí)話，有點(diǎn)太粗糙了！我們來(lái)看看大名鼎鼎的內(nèi)核鯊魚(yú)——kernelshark。

下面我們用trace-cmd來(lái)錄制sched相關(guān)的trace點(diǎn)：

~$ sudo trace-cmd record -e 'sched_wakeup*' -e sched_switch -e 'sched_migrate*'Hit Ctrl^C to stop recording^CCPU0 data recorded at offset=0x60e000 61440 bytes in sizeCPU1 data recorded at offset=0x61d000 184320 bytes in sizeCPU2 data recorded at offset=0x64a000 24576 bytes in sizeCPU3 data recorded at offset=0x650000 12288 bytes in sizeCPU4 data recorded at offset=0x653000 12288 bytes in sizeCPU5 data recorded at offset=0x656000 86016 bytes in sizeCPU6 data recorded at offset=0x66b000 172032 bytes in sizeCPU7 data recorded at offset=0x69500028672bytesinsize

用kernelshark來(lái)打開(kāi)錄制的點(diǎn)：

~$ kernelshark trace.datLoading"trace.dat"

看到下面的圖形界面：

我們可以在UI上面進(jìn)行各種操作，比如我們關(guān)注a.out，我們就選擇task：

我們得到這樣的視圖：

比如我圖上畫(huà)的那個(gè)點(diǎn)，a.out的顏色發(fā)生了變化，而下面的文字則表達(dá)了發(fā)生變化的原因是調(diào)度，調(diào)度的目標(biāo)是swapper,這個(gè)調(diào)度點(diǎn)發(fā)生在CPU4上面：

如果你期待的是一個(gè)橫軸是時(shí)間，縱軸是每個(gè)線程、CPU在某個(gè)時(shí)間段里面在干什么的圖，kernelshark，你當(dāng)然值得擁有。

原文標(biāo)題：宋寶華：當(dāng)Linux內(nèi)核遭遇鯊魚(yú)—kernelshark

文章出處：【微信公眾號(hào)：Linuxer】歡迎添加關(guān)注！文章轉(zhuǎn)載請(qǐng)注明出處。