# Appendix C
這篇主要紀錄在 python 使用 BCC 的使用方法。在 [BPF Performance Tools: Linux System and Application Observability](http://www.brendangregg.com/bpf-performance-tools-book.html) 一書中，放在 Appendix C。而主要參考的資料是 BCC repo 中的[文件](https://github.com/iovisor/bcc/blob/master/docs/reference_guide.md)與[教學](https://github.com/iovisor/bcc/blob/master/docs/tutorial_bcc_python_developer.md)。使用 BCC 搭配 python 的好處是比 `bpftrace` 有彈性很多，比如 BPF 紀錄的資料可以直接用 matplotlib 之類的函式庫繪圖，或是搭配 python 內建的 [subprocess](https://docs.python.org/2/library/subprocess.html) 模組自動化整個測試等等。
# Outline
如果是在 python 搭配 BCC 使用，那麼整個程式大致上會有兩個部份：
1. 要注入 BPF 執行的物件(C 語言寫成)
2. 接收回傳的資料進行, 並進行可能的後處理(python 寫成)
所以如果去 bcc repo 的教學，大多數的程式架構會看起來會像下面這樣：
```python=
from bcc import BPF
# load BPF program
b = BPF(text="""
#include <uapi/linux/ptrace.h>
BPF_HASH(last);
int do_trace(struct pt_regs *ctx) {
u64 ts, *tsp, delta, key = 0;
// attempt to read stored timestamp
tsp = last.lookup(&key);
if (tsp != 0) {
delta = bpf_ktime_get_ns() - *tsp;
if (delta < 1000000000) {
// output if time is less than 1 second
bpf_trace_printk("%d\\n", delta / 1000000);
}
last.delete(&key);
}
// update stored timestamp
ts = bpf_ktime_get_ns();
last.update(&key, &ts);
return 0;
}
""")
b.attach_kprobe(event=b.get_syscall_fnname("sync"), fn_name="do_trace")
# format output
start = 0
while 1:
(task, pid, cpu, flags, ts, ms) = b.trace_fields()
if start == 0:
start = ts
ts = ts - start
print("At time %.2f s: multiple syncs detected, last %s ms ago" % (ts, ms))
```
一開始建立 `BPF` 物件中，給的那個 `text` 字串就是要注入 BPF 的物件。而在`attach_*` 函數去把 probe 跟相應的 handler 進行綁定，並且做資料的後處理。
## C
這一部份的程式，是要編成 BPF byte code 的部份。而這些東西畢竟是要在一個放在核心的虛擬機中執行，所以自然會有一些限制。比如：
1. 不能直接呼叫 kernel function，只能使用 BPF 提供的輔助函數。這些函數的格式都是 `bpf_<function_name>` ，比如說 `bpf_ktime_get_ns()`, `bpf_trace_printk()` 等等。更多 BPF 提供的輔助函數可以去[文件](https://github.com/iovisor/bcc/blob/master/docs/reference_guide.md#data)找。
2. 資料必須儲存在 BPF 定義的資料結構 ：不能擅自使用如整數或陣列這種資料型態，而是要某些 BPF 專用的資料結構。這些 BPF 專屬的資料型態在文件中統稱 map (這在 `bpftrace` 的 script 對應到大概是 `@[]` 的語法)。最常見的大概是 `BPF_HASH`，而更多資料型態可以去文件中的 [map](https://github.com/iovisor/bcc/blob/master/docs/reference_guide.md#maps) 可以查到資訊。
3. 若想要讀取核心相關的的資料結構，要先用 [`bpf_probe_read()`](https://github.com/iovisor/bcc/blob/master/docs/reference_guide.md#1-bpf_probe_read) 函數搬到 BPF Stack 中。
4. 不能有迴圈
5. 更多限制可以看[這裡](https://stackoverflow.com/questions/57688344/what-is-not-allowed-in-restricted-c-for-ebpf)的整理。
## python
主要使用的是 `bcc` 中的 `BPF` 這個 class。最重要的動作是把 event source 及其觸發時所對應到的動作綁定。而綁定的方法又有兩種：一種是用 `attach_*` 名稱的函數：
```python=
from bcc import BPF
prog="""
int probe_handler(void *arg)
{
/* ... */
}
int ret_handler(void *arg)
{
/* ... */
}
"""
b = BPF(text=prog);
b.attach_kprobe(event='fibdrv_read', fn_name="probe_handler")
b.attach_kretprobe(event='fibdrv_read', fn_name="ret_handler")
```
另外一種是明確地用如 `kprobe__`, `kretprobe__` + 想追蹤的函數名稱：
```python=
from bcc import BPF
prog="""
int kprob__fib_read(void *arg)
{
/* ... */
}
int kretprobe__fib_read(void *arg)
{
/* ... */
}
"""
b = BPF(text=prog);
```
下面舉例簡單說明。
# 綁定 kprobe
以下示範幾個使用的例子。以 [fibdrv](https://github.com/sysprog21/fibdrv) 為例，追蹤 [fibdrv](https://github.com/sysprog21/fibdrv) 中，`fib_read` 這個函數。這邊假定模組已經先 `insmod` 好了：
```shell=
$ sudo insmod fibdrv.ko
```
> 因為在試驗的時候是使用 python 3 (BCC 手動編譯預設使用 python 2)，所以終端機的指令或輸出部份能會與 python 2 不一致。
## 使用 attach*
### kprobe
舉例來說，想要紀錄每一次進入 `fib_read` 時的時間：
```python=
from bcc import BPF
prog = """
#include <uapi/linux/ptrace.h>
int probe_handler(struct pt_regs *ctx)
{
u64 ts = bpf_ktime_get_ns();
bpf_trace_printk("Enter fib_read at %llu\\n", ts);
return 0;
}
"""
b = BPF(text=prog)
b.attach_kprobe(event="fib_read", fn_name="probe_handler")
b.trace_print()
```
使用 python 執行這個程式，那麼接下來只要有程式呼叫到 `fib_read` 時(比如說另外執行 `client` 程式的時候)，就會出現以下輸出：
```shell=
$ sudo python3 fib_hello.py
b' client-5610 [001] .... 3345.315537: 0: Enter fib_read at 3345172238601'
b' client-5610 [001] .... 3345.315630: 0: Enter fib_read at 3345172333863'
b' client-5610 [001] .... 3345.315637: 0: Enter fib_read at 3345172341982'
b' client-5610 [001] .... 3345.315642: 0: Enter fib_read at 3345172346697'
b' client-5610 [001] .... 3345.315647: 0: Enter fib_read at 3345172351477'
b' client-5610 [001] .... 3345.315652: 0: Enter fib_read at 3345172356987'
b' client-5610 [001] .... 3345.315659: 0: Enter fib_read at 3345172363958'
b' client-5610 [001] .... 3345.315688: 0: Enter fib_read at 3345172392777'
b' client-5610 [001] .... 3345.315696: 0: Enter fib_read at 3345172400831'
b' client-5610 [001] .... 3345.315702: 0: Enter fib_read at 3345172406864'
[...]
```
> BCC 文件中並不推薦使用 `bpf_trace_printk` 作為輸出，而是應`BPF_PERF_OUTOUT` 以及 `perf_submit` 作為輸出。不過為了簡便，這邊先用 `bpf_trace_printk` 輸出。詳細可參考文件的 [Output](https://github.com/iovisor/bcc/blob/master/docs/reference_guide.md#output) 一節。
### kretprobe
接下來自然而然的想到能不能用 `kretprobe`，答案是可以。只要換成 `attach_kretprobe` 就可以了：
```python=
from bcc import BPF
prog = """
#include <uapi/linux/ptrace.h>
#define TASK_COMM_LEN 64
int probe_handler(struct pt_regs *ctx)
{
char comm[TASK_COMM_LEN];
u64 ts = bpf_ktime_get_ns();
bpf_get_current_comm(&comm, sizeof(comm));
bpf_trace_printk("in: %s %llu\\n", comm, ts);
return 0;
}
int ret_handler(struct pt_regs *ctx)
{
char comm[TASK_COMM_LEN];
u64 ts = bpf_ktime_get_ns();
bpf_get_current_comm(&comm, sizeof(comm));
bpf_trace_printk("out:%s %llu\\n", comm, ts);
return 0;
}
"""
b = BPF(text=prog)
b.attach_kprobe(event="fib_read", fn_name="probe_handler")
b.attach_kretprobe(event="fib_read", fn_name="ret_handler")
b.trace_print()
```
用 python 執行之後再執行 `client`，就會發現：
```shll=
$ sudo python fibdrv-read-time.py
client-12158 [004] .... 7532.465565: 0: in: client 7532134752662
client-12158 [004] d... 7532.465576: 0: out:client 7532134765688
client-12158 [004] .... 7532.465637: 0: in: client 7532134826066
client-12158 [004] d... 7532.465639: 0: out:client 7532134828550
client-12158 [004] .... 7532.465643: 0: in: client 7532134832734
client-12158 [004] d... 7532.465644: 0: out:client 7532134833583
client-12158 [004] .... 7532.465647: 0: in: client 7532134837273
client-12158 [004] d... 7532.465648: 0: out:client 7532134838101
[...]
```
既然進入時間跟結束時間都可以紀錄，那麼就可以由兩者之間的差計算待在這個函數裡面的時間。仿照 bcc/tools 中的 [vfsreadlat](https://github.com/iovisor/bcc/blob/master/examples/tracing/vfsreadlat.c) 部份，寫一個檢測時間差的程式：
```python=
from bcc import BPF
prog = """
#include <uapi/linux/ptrace.h>
#define TASK_COMM_LEN 64
BPF_HASH(start, u64, u64);
int probe_handler(struct pt_regs *ctx)
{
u64 ts = bpf_ktime_get_ns();
u64 pid = bpf_get_current_pid_tgid();
start.update(&pid, &ts);
return 0;
}
int ret_handler(struct pt_regs *ctx)
{
u64 ts = bpf_ktime_get_ns();
u64 pid = bpf_get_current_pid_tgid();
u64 *tsp = (start.lookup(&pid));
if (tsp != 0) {
bpf_trace_printk("duration: %llu\\n", ts - *tsp);
start.delete(&pid);
}
return 0;
}
"""
b = BPF(text=prog)
b.attach_kprobe(event="fib_read", fn_name="probe_handler")
b.attach_kretprobe(event="fib_read", fn_name="ret_handler")
b.trace_print()
```
並且執行：
```=
$ sudo python fibdrv-read-time.py
client-13603 [007] d... 10238.629451: 0: duration: 1855
client-13603 [007] d... 10238.629518: 0: duration: 450
client-13603 [007] d... 10238.629523: 0: duration: 227
client-13603 [007] d... 10238.629525: 0: duration: 215
client-13603 [007] d... 10238.629528: 0: duration: 195
client-13603 [007] d... 10238.629531: 0: duration: 196
client-13603 [007] d... 10238.629533: 0: duration: 198
client-13603 [007] d... 10238.629536: 0: duration: 200
client-13603 [007] d... 10238.629540: 0: duration: 287
client-13603 [007] d... 10238.629550: 0: duration: 586
client-13603 [007] d... 10238.629556: 0: duration: 297
client-13603 [007] d... 10238.629561: 0: duration: 340
client-13603 [007] d... 10238.629566: 0: duration: 338
client-13603 [007] d... 10238.629571: 0: duration: 359
[...]
```
更進一步，可以仿照 [disksnoop](https://github.com/iovisor/bcc/blob/master/docs/tutorial_bcc_python_developer.md#lesson-6-disksnooppy)的例子，把這個函數吃的參數拉出來。並且搭配 `BPF.trace_fields()` ，只取出 `bpf_trace_printk()` 輸出的東西 (而不是像 `BPF.trace_print()` 那樣會把名稱, pid 等等資訊通通列出來)：
```python=
from bcc import BPF
prog = """
#include <uapi/linux/ptrace.h>
#include <linux/fs.h>
BPF_HASH(start, u64, u64);
BPF_HASH(args, u64, loff_t);
int probe_handler(struct pt_regs *ctx,
struct file *file,
char *buf,
size_t size,
loff_t *offset)
{
u64 ts = bpf_ktime_get_ns();
u64 pid = bpf_get_current_pid_tgid();
loff_t arg = *offset;
start.update(&pid, &ts);
args.update(&pid, &arg);
return 0;
}
int ret_handler(struct pt_regs *ctx)
{
u64 ts = bpf_ktime_get_ns();
u64 pid = bpf_get_current_pid_tgid();
u64 *tsp = start.lookup(&pid);
loff_t *offset = args.lookup(&pid);
if (tsp != 0 && offset != 0) {
bpf_trace_printk("%lld, %llu\\n", *offset, ts - *tsp);
start.delete(&pid);
args.delete(&pid);
}
return 0;
}
"""
b = BPF(text=prog)
b.attach_kprobe(event="fib_read", fn_name="probe_handler")
b.attach_kretprobe(event="fib_read", fn_name="ret_handler")
while 1:
try:
res = b.trace_fields()
except ValueError:
continue
print(res[5].decode("UTF-8"))
```
就可以輸出類似 csv 格式，可供 gnuplot 繪圖的輸出：
```shell=
$ sudo python3 fibdrv-read-time.py
0, 3369
1, 622
2, 314
3, 308
4, 320
5, 320
6, 317
7, 315
8, 316
9, 326
10, 321
11, 332
12, 337
13, 340
14, 323
15, 325
[...]
```
> 正在嘗試在 fibdrv 的 [`client`](https://github.com/0xff07/fibdrv/blob/master/client.c) 加上一些 user space 的計時手段，並且搭配 `subprocess`，如：
>
> ```python=
> prog = ...
> b = BPF(text=prog)
> out = subprocess.check_output("./client")
>
> while 1:
> try:
> res = b.trace_fields()
> except ValueError:
> continue
> except KeyboardInterrupt:
> break
> print(res[5].decode('utf-8'))
>
> print(out.decode('utf-8'))
> ```
>
> 似乎就可以自動紀錄 ` clock_gettime` 得到的時間差跟 kprobe 得到的計時。
## 使用 kprobe__ 及 kretprobe__ 提示
另外一種方法是把 handler 前面加上 `kprobe__` 提示，也就是寫成 `kprobe__<fn_name>` 跟 `kretprobe__<fn_name>` 。比如說這個程式：
```python=
from bcc import BPF
prog = """
#include <uapi/linux/ptrace.h>
int probe_handler(struct pt_regs *ctx)
{
u64 ts = bpf_ktime_get_ns();
bpf_trace_printk("in: %llu\\n", ts);
return 0;
}
int ret_handler(struct pt_regs *ctx)
{
u64 ts = bpf_ktime_get_ns();
bpf_trace_printk("out:%llu\\n", ts);
return 0;
}
"""
b = BPF(text=prog)
b.attach_kprobe(event="fib_read", fn_name="probe_handler")
b.attach_kretprobe(event="fib_read", fn_name="ret_handler")
b.trace_print()
```
也可以改成使用：
```python=
from bcc import BPF
prog = """
#include <uapi/linux/ptrace.h>
int kprobe__fib_read(struct pt_regs *ctx)
{
u64 ts = bpf_ktime_get_ns();
bpf_trace_printk("in: %llu\\n", ts);
return 0;
}
int kretprobe__fib_read(struct pt_regs *ctx)
{
u64 ts = bpf_ktime_get_ns();
bpf_trace_printk("out:%llu\\n", ts);
return 0;
}
"""
b = BPF(text=prog)
b.trace_print()
```
Sign in with Wallet
Connect another wallet