perf 系統調用

• perf top

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

linux系統下可以使用perf性能分析工具，做熱點函數分析，perf安裝命令yum install perf。perf常用的熱點函數定位命令如下：

• 進程級：perf top -p <pid>
• 線程級：perf top -t <tid>

• perf record

perf record -a -e cycles -o cycle.perf -g sleep 10

-a 對所有 CPU 采樣 -o 輸出文件名，如果不指定，默認生成 perf.data -g 額外記錄函數調用關系 sleep 10 采樣 10s

perf record -F 99 -p 13204 -g -- sleep 30 

perf record表示記錄 -F 99表示每秒99次 -p 13204是進程號，即對哪個進程進行分析 -g 表示記錄調用棧 sleep 30 如上所述則是持續30秒。

perf record命令可以統計每個調用棧出現的百分比，然后從高到低排列。

一樣地，perf record 可以加 -p 表示跟蹤單個進程，也可以不加表示跟蹤整個系統。

perf record記錄程序運行數據，會在當前目錄生成 perf.data文件，這個文件可以用 perf report來進行解析和展示，它也是默認讀取的當前目錄下的 perf.data。

• perf report

perf report -n --stdio

perf report -i <file> 

-i 指定 perf record 生成的 perf data 文件，如果不指定 -i 則默認分析 perf.data 文件。 –max-stack=0 只輸出第一層函數調用 –stdio 輸出到標准輸出

 

 

–stdio 參數可以讓 perf report 標准輸出進行展示，這個我比較喜歡，總覺得比 tui 的模式一個一個站看看要方便很多。 –no-children 是以自底向上的模式真是統計數據，這里需要說明一下的是，一般profiler最終展示堆棧統計數據，都會提供兩種模式，一種叫 TopDown，就是從調用棧的根（C/C++一般就是 _start -> __libc_start_main -> main）從上至下進行分解，每個函數分支占用了多少資源占用比例；另外一種就是 BottomUp，這種方式下profiler會挑選各個占用資源最多的葉子函數，這里葉子的意思就是它沒有子函數調用了。 –no-children就是后面這種方式，不過個人感覺還是 TopDown 的方式比較直觀，能從宏觀上進行把控，BottomUp 直接掉進細節里面去了，這種方式對付簡單的程序還好，但是復雜的系統就比較麻煩了

[root@bogon ~]# perf record -F 99 -p 14060  -g -o neturon.perf  -- sleep 5
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.021 MB neturon.perf (5 samples) ]

[root@bogon ~]# perf report -n --stdio -i neturon.perf
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 5  of event 'cycles:ppp'
# Event count (approx.): 55785
#
# Children      Self       Samples  Command  Shared Object      Symbol                            
# ........  ........  ............  .......  .................  ..................................
#
   100.00%     0.00%             0  haproxy  [unknown]          [k] 0x0000ffffeb73fe5f
            |
            ---0xffffeb73fe5f
               0xaaaaaddd42e8
               __libc_start_main
               main
               0xaaaaaddd6528
               |          
                --99.82%--0xaaaaadde1e30

   100.00%     0.00%             0  haproxy  haproxy            [.] 0x0000aaaaaddd42e8
            |
            ---0xaaaaaddd42e8
               __libc_start_main
               main
               0xaaaaaddd6528
               |          
                --99.82%--0xaaaaadde1e30

   100.00%     0.00%             0  haproxy  libc-2.17.so       [.] __libc_start_main
            |
            ---__libc_start_main
               main
               0xaaaaaddd6528
               |          
                --99.82%--0xaaaaadde1e30

   100.00%     0.00%             0  haproxy  haproxy            [.] main
            |
            ---main
               0xaaaaaddd6528
               |          
                --99.82%--0xaaaaadde1e30

   100.00%     0.00%             0  haproxy  haproxy            [.] 0x0000aaaaaddd6528
            |
            ---0xaaaaaddd6528
               |          
                --99.82%--0xaaaaadde1e30

    99.82%    99.82%             1  haproxy  haproxy            [.] 0x0000000000021e30
            |
            ---0xffffeb73fe5f
               0xaaaaaddd42e8
               __libc_start_main
               main
               0xaaaaaddd6528
               0xaaaaadde1e30

    99.82%     0.00%             0  haproxy  haproxy            [.] 0x0000aaaaadde1e30
            |
            ---0xaaaaadde1e30

     0.18%     0.18%             4  haproxy  [kernel.kallsyms]  [k] finish_task_switch
     0.18%     0.00%             0  haproxy  haproxy            [.] 0x0000aaaaade430fc
     0.18%     0.00%             0  haproxy  libc-2.17.so       [.] epoll_pwait
     0.18%     0.00%             0  haproxy  [kernel.kallsyms]  [k] __sys_trace_return
     0.18%     0.00%             0  haproxy  [kernel.kallsyms]  [k] sys_epoll_pwait
     0.18%     0.00%             0  haproxy  [kernel.kallsyms]  [k] sys_epoll_wait
     0.18%     0.00%             0  haproxy  [kernel.kallsyms]  [k] schedule_hrtimeout_range
     0.18%     0.00%             0  haproxy  [kernel.kallsyms]  [k] schedule_hrtimeout_range_clock
     0.18%     0.00%             0  haproxy  [kernel.kallsyms]  [k] schedule
     0.18%     0.00%             0  haproxy  [kernel.kallsyms]  [k] __sched_text_start


#
# (Cannot load tips.txt file, please install perf!)
#

 

 

[root@bogon ~]# ps -elf | grep ping
4 S root     22924 22245  0  80   0 -  1784 poll_s 11:36 pts/1    00:00:00 ping 8.8.8.8
0 S root     22927 21295  0  80   0 -  1726 pipe_w 11:36 pts/0    00:00:00 grep --color ping
[root@bogon ~]# perf trace record --call-graph dwarf -p  22924  -o ping.perf -- sleep 5
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.603 MB ping.perf (70 samples) ]
[root@bogon ~]# perf report -n --stdio -i  ping.perf
# To display the perf.data header info, please use --header/--header-only options.
#

Perf

眾所周知，perf 是 Linux 系統下非常強大的性能工具，由 Linux 內核開發人員在不斷演進和優化。除了可以分析 PMU (Performance Monitoring Unit) 硬件事件，內核事件等通用功能外，perf 還提供了其他“子模塊”，比如 sched 分析調度器，timechart 根據負載特征可視化系統行為，c2c 分析可能存在的 false sharing （RedHat 在大量 Linux 的應用上，測試過這套 c2c 的開發原型，成功地發現了很多熱點的偽共享緩存行問題。）等, 而 trace 則可用於分析系統調用，其功能非常強大，並保證了可以接受的開銷—— 運行速度僅放慢 1.36 倍(dd 作為測試負載) 。我們一起看下幾個常用的場景：

1. 調用 syscall 數量的 top 排行榜

   perf top -F 49 -e raw_syscalls:sys_enter --sort comm,dso --show-nr-samples 

    

   

   image

   從輸出可以看到在采樣期間，kube-apiserver 的調用 syscall 的次數最多。

2. 顯示超過一定延遲的系統調用信息

   perf trace --duration 200
   

    

   

   image

   從輸出中可以看到進程名稱、pid ，超過 200 ms 的具體系統調用參數和返回值。

3. 統計某個進程一段時間內系統調用的開銷

   perf trace -p $PID  -s
   

    

   

   image

   從輸出中可以看到各系統調用的次數，返回錯誤次數，總延遲，平均延遲等信息。

4. 我們也可以進一步分析高延遲的調用棧信息

   perf trace record --call-graph dwarf -p $PID -- sleep 10
   

    

   

   image

5. 對一組任務進行 trace，比如后台有 2 個 bpf 工具在運行，我們想看下它們系統調用使用情況，就可以先將它們添加到 perf_event 這個 cgroup 下，再執行 perf trace：

   mkdir /sys/fs/cgroup/perf_event/bpftools/ echo 22542 >> /sys/fs/cgroup/perf_event/bpftools/tasks echo 20514 >> /sys/fs/cgroup/perf_event/bpftools/tasks perf trace -G bpftools -a -- sleep 10 

    

   

   image

perf-trace 的使用就介紹到這里，更多的用法請參考 man 手冊，從上面可以看到 perf-trace 的功能非常強大，根據 pid 或 tid 就可以進行過濾。但似乎沒有對容器和 K8S 環境進行便捷的支持。不用着急，接下來介紹的這個工具就是針對容器和 K8S 環境的。

 

perf record -e cpu-clock -g -o ping.perf  ping 8.8.8.8 

 

 

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

 

 

 perf report  -i  ping.perf 

 

 

 perf report -n --stdio -i  ping.perf 

 

perf record -a -g dd if=/data1/ -centos-arm64.iso  of=/dev/null

 

 

 

[root@bogon ~]#  perf stat -e context-switches ping 8.8.8.8
PING 8.8.8.8 (8.8.8.8) 56(84) bytes of data.
64 bytes from 8.8.8.8: icmp_seq=1 ttl=106 time=12.0 ms
64 bytes from 8.8.8.8: icmp_seq=2 ttl=106 time=12.1 ms
64 bytes from 8.8.8.8: icmp_seq=3 ttl=106 time=11.8 ms
64 bytes from 8.8.8.8: icmp_seq=4 ttl=106 time=11.6 ms
64 bytes from 8.8.8.8: icmp_seq=5 ttl=106 time=11.7 ms
^C
--- 8.8.8.8 ping statistics ---
5 packets transmitted, 5 received, 0% packet loss, time 4005ms
rtt min/avg/max/mdev = 11.645/11.870/12.121/0.211 ms

 Performance counter stats for 'ping 8.8.8.8':

                10      context-switches                                            

       4.704210796 seconds time elapsed

       0.000000000 seconds user
       0.002517000 seconds sys


[root@bogon ~]# 

 

 

perf診斷ksoftirqd

 

 

 

 

 

 熱點代碼分析

perf record -g --call-graph=dwarf -F 99 -p 12424

perf report -i perf.data    vs  perf report --stdio -i perf.data 

 

代碼展開

>perf report // 可以看到每個函數的耗時，看不到堆棧
或
> perf report -g // 詳細
// 報告中可以使用方向鍵和enter鍵查詢展開，或者使用如下方式自動全部展開
> perf report -g >1.txt