eBPF Talk: 一行代码两行泪

文摘   2024-06-03 08:10   新加坡  

周一(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 工具后,实现了对 bpf2bpffreplace 的 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 分析过程

先看看桩程序的源码:

__noinline int
module3(struct xdp_md *ctx)
{
    volatile int retval = 33;

    bpf_tail_call_static(ctx, &prog_array, 3);

    return retval;
}
  1. __noinline 防止该函数被编译器内联优化掉了。
  2. volatile 强行将变量 retval 写到栈上。
  3. bpf_tail_call_static() 如果该函数没有被 freplace 替换掉,则进行 tailcall
  4. return retval; 从栈上读取 retval,然后返回给 caller;同时能阻止编译器对函数返回值的优化。

一切尽在源代码中。在项目的源代码中?非也。在内核源代码中?是也不是。

一切尽在机器码中。

使用 drgn-bpf[1] 找到那个桩程序和对应的 trampoline:

# 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

直接看桩程序的反汇编吧。

# 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 的反汇编。

# 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 的地方。

fexit on bpf2bpf

Kernel BUG 发生过程:

  1. trampoline 里没有使用 push rax 去缓存 tail_call_cnt
  2. trampoline 里 call 原 bpf prog 前,没有恢复 tail_call_cnt
  3. trampoline 里 call 原 bpf prog 前,rax 的值是不确定的。
  4. 桩程序里把 rax 当作 tail_call_cnt
  5. 桩程序里使用 tail_call_cntMAX_TAIL_CALL_CNT 对比时,tail_call_cnt 超出了限制。
  6. 桩程序里使用栈上保存的 retval 当作返回值返回了。

咦,这个 BUG 发生过程有点似曾相识:eBPF Talk: 内核 bpf 子系统贡献之修复 tailcall 无限循环。如果桩程序里的 tail_call_cnt 一直没超出 MAX_TAIL_CALL_CNT 的限制,就可以利用这个 BUG 构造一个无限循环。

  • bpf, x64: Fix tailcall infinite loop[2] since 6.7 kernel

好吧,这个 patch 其实也修复了这个 BUG,让 tail_call_cnt 正确地经过 trampoline 传递给桩程序。

白白错失又一个内核贡献的机会。

总结

由一行代码引发的一个 BUG,排查 BUG 的过程中触发了一个 kernel BUG,导致未能顺利地解决代码 BUG。

排查 BUG 搞得身心疲惫,一行代码两行泪


更多 XDP 资料,请加入「eBPF Talk」知识星球来学习《XDP 进阶手册》吧。

eBPF Talk 知识星球
参考资料
[1]

drgn-bpf: https://github.com/Asphaltt/drgn-bpf

[2]

bpf, x64: Fix tailcall infinite loop: https://github.com/torvalds/linux/commit/2b5dcb31a19a2e0acd869b12c9db9b2d696ef544

eBPF Talk
专注于 eBPF 技术,以及 Linux 网络上的 eBPF 技术应用