引
当你问ChatGPT
:eBPF
和bcc
是什么?
eBPF是一种内核技术,它允许用户在不修改内核源代码的情况下,通过一种安全的、可编程的方式来扩展内核功能。BCC是一组用于eBPF的工具和库,它们使开发人员能够使用高级语言编写eBPF程序,从而更轻松地构建和部署内核跟踪和监控工具。
本文不会介绍eBPF
和bcc
的由来和历史,而是会基于bcc
文档中的例子来介绍与学习ebpf
和bcc
。
eBPF
和bcc
后续简写为bcc
。本文提到的例子均出现在bcc
仓库examples
下。
Hello World
让我们来看看计算机中不可避免的Hello World
例子:
from bcc import BPF
BPF(text='int kprobe__sys_clone(void *ctx) { bpf_trace_printk("Hello, World!\n"); return 0; }').trace_print()
让我们运行一下:
代码语言:javascript复制[root@VM-16-2-centos bcc]# ./examples/hello_world.py
b' <...>-3512395 [000] d... 9506128.282815: bpf_trace_printk: Hello, World!'
在这里我们需要知道以下的一些知识点:
text='...'
里面的内容是真正的eBPF
程序,是用C
编写的,而我们这里使用的bcc
可以认为是eBPF
的一个前端,通过它快速的编写eBPF
程序;这段代码是注入到内核中执行的,所以调用的时候请注意用root
权限;如果没有输出的话可以打开一个新的shell
然后随便执行一些命令;kprobe__sys_clone()
:这里通过了一个内核探针来进行内核动态追踪,其命名规则是kprobe__
,后面跟相关的内核函数名,例如这里是sys_clone
;void *ctx
:这里ctx
中也包含了一些参数,但是在这个例子中用不到;bpf_trace_printk
:按照referance_guide中的说明,这个函数是bcc
的一个辅助函数,用于将printf
的结果输出到trace_pipe
,注意这里的trace_pipe
是全局共享,因此并发时会有冲突,可以用BPF_PERF_OUTPUT
替代;return 0
:eBPF
程序必需的组成部分;.trace_point()
:bcc
进程会通过这个方式读取trace_pipe
的内容并打印;
这段代码的意思是追踪sys_clone
这个系统调用,一旦该系统调用触发,就输出Hello, World!
。这个程序被执行以后,会先将text='...'
的内容注入到内核中,挂载到sys_clone
这个函数开始的地方。内核每次执行sys_clone
的时候,都会执行我们注入的函数,也即输出Hello, World!
。
如何查看全部的kprobe
列表?
可以首先挂载debugfs
:
mkdir debugfs
mount -t debugfs none debugfs/
cd debugfs
cat kprobe/list
或者直接通过:
代码语言:javascript复制/sys/kernel/debug/kprobes/list
如下图所示:
kprobe
通过这种方式,我们可以得到已注册(registered
)的kprobe
列表,如果要查看可获得(available
)的kprobe
,可以通过:
cat /sys/kernel/debug/tracing/available_filter_functions
sys_sync
学习了如何追踪sys_clone
后,让我们尝试追踪一下sys_sync
吧。
ChatGPT说:sys_sync是一个系统调用,它将所有已修改的文件系统缓存数据写入磁盘,以确保数据的持久性。在调用sys_sync之后,文件系统缓存数据将与磁盘上的数据同步,因此在系统崩溃或意外断电等情况下,不会丢失数据。sys_sync通常由系统管理员或应用程序在执行重要操作之前调用,例如进行备份或升级操作。但是,由于sys_sync需要将所有数据写入磁盘,因此可能会导致系统性能下降。
基于我们刚才的学习,我们可以修改代码如下所示:
代码语言:javascript复制#!/usr/bin/python
from bcc import BPF
BPF(text='int kprobe__sys_sync(void *ctx) { bpf_trace_printk("Sync!!!\n"); return 0; }').trace_print()
运行一下看看:
代码语言:javascript复制[root@VM-16-2-centos examples]# ./sync.py
似乎短时间内没有输出,这可能是因为系统并没有什么写入操作,我们新起一个终端,手动触发一下:
代码语言:javascript复制[root@VM-16-2-centos examples]# sync
可以看到现在就有输出了:
sync
hello_fields.py
前面我们介绍了很简短的bcc
程序例子,那么比较长的程序我们该如何编写呢?我们来学习/tracing/hello_fields.py
:
#!/usr/bin/python
#
# This is a Hello World example that formats output as fields.
from bcc import BPF
from bcc.utils import printb
# define BPF program
prog = """
int hello(void *ctx) {
bpf_trace_printk("Hello, World!\n");
return 0;
}
"""
# load BPF program
b = BPF(text=prog)
b.attach_kprobe(event=b.get_syscall_fnname("clone"), fn_name="hello")
# header
print("%-18s %-16s %-6s %s" % ("TIME(s)", "COMM", "PID", "MESSAGE"))
# format output
while 1:
try:
(task, pid, cpu, flags, ts, msg) = b.trace_fields()
except ValueError:
continue
except KeyboardInterrupt:
exit()
printb(b"%-18.9f %-16s %-6d %s" % (ts, task, pid, msg))
从注释上我们可以看出,其整体是对Hello World
例子的格式更换,我们需要了解如下几点:
prog =
:我们通过先声明源码的方式声明了eBPF
的代码,然后再将其载入到我们的bcc
前端中,这样的话,我们就可以更好的编写代码了。hello()
:这是我们声明的一个C
函数,这个函数后续会被挂载到对应的函数调用上,其传入的参数ctx
必须要放在函数第一位;b.attach_probe(event=b.get_syscall_fnname("clone"), fn_name="hello")
:这段话的意思是将我们前面声明的hello
函数挂载到sys_clone
这个内核探针上,我们可以多次调用进行多次挂载,比如同时将hello
挂载到sys_sync
上,这样就不需要重复编写了;trace_fields()
:是一个bcc
的辅助函数,可以读取trace_pipe
的内容并进行划分,可以在调试的时候使用,正式使用还是建议通过BPF_PERF_OUTPUT
机制;
阅读代码我们发现,这个程序并没有对Hello World
做太大的变更,只是对程序的写法做了更好的调整,从而能够让我们更好的开发。由于clone
触发过于频繁,在这里我们调整为对sync
的追踪,并且添加两个追踪函数:
# define BPF program
prog = """
int hello(void *ctx) {
bpf_trace_printk("Hello, World!\n");
return 0;
}
int sync(void *ctx) {
bpf_trace_printk("Hello, Sync!\n");
return 0;
}
"""
# load BPF program
b = BPF(text=prog)
b.attach_kprobe(event=b.get_syscall_fnname("sync"), fn_name="hello")
b.attach_kprobe(event=b.get_syscall_fnname("sync"), fn_name="sync")
运行看看:
hello_sync
可以看到两个挂载函数都执行了,比起前面的例子可读性更强。
sync_timing.py
正如ChatGPT
告诉我们的,sys_sync
需要将所有数据写入磁盘,因此可能会导致系统性能下降。sys_sync
执行会花多少时间呢?如果有人短时间内多次运行sys_sync
,我们就需要给出警示,该如何实现呢?
实现这个需求,我们自然而然的会想到:得记录一下sys_sync
每次执行出现的时间,然后进行计算和提示。也即:「eBPF中如何保存数据呢?」
我们学习一下/tracing/sync_timing.py
,如果 1 秒之内多次使用了 sync
,它会告诉我们到底 do_sync
花了多少时间。也即如果使用了 sync;sync;sync
,后面两次 sync
会被打印出来:
#!/usr/bin/python
#
# sync_timing.py Trace time between syncs.
# For Linux, uses BCC, eBPF. Embedded C.
#
# Written as a basic example of tracing time between events.
#
# Copyright 2016 Netflix, Inc.
# Licensed under the Apache License, Version 2.0 (the "License")
from __future__ import print_function
from bcc import BPF
from bcc.utils import printb
# load BPF program
b = BPF(text="""
#include <uapi/linux/ptrace.h>
BPF_HASH(last); // 声明全局哈希 {0: xxx}
int do_trace(struct pt_regs *ctx) {
u64 ts, *tsp, delta, key = 0; // 由于只有一个键值对,所以key=0
// attempt to read stored timestamp
tsp = last.lookup(&key); // 寻找 key = 0的哈希值
if (tsp != NULL) { // 能够找到 也即tsp是0对应的值,也即上次执行sync的时间
delta = bpf_ktime_get_ns() - *tsp; // 计算两次执行的差值
if (delta < 1000000000) { // 差值过小,短时间内执行多次sync
// output if time is less than 1 second
bpf_trace_printk("%d\n", delta / 1000000); // 通过bpf_trace_printk提示
}
last.delete(&key); // 删除键值对,这是一个内核bug,已在4.8.10修复
}
// update stored timestamp
ts = bpf_ktime_get_ns(); // 获取当前时间,重新存储到0位置
last.update(&key, &ts);
return 0;
}
""")
b.attach_kprobe(event=b.get_syscall_fnname("sync"), fn_name="do_trace") # 挂载do_trace到sync
print("Tracing for quick sync's... Ctrl-C to end")
# format output
start = 0
while 1:
try:
(task, pid, cpu, flags, ts, ms) = b.trace_fields()
if start == 0:
start = ts
ts = ts - start
printb(b"At time %.2f s: multiple syncs detected, last %s ms ago" % (ts, ms))
except KeyboardInterrupt:
exit()
在这个程序中,我们需要了解到:
bpf_ktime_get_ns()
:返回表示当前时间的u64
类别的纳秒数;BPF_HASH(last)
:创建一个叫做last
的BPF
哈希,key
和value
都是默认的u64
类型。我们可以想象这是一个很大的哈希表,可以存储我们可能用到的数据,从而在多个不同的函数中使用;该函数可以在reference_guide查看更多信息;key = 0
:只有一个键值对,所以key
为零;last.lookup(&key)
:通过key
去全局哈希表里面找对应的值,找到的话返回值,否则返回空;last.delete(&key)
:从哈希中删除键值对,这是一个内核bug
,已经在4.8.10
中修复;last.update(&key, &ts)
:传入两个参数,覆盖更新原有的键值对;
运行看看:
sync_timing.py
sync_count.py
我们通过sync_timing
检测到了多次短时间内调用sync
的情况,那么分别调用了多少次呢?让我们来实现一个sync_count.py
。
需求是:统计sync
调用的次数以及短时间内调用sync
的次数。前者很容易理解,后者我们可以认为是被检测到sync
运行过快的次数。
我们该如何实现呢?显然这里我们需要做一些数据的保存工作,那么BPF_HASH
一定是需要用到的,看起来只要保存对应的数据就可以了,让我们试试吧。
我们可以复用BPF_HASH(last)
,在其中的key=1
和key=2
的位置分别保存两个数据:
u64 *all_count, *detected_count; // 指针
u64 all_count_key = 1;
u64 detected_count_key = 2;
u64 all_count_data = 0, detected_count_data = 0; // 值类型
接着,修改do_trace
函数,首先获取到原来的值:
// get sync all count
all_count = last.lookup(&all_count_key);
if (all_count != NULL) {
all_count_data = *all_count;
}
// get sync detected count
detected_count = last.lookup(&detected_count_key);
if (detected_count != NULL) {
detected_count_data = *detected_count;
} else {
detected_count_data = 0;
}
由于all_count
每次都会更新,我们直接更新:
// update sync all count
all_count_data = 1;
last.delete(&all_count_key);
last.update(&all_count_key, &all_count_data);
接着我们在检测到短时间内多次执行的逻辑中添加更新detected_count
的逻辑:
if (delta < 1000000000) {
// output if time is less than 1 second
bpf_trace_printk("%d\n", delta / 1000000);
// update detected_count_data
detected_count_data = 1;
last.delete(&detected_count_key);
last.update(&detected_count_key, &detected_count_data);
}
last.delete(&key);
由于我们使用bpf_trace_printk
作为输出函数,为了避免输出不一致的情况,我们添加一个变量来存储delta_time
,如果检测到了短时间内多次执行则delta_time
就是间隔时间,否则是零,然后统一输出:
u64 delta_time = 0;
if (tsp != NULL) {
delta = bpf_ktime_get_ns() - *tsp;
if (delta < 1000000000) {
// output if time is less than 1 second
delta_time = delta / 1000000;
// update detected_count_data
detected_count_data = 1;
last.delete(&detected_count_key);
last.update(&detected_count_key, &detected_count_data);
}
last.delete(&key);
}
bpf_trace_printk("%d,%d,%d\n", delta_time, all_count_data , detected_count_data);
bpf_trace_printk
的输出本质上是个字符串,所以我们需要自行解析:
(task, pid, cpu, flags, ts, all_data) = b.trace_fields()
delta_time, all_count, detected_count = all_data.split(b',')
if start == 0:
start = ts
ts = ts - start
if delta_time is not b'0':
printb(b"At time %.2f s: multiple syncs detected, last %s ms ago, all_count:%s, detected_count: %s" % (ts, delta_time, all_count, detected_count))
else:
printb(b"At time %.2f s: all_count:%s, detected_count: %s" % (ts, all_count, detected_count))
通过判断delta_time
是否为0
来区分两种情况并输出。让我们运行一下试试:
sync_count
看起来确实实现了我们的需求。
sync_count
代码语言:javascript复制#!/usr/bin/python
from __future__ import print_function
from bcc import BPF
from bcc.utils import printb
# 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;
u64 *all_count, *detected_count;
u64 all_count_key = 1;
u64 detected_count_key = 2;
u64 all_count_data = 0, detected_count_data = 0;
// get sync all count
all_count = last.lookup(&all_count_key);
if (all_count != NULL) {
all_count_data = *all_count;
}
// get sync detected count
detected_count = last.lookup(&detected_count_key);
if (detected_count != NULL) {
detected_count_data = *detected_count;
} else {
detected_count_data = 0;
}
// update sync all count
all_count_data = 1;
last.delete(&all_count_key);
last.update(&all_count_key, &all_count_data);
// attempt to read stored timestamp
tsp = last.lookup(&key);
u64 delta_time = 0;
if (tsp != NULL) {
delta = bpf_ktime_get_ns() - *tsp;
if (delta < 1000000000) {
// output if time is less than 1 second
delta_time = delta / 1000000;
// update detected_count_data
detected_count_data = 1;
last.delete(&detected_count_key);
last.update(&detected_count_key, &detected_count_data);
}
last.delete(&key);
}
// update stored timestamp
ts = bpf_ktime_get_ns();
last.update(&key, &ts);
bpf_trace_printk("%d,%d,%d\n", delta_time, all_count_data , detected_count_data);
return 0;
}
""")
b.attach_kprobe(event=b.get_syscall_fnname("sync"), fn_name="do_trace")
print("Tracing for quick sync's... Ctrl-C to end")
# format output
start = 0
while 1:
try:
(task, pid, cpu, flags, ts, all_data) = b.trace_fields()
delta_time, all_count, detected_count = all_data.split(b',')
if start == 0:
start = ts
ts = ts - start
if delta_time is not b'0':
printb(b"At time %.2f s: multiple syncs detected, last %s ms ago, all_count:%s, detected_count: %s" % (ts, delta_time, all_count, detected_count))
else:
printb(b"At time %.2f s: all_count:%s, detected_count: %s" % (ts, all_count, detected_count))
except KeyboardInterrupt:
exit()