周一（5 月 27 日）上班在验证个功能的时候，发现功能异常了。
周一排查了一整天，心都要滴血了，都没能排查出功能异常的原因。
周二排查出原因了，是同事修改了某个 bpf 函数的默认返回值。不过，在对 bpf 程序进行 trace 时，却没有拿到这个异常的返回值，这又排查了一整天。
周三排查出原因了，这是个 bpf 子系统的 BUG；不过，在最新内核里，已经被修复了。
背景
项目是一个超级复杂的 XDP 项目，采用了 bpf2bpf + freplace 混合 bpf2bpf + tailcall 的方式实现了模块化。参考 eBPF Talk: eBPF 程序模块化与单测构想。
其中，bpf2bpf 子程序用来当作 XDP 模块的桩；该桩要么被 freplace 替换成 XDP 模块，要么使用 tailcall 去调 XDP 模块。为什么不能统一成 freplace 呢？因为 eBPF Talk: tailcall in freplace 有 BUG。
发生异常的模块使用的桩是 bpf2bpf + tailcall 实现的。
此时，对 bpf2bpf 子程序使用 fentry + fexit 进行 trace。fentry/fexit 的资料，请看 eBPF Talk: trampoline on x86。
对 bpf2bpf 子程序进行 trace，请看 eBPF Talk: trace bpf2bpf 函数调用。
能否对 freplace 程序进行 trace？请看 eBPF Talk: trace freplace 程序。
直接对 tailcall 进行 trace？
排查过程
改进了内部的 XDP trace 工具后，实现了对 bpf2bpf 和 freplace 的 trace 功能；如此，便能够对 XDP 模块进行精准 trace 了。
对所有 XDP 模块同时使用 fentry + fexit 进行 trace，发现其中有个模块的返回值是 33（该值是 bpf2bpf 桩没有按预期运行的默认返回值）。
如果桩程序按预期运行，预期应该拿到 255 这个返回值；噢，这个就是同事改错的地方。预期应该拿到 XDP_PASS/XDP_TX/XDP_DROP/XDP_REDIRECT 的。我是在 review 代码时，发现了这个错误的地方。
不过，即使我修正了这里，使用 fexit 进行 trace 时，拿到的返回值还是 33。这是为什么呢？如果不使用 fentry/fexit，就没问题了。
kernel BUG 分析过程
先看看桩程序的源码：
1
2
3
4
5
6
7
8
9
|
__noinline int
module3(struct xdp_md *ctx)
{
volatile int retval = 33;
bpf_tail_call_static(ctx, &prog_array, 3);
return retval;
}
|
__noinline 防止该函数被编译器内联优化掉了。volatile 强行将变量 retval 写到栈上。bpf_tail_call_static() 如果该函数没有被 freplace 替换掉，则进行 tailcall。return retval; 从栈上读取 retval，然后返回给 caller；同时能阻止编译器对函数返回值的优化。
一切尽在源代码中。在项目的源代码中？非也。在内核源代码中？是也不是。
一切尽在机器码中。
使用 drgn-bpf 找到那个桩程序和对应的 trampoline：
1
2
3
4
5
6
7
8
9
10
11
|
# drgn ./tools/bpf_inspect.py p
26: BPF_PROG_TYPE_XDP xdp_xxx bpf_prog_8715bbbd4b4ee80f_xdp_dispatcher 0xffffffffc02e433c tail_call_reachable
// ...
4: 0 BPF_PROG_TYPE_XDP xdp_xxx bpf_prog_e62ce70b7576e225_F 0xffffffffc1009620
# drgn ./tools/bpf_inspect.py l
47: BPF_LINK_TYPE_TRACING
linked prog: 106 BPF_PROG_TYPE_TRACING fexit_xdp bpf_prog_fcc2f82f74950a24_fexit_xdp 0xffffffffc10aa71c
target prog: 26 BPF_PROG_TYPE_XDP xdp_xxx bpf_prog_8715bbbd4b4ee80f_xdp_xxx 0xffffffffc02e433c tail_call_reachable
target func: module3
current image: 0xffffffffc10b0000 bpf_trampoline_111669149702_1 0xffffffffc10b0000
|
直接看桩程序的反汇编吧。
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
|
# gdb -q -c /proc/kcore -ex 'disas/r 0xffffffffc100bb58,+1000' -ex 'quit'
Dump of assembler code from 0xffffffffc100bb58 to 0xffffffffc100bc0c:
// call trampoline of fentry/fexit
0xffffffffc100bb58: e8 a3 44 0a 00 callq 0xffffffffc10b0000
// nop2
0xffffffffc100bb5d: 66 90 xchg %ax,%ax
// prepare stack frame
0xffffffffc100bb5f: 55 push %rbp
0xffffffffc100bb60: 48 89 e5 mov %rsp,%rbp
// reserve 8 bytes stack space
0xffffffffc100bb63: 48 81 ec 08 00 00 00 sub $0x8,%rsp
// push tail_call_cnt to stack
0xffffffffc100bb6a: 50 push %rax
// push callee saved regs
0xffffffffc100bb6b: 53 push %rbx
0xffffffffc100bb6c: 41 55 push %r13
// cache the first arg to rbx
0xffffffffc100bb6e: 48 89 fb mov %rdi,%rbx
// save retval(0x1f, 33) to stack
0xffffffffc100bb71: bf 1f 00 00 00 mov $0x21,%edi
0xffffffffc100bb76: 89 7d fc mov %edi,-0x4(%rbp)
// &prog_array
0xffffffffc100bb79: 49 bd 00 72 9c d4 09 8d ff ff movabs $0xffff8d09d49c7200,%r13
// prepare args for bpf_tail_call()
0xffffffffc100bb83: 48 89 df mov %rbx,%rdi
0xffffffffc100bb86: 4c 89 ee mov %r13,%rsi
0xffffffffc100bb89: ba 04 00 00 00 mov $0x3,%edx
// load tail_call_cnt from stack
0xffffffffc100bb8e: 8b 85 f4 ff ff ff mov -0xc(%rbp),%eax
// jmp 0xffffffffc100bbb7 if tail_call_cnt > 32
0xffffffffc100bb94: 83 f8 20 cmp $0x20,%eax
0xffffffffc100bb97: 77 1e ja 0xffffffffc100bbb7
// inc tail_call_cnt
0xffffffffc100bb99: 83 c0 01 add $0x1,%eax
// store tail_call_cnt to stack
0xffffffffc100bb9c: 89 85 f4 ff ff ff mov %eax,-0xc(%rbp)
// nops5
0xffffffffc100bba2: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
// pop callee saved regs
0xffffffffc100bba7: 41 5d pop %r13
0xffffffffc100bba9: 5b pop %rbx
// pop tail_call_cnt
0xffffffffc100bbaa: 58 pop %rax
// restore stack frame
0xffffffffc100bbab: 48 81 c4 08 00 00 00 add $0x8,%rsp
// jmp tailcall tgt bpf prog
0xffffffffc100bbb2: e9 98 f7 02 00 jmpq 0xffffffffc103b34f
// load retval from stack
0xffffffffc100bbb7: 8b 45 fc mov -0x4(%rbp),%eax
// pop callee saved regs
0xffffffffc100bbba: 41 5d pop %r13
0xffffffffc100bbbc: 5b pop %rbx
// leave
0xffffffffc100bbbd: c9 leaveq
// ret
0xffffffffc100bbbe: c3 retq
0xffffffffc100bbbf: cc int3
|
留意其中的 rax，即 tail_call_cnt。
再来看 fentry/fexit 的 trampoline 的反汇编。
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
|
# gdb -q -c /proc/kcore -ex 'disas/r 0xffffffffc10b0000,+1000' -ex 'quit'
Dump of assembler code from 0xffffffffc10b0000 to 0xffffffffc10b0258:
// prepare stack frame
0xffffffffc10b0000: 55 push %rbp
0xffffffffc10b0001: 48 89 e5 mov %rsp,%rbp
// reserve stack space
0xffffffffc10b0004: 48 83 ec 10 sub $0x10,%rsp
// push callee saved regs
0xffffffffc10b0008: 53 push %rbx
// save the first arg to stack
0xffffffffc10b0009: 48 89 7d f0 mov %rdi,-0x10(%rbp)
0xffffffffc10b000d: 48 bf 00 a8 b3 73 19 8d ff ff movabs $0xffff8d1973b3a800,%rdi
0xffffffffc10b0017: e8 04 65 9a c0 callq 0xffffffff81a56520
0xffffffffc10b001c: 48 bf 00 50 24 47 e3 b9 ff ff movabs $0xffffb9e347245000,%rdi
0xffffffffc10b0026: e8 c5 63 9a c0 callq 0xffffffff81a563f0
0xffffffffc10b002b: 48 89 c3 mov %rax,%rbx
0xffffffffc10b002e: 48 85 c0 test %rax,%rax
0xffffffffc10b0031: 74 09 je 0xffffffffc10b003c
0xffffffffc10b0033: 48 8d 7d f0 lea -0x10(%rbp),%rdi
0xffffffffc10b0037: e8 0c aa fc ff callq 0xffffffffc107aa48
0xffffffffc10b003c: 48 bf 00 50 24 47 e3 b9 ff ff movabs $0xffffb9e347245000,%rdi
0xffffffffc10b0046: 48 89 de mov %rbx,%rsi
0xffffffffc10b0049: e8 e2 63 9a c0 callq 0xffffffff81a56430
// restore the first arg
0xffffffffc10b004e: 48 8b 7d f0 mov -0x10(%rbp),%rdi
// call the tgt bpf prog
0xffffffffc10b0052: e8 06 bb f5 ff callq 0xffffffffc100bb5d
// save retval of bpf prog to stack
0xffffffffc10b0057: 48 89 45 f8 mov %rax,-0x8(%rbp)
0xffffffffc10b005b: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
0xffffffffc10b0060: 48 bf 00 90 41 47 e3 b9 ff ff movabs $0xffffb9e347419000,%rdi
0xffffffffc10b006a: e8 81 63 9a c0 callq 0xffffffff81a563f0
0xffffffffc10b006f: 48 89 c3 mov %rax,%rbx
0xffffffffc10b0072: 48 85 c0 test %rax,%rax
0xffffffffc10b0075: 74 09 je 0xffffffffc10b0080
0xffffffffc10b0077: 48 8d 7d f0 lea -0x10(%rbp),%rdi
0xffffffffc10b007b: e8 9c a6 ff ff callq 0xffffffffc10aa71c
0xffffffffc10b0080: 48 bf 00 90 41 47 e3 b9 ff ff movabs $0xffffb9e347419000,%rdi
0xffffffffc10b008a: 48 89 de mov %rbx,%rsi
0xffffffffc10b008d: e8 9e 63 9a c0 callq 0xffffffff81a56430
0xffffffffc10b0092: 48 bf 00 a8 b3 73 19 8d ff ff movabs $0xffff8d1973b3a800,%rdi
0xffffffffc10b009c: e8 af 64 9a c0 callq 0xffffffff81a56550
0xffffffffc10b00a1: 48 8b 45 f8 mov -0x8(%rbp),%rax
0xffffffffc10b00a5: 5b pop %rbx
0xffffffffc10b00a6: c9 leaveq
0xffffffffc10b00a7: 48 83 c4 08 add $0x8,%rsp
0xffffffffc10b00ab: c3 retq
|
留意其中调用原 bpf prog 的地方。
Kernel BUG 发生过程：
- trampoline 里没有使用
push rax 去缓存 tail_call_cnt。
- trampoline 里
call 原 bpf prog 前，没有恢复 tail_call_cnt。
- trampoline 里
call 原 bpf prog 前，rax 的值是不确定的。
- 桩程序里把
rax 当作 tail_call_cnt。
- 桩程序里使用
tail_call_cnt 跟 MAX_TAIL_CALL_CNT 对比时，tail_call_cnt 超出了限制。
- 桩程序里使用栈上保存的
retval 当作返回值返回了。
咦，这个 BUG 发生过程有点似曾相识：eBPF Talk: 内核 bpf 子系统贡献之修复 tailcall 无限循环。如果桩程序里的 tail_call_cnt 一直没超出 MAX_TAIL_CALL_CNT 的限制，就可以利用这个 BUG 构造一个无限循环。
好吧，这个 patch 其实也修复了这个 BUG，让 tail_call_cnt 正确地经过 trampoline 传递给桩程序。
白白错失又一个内核贡献的机会。
总结
由一行代码引发的一个 BUG，排查 BUG 的过程中触发了一个 kernel BUG，导致未能顺利地解决代码 BUG。
排查 BUG 搞得身心疲惫，一行代码两行泪。
更多 XDP 资料，请加入「eBPF Talk」知识星球来学习《XDP 进阶手册》吧。
