如何使用perf top 探究性能


Perf 內置於Linux 內核源碼樹中的性能剖析工具。它基於事件采樣原理,以性能事件為基礎,支持針對處理器相關性能指標與操作系統相關性能指標的性能剖析。可用於性能瓶頸的查找與熱點代碼的定位。linux2.6及后續版本都自帶該工具,幾乎能夠處理所有與性能相關的事件。perf top 是比較常用於展示占用CPU始終最多的函數或者指令,一般以此來查找熱點函數。

 

實戰

root@xxxx:~# apt install linux-tools-common
root@xxxx:~# perf top

Samples: 6K of event 'cycles', 4000 Hz, Event count (approx.): 48144737 lost: 0/0 drop: 0/0
Overhead  Shared Object                           Symbol
   3.84%  [kernel]                                [k] native_write_msr
   2.25%  [kernel]                                [k] update_blocked_averages
   1.89%  [kernel]                                [k] update_sd_lb_stats.constprop.0
   1.80%  [kernel]                                [k] pvclock_clocksource_read

 

Samples : 采樣數, perf 總共采集了 6K 個 CPU 時鍾事件。

event : 事件類型。

Event count (approx.) : 事件總數量

 

行列:

Overhead: 是該符號的性能事件在所有采樣中的比例,用百分比來表示。

Shared: Shared ,是該函數或指令所在的動態共享對象(Dynamic Shared Object),如內核、進程名、動態鏈接庫名、內核模塊名等。

Object: Object ,是動態共享對象的類型。比如 [.] 表示用戶空間的可執行程序、或者動態鏈接庫,而 [k] 則表示內核空間。

Symbol: Symbol 是符號名,也就是函數名。當函數名未知時,用十六進制的地址來表示。

上面結果顯示內核模塊中native_write_msr 占用 CPU時鍾最多,比列占3.84%。

同樣可以使用perf record 與 perf report 進行定時采集再展示。加上 -g 參數,開啟調用關系的采樣,方便我們根據調用鏈來分析性能問題。

root@xxxx:~# perf record
^C //(結束采集)
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.967 MB perf.data (739 samples) ]

root@xxxx:~# perf report

Samples: 739  of event 'cycles', Event count (approx.): 22853303
Overhead  Command          Shared Object             Symbol
   4.38%  swapper          [kernel.kallsyms]         [k] native_write_msr
   4.04%  swapper          [kernel.kallsyms]         [k] native_safe_halt
   3.26%  swapper          [kernel.kallsyms]         [k] update_blocked_averages
   2.63%  swapper          [kernel.kallsyms]         [k] pvclock_clocksource_read
   2.07%  swapper          [kernel.kallsyms]         [k] update_sd_lb_stats.constprop.0
   1.94%  swapper          [kernel.kallsyms]         [k] rcu_cblist_dequeue
   1.79%  swapper          [kernel.kallsyms]         [k] _raw_spin_lock_irqsave
   1.76%  swapper          [kernel.kallsyms]         [k] ktime_get

 

利用 Nginx PHP做演示

root@xxxx:~# docker run --name nginx -p 10000:80 -itd feisky/nginx
root@xxxx:~# docker run --privileged --name phpfpm -itd --network container:nginx feisky/php-fpm

root@xxxx:~# curl http://localhost:10000/
It works!

 

接着,我們來測試一下這個 Nginx 服務的性能。在第二個終端運行下面的 ab 命令:

root@xxxx:~# ab -c 10 -n 100 http://localhost:10000/
This is ApacheBench, Version 2.3 <$Revision: 1843412 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient).....done


Server Software:        nginx/1.15.4
Server Hostname:        localhost
Server Port:            10000

Document Path:          /
Document Length:        9 bytes

Concurrency Level:      10
Time taken for tests:   1.188 seconds
Complete requests:      100
Failed requests:        0
Total transferred:      17200 bytes
HTML transferred:       900 bytes
Requests per second:    84.14 [#/sec] (mean)
Time per request:       118.849 [ms] (mean)

Time per request:       11.885 [ms] (mean, across all concurrent requests)
Transfer rate:          14.13 [Kbytes/sec] received

 

 

從 ab 的輸出結果我們可以看到,Nginx 能承受的每秒平均請求數只有 84.14。

繼續在第二個終端,運行 ab 命令:

root@xxxx:~# ab -c 10 -n 10000 http://localhost:10000/

 

接着,回到第一個終端使用docker exec 指令進入容器,然后運行 top 命令,並按下數字 1 ,切換到每個 CPU 的使用率:

top - 17:50:45 up 21:25,  3 users,  load average: 1.11, 0.27, 0.12
Tasks: 243 total,   6 running, 237 sleeping,   0 stopped,   0 zombie
%Cpu0  : 98.0 us,  1.7 sy,  0.0 ni,  0.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu1  : 98.7 us,  1.3 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu2  : 99.0 us,  0.7 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.3 si,  0.0 st
%Cpu3  : 99.0 us,  1.0 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   7961.2 total,   4756.2 free,    993.1 used,   2211.9 buff/cache
MiB Swap:   2048.0 total,   2048.0 free,      0.0 used.   6669.1 avail Mem


// 在容器內部top
KiB Swap:  2097148 total,  2097148 free,        0 used.  6706484 avail Mem
 Unknown command - try 'h' for help
    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
    552 daemon    20   0  336700  15420   7744 R  93.3  0.2   0:04.42 php-fpm
    553 daemon    20   0  336700  15420   7744 R  86.7  0.2   0:04.14 php-fpm
    555 daemon    20   0  336700  15420   7744 R  86.7  0.2   0:03.55 php-fpm
    551 daemon    20   0  336700  15420   7744 R  53.3  0.2   0:03.78 php-fpm
    554 daemon    20   0  336700  15420   7744 R  46.7  0.2   0:04.51 php-fpm
      1 root      20   0  336316  47672  40276 S   0.0  0.6   0:00.31 php-fpm
      7 root      20   0   18196   3416   2872 S   0.0  0.0   0:00.00 bash
    556 root      20   0   43152   3260   2768 R   0.0  0.0   0:00.00 top

 

 

這里可以看到,系統中有幾個 php-fpm 進程的 CPU 使用率加起來接近 400%;而每個 CPU 的用戶使用率(us)也已經超過了 98%,接近飽和。這樣,我們就可以確認,正是用戶空間的 php-fpm 進程,導致 CPU 使用率驟升。那再往下走,怎么知道是 php-fpm 的哪個函數導致了 CPU 使用率升高呢?我們來用 perf 分析一下。

root@xxxx:~# docker exec -i -t phpfpm bash // 進入容器

//容器內部
root@xxxx:~# apt-get update && apt-get install -y linux-perf linux-tools procps
root@xxxx:~# perf top -g -p 555

 

按方向鍵切換到 php-fpm,再按下回車鍵展開 php-fpm 的調用關系,你會發現,調用關系最終到了 sqrt 和 add_function。看來,我們需要從這兩個函數入手了。

我們拷貝出 Nginx 應用的源碼,看看是不是調用了這兩個函數:

//從容器phpfpm中將PHP源碼拷貝出來
root@xxxx:~# docker cp phpfpm:/app .

//使用grep查找函數調用
root@xxxx:~# grep sqrt -r app/
app/index.php:  $x += sqrt($x);

root@xxxxx:~# cat app/index.php
<?php
// test only.
$x = 0.0001;
for ($i = 0; $i <= 1000000; $i++) {
  $x += sqrt($x);
}

echo "It works!"
?>root

 

可以看得出這段測試代碼導致運行速度變慢。

# 停止原來的應用
root@xxxx:~# docker rm -f nginx phpfpm
# 運行優化后的應用
root@xxxx:~# docker run --name nginx -p 10000:80 -itd feisky/nginx:cpu-fix
root@xxxx:~# docker run --name phpfpm -itd --network container:nginx feisky/php-fpm:cpu-fix

 

刪除測試代碼后再次編譯運行。

$ ab -c 10 -n 10000 http://localhost:10000/
...
Complete requests:      10000
Failed requests:        0
Non-2xx responses:      10000
Total transferred:      3030000 bytes
HTML transferred:       1530000 bytes
Requests per second:    12273.25 [#/sec] (mean)
Time per request:       0.815 [ms] (mean)
Time per request:       0.081 [ms] (mean, across all concurrent requests)
Transfer rate:          3631.64 [Kbytes/sec] received

...

 

從這里你可以發現,現在每秒的平均請求數,已經從原來的 84.14 變成了 12273.25

1.用戶 CPU 和 Nice CPU 高,說明用戶態進程占用了較多的 CPU,所以應該着重排查進程的性能問題。

2.系統 CPU 高,說明內核態占用了較多的 CPU,所以應該着重排查內核線程或者系統調用的性能問題。

3.I/O 等待 CPU 高,說明等待 I/O 的時間比較長,所以應該着重排查系統存儲是不是出現了 I/O 問題。

4.軟中斷和硬中斷高,說明軟中斷或硬中斷的處理程序占用了較多的 CPU,所以應該着重排查內核中的中斷服務程序。

 

結束語

碰到 CPU 使用率升高的問題,你可以借助 top、pidstat 等工具,確認引發 CPU 性能問題的來源;再使用 perf 等工具,排查出引起性能問題的具體函數。


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM