[syzbot] WARNING: suspicious RCU usage in get_signal

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: d2b6f8a1 Merge tag 'xfs-5.13-merge-3' of git://git.kernel...
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=123a56a5d00000
kernel config: https://syzkaller.appspot.com/x/.config?x=65c207250bba4efe
dashboard link: https://syzkaller.appspot.com/bug?extid=37fc8b84ffa2279d636d
userspace arch: i386

Unfortunately, I don't have any reproducer for this issue yet.

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+37fc8b...@syzkaller.appspotmail.com

=============================
WARNING: suspicious RCU usage
5.12.0-syzkaller #0 Not tainted
-----------------------------
kernel/sched/core.c:8304 Illegal context switch in RCU-sched read-side critical section!

other info that might help us debug this:


rcu_scheduler_active = 2, debug_locks = 0
no locks held by syz-executor.4/10430.

stack backtrace:
CPU: 0 PID: 10430 Comm: syz-executor.4 Not tainted 5.12.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:79 [inline]
dump_stack+0x141/0x1d7 lib/dump_stack.c:120
___might_sleep+0x266/0x2c0 kernel/sched/core.c:8304
try_to_freeze_unsafe include/linux/freezer.h:57 [inline]
try_to_freeze include/linux/freezer.h:67 [inline]
get_signal+0x14a/0x2150 kernel/signal.c:2613
arch_do_signal_or_restart+0x2a8/0x1eb0 arch/x86/kernel/signal.c:789
handle_signal_work kernel/entry/common.c:147 [inline]
exit_to_user_mode_loop kernel/entry/common.c:171 [inline]
exit_to_user_mode_prepare+0x171/0x280 kernel/entry/common.c:208
irqentry_exit_to_user_mode+0x5/0x40 kernel/entry/common.c:314
exc_page_fault+0xc6/0x180 arch/x86/mm/fault.c:1534
asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:577
RIP: 0023:0x8052207
Code: 0c 50 e8 ac 5a 01 00 83 c4 10 85 c0 0f 84 b9 01 00 00 65 f0 83 2d d8 ff ff ff 01 8b 5c 24 08 e8 6f f7 00 00 8b 4c 24 0c 8b 00 <8b> 71 50 89 41 54 85 c0 75 05 83 fe ff 74 19 6b 44 24 1c 34 8b 4c
RSP: 002b:00000000f5514640 EFLAGS: 00010283
RAX: 000000000000000e RBX: 0000000000000000 RCX: 0000000000000000
RDX: 00000000080521e4 RSI: 0000000000000005 RDI: 00000000080ea51d
RBP: 000000000819afc0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000296 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

[Peter Zijlstra]

On Thu, May 06, 2021 at 02:34:27PM -0700, syzbot wrote:
> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit: d2b6f8a1 Merge tag 'xfs-5.13-merge-3' of git://git.kernel...
> git tree: upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=123a56a5d00000
> kernel config: https://syzkaller.appspot.com/x/.config?x=65c207250bba4efe
> dashboard link: https://syzkaller.appspot.com/bug?extid=37fc8b84ffa2279d636d
> userspace arch: i386
>
> Unfortunately, I don't have any reproducer for this issue yet.
>
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+37fc8b...@syzkaller.appspotmail.com
>
> =============================
> WARNING: suspicious RCU usage
> 5.12.0-syzkaller #0 Not tainted
> -----------------------------
> kernel/sched/core.c:8304 Illegal context switch in RCU-sched read-side critical section!
>
> other info that might help us debug this:
>
>
> rcu_scheduler_active = 2, debug_locks = 0
> no locks held by syz-executor.4/10430.

Looks like this is a concurrent fail?, if !debug_locks (as per the above)
then RCU_LOCKDEP_WARN() should not trigger.

[Dmitry Vyukov]

FTR the log is here:
https://syzkaller.appspot.com/text?tag=CrashLog&x=123a56a5d00000

It contains 2 intermixed reports:

[ 289.896033][T10430] =============================
[ 289.896039][T10430] WARNING: suspicious RCU usage
[ 289.896046][T10430] 5.12.0-syzkaller #0 Not tainted
[ 289.898388][T13493] ======================================================
[ 289.898401][T13493] WARNING: possible circular locking dependency detected
[ 289.898410][T13493] 5.12.0-syzkaller #0 Not tainted
[ 289.898424][T13493] ------------------------------------------------------
[ 289.898432][T13493] syz-executor.0/13493 is trying to acquire lock:
[ 289.898448][T13493] ffff888019065ca0 (&bdev->bd_mutex){+.+.}-{3:3},
at: del_gendisk+0x250/0x9e0

[Paul E. McKenney]

This "suspicious RCU usage" false positive looks to be addressed by this
commit in -rcu, slated for the v5.14 merge window:

81a5e05455d4 ("rcu: Reject RCU_LOCKDEP_WARN() false positives")

So I suggest ignoring the "suspicious RCU usage" report in favor of the
"possible circular locking dependency detected" report.

Thanx, Paul

[Dmitry Vyukov]

Oh, I see, it's not merged yet.
In my memory we discussed it so long ago that I assumed it is fixed already.
Let's mark it as fixed then:

#syz fix: rcu: Reject RCU_LOCKDEP_WARN() false positives

Thanks for double checking.

[Paul E. McKenney]

It was a bit too late to make my pull request. I won't lose it. ;-)

Thanx, Paul