Guide:
- eBCC性能分析最佳實踐(0) - 開啟性能分析新篇章
- eBCC性能分析最佳實踐(1) - 線上lstat, vfs_fstatat 開銷高情景分析
- eBCC性能分析最佳實踐(2) - 一個簡單的eBCC分析網絡函數的latency
- 敬請期待...
0. eBCC Introduction
BCC是基于4.x kernel版本上的ebpf發展出來的一套性能分析工具集;
eBCC,顧名思義則是extended BCC的縮寫,是阿裡巴巴核心團隊在
Aliyun Linux 2上對BCC項目的拓展,包含BCC本身已有的工具集,和我們新開發的一些小的工具; eBCC則是基于在最新的BCC版本0.9之上做了一些拓展。
Aliyun Linux則使用了相對比較前沿,較新的kernel版本,支援ebpf特性,是以,如果想嘗試ebpf,eBCC帶來的系統上對“性能優化調試” 和 “問題診斷”上的新體驗,那就請趕快更新到
上吧。
1. Linux未來監控tracing架構:eBPF
eBPF源于早年間的成型于 BSD 之上的傳統技術 BPF(Berkeley Packet Filter)。BPF 的全稱是 Berkeley Packet Filter,顧名思義,這是一個用于過濾(filter)網絡封包(packet)的架構。
BPF 是在 1997 年首次被引入 Linux 的,Linux 核心中的封包過濾機制其實是有自己的名字的:Linux Socket Filter,簡稱 LSF。
從 3.15 開始,一個套源于 BPF 的全新設計開始,在3.17被添置到了 kernel/bpf 下。全新設計最終被命名為了 extended BPF(eBPF);為了後向相容,傳統的 BPF 仍被保留了下來,并被重命名為 classical BPF(cBPF)。相對于 cBPF,eBPF 帶來的改變可謂是革命性的:一方面,它已經為核心追蹤(Kernel Tracing)、應用性能調優/監控、流控(Traffic Control)等領域帶來了激動人心的變革;另一方面,在接口的設計以及易用性上,eBPF 也有了較大的改進。
cBPF 所覆寫的功能範圍很簡單,就是網絡監控和 seccomp 兩塊,資料接口設計的粗放;而 eBPF 的利用範圍要廣的多,性能調優、核心監控、流量控制什麼的,資料接口的多樣性設計。
由一個檔案(net/core/filter.c)進化到一個目錄(kernel/bpf)
目前,支援生成 BPF 僞代碼的編譯器隻有 llvm 一家,即使是通篇使用 gcc 編譯的 Linux 核心,samples 目錄下的 bpf 範例也要借用 llvm 來編譯完成。
下圖是ebpf的工作機制:
2. eBCC是什麼?
用一句話簡單的說: eBCC是一個工具集, 用來做Kernel space 和 User space 使用者程式的, 問題排查,和性能診斷!
eBCC能做什麼呢?
現在可以用 C 來實作 BPF,但編譯出來的卻仍然是 ELF 檔案,開發者需要手動析出真正可以注入核心的代碼。這工作有些麻煩,于是就有人設計了 BPF Compiler Collection(BCC),BCC 是一個 python 庫,但是其中有很大一部分的實作是基于 C 和 C++的,python實作了對 BCC 應用層接口的封裝。而eBCC則是對BCC的拓展和開發。
使用 eBCC 進行 BPF 的開發仍然需要開發者自行利用 C 來設計 BPF 程式——但也僅此而已,餘下的工作,包括編譯、解析 ELF、加載 BPF 代碼塊以及建立 map 等等基本可以由 eBCC 一力承擔,無需多勞開發者費心。
eBCC tracing:
3. eBCC安裝
3.1 方式:RPM包安裝:
安裝eBCC:
# yum install -y ebcc
# yum install -y ebcc-osstat
完事兒。
4. eBCC使用
- eBCC 裡面包含了一系列的 “工具集”,這些工具是module化的開發,主要運用場景是 “profiling” 性能優化 和“出現性能問題的時候的debug” 場景,但是,對于某些重要的module,我們也增加了 monitor的監控的方式,可以直接将資料 傳送到 alimonitor(需要簡單配置一下alimonitor的監控項,但是資料量大的時候開銷可能會比較大);
- 運作方式:支援command line(主要,推薦), daemonize(部分module)的方式運作;
- command line: 直接列印到console上,支援排序等功能。
- daemonize:需要配置化管理(/etc/osstat/osstat.conf),将資料json格式列印到 (/var/log/osstat.log)
- 工具集:
- /usr/share/ebcc/tools
- /usr/share/ebcc/osstat/tools/
- osstat:
- syscall:支援将所有的syscall的次數和時間統計上來,并且可以根據時間或者次數排序輸出
- softirq
- 等等
比如,eBCC中的一個工具:osstat,osstat将會包含多個module
4.0 ebcc
首先,我們先看下ebcc下都有哪些小工具呢?
這裡我們提供了一個簡單的
ebcc
小指令:
#ebcc
An advanced Linux Performance Profling toolset: eBCC
Usage ebcc:
-h - Help
-t - Show all supported tools, classify with type
-a - Show all supported tools totally
Examples:
ebcc -h
ebcc -t
ebcc syscount -h
ebcc vfsstat 1 10
ebcc osstat -m syscall -h
ebcc -t
對小工具進行分類:
#ebcc -t
tcp:
tcpaccept
tcpconnect
tcpconnlat
tcplife
tcpretrans
tcpstates
tcpsubnet
tcptop
tcptracer
func:
funccount
funclatency
funcslower
vfs:
vfscount
vfsstat
syscall:
syscount
osstat -m syscall -h
ext4:
ext4dist
ext4slower
file:
filelife
fileslower
filetop
...
決定使用哪個工具,隻需要在ebcc 後面直接添加 "工具名字 -h", 便可以檢視工具對應的功能
# ebcc vfscount -h
4.1 工具:osstat
osstat是一個比較重要的工具之一, osstat中的syscall module 可以将從将一個OS系統上的, 所有的syscall 捕獲,并且将 次數和時間統計出來,并且,支援sys, pid 兩個級别。 syscall 是使用者态進入 核心态的 入口。 osstat -m syscall 可以幫助 分析 cpu sys的開銷究竟是使用者态的 瘋狂使用導緻,還是 核心函數本身存在 latency? 這非常有助于 使用者态開發者和核心态開發者一起分析性能問題。
# ebcc osstat -h
...
...
...
Examples:
command mode: (-l)
#osstat -m syscall -t 10 -i 1 -u 1 -l sys
#osstat -m syscall -t 10 -i 1 -u 1 -l sys -n 10
#osstat -m syscall -t 10 -i 1 -u 1 -l sys -n 10 -T
#osstat -m syscall -t 10 -i 1 -u 1 -l pid
#osstat -m syscall -t 10 -i 1 -u 1 -l pid -p 1
daemonize mode: (-d)
#osstat -d -i 7 -u 3
#osstat -d -i 7 -u 3 -n 3
#osstat -d -i 7 -u 3 -f /etc/osstat/osstat.conf
4.1.1 首先看看osstat 工具包含了哪些子產品
#ebcc osstat -M
Supported Modules:
-m syscall
-m softirq
-m pgfault
4.1.2 osstat -m syscall sys級别
#ebcc osstat -m syscall -t 10 -i 1 -u 1 -l sys -n 10 -T
NR SYSCALL COUNT TIME MIN MAX
=================================================================================================
35 nanosleep 2883 907074501 236 3944864
281 epoll_pwait 27 820857284 210 773773366
23 select 2619 762921173 100 2951538
232 epoll_wait 14404 551436152 58 1048206
202 futex 304891 301412809 0 1251552
6 lstat 130117 291113663 287 40958
0 read 45173 95759688 21 656713
217 getdents64 26238 75171208 214 82231
1 write 8497 56316398 177 169597
270 pselect6 706 50987375 199 1391351
61 wait4 276 49677081 202 8727287
NR SYSCALL COUNT TIME MIN MAX
=================================================================================================
35 nanosleep 3347 910159174 134 1103293
23 select 2529 764573883 129 3241268
232 epoll_wait 15093 528232341 80 983735
202 futex 399478 312154858 2 73387
6 lstat 109124 243709631 319 61048
281 epoll_pwait 41 189470734 273 161519558
0 read 23374 94921119 88 721009
1 write 10737 74747585 107 95367
217 getdents64 34223 73694555 211 80931
270 pselect6 1301 66246720 233 78281
7 poll 843 47574550 229 3452827
NR SYSCALL COUNT TIME MIN MAX
4.1.3 osstat -m syscall pid級别
#ebcc osstat -m syscall -t 10 -i 1 -u 1 -l pid -n 10 -T
PID NR SYSCALL COUNT TIME MIN MAX
=================================================================================================================
110811 232 epoll_wait 290 1010778217 51616 60855391
23562 23 select 100 1005190909 10040021 10059593
94425 23 select 100 1005115914 10030841 10064314
5215 202 futex 71 1001496291 118 50058356
4663 202 futex 67 1001326053 248 50058880
4079 232 epoll_wait 1 1001010674 1001010674 1001010674
14622 7 poll 3 1000988330 470 1000987095
37574 23 select 40 1000883822 13119428 36926820
22902 232 epoll_wait 33 1000831340 188043 42588209
123536 61 wait4 3 1000769383 388 1000768392
4513 232 epoll_wait 47 1000573946 84183 117256230
4.1.4 osstat -m softirq sys級别
#ebcc -m softirq -t 10 -i 1 -u 1 -l sys -T -n 10
NUM SOFTIRQ COUNT TIME MIN MAX
=================================================================================================
1 timer 365 532979 389 35078
7 sched 148 371802 496 54114
3 net_rx 62 326907 1508 25594
9 rcu 248 180176 320 4579
4 block 3 13255 2669 6135
2 net_tx 1 4666 4666 4666
NUM SOFTIRQ COUNT TIME MIN MAX
=================================================================================================
3 net_rx 86 461913 886 32398
1 timer 202 343770 222 18041
7 sched 161 216259 340 4418
9 rcu 175 106446 134 4195
NUM SOFTIRQ COUNT TIME MIN MAX
=================================================================================================
3 net_rx 250 790444 500 38084
1 timer 241 481612 175 37471
7 sched 159 294294 304 47044
9 rcu 189 131113 249 7499
工具:funclatency
funclatency 可以将 核心中的重要的 函數的latency統計出來,并且,模拟做一個 柱狀圖, 主要關心的還是時間!
#ebcc funclatency -mTi 1 vfs_read
Tracing 1 functions for "vfs_read"... Hit Ctrl-C to end.
17:14:20
msecs : count distribution
0 -> 1 : 34376 |****************************************|
2 -> 3 : 38 | |
4 -> 7 : 21 | |
8 -> 15 : 12 | |
16 -> 31 : 1 | |
32 -> 63 : 4 | |
64 -> 127 : 2 | |
128 -> 255 : 1 | |
17:14:21
msecs : count distribution
0 -> 1 : 75623 |****************************************|
2 -> 3 : 44 | |
4 -> 7 : 25 | |
8 -> 15 : 18 | |
16 -> 31 : 6 | |
32 -> 63 : 4 | |
64 -> 127 : 9 | |
128 -> 255 : 5 | |
256 -> 511 : 1 | |
512 -> 1023 : 5 | |
4.2 工具funccount
#ebcc funccount -Ti 1 'vfs_*'
Tracing 49 functions for "vfs_*"... Hit Ctrl-C to end.
17:24:16
FUNC COUNT
vfs_readv 1
vfs_statfs 96
vfs_writev 108
vfs_getxattr 128
vfs_rename 224
vfs_lock_file 405
vfs_get_link 1895
vfs_fstat 3814
vfs_write 10657
vfs_open 17892
vfs_read 20974
vfs_fstatat 151758
vfs_getattr 168803
vfs_getattr_nosec 184572
4.2 工具mysqld_qslower
利用mysql中的USDT, 在mysql server端,追蹤 mysql 語句執行的lantency
請使用
CMake的-DENABLE_DTRACE = 1
或
-DENABLE_DTRACE = 0
選項。
執行:
MariaDB [mysql]> select * from time_zone;
Empty set (0.00 sec)
MariaDB [mysql]>
trace latency:
可以看到 select * from time_zone SQL語句的lentency: 0.160ms
#ebcc mysqld_qslower 101983 0
Tracing MySQL server queries for PID 101983 slower than 0 ms...
TIME(s) PID MS QUERY
0.000000 54806 0.098 select @@version_comment limit 1
3.959677 54806 0.054 show datebases
15.462936 54806 0.269 show databases
23.710874 54806 0.090 SELECT DATABASE()
23.712041 54806 0.199 show databases
23.712308 54806 0.224 show tables
26.310581 54806 0.293 show tables
35.086895 54806 0.160 select * from time_zone