Re: WARNING: bad unlock balance in rcu_lock_release

[Eric Biggers]

On Tue, Oct 15, 2019 at 09:56:31AM +0200, Jan Kara wrote:
> On Sun 13-10-19 14:28:06, syzbot wrote:
> > syzbot has found a reproducer for the following crash on:
> > 
> > HEAD commit:    da940012 Merge tag 'char-misc-5.4-rc3' of git://git.kernel..
> > git tree:       upstream
> > console output: https://syzkaller.appspot.com/x/log.txt?x=12cfdf4f600000
> > kernel config:  https://syzkaller.appspot.com/x/.config?x=2d2fd92a28d3e50
> > dashboard link: https://syzkaller.appspot.com/bug?extid=f9545ab3e9f85cd43a3a
> > compiler:       clang version 9.0.0 (/home/glider/llvm/clang
> > 80fee25776c2fb61e74c1ecb1a523375c2500b69)
> > syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=148c9fc7600000
> > C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=100d3f8b600000
> > 
> > IMPORTANT: if you fix the bug, please add the following tag to the commit:
> > Reported-by: syzbot+f9545ab3e9f85cd43a3a@xxxxxxxxxxxxxxxxxxxxxxxxx
> > 
> > =====================================
> > WARNING: bad unlock balance detected!
> > 5.4.0-rc2+ #0 Not tainted
> > -------------------------------------
> > syz-executor111/7877 is trying to release lock (rcu_callback) at:
> > [<ffffffff81612bd4>] rcu_lock_release+0x4/0x20 include/linux/rcupdate.h:212
> > but there are no more locks to release!
> 
> Hum, this is really weird. Look:
> 
> > other info that might help us debug this:
> > 1 lock held by syz-executor111/7877:
> >  #0: ffff8880a3c600d8 (&type->s_umount_key#42/1){+.+.}, at:
> > alloc_super+0x15f/0x790 fs/super.c:229
> > 
> > stack backtrace:
> > CPU: 1 PID: 7877 Comm: syz-executor111 Not tainted 5.4.0-rc2+ #0
> > Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
> > Google 01/01/2011
> > Call Trace:
> >  <IRQ>
> >  __dump_stack lib/dump_stack.c:77 [inline]
> >  dump_stack+0x1d8/0x2f8 lib/dump_stack.c:113
> >  print_unlock_imbalance_bug+0x20b/0x240 kernel/locking/lockdep.c:4008
> >  __lock_release kernel/locking/lockdep.c:4244 [inline]
> >  lock_release+0x473/0x780 kernel/locking/lockdep.c:4506
> >  rcu_lock_release+0x1c/0x20 include/linux/rcupdate.h:214
> >  __rcu_reclaim kernel/rcu/rcu.h:223 [inline]
> 
> __rcu_reclaim_kernel() has:
> 
>         rcu_lock_acquire(&rcu_callback_map);
>         if (__is_kfree_rcu_offset(offset)) {
>                 trace_rcu_invoke_kfree_callback(rn, head, offset);
>                 kfree((void *)head - offset);
>                 rcu_lock_release(&rcu_callback_map);
>                 return true;
>         } else {
>                 trace_rcu_invoke_callback(rn, head);
>                 f = head->func;
>                 WRITE_ONCE(head->func, (rcu_callback_t)0L);
>                 f(head);
>                 rcu_lock_release(&rcu_callback_map);
>                 return false;
>         }
> 
> So RCU locking is clearly balanced there. The only possibility I can see
> how this can happen is that RCU callback we have called actually released
> rcu_callback_map but grepping the kernel doesn't show any other place where
> that would get released? Confused.
> 
> But apparently there is even a reproducer for this so we could dig
> further...
> 

It's probably the same cause as "WARNING: bad unlock balance in rcu_core", see
the thread: https://lkml.kernel.org/linux-fsdevel/000000000000c0bffa0586795098@xxxxxxxxxx/T/#u
Looks related to the lockdep_off() in ntfs_fill_super().

- Eric