perf 性能分析工具使用分享

前言

之前有分享過自己工作中自己搭建的 CPU 監控腳本等，但那個屬於是自己手工寫的一些腳本，比較粗淺的使用。後來就直接使用 perf 編譯到驅動裏面，在設備中直接使用 perf 了，比起自己寫的腳本，效率直線提升。今天就來分享以下 perf 的功能使用, 它可以將消耗 CPU 時間比較大的用戶程序調用棧打印出來，並生成火焰圖。

perf 的介紹和安裝

Perf 是 Linux kernel 自帶的系統性能優化工具。Perf 的優勢在於與 Linux Kernel 的緊密結合，它可以最先應用到加入 Kernel 的 new feature。pef 可以用於查看熱點函數，查看 cashe miss 的比率，從而幫助開發者來優化程序性能, 也可以分析程序運行期間發生的硬件事件，比如 instructions retired ，processor clock cycles 等；您也可以分析
軟件事件，比如 Page Fault 和進程切換，這使得 Perf 擁有了衆多的性能分析能力，

通過它，應用程序可以利用 PMU，tracepoint 和內核中的特殊計數器來進行性能統計。它不但可以分析指定應用程序的性能問題 (per thread)，也可以用來分析內核的性能問題，當然也可以同時分析應用代碼和內核，從而全面理解應用程序中的性能瓶頸。

舉例來說，使用 Perf 可以計算每個時鐘週期內的指令數，稱爲 IPC，IPC 偏低表明代碼沒有很好地利用 CPU。Perf 還可以對程序進行函數級別的採樣，從而瞭解程序的性能瓶頸究竟在哪裏等等。Perf 還可以替代 strace，可以添加動態內核 probe 點，還可以做 benchmark 衡量調度器的好壞。。。

ubuntu 安裝：

sudo apt-get install linux-tools-common linux-tools-"$(uname -r)" linux-cloud-tools-"$(uname -r)" linux-tools-generic linux-cloud-tools-generic

安裝好之後使用perf -v命令查看版本

在設備中安裝
如果你使用 yocto，那麼可是用 bitbake perf 直接編譯 perf 工具出來，然後做成鏡像燒錄到設備中，如果你使用的是其他根文件系統製作工具，方法也是類似。

將編譯好的的 lib 和 bin 目錄拷貝到設備中使用。

perf 基本使用

它和 Oprofile 性能調優工具等的基本原理都是對被監測對象進行採樣，最簡單的情形是根據 tick 中斷進行採樣，即在 tick 中斷內觸發採樣點，在採樣點裏判斷程序當時的上下文。假如一個程序 90% 的時間都花費在函數 foo() 上，那麼 90% 的採樣點都應該落在函數 foo() 的上下文中。運氣不可捉摸，那麼只要採樣頻率足夠高，採樣時間足夠長，那麼以上推論就比較可靠。因此，通過 tick 觸發採樣，我們便可以瞭解程序中哪些地方最耗時間，從而重點分析。

上面介紹了 perf 的原理，“根據 tick 中斷進行採樣，即在 tick 中斷內觸發採樣點，在採樣點裏判斷程序當時的上下文”，我們可以改變採樣的觸發條件使得我們可以獲得不同的統計數據，例如以時間點 ( 如 tick) 作爲事件觸發採樣便可以獲知程序運行時間的分佈；以 cache miss 事件觸發採樣便可以知道 cache miss 的分佈，即 cache 失效經常發生在哪些程序代碼中。如此等等。

首先我們可以看一下 perf 中能夠觸發採樣的事件有哪些。

perf list 使用，可以列出所有的採樣事件

sudo perf list

可以看到 Hadrware event Software event 等

Hardware Event 是由 PMU 硬件產生的事件，比如 cache 命中，當您需要了解程序對硬件特性的使用情況時，便需要對這些事件進行採樣
Software Event 是內核軟件產生的事件，比如進程切換，tick 數等
Tracepoint event 是內核中的靜態 tracepoint 所觸發的事件，這些 tracepoint 用來判斷程序運行期間內核的行爲細節，比如 slab 分配器的分配次數等

perf stat 概覽程序的運行情況

perf stat 選項，可以在終端上執行命令時收集性能統計信息

sudo perf stat -p 11664
指定進程查看, ctrl +c 殺死進程之後，就可以看到相應的數據了。

task-clock(msec) 是指程序運行期間佔用了 xx 的任務時鐘週期，該值高，說明程序的多數時間花費在 CPU 計算上而非 IO
context-switches 是指程序運行期間發生了 xx 次上下文切換，記錄了程序運行過程中發生了多少次進程切換，頻繁的進程切換是應該避免的。（有進程進程間頻繁切換，或者內核態與用戶態頻繁切換）
cpu-migrations 是指程序運行期間發生了 xx 次 CPU 遷移，即用戶程序原本在一個 CPU 上運行，後來遷移到另一個 CPU
cycles：處理器時鐘，一條機器指令可能需要多個 cycles
Instructions: 機器指令數目。
其他可以監控的譬如分支預測、cache 命中, page-faults 是指程序發生了 xx 次頁錯誤等

sudo  perf stat -p 13465
root@lyn:/mnt# ps -ux | grep target
root     13465 89.7  0.1   4588  1472 pts/1    R+   17:30   0:07 ./target
root     13467  0.0  0.0   3164   744 pts/0    S+   17:30   0:00 grep target
root@lyn:/mnt# perf stat -p 13465
^C
 Performance counter stats for process id '13465':

      13418.914783      task-clock (msec)         #    1.000 CPUs utilized          
                13      context-switches          #    0.001 K/sec                  
                 0      cpu-migrations            #    0.000 K/sec                  
                 0      page-faults               #    0.000 K/sec                  
       25072130385      cycles                    #    1.868 GHz                    
          20056061      stalled-cycles-frontend   #    0.08% frontend cycles idle   
        8663621265      stalled-cycles-backend    #   34.55% backend  cycles idle   
       27108898221      instructions              #    1.08  insns per cycle        
                                                  #    0.32  stalled cycles per insn
        3578980615      branches                  #  266.712 M/sec                  
            841545      branch-misses             #    0.02% of all branches        

      13.419173431 seconds time elapsed

參考鏈接

perf top 實時顯示當前系統的性能統計信息

sudo perf top -g

用於實時顯示當前系統的性能統計信息。該命令主要用來觀察整個系統當前的狀態，比如可以通過查看該命令的輸出來查看當前系統最耗時的內核函數或某個用戶進程。

[.] : user level 用戶態空間，若自己監控的進程爲用戶態進程，那麼這些即主要爲用戶態的 cpu-clock 佔用的數值
[k]: kernel level 內核態空間
[g]: guest kernel level (virtualization) 客戶內核級別
[u]: guest os user space 操作系統用戶空間
[H]: hypervisor 管理程序
The final column shows the symbol name.

當 perf 收集調用鏈時，開銷可以在兩列中顯示爲 Children 和 Self 。這裏的Self列與沒有 “-g” 的列類似：這是每個函數花費的 CPU 週期百分比。但是Children列在其下方添加了所有調用函數所花費的時間。不僅是直系子女，而且是所有後代。對於調用圖的葉子，函數不調用其他任何東西，Self 和 Children 的值是相等的。但是對於 main()，它增加了在 f1()<-main() 和 f2()<-main() 中花費的時間。您將第一行讀爲：95.61% 的時間花在調用 main() 上，而只有 8.19% 的時間花在 main() 指令上，因爲它大部分時間都在調用其他函數。請注意，您可以添加 “Self” 以覆蓋 100%，但在 “Children” 中，兒童樣本佔多行。這個想法是在頂部查看佔樣本最多的調用堆棧片段。

有一個 “+”，可以向下查看調用關係。

perf record 記錄採集的數據

使用 top 和 stat 之後，perf 可能已經大致有數了。要進一步分析，便需要一些粒度更細的信息。比如說我們已經斷

使用 top 和 stat 之後，perf 可能已經大致有數了。要進一步分析，便需要一些粒度更細的信息。比如說我們已經斷定目標程序計算量較大，也許是因爲有些代碼寫的不夠精簡。那麼面對長長的代碼文件，究竟哪幾行代碼需要進一步修改呢？這便需要使用 perf record 記錄單個函數級別的統計信息，並使用 perf report 來顯示統計結果（perf record 表示記錄到文件，perf top 直接會顯示到界面）。

perf record ，它可以對事件進行採樣，將採樣的數據收集在一個 perf.data 的文件中，這將會帶來一定的性能開銷，不過這個命令很有用，可以用來找出最佔 CPU 的進程。

下面的命令對系統 CPU 事件做採樣，採樣時間爲 60 秒，每秒採樣 99 個事件，-g 表示記錄程序的調用棧。
sudoperf record -F 99 -a -g -- sleep 60

此外我們還可以使用 PID 監控程序 perf record -e cpu-clock -g -p pid 監控已啓動的進程；也可以使用程序名監控程序 perf record -e cpu-clock -g -p grep your_program

-e選項允許您在 perf list 命令中列出的多個類別中選擇一個事件類別。例如，在這裏，我們使用-e cpu-clock 是指 perf record 監控的指標爲 cpu 週期程序運行完之後，perf record 會生成一個名爲 perf.data 的文件（缺省值），如果之前已有，那麼之前的 perf.data 文件會變爲 perf.data.old 文件

-g選項是告訴 perf record 額外記錄函數的調用關係，因爲原本 perf record 記錄大都是庫函數，直接看庫函數，大多數情況下，你的代碼肯定沒有標準庫的性能好對吧？除非是針對產品進行特定優化，所以就需要知道是哪些函數頻繁調用這些庫函數，通過減少不必要的調用次數來提升性能

perf record 的其他參數：

-f：強制覆蓋產生的. data 數據
-c：事件每發生 count 次採樣一次
-p：指定進程
-t：指定線程

可以使用 ctrl+c 中斷 perf 進程，或者在命令最後加上參數 --sleep n (n 秒後停止)

sudo perf report -n 可以生成報告的預覽。
sudo perf report -n --stdio 可以生成一個詳細的報告。
sudo perf script 可以 dump 出 perf.data 的內容。

獲得這個 perf.data 文件之後，我們其實還不能直接查看，下面就需要 perf report 工具進行查看

perf report 輸出 record 的結果

如果 record 之後想直接輸出結果，使用 perf report 即可
perf report 的相關參數：
-i : 指定文件輸出
　　-k：指定未經壓縮的內核鏡像文件，從而獲得內核相關信息
　　--report：cpu 按照 cpu 列出負載

sudo perf report

Samples: 123K of event 'cycles', Event count (approx.): 36930701307
Overhead  Command          Shared Object                                       Symbol
  18.91%  swapper          [kernel.kallsyms]                                   [k] intel_idle
     5.18%  dev_ui		    libQt5lxxx                                    [.] 0x00000000013044c7
    3.20%  dev_ui             libc-2.19.so                                 [.] _int_malloc                                                                                                                                    
	1.03%  dev_ui            libc-2.19.so                                  [.] __clock_gettime                                                                                                                                      
   3.04%  todesk           libpixman-1.so.0.38.4                               [.] 0x000000000008cac0
   1.20%  todesk           [JIT] tid 126593                                    [.] 0x0000000001307c7a
   0.84%  todesk           [JIT] tid 126593                                    [.] 0x000000000143c3f4
   0.73%  Xorg             i965_dri.so                                         [.] 0x00000000007cefe0
   0.65%  todesk           libsciter-gtk.so                                    [.] tool::tslice<gool::argb>::xcopy
   0.58%  Xorg             i965_dri.so                                         [.] 0x00000000007cf00e
   0.53%  Xorg             i965_dri.so                                         [.] 0x00000000007cf03c
   0.49%  todesk           [JIT] tid 126593                                    [.] 0x0000000001307cb2
   0.48%  Xorg             i965_dri.so                                         [.] 0x00000000007cf06a
   0.44%  todesk           [JIT] tid 126593                                    [.] 0x0000000001307cb6
   0.41%  todesk           [JIT] tid 126593                                    [.] 0x0000000001307cc0
   0.40%  x-terminal-emul  libz.so.1.2.11                                      [.] adler32_z
   0.40%  todesk           [JIT] tid 126593                                    [.] 0x0000000001307c83
   0.38%  todesk           [JIT] tid 126593                                    [.] 0x0000000001307cbb
   0.33%  swapper          [kernel.kallsyms]                                   [k] menu_select
   0.32%  gnome-shell      libmutter-clutter-6.so.0.0.0                        [.] clutter_actor_paint
   0.31%  gnome-shell      libgobject-2.0.so.0.6400.6                          [.] g_type_check_instance_is_a
   0.31%  swapper          [kernel.kallsyms]                                   [k] psi_group_change
   0.24%  SDK_Timer-8      [kernel.kallsyms]                                   [k] psi_group_change
   0.24%  todesk           libc-2.31.so                                        [.] __memset_avx2_unaligned_erms
   0.18%  todesk           [JIT] tid 126593                                    [.] 0x00000000013044c7
   0.18%  todesk           [JIT] tid 126593                                    [.] 0x000000000143c3f0
   0.17%  gnome-shell      libglib-2.0.so.0.6400.6                             [.] g_hash_table_lookup
   0.17%  todesk           [JIT] tid 126593                                    [.] 0x000000000143c426
   0.17%  todesk           [JIT] tid 126593                                    [.] 0x000000000143c3dd
   0.16%  todesk           [JIT] tid 126593                                    [.] 0x000000000143c3d9
   0.16%  swapper          [kernel.kallsyms]                                   [k] cpuidle_enter_state
   0.16%  SDK_Timer-8      [kernel.kallsyms]                                   [k] syscall_exit_to_user_mode
   0.16%  swapper          [kernel.kallsyms]                                   [k] __sched_text_start

在第二行我們發現一個 dev_ui ，佔用了 5.18%，使用了 libQt5lxxx 庫，它本身功能 UI 顯示，，但是佔用較高的 CPU，說明調用該庫存在問題（代碼本身問題），需要對調用該庫的代碼進行檢查。
第三行 libc-2.19.so [.] _int_malloc 這是常用的 malloc 操作，由於對代碼比較熟悉，在這個過程中不應該有這麼多次申請內存，說明代碼本身有問題，需要對申請動態內存的代碼進行檢查
第四行行 __clock_gettime 這個是由於計時需要，需要頻繁獲取時間，通常是指 gettimeofday() 函數
整個統計顯示有很多 task-clock 佔用是由於 kernel.kallsyms 導致，同時也驗證了對 perf stat 獲得的數據的初步判斷，即 CPU 飆升也與頻繁的 CPU 遷移（內核態中斷用戶態操作）導致，解決辦法是採用 CPU 綁核

也許有的人會奇怪爲什麼自己完全是一個用戶態的程序爲什麼還會統計到內核態的指標？一是用戶態程序運行時會受到內核態的影響，若內核態對用戶態影響較大，統計內核態信息可以瞭解到是內核中的哪些行爲導致對用戶態產生影響；二則是有些用戶態程序也需要依賴內核的某些操作，譬如 I/O 操作 + 4.93% dev_ui libcurl-gnutls.so.4.3.0 [.] 0x000000000001e1e0 ，左邊的加號代表 perf 已經記錄了該調用關係，按 enter 鍵可以查看調用關係，perf 監控該進程結果記錄到很多內核調用，說明該進程在運行過程中，有可能被內核態任務頻繁中斷，應儘量避免這種情況，對於這個問題我的解決辦法是採用綁核，譬如機器有 8 個 CPU，那麼我就綁定內核操作、中斷等主要在 0-5CPU，GW 由於有兩個線程，分別綁定到 6、7CPU 上。

注意：調優應該將注意力集中到百分比高的熱點代碼片段上，假如一段代碼只佔用整個程序運行時間的 0.1%，即使您將其優化到僅剩一條機器指令，恐怕也只能將整體的程序性能提高 0.1%。俗話說，好鋼用在刀刃上.

參考文章：鏈接

也可以用關鍵詞篩選
使用了sudo perf report 可以查看當前 perf.data 的數據，但是當你代碼調用很多時候不好進行分析查看，這個時候我們就可以選擇我們需要關注的重點信息查看，提高效率。例如以下的 futex_wait：

選中之後，使用 --call-graph ,,,,callee --symbol-filter = 後面增加你需要篩選監控的類型就可以單獨顯示了。

sudo perf report --call-graph ,callee –symbol-filter=futex_wait

這篇文章可以更多的幫助你理解 filter：鏈接

perf diff 進行兩次 record 對比

我們多次 perf record 之後，當前路徑下會有兩個 perf.data 和 perf.data.old 文件，分別是本次和上次 record 的記錄，這個時候我們可以通過 perf diff 進行對比優化的結果。

sudo perf diff perf.data perf.data.old

介紹一些了 perf 細節使用的描繪，再給大家分享一個 perf 詳細使用介紹的網址，大家對於 perf 介紹中有需要繼續深入探索的部分，可以點擊以下鏈接進行學習。

perf Examples 詳細的使用介紹

鏈接：https://www.brendangregg.com/perf.html

Linux Perf commands 命令介紹使用
鏈接：https://linuxhint.com/linux-perf-commands/

火焰圖的製作

CPU 的性能，它可以將消耗 CPU 時間比較大的用戶程序調用棧打印出來，並生成火焰圖。通過分析火焰圖的頂層的顯示，我們就可以很直觀的查看我們函數的性能情況了。

這個是自己 ubuntu20 系統做捕獲的火焰圖顯示

x 軸表示採樣次數或者頻率，如果一個函數在 x 軸佔據的寬度越寬，就表示它被抽到的次數多，即執行的時間長。注意，x 軸不代表時間，而是所有的調用棧合併後，按字母順序排列的。
y 軸表示調用棧，每一層都是一個函數。調用棧越深，火焰就越高，頂部就是正在執行的函數，下方都是它的父函數。

火焰圖就是看頂層的哪個函數佔據的寬度最大。只要有 "平頂"（plateaus），就表示該函數可能存在性能問題。

參考：鏈接 1; 鏈接 2

具體步驟：

1 首先，在 Ubuntu 安裝 perf 工具：
2 再從 github 下載分析腳本
git clone https://github.com/brendangregg/FlameGraph.git
3 使用 perf script 工具對 perf.data 進行解析
perf script -i perf.data &> perf.unfold
生成火焰圖通常的做法是將 perf.unfold 拷貝到本地機器，在本地生成火焰圖
4 將 perf.unfold 中的符號進行摺疊
FlameGraph/stackcollapse-perf.pl perf.unfold &> perf.folded
5 最後生成 svg 圖
FlameGraph/flamegraph.pl perf.folded > perf.svg
　　生成火焰圖可以指定參數，–width 可以指定圖片寬度，–height 指定每一個調用棧的高度，生成的火焰圖，寬度越大就表示 CPU 耗時越多。

注：如果 svg 圖出現 unknown 函數，使用如下命令

sudo perf record -e cpu-clock --call-graph dwarf -p pid

範例：perf record -e cpu-clock -g -p 29713 --call-graph dwarf 使用–call-graph dwarf 之後 record 生成的 perf.data 很大，大家生成的時候要時刻注意設備剩餘空間是否足夠

實際測試範例

如圖一段代碼
main -> do_main -> foo -> bar
其中 foo 函數和 bar 各有一個 for 循環，用來表示代碼時間運行消耗的 cpu

#include <iostream>
#include <vector>
#include <string>
#include <unistd.h>

using namespace std;
void bar(){
//   usleep(40*1000);
  /* do something here */
  for(int i=0;i< 4000;i++)
  {

  }
}

void foo(){
//   usleep(60*1000);
  for(int i=0;i< 5700;i++)
  {
      
  }      
  bar();
}

void do_main() {
  foo();
}

int main(int argc,char** argv){
    while(1)
    {
        do_main();
    }
}

運行代碼之後進行 top 實時查看（因爲我的設備默認都是 sudo 權限，所以以下命令都不用前綴 sudo）

ps -xu | grep target

perf top -e cpu-clock -p 29713

發現 foo 佔用 60%cpu 時間，而 bar 佔用 40% 時間，和 for 循環展示的大致一樣

perf record -e cpu-clock -g -p 29713

ctrl + c 停止記錄，發現當前目錄下保存了文件 perf.data

使用 report 查看
perf report -i perf.data

對比兩者差異，因爲只是單純記錄兩次，代碼沒有修改，所以沒有差異
perf diff perf.data perf.data

perf script -i perf.data &> perf.unfold

FlameGraph/stackcollapse-perf.pl test_data/perf.unfold &> test_data/perf.folded

拷貝到主機端進行轉換成火焰圖
FlameGraph/flamegraph.pl test_data/perf.folded > test_data/perf.svg

大家可以看到這個 cpu 佔用關係，火焰圖的頂層是個大平層，說明這段代碼 cpu 單個函數 foo 和 bar 佔用率太高，這段代碼優化空間很大。

結語

這就是我自己的一些 perf 使用分享。如果大家有更好的想法和需求，也歡迎大家加我好友交流分享哈。

作者：良知猶存，白天努力工作，晚上原創公號號主。公衆號內容除了技術還有些人生感悟，一個認真輸出內容的職場老司機，也是一個技術之外豐富生活的人，攝影、音樂 and 籃球。關注我，與我一起同行。

本文由 Readfog 進行 AMP 轉碼，版權歸原作者所有。
來源：https://mp.weixin.qq.com/s/AKNl5x_Mrw0KcYuTy5v1Ug

前言