文章讲述了如何使用BPFtrace工具监测用户程序中动态链接的函数，如open函数。通过分析程序的符号表和动态链接表，作者发现open等函数在运行时动态加载，从而使用bpftrace的uprobe和uretprobe功能来跟踪这些函数的使用情况。
在上一次实验中，通过profile工具获取了进程的火焰图，在火焰图中有大量的函数符号，所以这次实验想用bpftrace来监测程序中某个函数的使用情况。
这次使用一个稍稍复杂一些的测试代码：
#include <stdio.h>
#include <string.h>
#include <unistd.h>
#include <fcntl.h>
#include <sys/types.h>
#include <sys/stat.h>
int main() {
while (1) {
int fd = open("test.txt", O_CREAT | O_WRONLY | O_APPEND, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH);
if (fd == -1) {
perror("Error opening file");
return 1;
}
pid_t pid = getpid();
printf("Process ID: %d\n", pid);
const char* msg = "hello, world\n";
write(fd, msg, strlen(msg));
write(STDOUT_FILENO, msg, strlen(msg));
usleep(100000); // sleep for 0.1 seconds
close(fd);
}
return 0;
}
这个程序使用使用open调用读写文件，并输出进程的pid，每0.1s重复一次。
先通过 gcc -o test test.c 得到可执行文件test，再使用 bpftrace 工具获取其中的函数符号，由于是用户程序，所以使用uprobe，结果如下：
$sudo bpftrace -l 'uporbe:test:*'
uprobe:test:__do_global_dtors_aux
uprobe:test:_fini
uprobe:test:_init
uprobe:test:_start
uprobe:test:deregister_tm_clones
uprobe:test:frame_dummy
uprobe:test:main
uprobe:test:register_tm_clones
很奇怪的是，列出的函数挂载点中，并没有open函数，这是为什么呢？
先使用 nm 查看文件中的符号表，看一下文件中都有哪些符号：
$ objdump -tT ./test
./test: file format elf64-x86-64
SYMBOL TABLE:
0000000000000000 l df *ABS* 0000000000000000 Scrt1.o
000000000000038c l O .note.ABI-tag 0000000000000020 __abi_tag
0000000000000000 l df *ABS* 0000000000000000 crtstuff.c
0000000000001170 l F .text 0000000000000000 deregister_tm_clones
...
0000000000004018 g .bss 0000000000000000 _end
0000000000001140 g F .text 0000000000000026 _start
0000000000004010 g .bss 0000000000000000 __bss_start
0000000000001229 g F .text 00000000000000d3 main
0000000000000000 F *UND* 0000000000000000 open@GLIBC_2.2.5
0000000000000000 F *UND* 0000000000000000 perror@GLIBC_2.2.5
0000000000004010 g O .data 0000000000000000 .hidden __TMC_END__
0000000000000000 w *UND* 0000000000000000 _ITM_registerTMCloneTable
0000000000000000 w F *UND* 0000000000000000 __cxa_finalize@GLIBC_2.2.5
0000000000001000 g F .init 0000000000000000 .hidden _init
0000000000000000 F *UND* 0000000000000000 usleep@GLIBC_2.2.5
DYNAMIC SYMBOL TABLE:
0000000000000000 DF *UND* 0000000000000000 (GLIBC_2.34) __libc_start_main
0000000000000000 w D *UND* 0000000000000000 Base _ITM_deregisterTMCloneTable
0000000000000000 DF *UND* 0000000000000000 (GLIBC_2.2.5) write
0000000000000000 DF *UND* 0000000000000000 (GLIBC_2.2.5) getpid
0000000000000000 DF *UND* 0000000000000000 (GLIBC_2.2.5) strlen
0000000000000000 DF *UND* 0000000000000000 (GLIBC_2.2.5) printf
0000000000000000 DF *UND* 0000000000000000 (GLIBC_2.2.5) close
0000000000000000 w D *UND* 0000000000000000 Base __gmon_start__
0000000000000000 DF *UND* 0000000000000000 (GLIBC_2.2.5) open
0000000000000000 DF *UND* 0000000000000000 (GLIBC_2.2.5) perror
0000000000000000 w D *UND* 0000000000000000 Base _ITM_registerTMCloneTable
0000000000000000 DF *UND* 0000000000000000 (GLIBC_2.2.5) usleep
0000000000000000 w DF *UND* 0000000000000000 (GLIBC_2.2.5) __cxa_finalize
发现用bpftrace列出的符号都位于SYMBOL TABLE，这些符号是确定的静态符号；再观察下面的DYNAMIC SYMBOL TABLE，发现 open，getpid，printf这些符号都在这里。
这是因为这些符号都是运行时进行动态链接的，所以并不存在于test文件中，那应该怎么监测open函数呢？
既然open函数是动态链接的，那我们从test中找到对应的链接库，然后由监测test改为监测链接库不就好了。
通过ldd工具得到test文件中的链接库如下：
$ ldd ./test
linux-vdso.so.1 (0x00007ffe7a7f8000)
libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f67e4f03000)
/lib64/ld-linux-x86-64.so.2 (0x00007f67e513d000)
由之前从objdump得到的信息：0000000000000000 DF *UND* 0000000000000000 (GLIBC_2.2.5) open，可以判断open函数应该位于libc库里面，对应上面链接库的位置/lib/x86_64-linux-gnu/libc.so.6 。
接下来就可以编写bpftrace程序了，监测/lib/x86_64-linux-gnu/libc.so.6中的open函数：
$ sudo bpftrace -e 'uprobe:/lib/x86_64-linux-gnu/libc.so.6:open /comm=="test"/ { printf("Detected that test was using the open function, pid=%d\n", pid); }'
Detected that test was using the open function, pid=13674
Detected that test was using the open function, pid=13674
Detected that test was using the open function, pid=13674
...
这里采用的过滤条件是/comm=="test"/，即当执行进程由test创建时触发该挂载点。我们当然也可以使用pid作为过滤条件，但在容器或WSL中这样做可能监测不到test程序，因为进程自己看到的是namespace 下的pid，而 bpf 可以获取内核里面真实的 pid。
什么意思呢？在上面的bpftrace程序中，进程的pid为13674，这是bpf程序看到没有namespace条件下的pid，但是test实际的pid是多少呢？让我们看看test的输出：
$ ./test
hello, world
Process ID: 12809
hello, world
Process ID: 12809
...
它打印的自身的pid是12809，和bpf看到的不同，这个pid是进程在namespace下的pid。容器技术会采用namespace来划分资源，所以容易出现这种进程pid和bpf所看到的pid不一致的情况。
当采用/pid=="12809"/作为过滤条件时，很可能没有任何输出。
扩展内容
扩展一——统计open函数的调用时间
让我们看一个更复杂的例子，为了计算一个open函数的调用时间，我们需要分别获取函数的入口和返回点的时间戳，将两者相减获得函数的执行时间。由于是用户态程序，所以可以使用uretprobe编写bpftrace程序，如下：
$ sudo bpftrace -e 'uprobe:/lib/x86_64-linux-gnu/libc.so.6:open /comm=="test"/ { @start[tid] = nsecs; } uretprobe:/lib/x86_64-linux-gnu/libc.so.6:open /@start[tid]/ { @ns = hist(nsecs - @start[tid]); delete(@start[tid]); }'
@ns:
[8K, 16K) 5 |@@ |
[16K, 32K) 30 |@@@@@@@@@@@@@@@@ |
[32K, 64K) 96 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[64K, 128K) 1 | |
@start[529250]: 82101338270173
在程序test调用open函数的同时，系统中可能有大量的其他程序也在调用libc中的open函数，所以这里需要添加过滤条件/comm=="test"/（其实用pid作为过滤条件更好，毕竟pid是进程的唯一标识符）
这里有两个挂载点，一个是open函数的入口点：uprobe:/lib/x86_64-linux-gnu/libc.so.6:open，另一个位于open函数的返回位置：uretprobe:/lib/x86_64-linux-gnu/libc.so.6:open，入口位置使用一个名为start的map（或者说哈希表）来记录时间。
随后在出口位置，先用/@start[tid]/来判断线程号为tid的线程是否使用了open函数，如果没有，则@start[tid]为空值，条件不成立，则不会执行后面的过程。
否则表示该函数调用了open函数并将要返回，在返回点使用nsecs - @start[tid]计算调用open函数所花费的时间，并记录到一个hist的哈希表中。
最后通过delete(@start[tid])删除记录@satrt[tid]，确保第二个挂载点中/@start[tid]/做出正确判断。
在程序执行结束后，会打印各个map中的内容，从上面的结果中，可以看到open函数的执行时间大致在32微秒（32000纳秒）到64微秒之间。也可以使用lhist来获取更详细的时间分布：
$ sudo bpftrace -e 'uprobe:/lib/x86_64-linux-gnu/libc.so.6:open /comm=="test1"/ { @start[tid] = nsecs; } uretprobe:/lib/x86_64-linux-gnu/libc.so.6:open /@start[tid]/ { @ns = lhist(nsecs - @start[tid], 0, 60000, 4000); delete(@start[tid]); }'
Attaching 2 probes...
^C
@ns:
[8000, 12000) 1 | |
[12000, 16000) 3 |@@ |
[16000, 20000) 18 |@@@@@@@@@@@@@ |
[20000, 24000) 15 |@@@@@@@@@@@ |
[24000, 28000) 15 |@@@@@@@@@@@ |
[28000, 32000) 29 |@@@@@@@@@@@@@@@@@@@@@ |
[32000, 36000) 35 |@@@@@@@@@@@@@@@@@@@@@@@@@@ |
[36000, 40000) 70 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[40000, 44000) 61 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |
[44000, 48000) 48 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |
[48000, 52000) 4 |@@ |
[52000, 56000) 1 | |
[56000, 60000) 1 | |
[60000, ...) 9 |@@@@@@ |
@start[531035]: 82677229389246
lhist的使用可以参考lhist(): Linear Histogram，从上面的结果中，可以看到open函数的大部分时间开销在16~48微秒，有少数时间开销在60微秒以上。
扩展二——查看test文件中函数的执行顺序
前面通过sudo bpftrace -l 'uporbe:test:*' 了解到test文件下有8个挂载点，我们可以用bpftrace来查看他们的调用顺序：
$ sudo bpftrace -e 'uprobe:./test:* {printf("time:%d, pid:%d, probe:'%s'\n", nsecs, pid, probe);}' --unsafe
Attaching 8 probes...
time:1632067684, probe:uprobe:./test:_start
time:1632118273, probe:uprobe:./test:_init
time:1632124902, probe:uprobe:./test:frame_dummy
time:1632131074, probe:uprobe:./test:register_tm_clones
time:1632138484, probe:uprobe:./test:main
nsecs可以用于获取时间戳，可以看到test程序并不是直接执行main函数的，而是先执行_start，用chatgpt了解到各个函数的作用如下：
-
uprobe:./test:_start：_start函数是C/C++程序的入口点，它是程序开始执行的地方。在执行程序时，操作系统将控制权交给该函数，并在执行完成后进入main函数。 -
uprobe:./test:_init：_init函数在一些特定的系统架构中是一种特殊的初始化函数。它通常在_start函数之后调用，用于执行一些全局初始化工作，例如设置全局变量的初始值。 -
uprobe:./test:frame_dummy：frame_dummy是GCC编译器生成的一个辅助函数。它在程序中使用了C++静态全局对象构造函数时，用于调用这些构造函数。这个函数的作用是执行全局对象的构造工作。 -
uprobe:./test:register_tm_clones：register_tm_clones函数是GCC编译器为支持线程本地存储(Thread-Local Storage, TLS)而生成的函数。它注册线程本地存储相关的操作，用于在创建新线程时进行相应的处理。 -
uprobe:./test:main：main函数是C/C++程序的主函数，是程序的逻辑入口点。在执行完前面的初始化工作后，操作系统将控制权交给main函数。在main函数内部，程序将执行我们编写的主要逻辑，完成程序的功能。
综上所述，各个函数的作用分别为程序的入口点（_start），初始化全局数据（_init），执行全局对象的构造（frame_dummy），注册线程本地存储相关操作（register_tm_clones），以及执行主要逻辑（main）。
这里有一个要注意的点，在sudo bpftrace -l 'uporbe:test:*'中，test表示当前路径下的test程序，这里是正常的，但是如果要执行bpftrace，挂载点中需要改为程序的路径即./test。所以使用sudo bpftrace -e 'uprobe:test:* ...' 并不生效，需要使用sudo bpftrace -e 'uprobe:./test:* ...'。
扫一扫
1254
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
