Re: [PATCH] tracing: Refuse fprobe if RCU is not watching

[Masami Hiramatsu (Google) <mhiramat@kernel.org>]

On Sun, 9 Apr 2023 20:45:39 +0800
Yafang Shao <laoar.shao@gmail.com> wrote:

> On Sun, Apr 9, 2023 at 7:55 PM Steven Rostedt <rostedt@goodmis.org> wrote:
> >
> > On Sun, 9 Apr 2023 13:32:12 +0800
> > Yafang Shao <laoar.shao@gmail.com> wrote:
> > >
> > > Hi Steven,
> > >
> > > When I was trying to attach fentry to preempt_count_{sub,add}, the
> > > kernel just crashed. The crash info as follows,
> > >
> > > [  867.843050] BUG: TASK stack guard page was hit at 0000000009d325cf
> > > (stack is 0000000046a46a15..00000000537e7b28)
> > > [  867.843064] stack guard page: 0000 [#1] PREEMPT SMP NOPTI
> > > [  867.843067] CPU: 8 PID: 11009 Comm: trace Kdump: loaded Not tainted 6.2.0+ #4
> > > [  867.843071] RIP: 0010:exc_int3+0x6/0xe0
> > > [  867.843078] Code: e9 a6 fe ff ff e8 6a 3d 00 00 66 2e 0f 1f 84 00
> > > 00 00 00 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 55 48 89
> > > e5 41 55 <41> 54 49 89 fc e8 10 11 00 00 85 c0 75 31 4c 89 e7 41 f6 84
> > > 24 88
> > > [  867.843080] RSP: 0018:ffffaaac44f1c000 EFLAGS: 00010093
> > > [  867.843083] RAX: ffffaaac44f1c018 RBX: 0000000000000000 RCX: ffffffff98e0102d
> > > [  867.843085] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffaaac44f1c018
> > > [  867.843086] RBP: ffffaaac44f1c008 R08: 0000000000000000 R09: 0000000000000000
> > > [  867.843087] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
> > > [  867.843089] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
> > > [  867.843092] FS:  00007f8af6fbe740(0000) GS:ffff96d77f800000(0000)
> > > knlGS:0000000000000000
> > > [  867.843094] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > > [  867.843096] CR2: ffffaaac44f1bff8 CR3: 0000000105a9c002 CR4: 0000000000770ee0
> > > [  867.843097] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > > [  867.843098] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> > > [  867.843099] PKRU: 55555554
> > > [  867.843100] Call Trace:
> > > [  867.843101]  <TASK>
> > > [  867.843104]  asm_exc_int3+0x3a/0x40
> > > [  867.843108] RIP: 0010:preempt_count_sub+0x1/0xa0
> > > [  867.843112] Code: c7 c7 40 06 ff 9a 48 89 e5 e8 8b c6 1d 00 5d c3
> > > cc cc cc cc 0f 1f 44 00 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90
> > > 90 90 cc <1f> 44 00 00 55 8b 0d 2c 60 f0 02 48 89 e5 85 c9 75 1b 65 8b
> > > 05 4e
> > > [  867.843113] RSP: 0018:ffffaaac44f1c0f0 EFLAGS: 00000002
> > > [  867.843115] RAX: 0000000000000001 RBX: ffff96d77f82c380 RCX: 0000000000000000
> > > [  867.843116] RDX: 0000000000000000 RSI: ffffffff9947d6fd RDI: 0000000000000001
> > > [  867.843117] RBP: ffffaaac44f1c108 R08: 0000000000000020 R09: 0000000000000000
> > > [  867.843118] R10: 0000000000000000 R11: 0000000040000000 R12: ffff96c886c3c000
> > > [  867.843119] R13: 0000000000000009 R14: ffff96c880050000 R15: ffff96c8800504b8
> > > [  867.843128]  ? preempt_count_sub+0x1/0xa0
> > > [  867.843131]  ? migrate_disable+0x77/0x90
> > > [  867.843135]  __bpf_prog_enter_recur+0x17/0x90
> > > [  867.843148]  bpf_trampoline_6442468108_0+0x2e/0x1000
> > > [  867.843154]  ? preempt_count_sub+0x1/0xa0
> > > [  867.843157]  preempt_count_sub+0x5/0xa0
> > > [  867.843159]  ? migrate_enable+0xac/0xf0
> > > [  867.843164]  __bpf_prog_exit_recur+0x2d/0x40
> > > [  867.843168]  bpf_trampoline_6442468108_0+0x55/0x1000
> > > ...
> > > [  867.843788]  preempt_count_sub+0x5/0xa0
> > [..]
> > > 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24
> > > 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 17 e0 2c 00 f7 d8 64 89
> > > 01 48
> > > [  867.845543] RSP: 002b:00007ffcf51a64e8 EFLAGS: 00000246 ORIG_RAX:
> > > 0000000000000141
> > > [  867.845546] RAX: ffffffffffffffda RBX: 00007ffcf51a65d0 RCX: 00007f8af60f8e29
> > > [  867.845547] RDX: 0000000000000030 RSI: 00007ffcf51a6500 RDI: 000000000000001c
> > > [  867.845549] RBP: 0000000000000018 R08: 0000000000000020 R09: 0000000000000000
> > > [  867.845550] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000006
> > > [  867.845551] R13: 0000000000000006 R14: 0000000000922010 R15: 0000000000000000
> > > [  867.845561]  </TASK>
> > >
> > > The reason is that we will call migrate_disable before entering bpf prog
> > > and call migrate_enable after bpf prog exits. In
> > > migrate_disable, preempt_count_{add,sub} will be called, so the bpf prog
> > > will end up with dead looping there. We can't avoid calling
> > > preempt_count_{add,sub} in this procedure, so we have to hide them
> > > from ftrace, then they can't be traced.
> > >
> > > So I think we'd better fix it with below change,  what do you think ?
> >
> > Sounds like a bug in BPF. ftrace has recursion protection (see
> > ftrace_test_recursion_trylock()).
> >
> 
> bpf trampoline (AKA. fentry) uses bpf_prog->active to avoid the
> recursion, but migrate_disable() is called before checking
> bpf_prog->active, because bpf_prog->active is a percpu value.

You can use ftrace_test_recursion_trylock() before using migrate_disable()
if you ensure the callback is only for fentry. Can you prepare a fentry
specific callback?

Thank you,

-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>