Re: [PATCH v5 14/21] kprobes: Remove NMI context check

[Masami Hiramatsu]

On Mon, 2 Nov 2020 14:53:34 +0900
Masami Hiramatsu <mhiramat@xxxxxxxxxx> wrote:

> On Mon, 2 Nov 2020 14:11:38 +0900
> Masami Hiramatsu <mhiramat@xxxxxxxxxx> wrote:
> 
> > On Fri, 30 Oct 2020 21:38:31 -0400
> > Steven Rostedt <rostedt@xxxxxxxxxxx> wrote:
> > 
> > > On Sat, 29 Aug 2020 22:02:36 +0900
> > > Masami Hiramatsu <mhiramat@xxxxxxxxxx> wrote:
> > > 
> > > > Since the commit 9b38cc704e84 ("kretprobe: Prevent triggering
> > > > kretprobe from within kprobe_flush_task") sets a dummy current
> > > > kprobe in the trampoline handler by kprobe_busy_begin/end(),
> > > > it is not possible to run a kretprobe pre handler in kretprobe
> > > > trampoline handler context even with the NMI. If the NMI interrupts
> > > > a kretprobe_trampoline_handler() and it hits a kretprobe, the
> > > > 2nd kretprobe will detect recursion correctly and it will be
> > > > skipped.
> > > > This means we have almost no double-lock issue on kretprobes by NMI.
> > > > 
> > > > The last one point is in cleanup_rp_inst() which also takes
> > > > kretprobe_table_lock without setting up current kprobes.
> > > > So adding kprobe_busy_begin/end() there allows us to remove
> > > > in_nmi() check.
> > > > 
> > > > The above commit applies kprobe_busy_begin/end() on x86, but
> > > > now all arch implementation are unified to generic one, we can
> > > > safely remove the in_nmi() check from arch independent code.
> > > >
> > > 
> > > So are you saying that lockdep is lying?
> > > 
> > > Kprobe smoke test: started
> > > 
> > > ================================
> > > WARNING: inconsistent lock state
> > > 5.10.0-rc1-test+ #29 Not tainted
> > > --------------------------------
> > > inconsistent {INITIAL USE} -> {IN-NMI} usage.
> > > swapper/0/1 [HC1[1]:SC0[0]:HE0:SE1] takes:
> > > ffffffff82b07118 (&rp->lock){....}-{2:2}, at: pre_handler_kretprobe+0x4b/0x193
> > > {INITIAL USE} state was registered at:
> > >   lock_acquire+0x280/0x325
> > >   _raw_spin_lock+0x30/0x3f
> > >   recycle_rp_inst+0x3f/0x86
> > >   __kretprobe_trampoline_handler+0x13a/0x177
> > >   trampoline_handler+0x48/0x57
> > >   kretprobe_trampoline+0x2a/0x4f
> > >   kretprobe_trampoline+0x0/0x4f
> > >   init_kprobes+0x193/0x19d
> > >   do_one_initcall+0xf9/0x27e
> > >   kernel_init_freeable+0x16e/0x2b6
> > >   kernel_init+0xe/0x109
> > >   ret_from_fork+0x22/0x30
> > > irq event stamp: 1670
> > > hardirqs last  enabled at (1669): [<ffffffff811cc344>] slab_free_freelist_hook+0xb4/0xfd
> > > hardirqs last disabled at (1670): [<ffffffff81da0887>] exc_int3+0xae/0x10a
> > > softirqs last  enabled at (1484): [<ffffffff82000352>] __do_softirq+0x352/0x38d
> > > softirqs last disabled at (1471): [<ffffffff81e00f82>] asm_call_irq_on_stack+0x12/0x20
> > > 
> > > other info that might help us debug this:
> > >  Possible unsafe locking scenario:
> > > 
> > >        CPU0
> > >        ----
> > >   lock(&rp->lock);
> > >   <Interrupt>
> > >     lock(&rp->lock);
> > > 
> > >  *** DEADLOCK ***
> > > 
> > > no locks held by swapper/0/1.
> > > 
> > > stack backtrace:
> > > CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.10.0-rc1-test+ #29
> > > Hardware name: MSI MS-7823/CSM-H87M-G43 (MS-7823), BIOS V1.6 02/22/2014
> > > Call Trace:
> > >  dump_stack+0x7d/0x9f
> > >  print_usage_bug+0x1c0/0x1d3
> > >  lock_acquire+0x302/0x325
> > >  ? pre_handler_kretprobe+0x4b/0x193
> > >  ? stop_machine_from_inactive_cpu+0x120/0x120
> > >  _raw_spin_lock_irqsave+0x43/0x58
> > >  ? pre_handler_kretprobe+0x4b/0x193
> > >  pre_handler_kretprobe+0x4b/0x193
> > >  ? stop_machine_from_inactive_cpu+0x120/0x120
> > >  ? kprobe_target+0x1/0x16
> > >  kprobe_int3_handler+0xd0/0x109
> > >  exc_int3+0xb8/0x10a
> > >  asm_exc_int3+0x31/0x40
> > > RIP: 0010:kprobe_target+0x1/0x16
> > >  5d c3 cc
> > > RSP: 0000:ffffc90000033e00 EFLAGS: 00000246
> > > RAX: ffffffff8110ea77 RBX: 0000000000000001 RCX: ffffc90000033cb4
> > > RDX: 0000000000000231 RSI: 0000000000000000 RDI: 000000003ca57c35
> > > RBP: ffffc90000033e20 R08: 0000000000000000 R09: ffffffff8111d207
> > > R10: ffff8881002ab480 R11: ffff8881002ab480 R12: 0000000000000000
> > > R13: ffffffff82a52af0 R14: 0000000000000200 R15: ffff888100331130
> > >  ? register_kprobe+0x43c/0x492
> > >  ? stop_machine_from_inactive_cpu+0x120/0x120
> > >  ? kprobe_target+0x1/0x16
> > >  ? init_test_probes+0x2c6/0x38a
> > >  init_kprobes+0x193/0x19d
> > >  ? debugfs_kprobe_init+0xb8/0xb8
> > >  do_one_initcall+0xf9/0x27e
> > >  ? rcu_read_lock_sched_held+0x3e/0x75
> > >  ? init_mm_internals+0x27b/0x284
> > >  kernel_init_freeable+0x16e/0x2b6
> > >  ? rest_init+0x152/0x152
> > >  kernel_init+0xe/0x109
> > >  ret_from_fork+0x22/0x30
> > > Kprobe smoke test: passed successfully
> > > 
> > > Config attached.
> > 
> > Thanks for the report! Let me check what happen.
> 
> OK, confirmed. But this is actually false-positive report.
> 
> The lockdep reports rp->lock case between pre_handler_kretprobe()
> and recycle_rp_inst() from __kretprobe_trampoline_handler().
> Since kretprobe_trampoline_handler() sets current_kprobe,
> if other kprobes hits on same CPU, those are skipped. This means
> pre_handler_kretprobe() is not called while executing
> __kretprobe_trampoline_handler().
> 
> Actually, since this rp->lock is expected to be removed in the last
> patch in this series ([21/21]), I left this as is, but we might better
> to treat this case because the latter half of this series will be
> merged in 5.11.
> 
> Hmm, are there any way to tell lockdep this is safe?
> 

This can supress the warnings. After introducing the lockless patch,
we don't need this anymore.