上一節,我帶你一塊兒學習了常見的動態追蹤方法。所謂動態追蹤,就是在系統或者應用程序正常運行的時候,經過內核中提供的探針,來動態追蹤它們的行爲,
從而輔助排查出性能問題的瓶頸。python
使用動態追蹤,能夠在不修改代碼、不重啓服務的狀況下,動態瞭解應用程序或者內核的行爲,這對排查線上問題、特別是不容易重現的問題尤爲有效。linux
在 Linux 系統中,常見的動態追蹤方法包括 ftrace、perf、eBPF 以及 SystemTap 等。上節課,咱們具體學習了 ftrace 的使用方法。今天,咱們再來一塊兒看看其餘幾種方法。docker
perf 已是咱們的老朋友了。在前面的案例中,咱們屢次用到它,來查找應用程序或者內核中的熱點函數,從而定位性能瓶頸。而在內核線程 CPU 高的案例中,咱們還使用火焰圖動態展現
perf 的事件記錄,從而更直觀地發現了問題。數據庫
不過,咱們前面使用 perf record/top 時,都是先對事件進行採樣,而後再根據採樣數,評估各個函數的調用頻率。實際上,perf 的功能遠不止於此。好比,ubuntu
接下來,咱們仍是之內核函數 do_sys_open,以及用戶空間函數 readline 爲例,看一看 perf 動態追蹤的使用方法。api
同 ftrace 同樣,你也能夠經過 perf list ,查詢全部支持的事件:緩存
perf list
而後,在 perf 的各個子命令中添加 --event 選項,設置追蹤感興趣的事件。若是這些預約義的事件不知足實際須要,你還可使用 perf probe 來動態添加。並且,除了追蹤內核事件外,
perf 還能夠用來跟蹤用戶空間的函數。bash
咱們先來看第一個 perf 示例,內核函數 do_sys_open 的例子。你能夠執行 perf probe 命令,添加 do_sys_open 探針:數據結構
perf probe --add do_sys_open Added new event: probe:do_sys_open (on do_sys_open) You can now use it in all perf tools, such as: perf record -e probe:do_sys_open -aR sleep 1
探針添加成功後,就能夠在全部的 perf 子命令中使用。好比,上述輸出就是一個 perf record 的示例,執行它就能夠對 10s 內的 do_sys_open 進行採樣:負載均衡
perf record -e probe:do_sys_open -aR sleep 10 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.148 MB perf.data (19 samples) ]
而採樣成功後,就能夠執行 perf script ,來查看採樣結果了:
perf script perf 12886 [000] 89565.879875: probe:do_sys_open: (ffffffffa807b290) sleep 12889 [000] 89565.880362: probe:do_sys_open: (ffffffffa807b290) sleep 12889 [000] 89565.880382: probe:do_sys_open: (ffffffffa807b290) sleep 12889 [000] 89565.880635: probe:do_sys_open: (ffffffffa807b290) sleep 12889 [000] 89565.880669: probe:do_sys_open: (ffffffffa807b290)
實際安裝調試代碼:
root@luoahong ~]# perf list List of pre-defined events (to be used in -e): alignment-faults [Software bpf-output [Software context-switches OR cs [Software cpu-clock [Software [root@luoahong ~]# perf probe --add do_sys_open Added new event: probe:do_sys_open (on do_sys_open) You can now use it in all perf tools, such as: perf record -e probe:do_sys_open -aR sleep 1 [root@luoahong ~]# perf record -e probe:do_sys_open -aR sleep 10 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.153 MB perf.data (7 samples) ] [root@luoahong ~]# perf script perf 10318 [001] 3749.316261: probe:do_sys_open: (ffffffff8129f030) sleep 10319 [000] 3749.317116: probe:do_sys_open: (ffffffff8129f030) sleep 10319 [000] 3749.317130: probe:do_sys_open: (ffffffff8129f030) sleep 10319 [000] 3749.317753: probe:do_sys_open: (ffffffff8129f030) systemd 1 [001] 3752.144923: probe:do_sys_open: (ffffffff8129f030) irqbalance 7772 [001] 3753.567150: probe:do_sys_open: (ffffffff8129f030) irqbalance 7772 [001] 3753.567501: probe:do_sys_open: (ffffffff8129f030)
輸出中,一樣也列出了調用 do_sys_open 的任務名稱、進程 PID 以及運行的 CPU 等信息。不過,對於 open 系統調用來講,只知道它被調用了並不夠,咱們須要知道的是,進程到底在打
開哪些文件。因此,實際應用中,咱們還但願追蹤時能顯示這些函數的參數。
對於內核函數來講,你固然能夠去查看內核源碼,找出它的全部參數。不過還有更簡單的方法,那就是直接從調試符號表中查詢。執行下面的命令,你就能夠知道 do_sys_open 的全部參數:
perf probe -V do_sys_open Available variables at do_sys_open @<do_sys_open+0> char* filename int dfd int flags struct open_flags op umode_t mode
從這兒能夠看出,咱們關心的文件路徑,就是第一個字符指針參數(也就是字符串),參數名稱爲 filename。若是這個命令執行失敗,就說明調試符號表尚未安裝。那麼,你能夠執行下面的
命令,安裝調試信息後重試:
# Ubuntu $ apt-get install linux-image-`uname -r`-dbgsym # CentOS $ yum --enablerepo=base-debuginfo install -y kernel-debuginfo-$(uname -r)
找出參數名稱和類型後,就能夠把參數加到探針中了。不過因爲咱們已經添加過同名探針,因此在此次添加前,須要先把舊探針給刪掉:
# 先刪除舊的探針 perf probe --del probe:do_sys_open # 添加帶參數的探針 $ perf probe --add 'do_sys_open filename:string' Added new event: probe:do_sys_open (on do_sys_open with filename:string) You can now use it in all perf tools, such as: perf record -e probe:do_sys_open -aR sleep 1
新的探針添加後,從新執行 record 和 script 子命令,採樣並查看記錄:
# 從新採樣記錄 $ perf record -e probe:do_sys_open -aR ls # 查看結果 $ perf script perf 13593 [000] 91846.053622: probe:do_sys_open: (ffffffffa807b290) filename_string="/proc/13596/status" ls 13596 [000] 91846.053995: probe:do_sys_open: (ffffffffa807b290) filename_string="/etc/ld.so.cache" ls 13596 [000] 91846.054011: probe:do_sys_open: (ffffffffa807b290) filename_string="/lib/x86_64-linux-gnu/libselinux.so.1" ls 13596 [000] 91846.054066: probe:do_sys_open: (ffffffffa807b290) filename_string="/lib/x86_64-linux-gnu/libc.so.6」 ... # 使用完成後不要忘記刪除探針 $ perf probe --del probe:do_sys_open
實際安裝調試代碼:
[root@luoahong ~]# perf probe -x /bin/bash 'readline%return +0($retval):string' Added new event: probe_bash:readline (on readline%return in /usr/bin/bash with +0($retval):string) You can now use it in all perf tools, such as: perf record -e probe_bash:readline -aR sleep 1 [root@luoahong ~]# perf record -e probe_bash:readline__return -aR sleep 5 event syntax error: 'probe_bash:readline__return' \___ unknown tracepoint Error: File /sys/kernel/debug/tracing/events/probe_bash/readline__return not found. Hint: Perhaps this kernel misses some CONFIG_ setting to enable this feature?. Run 'perf list' for a list of valid events Usage: perf record [<options>] [<command>] or: perf record [<options>] -- <command> [<options>] -e, --event <event> event selector. use 'perf list' to list available events [root@luoahong ~]# perf script perf 10318 [001] 3749.316261: probe:do_sys_open: (ffffffff8129f030) sleep 10319 [000] 3749.317116: probe:do_sys_open: (ffffffff8129f030) sleep 10319 [000] 3749.317130: probe:do_sys_open: (ffffffff8129f030) sleep 10319 [000] 3749.317753: probe:do_sys_open: (ffffffff8129f030) systemd 1 [001] 3752.144923: probe:do_sys_open: (ffffffff8129f030) irqbalance 7772 [001] 3753.567150: probe:do_sys_open: (ffffffff8129f030) irqbalance 7772 [001] 3753.567501: probe:do_sys_open: (ffffffff8129f030) [root@luoahong ~]# perf probe --del probe_bash:readline__return "probe_bash:readline__return" does not hit any event. Error: Failed to delete events.
如今,你就能夠看到每次調用 open 時打開的文件了。不過,這個結果是否是看着很熟悉呢?
其實,在咱們使用 strace 跟蹤進程的系統調用時,也常常會看到這些動態庫的影子。好比,使用strace 跟蹤 ls 時,你能夠獲得下面的結果:
strace ls ... access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 ... access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3 ...
你估計在想,既然 strace 也能獲得相似結果,自己又容易操做,爲何咱們還要用 perf 呢?
實際上,不少人只看到了 strace 簡單易用的好處,卻忽略了它對進程性能帶來的影響。從原理上來講,strace 基於系統調用 ptrace 實現,這就帶來了兩個問題。
因此,在性能敏感的應用(好比數據庫)中,我並不推薦你用 strace (或者其餘基於 ptrace 的性能工具)去排查和調試。
在 strace 的啓發下,結合內核中的 utrace 機制, perf 也提供了一個 trace 子命令,是取代strace 的首選工具。相對於 ptrace 機制來講,perf trace 基於內核事件,天然要比進程跟蹤的
性能好不少。
perf trace 的使用方法以下所示,跟 strace 其實很像:
perf trace ls ? ( ): ls/14234 ... [continued]: execve()) = 0 0.177 ( 0.013 ms): ls/14234 brk( ) = 0x555d96be7000 0.224 ( 0.014 ms): ls/14234 access(filename: 0xad98082 ) = -1 ENOENT No such file or directory 0.248 ( 0.009 ms): ls/14234 access(filename: 0xad9add0, mode: R ) = -1 ENOENT No such file or directory 0.267 ( 0.012 ms): ls/14234 openat(dfd: CWD, filename: 0xad98428, flags: CLOEXEC ) = 3 0.288 ( 0.009 ms): ls/14234 fstat(fd: 3</usr/lib/locale/C.UTF-8/LC_NAME>, statbuf: 0x7ffd2015f230 ) = 0 0.305 ( 0.011 ms): ls/14234 mmap(len: 45560, prot: READ, flags: PRIVATE, fd: 3 ) = 0x7efe0af92000 0.324 Dockerfile test.sh ( 0.008 ms): ls/14234 close(fd: 3</usr/lib/locale/C.UTF-8/LC_NAME> ) = 0 ...
實際測試代碼以下:
[root@luoahong ~]# perf trace ls ? ( ? ): ls/10348 ... [continued]: execve()) = 0 0.386 ( 0.049 ms): ls/10348 brk( ) = 0xae0000 0.610 ( 0.090 ms): ls/10348 mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS ) = 0x7fe83213c000 0.755 ( 0.048 ms): ls/10348 access(filename: 0x31f3abd0, mode: R ) = -1 ENOENT No such file or directory 0.847 ( 0.052 ms): ls/10348 open(filename: 0x31f394c4, flags: CLOEXEC ) = 3 0.947 ( 0.042 ms): ls/10348 fstat(fd: 3</usr/lib64/libpthread-2.17.so>, statbuf: 0x7fff6a5b9360 ) = 0 1.036 ( 0.049 ms): ls/10348 mmap(len: 33764, prot: READ, flags: PRIVATE, fd: 3 ) = 0x7fe832133000 1.394 ( 0.047 ms): ls/10348 close(fd: 3</usr/lib64/libpthread-2.17.so> ) = 0 1.500 ( 0.053 ms): ls/10348 open(filename: 0x3213c640, flags: CLOEXEC ) = 3 1.599 ( 0.082 ms): ls/10348 read(fd: 3</usr/lib64/libpthread-2.17.so>, buf: 0x7fff6a5b9520, count: 832) = 832 1.725 ( 0.046 ms): ls/10348 fstat(fd: 3</usr/lib64/libpthread-2.17.so>, statbuf: 0x7fff6a5b93c0 ) = 0 1.820 ( 0.106 ms): ls/10348 mmap(len: 2255184, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 3 ) = 0x7fe831cf5000 2.027 ( 0.350 ms): ls/10348 mprotect(start: 0x7fe831d19000, len: 2093056 ) = 0 2.424 ( 0.056 ms): ls/10348 mmap(addr: 0x7fe831f18000, len: 8192, prot: READ|WRITE, flags: PRIVATE|DENYWRITE|FIXED, fd: 3, off: 143360) = 0x7fe831f18000 2.533 ( 0.053 ms): ls/10348 mmap(addr: 0x7fe831f1a000, len: 6480, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS|FIXED) = 0x7fe831f1a000
不過,perf trace 還能夠進行系統級的系統調用跟蹤(即跟蹤全部進程),而 strace 只能跟蹤特定的進程。
第二個 perf 的例子是用戶空間的庫函數。以 bash 調用的庫函數 readline 爲例,使用相似的方法,能夠跟蹤庫函數的調用(基於 uprobes)。
readline 的做用,是從終端中讀取用戶輸入,並把這些數據返回調用方。因此,跟 open 系統調用不一樣的是,咱們更關注 readline 的調用結果。
咱們執行下面的命令,經過 -x 指定 bash 二進制文件的路徑,就能夠動態跟蹤庫函數。這其實就是跟蹤了全部用戶在 bash 中執行的命令:
# 爲 /bin/bash 添加 readline 探針 $ perf probe -x /bin/bash 'readline%return +0($retval):string’ # 採樣記錄 $ perf record -e probe_bash:readline__return -aR sleep 5 # 查看結果 $ perf script bash 13348 [000] 93939.142576: probe_bash:readline__return: (5626ffac1610 <- 5626ffa46739) arg1="ls" # 跟蹤完成後刪除探針 $ perf probe --del probe_bash:readline__return
固然,若是你不肯定探針格式,也能夠經過下面的命令,查詢全部支持的函數和函數參數:
跟內核函數相似,若是你想要查看普通應用的函數名稱和參數,那麼在應用程序的二進制文件中,一樣須要包含調試信息。
ftrace 和 perf 的功能已經比較豐富了,不過,它們有一個共同的缺陷,那就是不夠靈活,無法像 DTrace 那樣經過腳本自由擴展。
而 eBPF 就是 Linux 版的 DTrace,能夠經過 C 語言自由擴展(這些擴展經過 LLVM 轉換爲 BPF字節碼後,加載到內核中執行)。下面這張圖,就表示了 eBPF 追蹤的工做原理:
從圖中你能夠看到,eBPF 的執行須要三步:
因此,從使用上來講,eBPF 要比咱們前面看到的 ftrace 和 perf ,都更加繁雜。
實際上,在 eBPF 執行過程當中,編譯、加載還有 maps 等操做,對全部的跟蹤程序來講都是通用的。把這些過程經過 Python 抽象起來,也就誕生了 BCC(BPF Compiler Collection)。
BCC 把 eBPF 中的各類事件源(好比 kprobe、uprobe、tracepoint 等)和數據操做(稱爲Maps),也都轉換成了 Python 接口(也支持 lua)。這樣,使用 BCC 進行動態追蹤時,編寫
簡單的腳本就能夠了。
不過要注意,由於須要跟內核中的數據結構交互,真正核心的事件處理邏輯,仍是須要咱們用 C語言來編寫。
至於 BCC 的安裝方法,在內存模塊的緩存案例中,我就已經介紹過了。若是你尚未安裝過,能夠執行下面的命令來安裝(其餘系統的安裝請參考這裏):
# Ubuntu sudo apt-key adv --keyserver keyserver.ubuntu.com --recv-keys 4052245BD4284CDD echo "deb https://repo.iovisor.org/apt/$(lsb_release -cs) $(lsb_release -cs) main" | sudo tee /etc/apt/sources.list.d/iovisor.list sudo apt-get update sudo apt-get install bcc-tools libbcc-examples linux-headers-$(uname -r) # REHL 7.6 yum install bcc-tools
安裝後,BCC 會把全部示例(包括 Python 和 lua),放到 /usr/share/bcc/examples 目錄中:
ls /usr/share/bcc/examples hello_world.py lua networking tracing
接下來,仍是以 do_sys_open 爲例,咱們一塊兒來看看,如何用 eBPF 和 BCC 實現一樣的動態跟蹤。
一般,咱們能夠把 BCC 應用,拆分爲下面這四個步驟。
第一,跟全部的 Python 模塊使用方法同樣,在使用以前,先導入要用到的模塊:
from bcc import BPF
第二,須要定義事件以及處理事件的函數。這個函數須要用 C 語言來編寫,做用是初始化剛纔導入的 BPF 對象。這些用 C 語言編寫的處理函數,要以字符串的形式送到 BPF 模塊中處理:
# define BPF program (""" is used for multi-line string). # '#' indicates comments for python, while '//' indicates comments for C. prog = """ #include <uapi/linux/ptrace.h> #include <uapi/linux/limits.h> #include <linux/sched.h> // define output data structure in C struct data_t { u32 pid; u64 ts; char comm[TASK_COMM_LEN]; char fname[NAME_MAX]; }; BPF_PERF_OUTPUT(events); // define the handler for do_sys_open. // ctx is required, while other params depends on traced function. int hello(struct pt_regs *ctx, int dfd, const char __user *filename, int flags){ struct data_t data = {}; data.pid = bpf_get_current_pid_tgid(); data.ts = bpf_ktime_get_ns(); if (bpf_get_current_comm(&data.comm, sizeof(data.comm)) == 0) { bpf_probe_read(&data.fname, sizeof(data.fname), (void *)filename); } events.perf_submit(ctx, &data, sizeof(data)); return 0; } """ # load BPF program b = BPF(text=prog) # attach the kprobe for do_sys_open, and set handler to hello b.attach_kprobe(event="do_sys_open", fn_name="hello")
第三步,是定義一個輸出函數,並把輸出函數跟 BPF 事件綁定:
# process event start = 0 def print_event(cpu, data, size): global start # event’s type is data_t event = b["events"].event(data) if start == 0: start = event.ts time_s = (float(event.ts - start)) / 1000000000 print("%-18.9f %-16s %-6d %-16s" % (time_s, event.comm, event.pid, event.fname)) # loop with callback to print_event b["events"].open_perf_buffer(print_event)
最後一步,就是執行事件循環,開始追蹤 do_sys_open 的調用:
# print header print("%-18s %-16s %-6s %-16s" % ("TIME(s)", "COMM", "PID", "FILE」)) # start the event polling loop while 1: try: b.perf_buffer_poll() except KeyboardInterrupt: exit()
咱們把上面幾個步驟的代碼,保存到文件 trace-open.py 中,而後就能夠用 Python 來運行了。若是一切正常,你能夠看到以下輸出:
python trace-open.py TIME(s) COMM PID FILE 0.000000000 irqbalance 1073 /proc/interrupts 0.000175401 irqbalance 1073 /proc/stat 0.000258802 irqbalance 1073 /proc/irq/9/smp_affinity 0.000290102 irqbalance 1073 /proc/irq/0/smp_affinity
從輸出中,你能夠看到 irqbalance 進程(你的環境中可能還會有其餘進程)正在打開不少文件,而 irqbalance 依賴這些文件中讀取的內容,來執行中斷負載均衡。
經過這個簡單的示例,你也能夠發現,eBPF 和 BCC 的使用,其實比 ftrace 和 perf 有更高的門檻。想用 BCC 開發本身的動態跟蹤程序,至少要熟悉 C 語言、Python 語言、被跟蹤事件或函數
的特徵(好比內核函數的參數和返回格式)以及 eBPF 提供的各類數據操做方法。
不過,由於強大的靈活性,雖然 eBPF 在使用上有必定的門檻,卻也沒法阻止它成爲目前最熱門、最受關注的動態追蹤技術。
固然,BCC 軟件包也內置了不少已經開發好的實用工具,默認安裝到 /usr/share/bcc/tools/ 目錄中,它們的使用場景以下圖所示:
這些工具,通常均可以直接拿來用。而在編寫其餘的動態追蹤腳本時,它們也是最好的參考資料。不過,有一點須要你特別注意,不少 eBPF 的新特性,都須要比較新的內核版本(以下圖所
示)。若是某些工具沒法運行,極可能就是由於使用了當前內核不支持的特性。
除了前面提到的 ftrace、perf、eBPF 和 BCC 外,SystemTap 和 sysdig 也是經常使用的動態追蹤工具。
SystemTap 也是一種能夠經過腳本進行自由擴展的動態追蹤技術。在 eBPF 出現以前,
SystemTap 是 Linux 系統中,功能最接近 DTrace 的動態追蹤機制。不過要注意,SystemTap在很長時間以來都遊離於內核以外(而 eBPF 自誕生以來,一直根植在內核中)。
因此,從穩定性上來講,SystemTap 只在 RHEL 系統中好用,在其餘系統中則容易出現各類異常問題。固然,反過來講,支持 3.x 等舊版本的內核,也是 SystemTap 相對於
eBPF 的一個巨大優點。
sysdig 則是隨着容器技術的普及而誕生的,主要用於容器的動態追蹤。sysdig 聚集了一些列性能工具的優點,能夠說是集百家之所長。我習慣用這個公式來表示 sysdig 的特色:
sysdig =strace + tcpdump + htop + iftop + lsof + docker inspect。
而在最新的版本中(內核版本 >= 4.14),sysdig 還能夠經過 eBPF 來進行擴展,因此,也能夠用來追蹤內核中的各類函數和事件。
到這裏,你可能又以爲頭大了,這麼多動態追蹤工具,在實際場景中到底該怎麼選擇呢?仍是那句話,具體性能工具的選擇,就要從具體的工做原理來入手。
這兩節課,咱們已經把常見工具的原理和特色都介紹過了,你能夠先本身思考區分一下,不一樣場景的工具選擇問題。好比:
在這裏,我也總結了幾個常見的動態追蹤使用場景,而且分別推薦了適合的工具。你能夠保存這個表格,方便本身查找並使用。
今天,我主要帶你學習了 perf、eBPF 和 BCC 等動態追蹤方法,並總結了不一樣場景中如何選擇動態追蹤方法
在 Linux 系統中,常見的動態追蹤方法,包括 ftrace、perf、eBPF 以及 SystemTap 等。在大多數性能問題中,使用 perf 配合火焰圖是一個不錯的方法。若是這知足不了你的要求,那麼:
在新版的內核中,eBPF 和 BCC 是最靈活的動態追蹤方法;而在舊版本內核中,特別是在 RHEL 系統中,因爲 eBPF 支持受限,SystemTap 每每是更好的選擇。
此外,在使用動態追蹤技術時,爲了獲得分析目標的詳細信息,通常須要內核以及應用程序的調試符號表。動態追蹤實際上也是在這些符號(包括函數和事件)上進行的,因此易讀易理解的符號,有助於加快動態追蹤的過程。