结合例子学习eBPF与bcc:初探

2023-11-01 17:09:56 浏览数 (2)

当你问ChatGPTeBPFbcc是什么?

eBPF是一种内核技术,它允许用户在不修改内核源代码的情况下,通过一种安全的、可编程的方式来扩展内核功能。BCC是一组用于eBPF的工具和库,它们使开发人员能够使用高级语言编写eBPF程序,从而更轻松地构建和部署内核跟踪和监控工具。

本文不会介绍eBPFbcc的由来和历史,而是会基于bcc文档中的例子来介绍与学习ebpfbcc

eBPFbcc后续简写为bcc。本文提到的例子均出现在bcc仓库examples下。

Hello World

让我们来看看计算机中不可避免的Hello World例子:

代码语言:javascript复制
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 0eBPF程序必需的组成部分;
  • .trace_point()bcc进程会通过这个方式读取trace_pipe的内容并打印;

这段代码的意思是追踪sys_clone这个系统调用,一旦该系统调用触发,就输出Hello, World!。这个程序被执行以后,会先将text='...'的内容注入到内核中,挂载到sys_clone这个函数开始的地方。内核每次执行sys_clone的时候,都会执行我们注入的函数,也即输出Hello, World!

如何查看全部的kprobe列表?

可以首先挂载debugfs

代码语言:javascript复制
mkdir debugfs
mount -t debugfs none debugfs/
cd debugfs
cat kprobe/list

或者直接通过:

代码语言:javascript复制
/sys/kernel/debug/kprobes/list

如下图所示:

kprobe

通过这种方式,我们可以得到已注册(registered)的kprobe列表,如果要查看可获得(available)的kprobe,可以通过:

代码语言:javascript复制
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

代码语言:javascript复制
#!/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的追踪,并且添加两个追踪函数:

代码语言:javascript复制
# 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 会被打印出来:

代码语言:javascript复制
#!/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):创建一个叫做lastBPF哈希,keyvalue都是默认的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=1key=2的位置分别保存两个数据:

代码语言:javascript复制
    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函数,首先获取到原来的值:

代码语言:javascript复制
// 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每次都会更新,我们直接更新:

代码语言:javascript复制
// update sync all count
all_count_data  = 1;
last.delete(&all_count_key);
last.update(&all_count_key, &all_count_data);

接着我们在检测到短时间内多次执行的逻辑中添加更新detected_count的逻辑:

代码语言:javascript复制
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就是间隔时间,否则是零,然后统一输出:

代码语言:javascript复制
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的输出本质上是个字符串,所以我们需要自行解析:

代码语言:javascript复制
        (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()

0 人点赞