linux-block.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [syzbot] possible deadlock in del_gendisk
@ 2021-04-13 17:33 syzbot
  2021-04-13 17:41 ` Steven Rostedt
  2021-06-07 10:56 ` [syzbot] possible deadlock in del_gendisk Tetsuo Handa
  0 siblings, 2 replies; 25+ messages in thread
From: syzbot @ 2021-04-13 17:33 UTC (permalink / raw)
  To: akpm, axboe, bp, hpa, jmattson, joro, kvm, linux-block,
	linux-kernel, mark.rutland, masahiroy, mingo, pbonzini, peterz,
	rafael.j.wysocki, rostedt, seanjc, syzkaller-bugs, tglx,
	vkuznets, wanpengli, will, x86

Hello,

syzbot found the following issue on:

HEAD commit:    e99d8a84 Add linux-next specific files for 20210409
git tree:       linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=13b01681d00000
kernel config:  https://syzkaller.appspot.com/x/.config?x=7cd69574979bfeb7
dashboard link: https://syzkaller.appspot.com/bug?extid=61e04e51b7ac86930589
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=148265d9d00000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=16a981a1d00000

The issue was bisected to:

commit 997acaf6b4b59c6a9c259740312a69ea549cc684
Author: Mark Rutland <mark.rutland@arm.com>
Date:   Mon Jan 11 15:37:07 2021 +0000

    lockdep: report broken irq restoration

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=16a7e77ed00000
final oops:     https://syzkaller.appspot.com/x/report.txt?x=15a7e77ed00000
console output: https://syzkaller.appspot.com/x/log.txt?x=11a7e77ed00000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+61e04e51b7ac86930589@syzkaller.appspotmail.com
Fixes: 997acaf6b4b5 ("lockdep: report broken irq restoration")

======================================================
WARNING: possible circular locking dependency detected
5.12.0-rc6-next-20210409-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor104/8440 is trying to acquire lock:
ffff888016e9dca0 (&bdev->bd_mutex){+.+.}-{3:3}, at: del_gendisk+0x250/0x9e0 block/genhd.c:618

but task is already holding lock:
ffffffff8c7d9430 (bdev_lookup_sem){++++}-{3:3}, at: del_gendisk+0x222/0x9e0 block/genhd.c:616

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (bdev_lookup_sem){++++}-{3:3}:
       down_write+0x92/0x150 kernel/locking/rwsem.c:1406
       del_gendisk+0x222/0x9e0 block/genhd.c:616
       loop_remove drivers/block/loop.c:2191 [inline]
       loop_control_ioctl drivers/block/loop.c:2291 [inline]
       loop_control_ioctl+0x40d/0x4f0 drivers/block/loop.c:2251
       vfs_ioctl fs/ioctl.c:48 [inline]
       __do_sys_ioctl fs/ioctl.c:753 [inline]
       __se_sys_ioctl fs/ioctl.c:739 [inline]
       __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:739
       do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
       entry_SYSCALL_64_after_hwframe+0x44/0xae

-> #1 (loop_ctl_mutex){+.+.}-{3:3}:
       __mutex_lock_common kernel/locking/mutex.c:949 [inline]
       __mutex_lock+0x139/0x1120 kernel/locking/mutex.c:1096
       lo_open+0x1a/0x130 drivers/block/loop.c:1890
       __blkdev_get+0x135/0xa30 fs/block_dev.c:1305
       blkdev_get_by_dev fs/block_dev.c:1457 [inline]
       blkdev_get_by_dev+0x26c/0x600 fs/block_dev.c:1425
       blkdev_open+0x154/0x2b0 fs/block_dev.c:1554
       do_dentry_open+0x4b9/0x11b0 fs/open.c:826
       do_open fs/namei.c:3361 [inline]
       path_openat+0x1c09/0x27d0 fs/namei.c:3494
       do_filp_open+0x190/0x3d0 fs/namei.c:3521
       do_sys_openat2+0x16d/0x420 fs/open.c:1187
       do_sys_open fs/open.c:1203 [inline]
       __do_sys_open fs/open.c:1211 [inline]
       __se_sys_open fs/open.c:1207 [inline]
       __x64_sys_open+0x119/0x1c0 fs/open.c:1207
       do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
       entry_SYSCALL_64_after_hwframe+0x44/0xae

-> #0 (&bdev->bd_mutex){+.+.}-{3:3}:
       check_prev_add kernel/locking/lockdep.c:2938 [inline]
       check_prevs_add kernel/locking/lockdep.c:3061 [inline]
       validate_chain kernel/locking/lockdep.c:3676 [inline]
       __lock_acquire+0x2a17/0x5230 kernel/locking/lockdep.c:4902
       lock_acquire kernel/locking/lockdep.c:5512 [inline]
       lock_acquire+0x1ab/0x740 kernel/locking/lockdep.c:5477
       __mutex_lock_common kernel/locking/mutex.c:949 [inline]
       __mutex_lock+0x139/0x1120 kernel/locking/mutex.c:1096
       del_gendisk+0x250/0x9e0 block/genhd.c:618
       loop_remove drivers/block/loop.c:2191 [inline]
       loop_control_ioctl drivers/block/loop.c:2291 [inline]
       loop_control_ioctl+0x40d/0x4f0 drivers/block/loop.c:2251
       vfs_ioctl fs/ioctl.c:48 [inline]
       __do_sys_ioctl fs/ioctl.c:753 [inline]
       __se_sys_ioctl fs/ioctl.c:739 [inline]
       __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:739
       do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
       entry_SYSCALL_64_after_hwframe+0x44/0xae

other info that might help us debug this:

Chain exists of:
  &bdev->bd_mutex --> loop_ctl_mutex --> bdev_lookup_sem

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(bdev_lookup_sem);
                               lock(loop_ctl_mutex);
                               lock(bdev_lookup_sem);
  lock(&bdev->bd_mutex);

 *** DEADLOCK ***

2 locks held by syz-executor104/8440:
 #0: ffffffff8ca5f148 (loop_ctl_mutex){+.+.}-{3:3}, at: loop_control_ioctl+0x7b/0x4f0 drivers/block/loop.c:2257
 #1: ffffffff8c7d9430 (bdev_lookup_sem){++++}-{3:3}, at: del_gendisk+0x222/0x9e0 block/genhd.c:616

stack backtrace:
CPU: 1 PID: 8440 Comm: syz-executor104 Not tainted 5.12.0-rc6-next-20210409-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
 check_noncircular+0x25f/0x2e0 kernel/locking/lockdep.c:2129
 check_prev_add kernel/locking/lockdep.c:2938 [inline]
 check_prevs_add kernel/locking/lockdep.c:3061 [inline]
 validate_chain kernel/locking/lockdep.c:3676 [inline]
 __lock_acquire+0x2a17/0x5230 kernel/locking/lockdep.c:4902
 lock_acquire kernel/locking/lockdep.c:5512 [inline]
 lock_acquire+0x1ab/0x740 kernel/locking/lockdep.c:5477
 __mutex_lock_common kernel/locking/mutex.c:949 [inline]
 __mutex_lock+0x139/0x1120 kernel/locking/mutex.c:1096
 del_gendisk+0x250/0x9e0 block/genhd.c:618
 loop_remove drivers/block/loop.c:2191 [inline]
 loop_control_ioctl drivers/block/loop.c:2291 [inline]
 loop_control_ioctl+0x40d/0x4f0 drivers/block/loop.c:2251
 vfs_ioctl fs/ioctl.c:48 [inline]
 __do_sys_ioctl fs/ioctl.c:753 [inline]
 __se_sys_ioctl fs/ioctl.c:739 [inline]
 __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:739
 do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x43ee49
Code: 28 c3 e8 2a 14 00 00 66 2e 0f 1f 84 00 00 00 00 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 c7 c1 c0 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fff4d86c238 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000400488 RCX: 000000000043ee49
RDX: 0000000000000002 RSI: 0000000000004c81 RDI: 0000000000000003
RBP: 0000000000402e30 R08: 0000000000000000 R09: 0000000000400488
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000402ec0
R13: 0000000000000000 R14: 00000000004ac018 R15: 0000000000400488


---
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 syzkaller@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
For information about bisection process see: https://goo.gl/tpsmEJ#bisection
syzbot can test patches for this issue, for details see:
https://goo.gl/tpsmEJ#testing-patches

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-04-13 17:33 [syzbot] possible deadlock in del_gendisk syzbot
@ 2021-04-13 17:41 ` Steven Rostedt
  2021-04-13 17:43   ` Steven Rostedt
  2021-06-07 10:56 ` [syzbot] possible deadlock in del_gendisk Tetsuo Handa
  1 sibling, 1 reply; 25+ messages in thread
From: Steven Rostedt @ 2021-04-13 17:41 UTC (permalink / raw)
  To: syzbot
  Cc: akpm, axboe, bp, hpa, jmattson, joro, kvm, linux-block,
	linux-kernel, mark.rutland, masahiroy, mingo, pbonzini, peterz,
	rafael.j.wysocki, seanjc, syzkaller-bugs, tglx, vkuznets,
	wanpengli, will, x86

On Tue, 13 Apr 2021 10:33:19 -0700
syzbot <syzbot+61e04e51b7ac86930589@syzkaller.appspotmail.com> wrote:

> Hello,
> 
> syzbot found the following issue on:
> 
> HEAD commit:    e99d8a84 Add linux-next specific files for 20210409
> git tree:       linux-next
> console output: https://syzkaller.appspot.com/x/log.txt?x=13b01681d00000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=7cd69574979bfeb7
> dashboard link: https://syzkaller.appspot.com/bug?extid=61e04e51b7ac86930589
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=148265d9d00000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=16a981a1d00000
> 
> The issue was bisected to:
> 
> commit 997acaf6b4b59c6a9c259740312a69ea549cc684
> Author: Mark Rutland <mark.rutland@arm.com>
> Date:   Mon Jan 11 15:37:07 2021 +0000
> 
>     lockdep: report broken irq restoration

As the below splats look like it has nothing to do with this patch, and
this patch will add a WARN() if there's broken logic somewhere, I bet the
bisect got confused (if it is automated and does a panic_on_warning),
because it will panic for broken code that his patch detects.

That is, the bisect was confused because it was triggering on two different
issues. One that triggered the reported splat below, and another that this
commit detects and warns on.

Hence, the bisect failed.

-- Steve


> 
> bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=16a7e77ed00000
> final oops:     https://syzkaller.appspot.com/x/report.txt?x=15a7e77ed00000
> console output: https://syzkaller.appspot.com/x/log.txt?x=11a7e77ed00000
> 
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+61e04e51b7ac86930589@syzkaller.appspotmail.com
> Fixes: 997acaf6b4b5 ("lockdep: report broken irq restoration")
> 
> ======================================================
> WARNING: possible circular locking dependency detected
> 5.12.0-rc6-next-20210409-syzkaller #0 Not tainted
> ------------------------------------------------------
> syz-executor104/8440 is trying to acquire lock:
> ffff888016e9dca0 (&bdev->bd_mutex){+.+.}-{3:3}, at: del_gendisk+0x250/0x9e0 block/genhd.c:618
> 
> but task is already holding lock:
> ffffffff8c7d9430 (bdev_lookup_sem){++++}-{3:3}, at: del_gendisk+0x222/0x9e0 block/genhd.c:616
> 
> which lock already depends on the new lock.
> 
> 
> the existing dependency chain (in reverse order) is:
> 
> -> #2 (bdev_lookup_sem){++++}-{3:3}:  
>        down_write+0x92/0x150 kernel/locking/rwsem.c:1406
>        del_gendisk+0x222/0x9e0 block/genhd.c:616
>        loop_remove drivers/block/loop.c:2191 [inline]
>        loop_control_ioctl drivers/block/loop.c:2291 [inline]
>        loop_control_ioctl+0x40d/0x4f0 drivers/block/loop.c:2251
>        vfs_ioctl fs/ioctl.c:48 [inline]
>        __do_sys_ioctl fs/ioctl.c:753 [inline]
>        __se_sys_ioctl fs/ioctl.c:739 [inline]
>        __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:739
>        do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
>        entry_SYSCALL_64_after_hwframe+0x44/0xae
> 
> -> #1 (loop_ctl_mutex){+.+.}-{3:3}:  
>        __mutex_lock_common kernel/locking/mutex.c:949 [inline]
>        __mutex_lock+0x139/0x1120 kernel/locking/mutex.c:1096
>        lo_open+0x1a/0x130 drivers/block/loop.c:1890
>        __blkdev_get+0x135/0xa30 fs/block_dev.c:1305
>        blkdev_get_by_dev fs/block_dev.c:1457 [inline]
>        blkdev_get_by_dev+0x26c/0x600 fs/block_dev.c:1425
>        blkdev_open+0x154/0x2b0 fs/block_dev.c:1554
>        do_dentry_open+0x4b9/0x11b0 fs/open.c:826
>        do_open fs/namei.c:3361 [inline]
>        path_openat+0x1c09/0x27d0 fs/namei.c:3494
>        do_filp_open+0x190/0x3d0 fs/namei.c:3521
>        do_sys_openat2+0x16d/0x420 fs/open.c:1187
>        do_sys_open fs/open.c:1203 [inline]
>        __do_sys_open fs/open.c:1211 [inline]
>        __se_sys_open fs/open.c:1207 [inline]
>        __x64_sys_open+0x119/0x1c0 fs/open.c:1207
>        do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
>        entry_SYSCALL_64_after_hwframe+0x44/0xae
> 
> -> #0 (&bdev->bd_mutex){+.+.}-{3:3}:  
>        check_prev_add kernel/locking/lockdep.c:2938 [inline]
>        check_prevs_add kernel/locking/lockdep.c:3061 [inline]
>        validate_chain kernel/locking/lockdep.c:3676 [inline]
>        __lock_acquire+0x2a17/0x5230 kernel/locking/lockdep.c:4902
>        lock_acquire kernel/locking/lockdep.c:5512 [inline]
>        lock_acquire+0x1ab/0x740 kernel/locking/lockdep.c:5477
>        __mutex_lock_common kernel/locking/mutex.c:949 [inline]
>        __mutex_lock+0x139/0x1120 kernel/locking/mutex.c:1096
>        del_gendisk+0x250/0x9e0 block/genhd.c:618
>        loop_remove drivers/block/loop.c:2191 [inline]
>        loop_control_ioctl drivers/block/loop.c:2291 [inline]
>        loop_control_ioctl+0x40d/0x4f0 drivers/block/loop.c:2251
>        vfs_ioctl fs/ioctl.c:48 [inline]
>        __do_sys_ioctl fs/ioctl.c:753 [inline]
>        __se_sys_ioctl fs/ioctl.c:739 [inline]
>        __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:739
>        do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
>        entry_SYSCALL_64_after_hwframe+0x44/0xae
> 
> other info that might help us debug this:
> 
> Chain exists of:
>   &bdev->bd_mutex --> loop_ctl_mutex --> bdev_lookup_sem
> 
>  Possible unsafe locking scenario:
> 
>        CPU0                    CPU1
>        ----                    ----
>   lock(bdev_lookup_sem);
>                                lock(loop_ctl_mutex);
>                                lock(bdev_lookup_sem);
>   lock(&bdev->bd_mutex);
> 
>  *** DEADLOCK ***
> 
> 2 locks held by syz-executor104/8440:
>  #0: ffffffff8ca5f148 (loop_ctl_mutex){+.+.}-{3:3}, at: loop_control_ioctl+0x7b/0x4f0 drivers/block/loop.c:2257
>  #1: ffffffff8c7d9430 (bdev_lookup_sem){++++}-{3:3}, at: del_gendisk+0x222/0x9e0 block/genhd.c:616
> 
> stack backtrace:
> CPU: 1 PID: 8440 Comm: syz-executor104 Not tainted 5.12.0-rc6-next-20210409-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
>  check_noncircular+0x25f/0x2e0 kernel/locking/lockdep.c:2129
>  check_prev_add kernel/locking/lockdep.c:2938 [inline]
>  check_prevs_add kernel/locking/lockdep.c:3061 [inline]
>  validate_chain kernel/locking/lockdep.c:3676 [inline]
>  __lock_acquire+0x2a17/0x5230 kernel/locking/lockdep.c:4902
>  lock_acquire kernel/locking/lockdep.c:5512 [inline]
>  lock_acquire+0x1ab/0x740 kernel/locking/lockdep.c:5477
>  __mutex_lock_common kernel/locking/mutex.c:949 [inline]
>  __mutex_lock+0x139/0x1120 kernel/locking/mutex.c:1096
>  del_gendisk+0x250/0x9e0 block/genhd.c:618
>  loop_remove drivers/block/loop.c:2191 [inline]
>  loop_control_ioctl drivers/block/loop.c:2291 [inline]
>  loop_control_ioctl+0x40d/0x4f0 drivers/block/loop.c:2251
>  vfs_ioctl fs/ioctl.c:48 [inline]
>  __do_sys_ioctl fs/ioctl.c:753 [inline]
>  __se_sys_ioctl fs/ioctl.c:739 [inline]
>  __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:739
>  do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
>  entry_SYSCALL_64_after_hwframe+0x44/0xae
> RIP: 0033:0x43ee49
> Code: 28 c3 e8 2a 14 00 00 66 2e 0f 1f 84 00 00 00 00 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 c7 c1 c0 ff ff ff f7 d8 64 89 01 48
> RSP: 002b:00007fff4d86c238 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
> RAX: ffffffffffffffda RBX: 0000000000400488 RCX: 000000000043ee49
> RDX: 0000000000000002 RSI: 0000000000004c81 RDI: 0000000000000003
> RBP: 0000000000402e30 R08: 0000000000000000 R09: 0000000000400488
> R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000402ec0
> R13: 0000000000000000 R14: 00000000004ac018 R15: 0000000000400488
> 
> 
> ---
> 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 syzkaller@googlegroups.com.
> 
> syzbot will keep track of this issue. See:
> https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
> For information about bisection process see: https://goo.gl/tpsmEJ#bisection
> syzbot can test patches for this issue, for details see:
> https://goo.gl/tpsmEJ#testing-patches


^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-04-13 17:41 ` Steven Rostedt
@ 2021-04-13 17:43   ` Steven Rostedt
  2021-04-13 18:24     ` Dmitry Vyukov
  0 siblings, 1 reply; 25+ messages in thread
From: Steven Rostedt @ 2021-04-13 17:43 UTC (permalink / raw)
  To: syzbot
  Cc: akpm, axboe, bp, hpa, jmattson, joro, kvm, linux-block,
	linux-kernel, mark.rutland, masahiroy, mingo, pbonzini, peterz,
	rafael.j.wysocki, seanjc, syzkaller-bugs, tglx, vkuznets,
	wanpengli, will, x86

On Tue, 13 Apr 2021 13:41:47 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> As the below splats look like it has nothing to do with this patch, and
> this patch will add a WARN() if there's broken logic somewhere, I bet the
> bisect got confused (if it is automated and does a panic_on_warning),
> because it will panic for broken code that his patch detects.
> 
> That is, the bisect was confused because it was triggering on two different
> issues. One that triggered the reported splat below, and another that this
> commit detects and warns on.

Is it possible to update the the bisect to make sure that if it is failing
on warnings, to make sure the warnings are somewhat related, before decided
that its the same bug?

-- Steve

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-04-13 17:43   ` Steven Rostedt
@ 2021-04-13 18:24     ` Dmitry Vyukov
  2021-04-13 18:40       ` Steven Rostedt
  0 siblings, 1 reply; 25+ messages in thread
From: Dmitry Vyukov @ 2021-04-13 18:24 UTC (permalink / raw)
  To: Steven Rostedt, syzkaller
  Cc: syzbot, Andrew Morton, Jens Axboe, Borislav Petkov,
	H. Peter Anvin, Jim Mattson, Joerg Roedel, KVM list, linux-block,
	LKML, Mark Rutland, masahiroy, Ingo Molnar, Paolo Bonzini,
	Peter Zijlstra, rafael.j.wysocki, Sean Christopherson,
	syzkaller-bugs, Thomas Gleixner, Vitaly Kuznetsov, Wanpeng Li,
	Will Deacon, the arch/x86 maintainers

On Tue, Apr 13, 2021 at 7:43 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Tue, 13 Apr 2021 13:41:47 -0400
> Steven Rostedt <rostedt@goodmis.org> wrote:
>
> > As the below splats look like it has nothing to do with this patch, and
> > this patch will add a WARN() if there's broken logic somewhere, I bet the
> > bisect got confused (if it is automated and does a panic_on_warning),
> > because it will panic for broken code that his patch detects.
> >
> > That is, the bisect was confused because it was triggering on two different
> > issues. One that triggered the reported splat below, and another that this
> > commit detects and warns on.
>
> Is it possible to update the the bisect to make sure that if it is failing
> on warnings, to make sure the warnings are somewhat related, before decided
> that its the same bug?

It does not seem to be feasible, bugs manifest differently in both
space and time. Also even if we somehow conclude the crash we see is
different, it says nothing about the original bug. For more data see:
https://groups.google.com/g/syzkaller/c/sR8aAXaWEF4/m/tTWYRgvmAwAJ

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-04-13 18:24     ` Dmitry Vyukov
@ 2021-04-13 18:40       ` Steven Rostedt
  2021-04-13 18:43         ` Steven Rostedt
  0 siblings, 1 reply; 25+ messages in thread
From: Steven Rostedt @ 2021-04-13 18:40 UTC (permalink / raw)
  To: Dmitry Vyukov
  Cc: syzkaller, syzbot, Andrew Morton, Jens Axboe, Borislav Petkov,
	H. Peter Anvin, Jim Mattson, Joerg Roedel, KVM list, linux-block,
	LKML, Mark Rutland, masahiroy, Ingo Molnar, Paolo Bonzini,
	Peter Zijlstra, rafael.j.wysocki, Sean Christopherson,
	syzkaller-bugs, Thomas Gleixner, Vitaly Kuznetsov, Wanpeng Li,
	Will Deacon, the arch/x86 maintainers

On Tue, 13 Apr 2021 20:24:00 +0200
Dmitry Vyukov <dvyukov@google.com> wrote:

> On Tue, Apr 13, 2021 at 7:43 PM Steven Rostedt <rostedt@goodmis.org> wrote:
> >
> > On Tue, 13 Apr 2021 13:41:47 -0400
> > Steven Rostedt <rostedt@goodmis.org> wrote:
> >  
> > > As the below splats look like it has nothing to do with this patch, and
> > > this patch will add a WARN() if there's broken logic somewhere, I bet the
> > > bisect got confused (if it is automated and does a panic_on_warning),
> > > because it will panic for broken code that his patch detects.
> > >
> > > That is, the bisect was confused because it was triggering on two different
> > > issues. One that triggered the reported splat below, and another that this
> > > commit detects and warns on.  
> >
> > Is it possible to update the the bisect to make sure that if it is failing
> > on warnings, to make sure the warnings are somewhat related, before decided
> > that its the same bug?  
> 
> It does not seem to be feasible, bugs manifest differently in both
> space and time. Also even if we somehow conclude the crash we see is
> different, it says nothing about the original bug. For more data see:
> https://groups.google.com/g/syzkaller/c/sR8aAXaWEF4/m/tTWYRgvmAwAJ

Sure, but if you trigger a lockdep bug, lockdep bugs are usually very
similar in all instances. It usually will include the same locks, or at
least be the same type of lockdep bug (where some types are related).

If the bisect saw an issue before and at this commit, I would think it
didn't trigger a lockdep bug at all, and simply triggered a warning.

In fact, according to:

  https://syzkaller.appspot.com/x/report.txt?x=15a7e77ed00000

That's exactly what it did.

That is, if the original bug is a lockdep warning, you should only be
interested in lockdep warnings (at a minimum). The final bug here had:

------------[ cut here ]------------
raw_local_irq_restore() called with IRQs enabled
WARNING: CPU: 0 PID: 8777 at kernel/locking/irqflag-debug.c:9 warn_bogus_irq_restore kernel/locking/irqflag-debug.c:9 [inline]
WARNING: CPU: 0 PID: 8777 at kernel/locking/irqflag-debug.c:9 warn_bogus_irq_restore+0x1d/0x20 kernel/locking/irqflag-debug.c:7
Modules linked in:
CPU: 0 PID: 8777 Comm: syz-executor.1 Not tainted 5.11.0-rc2-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:warn_bogus_irq_restore kernel/locking/irqflag-debug.c:9 [inline]
RIP: 0010:warn_bogus_irq_restore+0x1d/0x20 kernel/locking/irqflag-debug.c:7
Code: 51 00 e9 3f fe ff ff cc cc cc cc cc cc 80 3d e0 b4 ce 0a 00 74 01 c3 48 c7 c7 60 f5 8a 88 c6 05 cf b4 ce 0a 01 e8 17 01 a4 06 <0f> 0b c3 48 c7 c0 a0 46 4d 8e 53 48 89 fb 48 ba 00 00 00 00 00 fc
RSP: 0018:ffffc900017bf9f8 EFLAGS: 00010286
RAX: 0000000000000000 RBX: ffff8881477b2040 RCX: 0000000000000000
RDX: 0000000000000002 RSI: 0000000000000004 RDI: fffff520002f7f31
RBP: 0000000000000246 R08: 0000000000000001 R09: ffff8880b9e2015b
R10: ffffed10173c402b R11: 0000000000000001 R12: 0000000000000003
R13: ffffed1028ef6408 R14: 0000000000000001 R15: ffff8880b9e359c0
FS:  00000000017b8400(0000) GS:ffff8880b9e00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00000000017c1848 CR3: 0000000010920000 CR4: 00000000001506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 kvm_wait arch/x86/kernel/kvm.c:860 [inline]
 kvm_wait+0xc3/0xe0 arch/x86/kernel/kvm.c:837
 pv_wait arch/x86/include/asm/paravirt.h:564 [inline]
 pv_wait_head_or_lock kernel/locking/qspinlock_paravirt.h:470 [inline]
 __pv_queued_spin_lock_slowpath+0x8b8/0xb40 kernel/locking/qspinlock.c:508
 pv_queued_spin_lock_slowpath arch/x86/include/asm/paravirt.h:554 [inline]
 queued_spin_lock_slowpath arch/x86/include/asm/qspinlock.h:51 [inline]
 queued_spin_lock include/asm-generic/qspinlock.h:85 [inline]
 do_raw_spin_lock+0x200/0x2b0 kernel/locking/spinlock_debug.c:113
 spin_lock include/linux/spinlock.h:354 [inline]
 ext4_lock_group fs/ext4/ext4.h:3379 [inline]
 __ext4_new_inode+0x2da2/0x44d0 fs/ext4/ialloc.c:1187
 ext4_mkdir+0x298/0x910 fs/ext4/namei.c:2793
 vfs_mkdir+0x413/0x660 fs/namei.c:3652
 do_mkdirat+0x1eb/0x250 fs/namei.c:3675
 do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
 entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x465567
Code: 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 53 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007ffe00ad69f8 EFLAGS: 00000202 ORIG_RAX: 0000000000000053
RAX: ffffffffffffffda RBX: 00007ffe00ad6a90 RCX: 0000000000465567
RDX: 0000000000000000 RSI: 00000000000001ff RDI: 00007ffe00ad6a90
RBP: 00007ffe00ad6a6c R08: 0000000000000000 R09: 0000000000000006
R10: 00007ffe00ad6794 R11: 0000000000000202 R12: 0000000000000032
R13: 000000000006549a R14: 0000000000000002 R15: 00007ffe00ad6ad0



Which shows a WARN was triggered, and totally unrelated to what you were
bisecting.

Just matching types of warnings (lockdep to lockdep, or WARN_ON to WARN_ON)
would help reduce the number of bogus bisects you are having.

-- Steve

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-04-13 18:40       ` Steven Rostedt
@ 2021-04-13 18:43         ` Steven Rostedt
  2021-04-16  7:51           ` Bisections with different bug manifestations Dmitry Vyukov
  0 siblings, 1 reply; 25+ messages in thread
From: Steven Rostedt @ 2021-04-13 18:43 UTC (permalink / raw)
  To: Dmitry Vyukov
  Cc: syzkaller, syzbot, Andrew Morton, Jens Axboe, Borislav Petkov,
	H. Peter Anvin, Jim Mattson, Joerg Roedel, KVM list, linux-block,
	LKML, Mark Rutland, masahiroy, Ingo Molnar, Paolo Bonzini,
	Peter Zijlstra, rafael.j.wysocki, Sean Christopherson,
	syzkaller-bugs, Thomas Gleixner, Vitaly Kuznetsov, Wanpeng Li,
	Will Deacon, the arch/x86 maintainers

On Tue, 13 Apr 2021 14:40:09 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> ------------[ cut here ]------------
> raw_local_irq_restore() called with IRQs enabled
> WARNING: CPU: 0 PID: 8777 at kernel/locking/irqflag-debug.c:9 warn_bogus_irq_restore kernel/locking/irqflag-debug.c:9 [inline]
> WARNING: CPU: 0 PID: 8777 at kernel/locking/irqflag-debug.c:9 warn_bogus_irq_restore+0x1d/0x20 kernel/locking/irqflag-debug.c:7

In fact, when you have the above, which is a WARN() with text:

 "raw_local_irq_restore() called with IRQs enabled"

It is pretty much guaranteed that all triggers of this bug will have the
above warning with the same text.

-- Steve


^ permalink raw reply	[flat|nested] 25+ messages in thread

* Bisections with different bug manifestations
  2021-04-13 18:43         ` Steven Rostedt
@ 2021-04-16  7:51           ` Dmitry Vyukov
  2021-04-16 13:13             ` Steven Rostedt
  0 siblings, 1 reply; 25+ messages in thread
From: Dmitry Vyukov @ 2021-04-16  7:51 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: syzkaller, syzbot, Andrew Morton, Jens Axboe, Borislav Petkov,
	H. Peter Anvin, Jim Mattson, Joerg Roedel, KVM list, linux-block,
	LKML, Mark Rutland, masahiroy, Ingo Molnar, Paolo Bonzini,
	Peter Zijlstra, rafael.j.wysocki, Sean Christopherson,
	syzkaller-bugs, Thomas Gleixner, Vitaly Kuznetsov, Wanpeng Li,
	Will Deacon, the arch/x86 maintainers

On Tue, Apr 13, 2021 at 8:43 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Tue, 13 Apr 2021 14:40:09 -0400
> Steven Rostedt <rostedt@goodmis.org> wrote:
>
> > ------------[ cut here ]------------
> > raw_local_irq_restore() called with IRQs enabled
> > WARNING: CPU: 0 PID: 8777 at kernel/locking/irqflag-debug.c:9 warn_bogus_irq_restore kernel/locking/irqflag-debug.c:9 [inline]
> > WARNING: CPU: 0 PID: 8777 at kernel/locking/irqflag-debug.c:9 warn_bogus_irq_restore+0x1d/0x20 kernel/locking/irqflag-debug.c:7
>
> In fact, when you have the above, which is a WARN() with text:
>
>  "raw_local_irq_restore() called with IRQs enabled"
>
> It is pretty much guaranteed that all triggers of this bug will have the
> above warning with the same text.

This looks nice on paper and looking at only 1 bisection log. But
unfortunately in practice theory and practice are different...

This was discussed at length multiple times:
https://groups.google.com/g/syzkaller/search?q=bisection+different+manifestations
https://groups.google.com/g/syzkaller-bugs/c/nFeC8-UG1gg/m/y6gUEsvAAgAJ
https://groups.google.com/g/syzkaller/c/sR8aAXaWEF4/m/tTWYRgvmAwAJ
https://groups.google.com/g/syzkaller/c/9NdprHsGBqo/m/Yj9uWRDgBQAJ

If you look at substantial base of bisection logs, you will find lots
of cases where bug types, functions don't match. Kernel crashes
differently even on the same revision. And obviously things change if
you change revisions. Also if you see presumably a different bug, what
does it say regarding the original bug.

I would very much like to improve automatic bisection quality, but it
does not look trivial at all.

Some random examples where, say, your hypothesis of WARN-to-WARN,
BUG-to-BUG does not hold even on the same kernel revision (add to this
different revisions and the fact that a different bug does not give
info regarding the original bug):

run #0: crashed: KASAN: use-after-free Read in fuse_dev_do_read
run #1: crashed: WARNING in request_end
run #2: crashed: KASAN: use-after-free Read in fuse_dev_do_read
run #3: OK
run #4: OK

run #0: crashed: KASAN: slab-out-of-bounds Read in __ip_append_data
run #1: crashed: inconsistent lock state in rhashtable_walk_enter
run #2: crashed: inconsistent lock state in rhashtable_walk_enter
run #3: crashed: inconsistent lock state in rhashtable_walk_enter
run #4: crashed: inconsistent lock state in rhashtable_walk_enter
run #5: crashed: inconsistent lock state in rhashtable_walk_enter
run #6: crashed: inconsistent lock state in rhashtable_walk_enter
run #7: crashed: kernel BUG at arch/x86/mm/physaddr.c:LINE!
run #8: crashed: inconsistent lock state in rhashtable_walk_enter
run #9: crashed: inconsistent lock state in rhashtable_walk_enter

run #0: crashed: kernel BUG at arch/x86/mm/physaddr.c:LINE!
run #1: crashed: inconsistent lock state in rhashtable_walk_enter
run #2: crashed: inconsistent lock state in rhashtable_walk_enter
run #3: crashed: inconsistent lock state in rhashtable_walk_enter
run #4: crashed: inconsistent lock state in rhashtable_walk_enter
run #5: crashed: kernel BUG at arch/x86/mm/physaddr.c:LINE!
run #6: crashed: inconsistent lock state in rhashtable_walk_enter
run #7: crashed: kernel BUG at arch/x86/mm/physaddr.c:LINE!
run #8: crashed: inconsistent lock state in rhashtable_walk_enter
run #9: crashed: inconsistent lock state in rhashtable_walk_enter

run #0: crashed: KASAN: use-after-free Read in __vb2_perform_fileio
run #1: crashed: KASAN: use-after-free Write in __vb2_cleanup_fileio
run #2: crashed: KASAN: use-after-free Read in __vb2_perform_fileio
run #3: crashed: KASAN: use-after-free Read in __vb2_perform_fileio
run #4: crashed: INFO: task hung in vivid_stop_generating_vid_cap
run #5: crashed: INFO: task hung in vivid_stop_generating_vid_cap
run #6: crashed: INFO: task hung in vivid_stop_generating_vid_cap
run #7: crashed: INFO: task hung in vivid_stop_generating_vid_cap
run #8: crashed: INFO: task hung in vivid_stop_generating_vid_cap
run #9: crashed: INFO: task hung in vivid_stop_generating_vid_cap

run #0: crashed: general protection fault in sctp_assoc_rwnd_increase
run #1: crashed: general protection fault in sctp_ulpevent_free
run #2: crashed: general protection fault in sctp_assoc_rwnd_increase
run #3: crashed: general protection fault in sctp_assoc_rwnd_increase
run #4: crashed: general protection fault in sctp_assoc_rwnd_increase
run #5: crashed: general protection fault in sctp_assoc_rwnd_increase
run #6: crashed: general protection fault in sctp_assoc_rwnd_increase
run #7: crashed: general protection fault in sctp_assoc_rwnd_increase

run #0: crashed: general protection fault in sctp_assoc_rwnd_increase
run #1: crashed: general protection fault in sctp_assoc_rwnd_increase
run #2: crashed: general protection fault in sctp_assoc_rwnd_increase
run #3: crashed: general protection fault in sctp_assoc_rwnd_increase
run #4: crashed: general protection fault in corrupted
run #5: crashed: general protection fault in sctp_assoc_rwnd_increase
run #6: crashed: general protection fault in sctp_assoc_rwnd_increase
run #7: crashed: general protection fault in corrupted

run #0: crashed: INFO: rcu detected stall in corrupted
run #1: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #2: crashed: INFO: rcu detected stall in sys_sendfile64
run #3: crashed: INFO: rcu detected stall in corrupted
run #4: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #5: crashed: INFO: rcu detected stall in corrupted
run #6: crashed: INFO: rcu detected stall in corrupted
run #7: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #8: crashed: INFO: rcu detected stall in sys_sendfile64
run #9: crashed: INFO: rcu detected stall in ext4_file_write_iter

run #0: crashed: INFO: rcu detected stall in sys_sendfile64
run #1: crashed: INFO: rcu detected stall in corrupted
run #2: crashed: INFO: rcu detected stall in corrupted
run #3: crashed: INFO: rcu detected stall in sys_sendfile64
run #4: crashed: INFO: rcu detected stall in corrupted
run #5: crashed: INFO: rcu detected stall in corrupted
run #6: crashed: INFO: rcu detected stall in corrupted
run #7: crashed: INFO: rcu detected stall in corrupted
run #8: crashed: INFO: rcu detected stall in sys_sendfile64
run #9: crashed: INFO: rcu detected stall in corrupted

run #0: crashed: INFO: rcu detected stall in rw_verify_area
run #1: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #2: crashed: INFO: rcu detected stall in corrupted
run #3: crashed: INFO: rcu detected stall in corrupted
run #4: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #5: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #6: crashed: INFO: rcu detected stall in corrupted
run #7: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #8: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #9: crashed: INFO: rcu detected stall in rw_verify_area

run #0: crashed: INFO: rcu detected stall in ext4_file_write_iter
run #1: crashed: INFO: rcu detected stall in corrupted
run #2: crashed: INFO: rcu detected stall in sys_sendfile64
run #3: crashed: INFO: rcu detected stall in sys_sendfile64
run #4: crashed: INFO: rcu detected stall in corrupted
run #5: crashed: INFO: rcu detected stall in sys_sendfile64
run #6: crashed: INFO: rcu detected stall in sys_sendfile64
run #7: crashed: INFO: rcu detected stall in corrupted
run #8: crashed: INFO: rcu detected stall in corrupted
run #9: crashed: INFO: rcu detected stall in sys_sendfile64

run #0: crashed: KASAN: use-after-free Read in link_path_walk
run #1: crashed: KASAN: use-after-free Read in link_path_walk
run #2: crashed: KASAN: use-after-free Read in trailing_symlink
run #3: crashed: KASAN: use-after-free Read in trailing_symlink
run #4: crashed: KASAN: use-after-free Read in trailing_symlink
run #5: crashed: KASAN: use-after-free Read in link_path_walk
run #6: crashed: KASAN: use-after-free Read in link_path_walk
run #7: crashed: KASAN: use-after-free Read in link_path_walk
run #8: crashed: KASAN: use-after-free Read in trailing_symlink
run #9: crashed: KASAN: use-after-free Read in trailing_symlink

run #0: crashed: BUG: unable to handle kernel NULL pointer dereference
in mrvl_setup
run #1: crashed: BUG: unable to handle kernel NULL pointer dereference
in mrvl_setup
run #2: crashed: BUG: unable to handle kernel NULL pointer dereference
in mrvl_setup
run #3: crashed: BUG: unable to handle kernel NULL pointer dereference
in mrvl_setup
run #4: crashed: WARNING: ODEBUG bug in corrupted
run #5: crashed: BUG: unable to handle kernel NULL pointer dereference
in mrvl_setup
run #6: crashed: BUG: unable to handle kernel NULL pointer dereference
in mrvl_setup
run #7: crashed: BUG: unable to handle kernel NULL pointer dereference
in mrvl_setup
run #8: crashed: BUG: unable to handle kernel NULL pointer dereference
in mrvl_setup
run #9: crashed: BUG: unable to handle kernel NULL pointer dereference
in mrvl_setup

run #0: crashed: KASAN: use-after-free Read in delayed_uprobe_remove
run #1: crashed: KASAN: use-after-free Read in delayed_uprobe_remove
run #2: crashed: general protection fault in delayed_uprobe_remove
run #3: crashed: KASAN: use-after-free Read in delayed_uprobe_remove
run #4: crashed: general protection fault in delayed_uprobe_remove
run #5: crashed: KASAN: use-after-free Read in delayed_uprobe_remove
run #6: OK
run #7: OK
run #8: OK
run #9: OK

run #0: crashed: general protection fault in delayed_uprobe_remove
run #1: crashed: KASAN: use-after-free Read in delayed_uprobe_remove
run #2: crashed: KASAN: use-after-free Read in delayed_uprobe_remove
run #3: crashed: KASAN: use-after-free Read in delayed_uprobe_remove
run #4: crashed: general protection fault in delayed_uprobe_remove
run #5: crashed: KASAN: use-after-free Read in delayed_uprobe_remove
run #6: OK
run #7: OK
run #8: OK
run #9: OK

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: Bisections with different bug manifestations
  2021-04-16  7:51           ` Bisections with different bug manifestations Dmitry Vyukov
@ 2021-04-16 13:13             ` Steven Rostedt
  2021-04-16 13:26               ` Dmitry Vyukov
  0 siblings, 1 reply; 25+ messages in thread
From: Steven Rostedt @ 2021-04-16 13:13 UTC (permalink / raw)
  To: Dmitry Vyukov
  Cc: syzkaller, syzbot, Andrew Morton, Jens Axboe, Borislav Petkov,
	H. Peter Anvin, Jim Mattson, Joerg Roedel, KVM list, linux-block,
	LKML, Mark Rutland, masahiroy, Ingo Molnar, Paolo Bonzini,
	Peter Zijlstra, rafael.j.wysocki, Sean Christopherson,
	syzkaller-bugs, Thomas Gleixner, Vitaly Kuznetsov, Wanpeng Li,
	Will Deacon, the arch/x86 maintainers

On Fri, 16 Apr 2021 09:51:45 +0200
Dmitry Vyukov <dvyukov@google.com> wrote:
> 
> If you look at substantial base of bisection logs, you will find lots
> of cases where bug types, functions don't match. Kernel crashes
> differently even on the same revision. And obviously things change if
> you change revisions. Also if you see presumably a different bug, what
> does it say regarding the original bug.

Yes, but there are also several types of cases where the issue will be the
same. Namely lockdep. I agree that use after free warnings can have a side
effect, and may be more difficult. But there's many other bugs that remain
consistent across kernels. And if you stumble on one of them, look for it
only.

And if you hit another bug, and if it doesn't crash, then ignore it (of
course this could be an issue if you have panic on warning set). But
otherwise, just skip it.

> 
> I would very much like to improve automatic bisection quality, but it
> does not look trivial at all.
> 
> Some random examples where, say, your hypothesis of WARN-to-WARN,
> BUG-to-BUG does not hold even on the same kernel revision (add to this

At least lockdep to lockdep, as when I do manual bisects, that's exactly
what I look for, and ignore all other warnings. And that has found the
problem commit pretty much every time.

> different revisions and the fact that a different bug does not give
> info regarding the original bug):
> 

Can you tell me that all these examples bisected to the commit that caused
the bug? Because if it did not, then you may have just proved my point ;-)

> run #0: crashed: KASAN: use-after-free Read in fuse_dev_do_read
> run #1: crashed: WARNING in request_end
> run #2: crashed: KASAN: use-after-free Read in fuse_dev_do_read
> run #3: OK
> run #4: OK
> 

[..]

-- Steve

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: Bisections with different bug manifestations
  2021-04-16 13:13             ` Steven Rostedt
@ 2021-04-16 13:26               ` Dmitry Vyukov
  2021-04-16 13:48                 ` Dmitry Vyukov
  0 siblings, 1 reply; 25+ messages in thread
From: Dmitry Vyukov @ 2021-04-16 13:26 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: syzkaller, syzbot, Andrew Morton, Jens Axboe, Borislav Petkov,
	H. Peter Anvin, Jim Mattson, Joerg Roedel, KVM list, linux-block,
	LKML, Mark Rutland, masahiroy, Ingo Molnar, Paolo Bonzini,
	Peter Zijlstra, rafael.j.wysocki, Sean Christopherson,
	syzkaller-bugs, Thomas Gleixner, Vitaly Kuznetsov, Wanpeng Li,
	Will Deacon, the arch/x86 maintainers

On Fri, Apr 16, 2021 at 3:13 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Fri, 16 Apr 2021 09:51:45 +0200
> Dmitry Vyukov <dvyukov@google.com> wrote:
> >
> > If you look at substantial base of bisection logs, you will find lots
> > of cases where bug types, functions don't match. Kernel crashes
> > differently even on the same revision. And obviously things change if
> > you change revisions. Also if you see presumably a different bug, what
> > does it say regarding the original bug.
>
> Yes, but there are also several types of cases where the issue will be the
> same. Namely lockdep. I agree that use after free warnings can have a side
> effect, and may be more difficult.

But how do we know it's lockdep, rather than a use-after-free
manifested as lockdep?
A Significant portion of kernel bugs are caused by concurrency and can
manifest in different ways, e.g. these are not lockdep, or WARN, or
use-after-free, but rather a race in nature.

> But there's many other bugs that remain
> consistent across kernels. And if you stumble on one of them, look for it
> only.

For example? Does not look to be true for WARN, BUG, KASAN,
"inconsistent lock state".


> And if you hit another bug, and if it doesn't crash, then ignore it (of
> course this could be an issue if you have panic on warning set). But
> otherwise, just skip it.

It's not possible to skip, say, BUG.
And if we skip, say, a use-after-free, how do we know we are not
making things worse? Because now we are running on corrupted memory,
so anything can happen. Definitely a stray lockdep report can happen,
or other way around not happen when it should...

> > I would very much like to improve automatic bisection quality, but it
> > does not look trivial at all.
> >
> > Some random examples where, say, your hypothesis of WARN-to-WARN,
> > BUG-to-BUG does not hold even on the same kernel revision (add to this
>
> At least lockdep to lockdep, as when I do manual bisects, that's exactly
> what I look for, and ignore all other warnings. And that has found the
> problem commit pretty much every time.

What lockdep bug types do you mean? All?
In the examples above you can see at least "inconsistent lock state"
mixed with 2 other completely different bug types.

> > different revisions and the fact that a different bug does not give
> > info regarding the original bug):
> >
>
> Can you tell me that all these examples bisected to the commit that caused
> the bug? Because if it did not, then you may have just proved my point ;-)

I don't know now what was the result, but for a single run these were
manifestations of the same root bug.
E.g. see below, that's UAF in fuse_dev_do_read vs WARNING in
request_end. request_end is also fuse. And you can see that a memory
corruption causing a random bug type, in this case WARNING, but can as
well be LOCKDEP.


> > run #0: crashed: KASAN: use-after-free Read in fuse_dev_do_read
> > run #1: crashed: WARNING in request_end
> > run #2: crashed: KASAN: use-after-free Read in fuse_dev_do_read
> > run #3: OK
> > run #4: OK

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: Bisections with different bug manifestations
  2021-04-16 13:26               ` Dmitry Vyukov
@ 2021-04-16 13:48                 ` Dmitry Vyukov
  0 siblings, 0 replies; 25+ messages in thread
From: Dmitry Vyukov @ 2021-04-16 13:48 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: syzkaller, syzbot, Andrew Morton, Jens Axboe, Borislav Petkov,
	H. Peter Anvin, Jim Mattson, Joerg Roedel, KVM list, linux-block,
	LKML, Mark Rutland, masahiroy, Ingo Molnar, Paolo Bonzini,
	Peter Zijlstra, rafael.j.wysocki, Sean Christopherson,
	syzkaller-bugs, Thomas Gleixner, Vitaly Kuznetsov, Wanpeng Li,
	Will Deacon, the arch/x86 maintainers

On Fri, Apr 16, 2021 at 3:26 PM Dmitry Vyukov <dvyukov@google.com> wrote:
>
> On Fri, Apr 16, 2021 at 3:13 PM Steven Rostedt <rostedt@goodmis.org> wrote:
> >
> > On Fri, 16 Apr 2021 09:51:45 +0200
> > Dmitry Vyukov <dvyukov@google.com> wrote:
> > >
> > > If you look at substantial base of bisection logs, you will find lots
> > > of cases where bug types, functions don't match. Kernel crashes
> > > differently even on the same revision. And obviously things change if
> > > you change revisions. Also if you see presumably a different bug, what
> > > does it say regarding the original bug.
> >
> > Yes, but there are also several types of cases where the issue will be the
> > same. Namely lockdep. I agree that use after free warnings can have a side
> > effect, and may be more difficult.
>
> But how do we know it's lockdep, rather than a use-after-free
> manifested as lockdep?
> A Significant portion of kernel bugs are caused by concurrency and can
> manifest in different ways, e.g. these are not lockdep, or WARN, or
> use-after-free, but rather a race in nature.
>
> > But there's many other bugs that remain
> > consistent across kernels. And if you stumble on one of them, look for it
> > only.
>
> For example? Does not look to be true for WARN, BUG, KASAN,
> "inconsistent lock state".
>
>
> > And if you hit another bug, and if it doesn't crash, then ignore it (of
> > course this could be an issue if you have panic on warning set). But
> > otherwise, just skip it.
>
> It's not possible to skip, say, BUG.
> And if we skip, say, a use-after-free, how do we know we are not
> making things worse? Because now we are running on corrupted memory,
> so anything can happen. Definitely a stray lockdep report can happen,
> or other way around not happen when it should...
>
> > > I would very much like to improve automatic bisection quality, but it
> > > does not look trivial at all.
> > >
> > > Some random examples where, say, your hypothesis of WARN-to-WARN,
> > > BUG-to-BUG does not hold even on the same kernel revision (add to this
> >
> > At least lockdep to lockdep, as when I do manual bisects, that's exactly
> > what I look for, and ignore all other warnings. And that has found the
> > problem commit pretty much every time.
>
> What lockdep bug types do you mean? All?
> In the examples above you can see at least "inconsistent lock state"
> mixed with 2 other completely different bug types.

I've looked for some examples.

Here a reliable deadlock in io_uring changes to reliable task hung in io_uring:
run #6: crashed: possible deadlock in io_poll_double_wake
all runs: crashed: INFO: task hung in io_ring_exit_work
https://syzkaller.appspot.com/text?tag=Log&x=135e4d31d00000

Here deadlock is mixed with "lock held when returning to user space":
run #6: crashed: possible deadlock in inet_stream_connect
run #7: crashed: WARNING: lock held when returning to user space in
inet_stream_connect
https://syzkaller.appspot.com/text?tag=Log&x=109b88f2d00000

Here a reliable deadlock in n_tty_receive_buf_common changes to UAF in
n_tty_receive_buf_common:
all runs: crashed: possible deadlock in n_tty_receive_buf_common
all runs: crashed: KASAN: use-after-free Read in n_tty_receive_buf_common
https://syzkaller.appspot.com/text?tag=Log&x=106596b5e00000

Here deadlock changes to UAF and corrupted list:
run #4: crashed: possible deadlock in neigh_change_state
run #1: crashed: KASAN: use-after-free Read in neigh_mark_dead
run #2: crashed: BUG: corrupted list in ___neigh_create
run #3: crashed: BUG: corrupted list in neigh_mark_dead
https://syzkaller.appspot.com/text?tag=Log&x=1328a1e2e00000

But it also shows another interesting aspect, kernel output is
sometimes corrupted and kernel does not manage to print proper
complete oops message. In these cases we can't reliably say that it's
also a deadlock or not, we can't say anything about the crash, it's
unparsable. This problem also shows up here:
https://syzkaller.appspot.com/text?tag=Log&x=145c3a6d200000
and here
https://syzkaller.appspot.com/text?tag=Log&x=1006f18c600000
and in the second one also these 2 are mixed:
run #1: crashed: WARNING: locking bug in corrupted
run #2: crashed: WARNING: possible circular locking dependency detected

This one shows a related issue. Kernel crash output periodically
changes, and a testing system fails to parse it. This can happen if we
go back to older releases, or when we do fix bisection and test a very
new kernel with changed output:
https://syzkaller.appspot.com/text?tag=Log&x=108f4416e00000


It's also easy to imagine that a program that triggers 2 deadlocks on
different revisions, both are deadlocks, but completely different and
unrelated. And we can't look at function names as they change over
time.
All these things are almost trivial when you do bisection manually.
But for an automated system, they are quite challenging to handle.



> > > different revisions and the fact that a different bug does not give
> > > info regarding the original bug):
> > >
> >
> > Can you tell me that all these examples bisected to the commit that caused
> > the bug? Because if it did not, then you may have just proved my point ;-)
>
> I don't know now what was the result, but for a single run these were
> manifestations of the same root bug.
> E.g. see below, that's UAF in fuse_dev_do_read vs WARNING in
> request_end. request_end is also fuse. And you can see that a memory
> corruption causing a random bug type, in this case WARNING, but can as
> well be LOCKDEP.
>
>
> > > run #0: crashed: KASAN: use-after-free Read in fuse_dev_do_read
> > > run #1: crashed: WARNING in request_end
> > > run #2: crashed: KASAN: use-after-free Read in fuse_dev_do_read
> > > run #3: OK
> > > run #4: OK

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-04-13 17:33 [syzbot] possible deadlock in del_gendisk syzbot
  2021-04-13 17:41 ` Steven Rostedt
@ 2021-06-07 10:56 ` Tetsuo Handa
  2021-06-09 16:31   ` Tetsuo Handa
  1 sibling, 1 reply; 25+ messages in thread
From: Tetsuo Handa @ 2021-06-07 10:56 UTC (permalink / raw)
  To: Pavel Tatashin, Tyler Hicks, Petr Vorel; +Cc: linux-block, syzbot

Hello.

syzbot is reporting "possible deadlock in del_gendisk" problem.

I guess this is caused by commit 6cc8e7430801fa23 ("loop: scale loop device
by introducing per device lock") because it touches loop_ctl_mutex usage
between v5.11 and v5.12-rc1. Please have a look.

On 2021/04/14 2:33, syzbot wrote:
> Hello,
> 
> syzbot found the following issue on:
> 
> HEAD commit:    e99d8a84 Add linux-next specific files for 20210409
> git tree:       linux-next
> console output: https://syzkaller.appspot.com/x/log.txt?x=13b01681d00000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=7cd69574979bfeb7
> dashboard link: https://syzkaller.appspot.com/bug?extid=61e04e51b7ac86930589
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=148265d9d00000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=16a981a1d00000


^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-06-07 10:56 ` [syzbot] possible deadlock in del_gendisk Tetsuo Handa
@ 2021-06-09 16:31   ` Tetsuo Handa
  2021-06-09 16:46     ` Tyler Hicks
  0 siblings, 1 reply; 25+ messages in thread
From: Tetsuo Handa @ 2021-06-09 16:31 UTC (permalink / raw)
  To: Christoph Hellwig, Jens Axboe, Stefan Haberland, Jan Hoeppner
  Cc: linux-block, syzbot, Tyler Hicks, Petr Vorel, Pavel Tatashin, Tejun Heo

Hello, Christoph.

I'm currently trying full bisection.

  # bad: [fc0586062816559defb14c947319ef8c4c326fb3] Merge tag 'for-5.13/drivers-2021-04-27' of git://git.kernel.dk/linux-block
  # good: [42dec9a936e7696bea1f27d3c5a0068cd9aa95fd] Merge tag 'perf-core-2021-04-28' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
  # good: [68a32ba14177d4a21c4a9a941cf1d7aea86d436f] Merge tag 'drm-next-2021-04-28' of git://anongit.freedesktop.org/drm/drm
  # good: [a800abd3ecb9acc55821f7ac9bba6c956b36a595] net: enetc: move skb creation into enetc_build_skb
  # good: [6cc8e7430801fa238bd7d3acae1eb406c6e02fe1] loop: scale loop device by introducing per device lock
  git bisect start 'fc0586062816559defb14c947319ef8c4c326fb3' '42dec9a936e7696bea1f27d3c5a0068cd9aa95fd' '68a32ba14177d4a21c4a9a941cf1d7aea86d436f' 'a800abd3ecb9acc55821f7ac9bba6c956b36a595' '6cc8e7430801fa238bd7d3acae1eb406c6e02fe1'
  # good: [2958a995edc94654df690318df7b9b49e5a3ef88] block/rnbd-clt: Support polling mode for IO latency optimization
  git bisect good 2958a995edc94654df690318df7b9b49e5a3ef88

I think we will bisect this problem to

  commit c76f48eb5c084b1e ("block: take bd_mutex around delete_partitions in del_gendisk")

because that commit introduced new locking dependency bdev_lookup_sem => disk->part0->bd_mutex
which matches the lockdep's report.

  ======================================================
  WARNING: possible circular locking dependency detected
  5.12.0-rc6-next-20210409-syzkaller #0 Not tainted
  ------------------------------------------------------
  syz-executor.4/10285 is trying to acquire lock:
  ffff8881423245a0 (&bdev->bd_mutex){+.+.}-{3:3}, at: del_gendisk+0x250/0x9e0 block/genhd.c:618
  
  but task is already holding lock:
  ffffffff8c7d9430 (bdev_lookup_sem){++++}-{3:3}, at: del_gendisk+0x222/0x9e0 block/genhd.c:616

Do we need to revert "partition iteration simplifications" work?

On 2021/06/07 19:56, Tetsuo Handa wrote:
> Hello.
> 
> syzbot is reporting "possible deadlock in del_gendisk" problem.
> 
> I guess this is caused by commit 6cc8e7430801fa23 ("loop: scale loop device
> by introducing per device lock") because it touches loop_ctl_mutex usage
> between v5.11 and v5.12-rc1. Please have a look.
> 
> On 2021/04/14 2:33, syzbot wrote:
>> Hello,
>>
>> syzbot found the following issue on:
>>
>> HEAD commit:    e99d8a84 Add linux-next specific files for 20210409
>> git tree:       linux-next
>> console output: https://syzkaller.appspot.com/x/log.txt?x=13b01681d00000
>> kernel config:  https://syzkaller.appspot.com/x/.config?x=7cd69574979bfeb7
>> dashboard link: https://syzkaller.appspot.com/bug?extid=61e04e51b7ac86930589
>> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=148265d9d00000
>> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=16a981a1d00000
> 


^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-06-09 16:31   ` Tetsuo Handa
@ 2021-06-09 16:46     ` Tyler Hicks
  2021-06-10 13:37       ` Tetsuo Handa
  2021-06-11 14:47       ` [syzbot] possible deadlock in del_gendisk Tetsuo Handa
  0 siblings, 2 replies; 25+ messages in thread
From: Tyler Hicks @ 2021-06-09 16:46 UTC (permalink / raw)
  To: Tetsuo Handa
  Cc: Christoph Hellwig, Jens Axboe, Stefan Haberland, Jan Hoeppner,
	linux-block, syzbot, Petr Vorel, Pavel Tatashin, Tejun Heo

On 2021-06-10 01:31:17, Tetsuo Handa wrote:
> Hello, Christoph.
> 
> I'm currently trying full bisection.
> 
>   # bad: [fc0586062816559defb14c947319ef8c4c326fb3] Merge tag 'for-5.13/drivers-2021-04-27' of git://git.kernel.dk/linux-block
>   # good: [42dec9a936e7696bea1f27d3c5a0068cd9aa95fd] Merge tag 'perf-core-2021-04-28' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>   # good: [68a32ba14177d4a21c4a9a941cf1d7aea86d436f] Merge tag 'drm-next-2021-04-28' of git://anongit.freedesktop.org/drm/drm
>   # good: [a800abd3ecb9acc55821f7ac9bba6c956b36a595] net: enetc: move skb creation into enetc_build_skb
>   # good: [6cc8e7430801fa238bd7d3acae1eb406c6e02fe1] loop: scale loop device by introducing per device lock

Thanks for doing this. I haven't had a chance to retry this commit with
lockdep but I did re-review it and didn't think that it would be the
cause of this lockdep report since it strictly reduced the usage of the
loop_ctl_mutex.

Tyler

>   git bisect start 'fc0586062816559defb14c947319ef8c4c326fb3' '42dec9a936e7696bea1f27d3c5a0068cd9aa95fd' '68a32ba14177d4a21c4a9a941cf1d7aea86d436f' 'a800abd3ecb9acc55821f7ac9bba6c956b36a595' '6cc8e7430801fa238bd7d3acae1eb406c6e02fe1'
>   # good: [2958a995edc94654df690318df7b9b49e5a3ef88] block/rnbd-clt: Support polling mode for IO latency optimization
>   git bisect good 2958a995edc94654df690318df7b9b49e5a3ef88
> 
> I think we will bisect this problem to
> 
>   commit c76f48eb5c084b1e ("block: take bd_mutex around delete_partitions in del_gendisk")
> 
> because that commit introduced new locking dependency bdev_lookup_sem => disk->part0->bd_mutex
> which matches the lockdep's report.
> 
>   ======================================================
>   WARNING: possible circular locking dependency detected
>   5.12.0-rc6-next-20210409-syzkaller #0 Not tainted
>   ------------------------------------------------------
>   syz-executor.4/10285 is trying to acquire lock:
>   ffff8881423245a0 (&bdev->bd_mutex){+.+.}-{3:3}, at: del_gendisk+0x250/0x9e0 block/genhd.c:618
>   
>   but task is already holding lock:
>   ffffffff8c7d9430 (bdev_lookup_sem){++++}-{3:3}, at: del_gendisk+0x222/0x9e0 block/genhd.c:616
> 
> Do we need to revert "partition iteration simplifications" work?
> 
> On 2021/06/07 19:56, Tetsuo Handa wrote:
> > Hello.
> > 
> > syzbot is reporting "possible deadlock in del_gendisk" problem.
> > 
> > I guess this is caused by commit 6cc8e7430801fa23 ("loop: scale loop device
> > by introducing per device lock") because it touches loop_ctl_mutex usage
> > between v5.11 and v5.12-rc1. Please have a look.
> > 
> > On 2021/04/14 2:33, syzbot wrote:
> >> Hello,
> >>
> >> syzbot found the following issue on:
> >>
> >> HEAD commit:    e99d8a84 Add linux-next specific files for 20210409
> >> git tree:       linux-next
> >> console output: https://syzkaller.appspot.com/x/log.txt?x=13b01681d00000
> >> kernel config:  https://syzkaller.appspot.com/x/.config?x=7cd69574979bfeb7
> >> dashboard link: https://syzkaller.appspot.com/bug?extid=61e04e51b7ac86930589
> >> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=148265d9d00000
> >> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=16a981a1d00000
> > 
> 

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-06-09 16:46     ` Tyler Hicks
@ 2021-06-10 13:37       ` Tetsuo Handa
  2021-06-11  6:46         ` Tetsuo Handa
  2021-06-11 14:47       ` [syzbot] possible deadlock in del_gendisk Tetsuo Handa
  1 sibling, 1 reply; 25+ messages in thread
From: Tetsuo Handa @ 2021-06-10 13:37 UTC (permalink / raw)
  To: Tyler Hicks, Pavel Tatashin, Petr Vorel
  Cc: Christoph Hellwig, Jens Axboe, Stefan Haberland, Jan Hoeppner,
	linux-block, syzbot, Tejun Heo

On 2021/06/10 1:46, Tyler Hicks wrote:
> On 2021-06-10 01:31:17, Tetsuo Handa wrote:
>> Hello, Christoph.
>>
>> I'm currently trying full bisection.

I reached commit c76f48eb5c084b1e ("block: take bd_mutex around delete_partitions in del_gendisk").

  # bad: [fc0586062816559defb14c947319ef8c4c326fb3] Merge tag 'for-5.13/drivers-2021-04-27' of git://git.kernel.dk/linux-block
  # good: [42dec9a936e7696bea1f27d3c5a0068cd9aa95fd] Merge tag 'perf-core-2021-04-28' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
  # good: [68a32ba14177d4a21c4a9a941cf1d7aea86d436f] Merge tag 'drm-next-2021-04-28' of git://anongit.freedesktop.org/drm/drm
  # good: [a800abd3ecb9acc55821f7ac9bba6c956b36a595] net: enetc: move skb creation into enetc_build_skb
  # good: [6cc8e7430801fa238bd7d3acae1eb406c6e02fe1] loop: scale loop device by introducing per device lock
  git bisect start 'fc0586062816559defb14c947319ef8c4c326fb3' '42dec9a936e7696bea1f27d3c5a0068cd9aa95fd' '68a32ba14177d4a21c4a9a941cf1d7aea86d436f' 'a800abd3ecb9acc55821f7ac9bba6c956b36a595' '6cc8e7430801fa238bd7d3acae1eb406c6e02fe1'
  # good: [2958a995edc94654df690318df7b9b49e5a3ef88] block/rnbd-clt: Support polling mode for IO latency optimization
  git bisect good 2958a995edc94654df690318df7b9b49e5a3ef88
  # good: [16b3d0cf5bad844daaf436ad2e9061de0fe36e5c] Merge tag 'sched-core-2021-04-28' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
  git bisect good 16b3d0cf5bad844daaf436ad2e9061de0fe36e5c
  # bad: [cbb749cf377aa8aa32a036ebe9dd9f2d89037bf0] block: remove an incorrect check from blk_rq_append_bio
  git bisect bad cbb749cf377aa8aa32a036ebe9dd9f2d89037bf0
  # good: [9bb33f24abbd0fa2fadad01ec75438d7cc239189] block: refactor the bounce buffering code
  git bisect good 9bb33f24abbd0fa2fadad01ec75438d7cc239189
  # bad: [c76f48eb5c084b1e15c931ae8cc1826cd771d70d] block: take bd_mutex around delete_partitions in del_gendisk
  git bisect bad c76f48eb5c084b1e15c931ae8cc1826cd771d70d
  # good: [b896fa85e0ee4f09ba4be48a3f405fc82c38afb4] dasd: use bdev_disk_changed instead of blk_drop_partitions
  git bisect good b896fa85e0ee4f09ba4be48a3f405fc82c38afb4
  # good: [473338be3aaea117a7133720305f240eb7f68951] block: move more syncing and invalidation to delete_partition
  git bisect good 473338be3aaea117a7133720305f240eb7f68951
  # good: [d3c4a43d9291279c28b26757351a6ab72c110753] block: refactor blk_drop_partitions
  git bisect good d3c4a43d9291279c28b26757351a6ab72c110753
  # first bad commit: [c76f48eb5c084b1e15c931ae8cc1826cd771d70d] block: take bd_mutex around delete_partitions in del_gendisk

> 
> Thanks for doing this. I haven't had a chance to retry this commit with
> lockdep but I did re-review it and didn't think that it would be the
> cause of this lockdep report since it strictly reduced the usage of the
> loop_ctl_mutex.

OK. It seems that a patch shown below avoids this warning.

Since I think loop_remove() does not access resources in
loop module, I think we can drop loop_ctl_mutex as soon as
idr_remove(&loop_index_idr, lo->lo_number) completes.

Hmm, what protects lo_open() from loop_exit() destroying everything?
Is module's refcount taken before calling lo_open() ? If yes, does
module_exiting and/or loop_ctl_mutex in loop_exit() help protecting
something? If no, nothing protects and just crashes the kernel?

Is my understanding correct? Do you think this approach is OK?

 drivers/block/loop.c |   32 ++++++++++++++++++++++++++------
 1 file changed, 26 insertions(+), 6 deletions(-)

diff --git a/drivers/block/loop.c b/drivers/block/loop.c
index d58d68f3c7cd..5baa0207512e 100644
--- a/drivers/block/loop.c
+++ b/drivers/block/loop.c
@@ -80,18 +80,19 @@
 #include <linux/ioprio.h>
 #include <linux/blk-cgroup.h>
 
 #include "loop.h"
 
 #include <linux/uaccess.h>
 
 static DEFINE_IDR(loop_index_idr);
 static DEFINE_MUTEX(loop_ctl_mutex);
+static bool module_exiting;
 
 static int max_part;
 static int part_shift;
 
 static int transfer_xor(struct loop_device *lo, int cmd,
 			struct page *raw_page, unsigned raw_off,
 			struct page *loop_page, unsigned loop_off,
 			int size, sector_t real_block)
 {
@@ -1877,25 +1878,29 @@ static int lo_compat_ioctl(struct block_device *bdev, fmode_t mode,
 }
 #endif
 
 static int lo_open(struct block_device *bdev, fmode_t mode)
 {
 	struct loop_device *lo;
 	int err;
 
 	/*
-	 * take loop_ctl_mutex to protect lo pointer from race with
-	 * loop_control_ioctl(LOOP_CTL_REMOVE), however, to reduce contention
-	 * release it prior to updating lo->lo_refcnt.
+	 * Take loop_ctl_mutex to protect lo pointer from race with
+	 * loop_control_ioctl(LOOP_CTL_REMOVE) and loop_exit(). However,
+	 * to reduce contention, release it prior to updating lo->lo_refcnt.
 	 */
 	err = mutex_lock_killable(&loop_ctl_mutex);
 	if (err)
 		return err;
+	if (unlikely(module_exiting)) {
+		mutex_unlock(&loop_ctl_mutex);
+		return -EINVAL;
+	}
 	lo = bdev->bd_disk->private_data;
 	if (!lo) {
 		mutex_unlock(&loop_ctl_mutex);
 		return -ENXIO;
 	}
 	err = mutex_lock_killable(&lo->lo_mutex);
 	mutex_unlock(&loop_ctl_mutex);
 	if (err)
 		return err;
@@ -2073,18 +2078,19 @@ static int loop_init_request(struct blk_mq_tag_set *set, struct request *rq,
 	return 0;
 }
 
 static const struct blk_mq_ops loop_mq_ops = {
 	.queue_rq       = loop_queue_rq,
 	.init_request	= loop_init_request,
 	.complete	= lo_complete_rq,
 };
 
+/* Must be called with loop_ctl_mutex held. */
 static int loop_add(struct loop_device **l, int i)
 {
 	struct loop_device *lo;
 	struct gendisk *disk;
 	int err;
 
 	err = -ENOMEM;
 	lo = kzalloc(sizeof(*lo), GFP_KERNEL);
 	if (!lo)
@@ -2180,18 +2186,19 @@ static int loop_add(struct loop_device **l, int i)
 	blk_mq_free_tag_set(&lo->tag_set);
 out_free_idr:
 	idr_remove(&loop_index_idr, i);
 out_free_dev:
 	kfree(lo);
 out:
 	return err;
 }
 
+/* Must not be called with loop_ctl_mutex or lo->lo_mutex held. */
 static void loop_remove(struct loop_device *lo)
 {
 	del_gendisk(lo->lo_disk);
 	blk_cleanup_queue(lo->lo_queue);
 	blk_mq_free_tag_set(&lo->tag_set);
 	put_disk(lo->lo_disk);
 	mutex_destroy(&lo->lo_mutex);
 	kfree(lo);
 }
@@ -2251,18 +2258,22 @@ static void loop_probe(dev_t dev)
 static long loop_control_ioctl(struct file *file, unsigned int cmd,
 			       unsigned long parm)
 {
 	struct loop_device *lo;
 	int ret;
 
 	ret = mutex_lock_killable(&loop_ctl_mutex);
 	if (ret)
 		return ret;
+	if (unlikely(module_exiting)) {
+		mutex_unlock(&loop_ctl_mutex);
+		return -EINVAL;
+	}
 
 	ret = -ENOSYS;
 	switch (cmd) {
 	case LOOP_CTL_ADD:
 		ret = loop_lookup(&lo, parm);
 		if (ret >= 0) {
 			ret = -EEXIST;
 			break;
 		}
@@ -2282,19 +2293,21 @@ static long loop_control_ioctl(struct file *file, unsigned int cmd,
 		}
 		if (atomic_read(&lo->lo_refcnt) > 0) {
 			ret = -EBUSY;
 			mutex_unlock(&lo->lo_mutex);
 			break;
 		}
 		lo->lo_disk->private_data = NULL;
 		mutex_unlock(&lo->lo_mutex);
 		idr_remove(&loop_index_idr, lo->lo_number);
+		mutex_unlock(&loop_ctl_mutex);
 		loop_remove(lo);
+		return ret;
 		break;
 	case LOOP_CTL_GET_FREE:
 		ret = loop_lookup(&lo, -1);
 		if (ret >= 0)
 			break;
 		ret = loop_add(&lo, -1);
 	}
 	mutex_unlock(&loop_ctl_mutex);
 
@@ -2391,28 +2404,35 @@ static int loop_exit_cb(int id, void *ptr, void *data)
 {
 	struct loop_device *lo = ptr;
 
 	loop_remove(lo);
 	return 0;
 }
 
 static void __exit loop_exit(void)
 {
-	mutex_lock(&loop_ctl_mutex);
+	module_exiting = true;
 
+	/* Block future lo_open()/loop_control_ioctl() callers. */
+	mutex_lock(&loop_ctl_mutex);
+	mutex_unlock(&loop_ctl_mutex);
+	/*
+	 * Since loop_exit_cb() calls loop_remove(), we can not take
+	 * loop_ctl_mutex here. But since module_exiting == true is blocking
+	 * lo_open() and loop_control_ioctl(), it is safe to access
+	 * loop_index_idr without taking loop_ctl_mutex here.
+	 */
 	idr_for_each(&loop_index_idr, &loop_exit_cb, NULL);
 	idr_destroy(&loop_index_idr);
 
 	unregister_blkdev(LOOP_MAJOR, "loop");
 
 	misc_deregister(&loop_misc);
-
-	mutex_unlock(&loop_ctl_mutex);
 }
 
 module_init(loop_init);
 module_exit(loop_exit);
 
 #ifndef MODULE
 static int __init max_loop_setup(char *str)
 {
 	max_loop = simple_strtol(str, NULL, 0);



^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-06-10 13:37       ` Tetsuo Handa
@ 2021-06-11  6:46         ` Tetsuo Handa
  2021-06-11 15:14           ` [PATCH] loop: drop loop_ctl_mutex around del_gendisk() in loop_remove() Tetsuo Handa
  0 siblings, 1 reply; 25+ messages in thread
From: Tetsuo Handa @ 2021-06-11  6:46 UTC (permalink / raw)
  To: Tyler Hicks, Pavel Tatashin, Petr Vorel
  Cc: Christoph Hellwig, Jens Axboe, Stefan Haberland, Jan Hoeppner,
	linux-block, syzbot, Tejun Heo

I hoped that below patch fixes the problem, but it did not ( https://syzkaller.appspot.com/text?tag=CrashReport&x=111bc8f7d00000 ).
I guess we need to somehow serialize loop_add() and loop_remove() if we can't use loop_ctl_mutex...

From 2dfbd8e4a10c7883a85a2d4c32d83c93b2c3d485 Mon Sep 17 00:00:00 2001
From: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Date: Fri, 11 Jun 2021 05:54:25 +0000
Subject: [not-yet-a-PATCH] loop: drop loop_ctl_mutex before calling del_gendisk()

syzbot is reporting circular locking dependency between loop_ctl_mutex and
bdev->bd_mutex [1] due to commit c76f48eb5c084b1e ("block: take bd_mutex
around delete_partitions in del_gendisk").

Since the lo becomes unreachable before del_gendisk() is called by
loop_remove(lo) from loop_control_ioctl(LOOP_CTL_REMOVE), we can drop
loop_ctl_mutex before calling loop_remove().

Holding loop_ctl_mutex in loop_exit() is pointless, for module's refcount
being 0 (unless forced module unload is requested) guarantees that nobody
is using /dev/loop* interface.

Link: https://syzkaller.appspot.com/bug?extid=61e04e51b7ac86930589 [1]
Reported-by: syzbot <syzbot+61e04e51b7ac86930589@syzkaller.appspotmail.com>
Fixes: c76f48eb5c084b1e ("block: take bd_mutex around delete_partitions in del_gendisk")
---
 drivers/block/loop.c | 9 ++++-----
 1 file changed, 4 insertions(+), 5 deletions(-)

diff --git a/drivers/block/loop.c b/drivers/block/loop.c
index d58d68f3c7cd..3045bcb9f7ed 100644
--- a/drivers/block/loop.c
+++ b/drivers/block/loop.c
@@ -2079,6 +2079,7 @@ static const struct blk_mq_ops loop_mq_ops = {
 	.complete	= lo_complete_rq,
 };
 
+/* Must be called with loop_ctl_mutex held. */
 static int loop_add(struct loop_device **l, int i)
 {
 	struct loop_device *lo;
@@ -2186,6 +2187,7 @@ static int loop_add(struct loop_device **l, int i)
 	return err;
 }
 
+/* Must not be called with loop_ctl_mutex or lo->lo_mutex held. */
 static void loop_remove(struct loop_device *lo)
 {
 	del_gendisk(lo->lo_disk);
@@ -2288,8 +2290,9 @@ static long loop_control_ioctl(struct file *file, unsigned int cmd,
 		lo->lo_disk->private_data = NULL;
 		mutex_unlock(&lo->lo_mutex);
 		idr_remove(&loop_index_idr, lo->lo_number);
+		mutex_unlock(&loop_ctl_mutex);
 		loop_remove(lo);
-		break;
+		return 0;
 	case LOOP_CTL_GET_FREE:
 		ret = loop_lookup(&lo, -1);
 		if (ret >= 0)
@@ -2397,16 +2400,12 @@ static int loop_exit_cb(int id, void *ptr, void *data)
 
 static void __exit loop_exit(void)
 {
-	mutex_lock(&loop_ctl_mutex);
-
 	idr_for_each(&loop_index_idr, &loop_exit_cb, NULL);
 	idr_destroy(&loop_index_idr);
 
 	unregister_blkdev(LOOP_MAJOR, "loop");
 
 	misc_deregister(&loop_misc);
-
-	mutex_unlock(&loop_ctl_mutex);
 }
 
 module_init(loop_init);
-- 
2.25.1



^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-06-09 16:46     ` Tyler Hicks
  2021-06-10 13:37       ` Tetsuo Handa
@ 2021-06-11 14:47       ` Tetsuo Handa
  2021-06-11 15:11         ` Pavel Tatashin
  1 sibling, 1 reply; 25+ messages in thread
From: Tetsuo Handa @ 2021-06-11 14:47 UTC (permalink / raw)
  To: Tyler Hicks, Petr Vorel, Pavel Tatashin
  Cc: Christoph Hellwig, Jens Axboe, Stefan Haberland, Jan Hoeppner,
	linux-block, syzbot, Tejun Heo

On 2021/06/10 1:46, Tyler Hicks wrote:
> Thanks for doing this. I haven't had a chance to retry this commit with
> lockdep but I did re-review it and didn't think that it would be the
> cause of this lockdep report since it strictly reduced the usage of the
> loop_ctl_mutex.

Well, I made commit 310ca162d779efee ("block/loop: Use global lock for ioctl() operation.")
because per device lock was not sufficient. Did commit 6cc8e7430801fa23 ("loop: scale loop
device by introducing per device lock") take this problem into account?

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-06-11 14:47       ` [syzbot] possible deadlock in del_gendisk Tetsuo Handa
@ 2021-06-11 15:11         ` Pavel Tatashin
  2021-06-11 15:18           ` Pavel Tatashin
  0 siblings, 1 reply; 25+ messages in thread
From: Pavel Tatashin @ 2021-06-11 15:11 UTC (permalink / raw)
  To: Tetsuo Handa
  Cc: Tyler Hicks, Petr Vorel, Christoph Hellwig, Jens Axboe,
	Stefan Haberland, Jan Hoeppner, linux-block, syzbot, Tejun Heo

On Fri, Jun 11, 2021 at 10:47 AM Tetsuo Handa
<penguin-kernel@i-love.sakura.ne.jp> wrote:
>
> On 2021/06/10 1:46, Tyler Hicks wrote:
> > Thanks for doing this. I haven't had a chance to retry this commit with
> > lockdep but I did re-review it and didn't think that it would be the
> > cause of this lockdep report since it strictly reduced the usage of the
> > loop_ctl_mutex.
>
> Well, I made commit 310ca162d779efee ("block/loop: Use global lock for ioctl() operation.")
> because per device lock was not sufficient. Did commit 6cc8e7430801fa23 ("loop: scale loop
> device by introducing per device lock") take this problem into account?

This was my intention when I wrote 6cc8e7430801fa23 ("loop: scale loop
device by introducing per device lock"). This is why this change does
not simply revert 310ca162d779efee ("block/loop: Use global lock for
ioctl() operation."), but keeps loop_ctl_mutex to protect the global
accesses.  loop_control_ioctl() is still locked by global
loop_ctl_mutex.

^ permalink raw reply	[flat|nested] 25+ messages in thread

* [PATCH] loop: drop loop_ctl_mutex around del_gendisk() in loop_remove()
  2021-06-11  6:46         ` Tetsuo Handa
@ 2021-06-11 15:14           ` Tetsuo Handa
  2021-06-15  5:30             ` Tetsuo Handa
  2021-06-15  9:04             ` Jan Kara
  0 siblings, 2 replies; 25+ messages in thread
From: Tetsuo Handa @ 2021-06-11 15:14 UTC (permalink / raw)
  To: Tyler Hicks, Pavel Tatashin, Petr Vorel
  Cc: Christoph Hellwig, Jens Axboe, Stefan Haberland, Jan Hoeppner,
	linux-block, syzbot, Tejun Heo, Jan Kara

syzbot is reporting circular locking dependency between loop_ctl_mutex and
bdev->bd_mutex [1] due to commit c76f48eb5c084b1e ("block: take bd_mutex
around delete_partitions in del_gendisk").

But calling del_gendisk() from loop_remove() without loop_ctl_mutex held
triggers a different race problem regarding sysfs entry management. We
somehow need to serialize "add_disk() from loop_add()" and "del_gendisk()
 from loop_remove()". Fortunately, since loop_control_ioctl() is called
with no locks held, we can use "sleep and retry" approach without risking
deadlock.

Since "struct loop_device"->lo_disk->private_data is set to non-NULL at
loop_add() and is reset to NULL before calling loop_remove(), we can use
it as a flag for taking appropriate action ("sleep and retry" or "skip")
when loop_remove() is in progress.

Link: https://syzkaller.appspot.com/bug?extid=61e04e51b7ac86930589 [1]
Reported-by: syzbot <syzbot+61e04e51b7ac86930589@syzkaller.appspotmail.com>
Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Tested-by: syzbot <syzbot+61e04e51b7ac86930589@syzkaller.appspotmail.com>
Fixes: c76f48eb5c084b1e ("block: take bd_mutex around delete_partitions in del_gendisk")
---
 drivers/block/loop.c | 18 ++++++++++++++++--
 1 file changed, 16 insertions(+), 2 deletions(-)

diff --git a/drivers/block/loop.c b/drivers/block/loop.c
index d58d68f3c7cd..d4c9567b2904 100644
--- a/drivers/block/loop.c
+++ b/drivers/block/loop.c
@@ -2188,7 +2188,9 @@ static int loop_add(struct loop_device **l, int i)
 
 static void loop_remove(struct loop_device *lo)
 {
+	mutex_unlock(&loop_ctl_mutex);
 	del_gendisk(lo->lo_disk);
+	mutex_lock(&loop_ctl_mutex);
 	blk_cleanup_queue(lo->lo_queue);
 	blk_mq_free_tag_set(&lo->tag_set);
 	put_disk(lo->lo_disk);
@@ -2201,7 +2203,7 @@ static int find_free_cb(int id, void *ptr, void *data)
 	struct loop_device *lo = ptr;
 	struct loop_device **l = data;
 
-	if (lo->lo_state == Lo_unbound) {
+	if (lo->lo_state == Lo_unbound && lo->lo_disk->private_data) {
 		*l = lo;
 		return 1;
 	}
@@ -2254,6 +2256,13 @@ static long loop_control_ioctl(struct file *file, unsigned int cmd,
 	struct loop_device *lo;
 	int ret;
 
+	if (0) {
+unlock_and_retry:
+		mutex_unlock(&loop_ctl_mutex);
+		if (schedule_timeout_killable(HZ / 10))
+			return -EINTR;
+	}
+	debug_check_no_locks_held();
 	ret = mutex_lock_killable(&loop_ctl_mutex);
 	if (ret)
 		return ret;
@@ -2263,6 +2272,8 @@ static long loop_control_ioctl(struct file *file, unsigned int cmd,
 	case LOOP_CTL_ADD:
 		ret = loop_lookup(&lo, parm);
 		if (ret >= 0) {
+			if (!lo->lo_disk->private_data)
+				goto unlock_and_retry;
 			ret = -EEXIST;
 			break;
 		}
@@ -2272,6 +2283,8 @@ static long loop_control_ioctl(struct file *file, unsigned int cmd,
 		ret = loop_lookup(&lo, parm);
 		if (ret < 0)
 			break;
+		if (!lo->lo_disk->private_data)
+			goto unlock_and_retry;
 		ret = mutex_lock_killable(&lo->lo_mutex);
 		if (ret)
 			break;
@@ -2286,9 +2299,10 @@ static long loop_control_ioctl(struct file *file, unsigned int cmd,
 			break;
 		}
 		lo->lo_disk->private_data = NULL;
+		parm = lo->lo_number;
 		mutex_unlock(&lo->lo_mutex);
-		idr_remove(&loop_index_idr, lo->lo_number);
 		loop_remove(lo);
+		idr_remove(&loop_index_idr, parm);
 		break;
 	case LOOP_CTL_GET_FREE:
 		ret = loop_lookup(&lo, -1);
-- 
2.25.1



^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-06-11 15:11         ` Pavel Tatashin
@ 2021-06-11 15:18           ` Pavel Tatashin
  2021-06-11 15:49             ` Tetsuo Handa
  0 siblings, 1 reply; 25+ messages in thread
From: Pavel Tatashin @ 2021-06-11 15:18 UTC (permalink / raw)
  To: Tetsuo Handa
  Cc: Tyler Hicks, Petr Vorel, Christoph Hellwig, Jens Axboe,
	Stefan Haberland, Jan Hoeppner, linux-block, syzbot, Tejun Heo

On Fri, Jun 11, 2021 at 11:11 AM Pavel Tatashin
<pasha.tatashin@soleen.com> wrote:
>
> On Fri, Jun 11, 2021 at 10:47 AM Tetsuo Handa
> <penguin-kernel@i-love.sakura.ne.jp> wrote:
> >
> > On 2021/06/10 1:46, Tyler Hicks wrote:
> > > Thanks for doing this. I haven't had a chance to retry this commit with
> > > lockdep but I did re-review it and didn't think that it would be the
> > > cause of this lockdep report since it strictly reduced the usage of the
> > > loop_ctl_mutex.
> >
> > Well, I made commit 310ca162d779efee ("block/loop: Use global lock for ioctl() operation.")
> > because per device lock was not sufficient. Did commit 6cc8e7430801fa23 ("loop: scale loop
> > device by introducing per device lock") take this problem into account?
>
> This was my intention when I wrote 6cc8e7430801fa23 ("loop: scale loop
> device by introducing per device lock"). This is why this change does
> not simply revert 310ca162d779efee ("block/loop: Use global lock for
> ioctl() operation."), but keeps loop_ctl_mutex to protect the global
> accesses.  loop_control_ioctl() is still locked by global
> loop_ctl_mutex.

From commit log of:
 310ca162d779efee ("block/loop: Use global lock for ioctl() operation.")

    Since ioctl() request on loop devices is not frequent operation, we don't
    need fine grained locking. Let's use global lock in order to allow safe
    traversal at loop_validate_file().

Unfortunately using a global lock is not scalable here. At Microsoft
we had a slow startup issue because we have several loop devices per
every container. Also, this report:
https://lore.kernel.org/lkml/20210217145629.GA4503@xsang-OptiPlex-9020/

Pasha

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-06-11 15:18           ` Pavel Tatashin
@ 2021-06-11 15:49             ` Tetsuo Handa
  2021-06-12  2:35               ` Tetsuo Handa
  0 siblings, 1 reply; 25+ messages in thread
From: Tetsuo Handa @ 2021-06-11 15:49 UTC (permalink / raw)
  To: Pavel Tatashin
  Cc: Tyler Hicks, Petr Vorel, Christoph Hellwig, Jens Axboe,
	Stefan Haberland, Jan Hoeppner, linux-block, syzbot, Tejun Heo

On 2021/06/12 0:18, Pavel Tatashin wrote:
>>> Well, I made commit 310ca162d779efee ("block/loop: Use global lock for ioctl() operation.")
>>> because per device lock was not sufficient. Did commit 6cc8e7430801fa23 ("loop: scale loop
>>> device by introducing per device lock") take this problem into account?
>>
>> This was my intention when I wrote 6cc8e7430801fa23 ("loop: scale loop
>> device by introducing per device lock"). This is why this change does
>> not simply revert 310ca162d779efee ("block/loop: Use global lock for
>> ioctl() operation."), but keeps loop_ctl_mutex to protect the global
>> accesses.  loop_control_ioctl() is still locked by global
>> loop_ctl_mutex.

No, loop_control_ioctl() (i.e. /dev/loop-control) is irrelevant here.
What 310ca162d779efee addressed but (I worry) 6cc8e7430801fa23 broke is
lo_ioctl() (i.e. /dev/loop$num).

syzbot was reporting NULL pointer dereference which is caused by
race condition between ioctl(loop_fd, LOOP_CLR_FD, 0) versus
ioctl(other_loop_fd, LOOP_SET_FD, loop_fd) due to traversing other
loop devices at loop_validate_file() without holding corresponding
lo->lo_mutex lock.

For example, loop_change_fd("/dev/loop0") calls loop_validate_file()
with only "/dev/loop0"->lo_mutex held. Then, loop_validate_file() finds
that is_loop_device("/dev/loop0") == true and enters the "while" loop.
In the "while" loop, there is

	if (l->lo_state != Lo_bound) {
		return -EINVAL;
	}
	f = l->lo_backing_file;

which has a race window that l->lo_backing_file suddenly becomes NULL
between these statements because __loop_clr_fd("/dev/loop1") is doing

	lo->lo_backing_file = NULL;

with only "/dev/loop1"->lo_mutex held.

In other words, loop_validate_file() is a global accesses which are
no longer protected by loop_ctl_mutex, isn't it?

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-06-11 15:49             ` Tetsuo Handa
@ 2021-06-12  2:35               ` Tetsuo Handa
  2021-06-13 11:01                 ` Tetsuo Handa
  0 siblings, 1 reply; 25+ messages in thread
From: Tetsuo Handa @ 2021-06-12  2:35 UTC (permalink / raw)
  To: Pavel Tatashin
  Cc: Tyler Hicks, Petr Vorel, Christoph Hellwig, Jens Axboe,
	Stefan Haberland, Jan Hoeppner, linux-block, syzbot, Tejun Heo

On 2021/06/12 0:49, Tetsuo Handa wrote:
> On 2021/06/12 0:18, Pavel Tatashin wrote:
>>>> Well, I made commit 310ca162d779efee ("block/loop: Use global lock for ioctl() operation.")
>>>> because per device lock was not sufficient. Did commit 6cc8e7430801fa23 ("loop: scale loop
>>>> device by introducing per device lock") take this problem into account?
>>>
>>> This was my intention when I wrote 6cc8e7430801fa23 ("loop: scale loop
>>> device by introducing per device lock"). This is why this change does
>>> not simply revert 310ca162d779efee ("block/loop: Use global lock for
>>> ioctl() operation."), but keeps loop_ctl_mutex to protect the global
>>> accesses.  loop_control_ioctl() is still locked by global
>>> loop_ctl_mutex.
> 
> No, loop_control_ioctl() (i.e. /dev/loop-control) is irrelevant here.
> What 310ca162d779efee addressed but (I worry) 6cc8e7430801fa23 broke is
> lo_ioctl() (i.e. /dev/loop$num).
> 
> syzbot was reporting NULL pointer dereference which is caused by
> race condition between ioctl(loop_fd, LOOP_CLR_FD, 0) versus
> ioctl(other_loop_fd, LOOP_SET_FD, loop_fd) due to traversing other
> loop devices at loop_validate_file() without holding corresponding
> lo->lo_mutex lock.

Here is a reproducer and a race window widening patch.
Since loop_validate_file() traverses on other loop devices,
changing fd of loop device needs to be protected using a global lock.

----------------------------------------
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <unistd.h>
#include <sys/ioctl.h>
#include <linux/loop.h>
#include <sys/wait.h>

int main(int argc, char *argv[])
{
	const int file_fd = open("test.img", O_RDWR | O_CREAT, 0600);
	const int loop0_fd = open("/dev/loop0", O_RDWR);
	const int loop1_fd = open("/dev/loop1", O_RDWR);

	if (ftruncate(file_fd, 1024 * 1048576) ||
	    ioctl(loop0_fd, LOOP_SET_FD, file_fd))
		return 1;
	if (fork() == 0) {
		ioctl(loop1_fd, LOOP_SET_FD, loop0_fd); // Will trigger oops.
		_exit(0);
	} else {
		ioctl(loop0_fd, LOOP_CLR_FD, 0);
		wait(NULL);
	}
	ioctl(loop1_fd, LOOP_CLR_FD, 0);
	return 0;
}
----------------------------------------

----------------------------------------
diff --git a/drivers/block/loop.c b/drivers/block/loop.c
index d58d68f3c7cd..e1c4586afcaf 100644
--- a/drivers/block/loop.c
+++ b/drivers/block/loop.c
@@ -683,6 +683,9 @@ static int loop_validate_file(struct file *file, struct block_device *bdev)
 		if (l->lo_state != Lo_bound) {
 			return -EINVAL;
 		}
+		pr_info("Start delay injection at %s()\n", __func__);
+		schedule_timeout_killable(5 * HZ);
+		pr_info("End delay injection at %s()\n", __func__);
 		f = l->lo_backing_file;
 	}
 	if (!S_ISREG(inode->i_mode) && !S_ISBLK(inode->i_mode))
@@ -1219,9 +1222,11 @@ static int __loop_clr_fd(struct loop_device *lo, bool release)
 	/* freeze request queue during the transition */
 	blk_mq_freeze_queue(lo->lo_queue);
 
+	pr_info("Start resetting at %s()\n", __func__);
 	spin_lock_irq(&lo->lo_lock);
 	lo->lo_backing_file = NULL;
 	spin_unlock_irq(&lo->lo_lock);
+	pr_info("End resetting at %s()\n", __func__);
 
 	loop_release_xfer(lo);
 	lo->transfer = NULL;
@@ -1309,6 +1314,9 @@ static int loop_clr_fd(struct loop_device *lo)
 {
 	int err;
 
+	pr_info("Start delay injection at %s()\n", __func__);
+	schedule_timeout_killable(2 * HZ);
+	pr_info("End delay injection at %s()\n", __func__);
 	err = mutex_lock_killable(&lo->lo_mutex);
 	if (err)
 		return err;
----------------------------------------

----------------------------------------
[  393.386477][ T2736] loop: module loaded
[  396.310463][ T2785] loop0: detected capacity change from 0 to 2097152
[  396.323798][ T2785] Start delay injection at loop_clr_fd()
[  396.335087][ T2787] Start delay injection at loop_validate_file()
[  398.410156][ T2785] End delay injection at loop_clr_fd()
[  398.449494][ T2785] Start resetting at __loop_clr_fd()
[  398.453236][ T2785] End resetting at __loop_clr_fd()
[  401.369512][ T2787] End delay injection at loop_validate_file()
[  401.378793][ T2787] BUG: kernel NULL pointer dereference, address: 00000000000001b8
[  401.391729][ T2787] #PF: supervisor read access in kernel mode
[  401.401927][ T2787] #PF: error_code(0x0000) - not-present page
[  401.411844][ T2787] PGD 0 P4D 0 
[  401.417355][ T2787] Oops: 0000 [#1] PREEMPT SMP
[  401.425137][ T2787] CPU: 2 PID: 2787 Comm: a.out Tainted: G            E     5.13.0-rc5+ #705
[  401.440991][ T2787] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  401.456288][ T2787] RIP: 0010:loop_validate_file.isra.0.cold+0x3d/0x55 [loop]
[  401.468657][ T2787] Code: e8 52 86 a8 e1 bf f4 01 00 00 e8 d1 c4 ac e1 48 c7 c6 a0 a7 24 a0 48 c7 c7 f0 a2 24 a0 e8 35 86 a8 e1 49 8b 84 24 f0 00 00 00 <48> 8b 80 b8 01 00 00 4c 8b 20 4d 85 e4 0f 84 5a c8 ff ff e9 33 c8
[  401.502261][ T2787] RSP: 0018:ffffc90000637c70 EFLAGS: 00010282
[  401.737017][ T2787] RAX: 0000000000000000 RBX: ffff888104e9f8e8 RCX: ffff88800e34c440
[  402.204394][ T2787] RDX: 0000000000000000 RSI: ffff88800e34c440 RDI: 0000000000000002
[  402.675231][ T2787] RBP: 0000000000000001 R08: ffffffff81153303 R09: 0000000000000000
[  403.143909][ T2787] R10: 0000000000000005 R11: 0000000000000000 R12: ffff88810640b800
[  403.626245][ T2787] R13: ffff88811640425c R14: 0000000000700000 R15: ffff888104b66b78
[  404.133199][ T2787] FS:  00007f942f0eb540(0000) GS:ffff88811bd00000(0000) knlGS:0000000000000000
[  404.654995][ T2787] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  404.926956][ T2787] CR2: 00000000000001b8 CR3: 000000000e243003 CR4: 00000000000706e0
[  405.458619][ T2787] Call Trace:
[  405.717447][ T2787]  loop_configure+0x1b2/0x840 [loop]
[  405.978507][ T2787]  ? filemap_map_pages+0x2a8/0xe40
[  406.238951][ T2787]  ? write_comp_data+0x1c/0x70
[  406.496447][ T2787]  lo_ioctl+0x1cb/0xa00 [loop]
[  406.753819][ T2787]  ? loop_configure+0x840/0x840 [loop]
[  407.013433][ T2787]  blkdev_ioctl+0x18d/0x3a0
[  407.265515][ T2787]  block_ioctl+0x66/0x80
[  407.512857][ T2787]  ? blkdev_read_iter+0xa0/0xa0
[  407.756710][ T2787]  __x64_sys_ioctl+0xbb/0x110
[  408.000459][ T2787]  do_syscall_64+0x3a/0xb0
[  408.234492][ T2787]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  408.466905][ T2787] RIP: 0033:0x7f942f00f50b
[  408.691384][ T2787] Code: 0f 1e fa 48 8b 05 85 39 0d 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 0f 1f 44 00 00 f3 0f 1e fa b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 55 39 0d 00 f7 d8 64 89 01 48
[  409.380090][ T2787] RSP: 002b:00007ffdebd33a98 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  409.832289][ T2787] RAX: ffffffffffffffda RBX: 000055fb7ce9f2d0 RCX: 00007f942f00f50b
[  410.285264][ T2787] RDX: 0000000000000004 RSI: 0000000000004c00 RDI: 0000000000000005
[  410.737236][ T2787] RBP: 0000000000000005 R08: 0000000000000000 R09: 00007f942f0eb540
[  411.207972][ T2787] R10: 00007f942f0eb810 R11: 0000000000000246 R12: 0000000000000000
[  411.659094][ T2787] R13: 0000000000000004 R14: 0000000000000000 R15: 0000000000000000
[  412.119426][ T2787] Modules linked in: loop(E) input_leds evdev sg led_class mousedev video rapl backlight ac button binfmt_misc sd_mod t10_pi crc_t10dif crct10dif_generic sr_mod cdrom ata_generic psmouse ahci crct10dif_pclmul libahci crct10dif_common atkbd crc32_pclmul crc32c_intel ata_piix ghash_clmulni_intel libps2 libata aesni_intel libaes i8042 crypto_simd i2c_piix4 serio scsi_mod cryptd rtc_cmos i2c_core
[  413.585708][ T2787] CR2: 00000000000001b8
[  413.851068][ T2787] ---[ end trace 2bb5fac824816119 ]---
----------------------------------------

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [syzbot] possible deadlock in del_gendisk
  2021-06-12  2:35               ` Tetsuo Handa
@ 2021-06-13 11:01                 ` Tetsuo Handa
  0 siblings, 0 replies; 25+ messages in thread
From: Tetsuo Handa @ 2021-06-13 11:01 UTC (permalink / raw)
  To: Pavel Tatashin, Tyler Hicks, Petr Vorel, Christoph Hellwig
  Cc: Jens Axboe, Stefan Haberland, Jan Hoeppner, linux-block, syzbot,
	Tejun Heo, Linus Torvalds, Dmitry Vyukov

On 2021/06/12 11:35, Tetsuo Handa wrote:
> On 2021/06/12 0:49, Tetsuo Handa wrote:
>> On 2021/06/12 0:18, Pavel Tatashin wrote:
>>>>> Well, I made commit 310ca162d779efee ("block/loop: Use global lock for ioctl() operation.")
>>>>> because per device lock was not sufficient. Did commit 6cc8e7430801fa23 ("loop: scale loop
>>>>> device by introducing per device lock") take this problem into account?
>>>>
>>>> This was my intention when I wrote 6cc8e7430801fa23 ("loop: scale loop
>>>> device by introducing per device lock"). This is why this change does
>>>> not simply revert 310ca162d779efee ("block/loop: Use global lock for
>>>> ioctl() operation."), but keeps loop_ctl_mutex to protect the global
>>>> accesses.  loop_control_ioctl() is still locked by global
>>>> loop_ctl_mutex.
>>
>> No, loop_control_ioctl() (i.e. /dev/loop-control) is irrelevant here.
>> What 310ca162d779efee addressed but (I worry) 6cc8e7430801fa23 broke is
>> lo_ioctl() (i.e. /dev/loop$num).
>>
>> syzbot was reporting NULL pointer dereference which is caused by
>> race condition between ioctl(loop_fd, LOOP_CLR_FD, 0) versus
>> ioctl(other_loop_fd, LOOP_SET_FD, loop_fd) due to traversing other
>> loop devices at loop_validate_file() without holding corresponding
>> lo->lo_mutex lock.
> 
> Here is a reproducer and a race window widening patch.
> Since loop_validate_file() traverses on other loop devices,
> changing fd of loop device needs to be protected using a global lock.
> 

At least LOOP_SET_FD, LOOP_CONFIGURE, LOOP_CHANGE_FD, LOOP_CLR_FD needs to be
serialized using a global lock because loop_validate_file() traverses on other
loop devices which can cause NULL pointer dereference like syzbot has reported
in the past.

And I think LOOP_SET_CAPACITY, LOOP_SET_DIRECT_IO, LOOP_SET_BLOCK_SIZE also
needs to be serialized using a global lock because loop_change_fd() checks
capacity and dio state of other loop device which is not serialized.

I'd like to apply

  [PATCH] loop: drop loop_ctl_mutex around del_gendisk() in loop_remove()

as soon as possible because it is current top crasher (crashing on every 39 seconds).

I suggest simply reverting commit 6cc8e7430801fa23 ("loop: scale loop device by
introducing per device lock") for now. Do you want to revert 6cc8e7430801fa23
before my patch? If yes, I'll update my patch. If no, I'll just ask Jens to send
my patch to Linus.

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [PATCH] loop: drop loop_ctl_mutex around del_gendisk() in loop_remove()
  2021-06-11 15:14           ` [PATCH] loop: drop loop_ctl_mutex around del_gendisk() in loop_remove() Tetsuo Handa
@ 2021-06-15  5:30             ` Tetsuo Handa
  2021-06-15  5:31               ` syzbot
  2021-06-15  9:04             ` Jan Kara
  1 sibling, 1 reply; 25+ messages in thread
From: Tetsuo Handa @ 2021-06-15  5:30 UTC (permalink / raw)
  To: Christoph Hellwig
  Cc: Jens Axboe, Stefan Haberland, Jan Hoeppner, linux-block, syzbot,
	Tejun Heo, Jan Kara, Tyler Hicks, Pavel Tatashin, Petr Vorel

Found that commit 990e78116d38059c ("block: loop: fix deadlock between open and remove") went to 5.13-rc6.

#syz fix: block: loop: fix deadlock between open and remove

Now syzbot is reporting

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(nbd_index_mutex);
                               lock(&bdev->bd_mutex);
                               lock(nbd_index_mutex);
  lock(&bdev->bd_mutex);

at https://syzkaller.appspot.com/text?tag=CrashReport&x=11b8a5bbd00000 .


^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [PATCH] loop: drop loop_ctl_mutex around del_gendisk() in loop_remove()
  2021-06-15  5:30             ` Tetsuo Handa
@ 2021-06-15  5:31               ` syzbot
  0 siblings, 0 replies; 25+ messages in thread
From: syzbot @ 2021-06-15  5:31 UTC (permalink / raw)
  To: Tetsuo Handa
  Cc: axboe, hch, hoeppner, jack, linux-block, pasha.tatashin,
	penguin-kernel, pvorel, sth, tj, tyhicks, syzkaller-bugs

> Found that commit 990e78116d38059c ("block: loop: fix deadlock between open and remove") went to 5.13-rc6.
>
> #syz fix: block: loop: fix deadlock between open and remove

Your 'fix:' command is accepted, but please keep syzkaller-bugs@googlegroups.com mailing list in CC next time. It serves as a history of what happened with each bug report. Thank you.

>
> Now syzbot is reporting
>
>  Possible unsafe locking scenario:
>
>        CPU0                    CPU1
>        ----                    ----
>   lock(nbd_index_mutex);
>                                lock(&bdev->bd_mutex);
>                                lock(nbd_index_mutex);
>   lock(&bdev->bd_mutex);
>
> at https://syzkaller.appspot.com/text?tag=CrashReport&x=11b8a5bbd00000 .
>

^ permalink raw reply	[flat|nested] 25+ messages in thread

* Re: [PATCH] loop: drop loop_ctl_mutex around del_gendisk() in loop_remove()
  2021-06-11 15:14           ` [PATCH] loop: drop loop_ctl_mutex around del_gendisk() in loop_remove() Tetsuo Handa
  2021-06-15  5:30             ` Tetsuo Handa
@ 2021-06-15  9:04             ` Jan Kara
  1 sibling, 0 replies; 25+ messages in thread
From: Jan Kara @ 2021-06-15  9:04 UTC (permalink / raw)
  To: Tetsuo Handa
  Cc: Tyler Hicks, Pavel Tatashin, Petr Vorel, Christoph Hellwig,
	Jens Axboe, Stefan Haberland, Jan Hoeppner, linux-block, syzbot,
	Tejun Heo, Jan Kara

On Sat 12-06-21 00:14:20, Tetsuo Handa wrote:
> syzbot is reporting circular locking dependency between loop_ctl_mutex and
> bdev->bd_mutex [1] due to commit c76f48eb5c084b1e ("block: take bd_mutex
> around delete_partitions in del_gendisk").
> 
> But calling del_gendisk() from loop_remove() without loop_ctl_mutex held
> triggers a different race problem regarding sysfs entry management. We
> somehow need to serialize "add_disk() from loop_add()" and "del_gendisk()
>  from loop_remove()". Fortunately, since loop_control_ioctl() is called
> with no locks held, we can use "sleep and retry" approach without risking
> deadlock.
> 
> Since "struct loop_device"->lo_disk->private_data is set to non-NULL at
> loop_add() and is reset to NULL before calling loop_remove(), we can use
> it as a flag for taking appropriate action ("sleep and retry" or "skip")
> when loop_remove() is in progress.
> 
> Link: https://syzkaller.appspot.com/bug?extid=61e04e51b7ac86930589 [1]
> Reported-by: syzbot <syzbot+61e04e51b7ac86930589@syzkaller.appspotmail.com>
> Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
> Tested-by: syzbot <syzbot+61e04e51b7ac86930589@syzkaller.appspotmail.com>
> Fixes: c76f48eb5c084b1e ("block: take bd_mutex around delete_partitions in del_gendisk")

Christoph seems to have already fixed this by 990e78116d380 ("block: loop:
fix deadlock between open and remove").

								Honza

-- 
Jan Kara <jack@suse.com>
SUSE Labs, CR

^ permalink raw reply	[flat|nested] 25+ messages in thread

end of thread, other threads:[~2021-06-15  9:04 UTC | newest]

Thread overview: 25+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-04-13 17:33 [syzbot] possible deadlock in del_gendisk syzbot
2021-04-13 17:41 ` Steven Rostedt
2021-04-13 17:43   ` Steven Rostedt
2021-04-13 18:24     ` Dmitry Vyukov
2021-04-13 18:40       ` Steven Rostedt
2021-04-13 18:43         ` Steven Rostedt
2021-04-16  7:51           ` Bisections with different bug manifestations Dmitry Vyukov
2021-04-16 13:13             ` Steven Rostedt
2021-04-16 13:26               ` Dmitry Vyukov
2021-04-16 13:48                 ` Dmitry Vyukov
2021-06-07 10:56 ` [syzbot] possible deadlock in del_gendisk Tetsuo Handa
2021-06-09 16:31   ` Tetsuo Handa
2021-06-09 16:46     ` Tyler Hicks
2021-06-10 13:37       ` Tetsuo Handa
2021-06-11  6:46         ` Tetsuo Handa
2021-06-11 15:14           ` [PATCH] loop: drop loop_ctl_mutex around del_gendisk() in loop_remove() Tetsuo Handa
2021-06-15  5:30             ` Tetsuo Handa
2021-06-15  5:31               ` syzbot
2021-06-15  9:04             ` Jan Kara
2021-06-11 14:47       ` [syzbot] possible deadlock in del_gendisk Tetsuo Handa
2021-06-11 15:11         ` Pavel Tatashin
2021-06-11 15:18           ` Pavel Tatashin
2021-06-11 15:49             ` Tetsuo Handa
2021-06-12  2:35               ` Tetsuo Handa
2021-06-13 11:01                 ` Tetsuo Handa

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).