[v6.1] possible deadlock in hci_rfkill_set_block

Hello,

syzbot found the following issue on:

HEAD commit: 32c9cdbe383c Linux 6.1.60
git tree: linux-6.1.y
console output: https://syzkaller.appspot.com/x/log.txt?x=10a3b863680000
kernel config: https://syzkaller.appspot.com/x/.config?x=5bcc91053514ae0c
dashboard link: https://syzkaller.appspot.com/bug?extid=1cd9f78203c5a5d74187
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40

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

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/fa0c7d71cfa1/disk-32c9cdbe.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/6e0291f0843e/vmlinux-32c9cdbe.xz
kernel image: https://storage.googleapis.com/syzbot-assets/f990e610b477/bzImage-32c9cdbe.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: [email protected]

======================================================
WARNING: possible circular locking dependency detected
6.1.60-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.0/32558 is trying to acquire lock:
ffff88807d9250b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close net/bluetooth/hci_core.c:552 [inline]
ffff88807d9250b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_rfkill_set_block+0x129/0x200 net/bluetooth/hci_core.c:956

but task is already holding lock:
ffffffff8e543da8 (rfkill_global_mutex){+.+.}-{3:3}, at: rfkill_fop_write+0x1a5/0x790 net/rfkill/core.c:1278

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (rfkill_global_mutex){+.+.}-{3:3}:
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5661
__mutex_lock_common kernel/locking/mutex.c:603 [inline]
__mutex_lock+0x132/0xd80 kernel/locking/mutex.c:747
rfkill_register+0x30/0x880 net/rfkill/core.c:1057
hci_register_dev+0x4df/0xa40 net/bluetooth/hci_core.c:2655
__vhci_create_device drivers/bluetooth/hci_vhci.c:339 [inline]
vhci_create_device+0x3ba/0x6f0 drivers/bluetooth/hci_vhci.c:377
vhci_get_user drivers/bluetooth/hci_vhci.c:434 [inline]
vhci_write+0x38b/0x440 drivers/bluetooth/hci_vhci.c:514
call_write_iter include/linux/fs.h:2205 [inline]
new_sync_write fs/read_write.c:491 [inline]
vfs_write+0x7ae/0xba0 fs/read_write.c:584
ksys_write+0x19c/0x2c0 fs/read_write.c:637
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd

-> #2 (&data->open_mutex){+.+.}-{3:3}:
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5661
__mutex_lock_common kernel/locking/mutex.c:603 [inline]
__mutex_lock+0x132/0xd80 kernel/locking/mutex.c:747
vhci_send_frame+0x8a/0xf0 drivers/bluetooth/hci_vhci.c:78
hci_send_frame+0x1ef/0x370 net/bluetooth/hci_core.c:3035
hci_sched_acl_pkt net/bluetooth/hci_core.c:3642 [inline]
hci_sched_acl net/bluetooth/hci_core.c:3727 [inline]
hci_tx_work+0xec8/0x1ec0 net/bluetooth/hci_core.c:3826
process_one_work+0x8a9/0x11d0 kernel/workqueue.c:2292
worker_thread+0xa47/0x1200 kernel/workqueue.c:2439
kthread+0x28d/0x320 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306

-> #1 ((work_completion)(&hdev->tx_work)){+.+.}-{0:0}:
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5661
__flush_work+0xfe/0xad0 kernel/workqueue.c:3072
hci_dev_close_sync+0x233/0xfc0 net/bluetooth/hci_sync.c:4936
hci_dev_do_close net/bluetooth/hci_core.c:554 [inline]
hci_error_reset+0x104/0x250 net/bluetooth/hci_core.c:1059
process_one_work+0x8a9/0x11d0 kernel/workqueue.c:2292
worker_thread+0xa47/0x1200 kernel/workqueue.c:2439
kthread+0x28d/0x320 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306

-> #0 (&hdev->req_lock){+.+.}-{3:3}:
check_prev_add kernel/locking/lockdep.c:3090 [inline]
check_prevs_add kernel/locking/lockdep.c:3209 [inline]
validate_chain+0x1667/0x58e0 kernel/locking/lockdep.c:3824
__lock_acquire+0x125b/0x1f80 kernel/locking/lockdep.c:5048
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5661
__mutex_lock_common kernel/locking/mutex.c:603 [inline]
__mutex_lock+0x132/0xd80 kernel/locking/mutex.c:747
hci_dev_do_close net/bluetooth/hci_core.c:552 [inline]
hci_rfkill_set_block+0x129/0x200 net/bluetooth/hci_core.c:956
rfkill_set_block+0x1e7/0x430 net/rfkill/core.c:345
rfkill_fop_write+0x5b7/0x790 net/rfkill/core.c:1286
do_iter_write+0x503/0xc50 fs/read_write.c:863
vfs_writev fs/read_write.c:934 [inline]
do_writev+0x27b/0x460 fs/read_write.c:977
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd

other info that might help us debug this:

Chain exists of:
&hdev->req_lock --> &data->open_mutex --> rfkill_global_mutex

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(rfkill_global_mutex);
lock(&data->open_mutex);
lock(rfkill_global_mutex);
lock(&hdev->req_lock);

*** DEADLOCK ***

1 lock held by syz-executor.0/32558:
#0: ffffffff8e543da8 (rfkill_global_mutex){+.+.}-{3:3}, at: rfkill_fop_write+0x1a5/0x790 net/rfkill/core.c:1278

stack backtrace:
CPU: 0 PID: 32558 Comm: syz-executor.0 Not tainted 6.1.60-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/06/2023
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x1e3/0x2cb lib/dump_stack.c:106
check_noncircular+0x2fa/0x3b0 kernel/locking/lockdep.c:2170
check_prev_add kernel/locking/lockdep.c:3090 [inline]
check_prevs_add kernel/locking/lockdep.c:3209 [inline]
validate_chain+0x1667/0x58e0 kernel/locking/lockdep.c:3824
__lock_acquire+0x125b/0x1f80 kernel/locking/lockdep.c:5048
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5661
__mutex_lock_common kernel/locking/mutex.c:603 [inline]
__mutex_lock+0x132/0xd80 kernel/locking/mutex.c:747
hci_dev_do_close net/bluetooth/hci_core.c:552 [inline]
hci_rfkill_set_block+0x129/0x200 net/bluetooth/hci_core.c:956
rfkill_set_block+0x1e7/0x430 net/rfkill/core.c:345
rfkill_fop_write+0x5b7/0x790 net/rfkill/core.c:1286
do_iter_write+0x503/0xc50 fs/read_write.c:863
vfs_writev fs/read_write.c:934 [inline]
do_writev+0x27b/0x460 fs/read_write.c:977
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fcc5d27cae9
Code: 28 00 00 00 75 05 48 83 c4 28 c3 e8 e1 20 00 00 90 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 b0 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fcc5dfc10c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000014
RAX: ffffffffffffffda RBX: 00007fcc5d39bf80 RCX: 00007fcc5d27cae9
RDX: 0000000000000001 RSI: 00000000200000c0 RDI: 0000000000000003
RBP: 00007fcc5d2c847a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000000b R14: 00007fcc5d39bf80 R15: 00007ffd96a53138
</TASK>


---
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 [email protected].

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

If the bug is already fixed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want to overwrite bug's subsystems, reply with:
#syz set subsystems: new-subsystem
(See the list of subsystem names on the web dashboard)

If the bug is a duplicate of another bug, reply with:
#syz dup: exact-subject-of-another-report

If you want to undo deduplication, reply with:
#syz undup

syzbot has found a reproducer for the following issue on:
console output: https://syzkaller.appspot.com/x/log.txt?x=125c10f1680000
kernel config: https://syzkaller.appspot.com/x/.config?x=c022d971b9287d2b
userspace arch: arm64
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=12cc91fd680000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=175e65b3680000

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/a490a5ba6b9d/disk-32c9cdbe.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/2c65d1af9e04/vmlinux-32c9cdbe.xz
kernel image: https://storage.googleapis.com/syzbot-assets/d262499bca4d/Image-32c9cdbe.gz.xz
syz-executor477/4222 is trying to acquire lock:
ffff0000cf8c8dc0 ((work_completion)(&hdev->tx_work)){+.+.}-{0:0}, at: __flush_work+0xd0/0x1c0 kernel/workqueue.c:3072
ffff0000cf8c90b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close net/bluetooth/hci_core.c:552 [inline]
ffff0000cf8c90b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_rfkill_set_block+0xe8/0x20c net/bluetooth/hci_core.c:956
-> #3 (&hdev->req_lock){+.+.}-{3:3}:
__mutex_lock_common+0x190/0x21a0 kernel/locking/mutex.c:603
__mutex_lock kernel/locking/mutex.c:747 [inline]
mutex_lock_nested+0x38/0x44 kernel/locking/mutex.c:799
hci_dev_do_close net/bluetooth/hci_core.c:552 [inline]
hci_rfkill_set_block+0xe8/0x20c net/bluetooth/hci_core.c:956
rfkill_set_block+0x18c/0x37c net/rfkill/core.c:345
rfkill_fop_write+0x578/0x734 net/rfkill/core.c:1286
vfs_write+0x2a4/0x914 fs/read_write.c:582
ksys_write+0x15c/0x26c fs/read_write.c:637
__do_sys_write fs/read_write.c:649 [inline]
__se_sys_write fs/read_write.c:646 [inline]
__arm64_sys_write+0x7c/0x90 fs/read_write.c:646
__invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
invoke_syscall+0x98/0x2c0 arch/arm64/kernel/syscall.c:52
el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
do_el0_svc+0x64/0x218 arch/arm64/kernel/syscall.c:206
el0_svc+0x58/0x168 arch/arm64/kernel/entry-common.c:637
el0t_64_sync_handler+0x84/0xf0 arch/arm64/kernel/entry-common.c:655
el0t_64_sync+0x18c/0x190 arch/arm64/kernel/entry.S:585

-> #2 (rfkill_global_mutex){+.+.}-{3:3}:
__mutex_lock_common+0x190/0x21a0 kernel/locking/mutex.c:603
__mutex_lock kernel/locking/mutex.c:747 [inline]
mutex_lock_nested+0x38/0x44 kernel/locking/mutex.c:799
rfkill_register+0x44/0x7a4 net/rfkill/core.c:1057
hci_register_dev+0x3e0/0x954 net/bluetooth/hci_core.c:2655
__vhci_create_device drivers/bluetooth/hci_vhci.c:339 [inline]
vhci_create_device+0x358/0x694 drivers/bluetooth/hci_vhci.c:377
vhci_get_user drivers/bluetooth/hci_vhci.c:434 [inline]
vhci_write+0x318/0x3b8 drivers/bluetooth/hci_vhci.c:514
vfs_write+0x610/0x914 fs/read_write.c:584
ksys_write+0x15c/0x26c fs/read_write.c:637
__do_sys_write fs/read_write.c:649 [inline]
__se_sys_write fs/read_write.c:646 [inline]
__arm64_sys_write+0x7c/0x90 fs/read_write.c:646
__invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
invoke_syscall+0x98/0x2c0 arch/arm64/kernel/syscall.c:52
el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
do_el0_svc+0x64/0x218 arch/arm64/kernel/syscall.c:206
el0_svc+0x58/0x168 arch/arm64/kernel/entry-common.c:637
el0t_64_sync_handler+0x84/0xf0 arch/arm64/kernel/entry-common.c:655
el0t_64_sync+0x18c/0x190 arch/arm64/kernel/entry.S:585

-> #1 (&data->open_mutex){+.+.}-{3:3}:
__mutex_lock_common+0x190/0x21a0 kernel/locking/mutex.c:603
__mutex_lock kernel/locking/mutex.c:747 [inline]
mutex_lock_nested+0x38/0x44 kernel/locking/mutex.c:799
vhci_send_frame+0x8c/0x10c drivers/bluetooth/hci_vhci.c:78
hci_send_frame+0x1c4/0x35c net/bluetooth/hci_core.c:3035
hci_tx_work+0xba0/0x18e4 net/bluetooth/hci_core.c:3826
process_one_work+0x7ac/0x1404 kernel/workqueue.c:2292
worker_thread+0x8e4/0xfec kernel/workqueue.c:2439
kthread+0x250/0x2d8 kernel/kthread.c:376
ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:864

-> #0 ((work_completion)(&hdev->tx_work)){+.+.}-{0:0}:
validate_chain kernel/locking/lockdep.c:3824 [inline]
__lock_acquire+0x3338/0x764c kernel/locking/lockdep.c:5048
lock_acquire+0x26c/0x7cc kernel/locking/lockdep.c:5661
__flush_work+0xf8/0x1c0 kernel/workqueue.c:3072
flush_work+0x24/0x38 kernel/workqueue.c:3097
hci_dev_close_sync+0x1c8/0xf1c net/bluetooth/hci_sync.c:4936
hci_dev_do_close net/bluetooth/hci_core.c:554 [inline]
hci_rfkill_set_block+0xf0/0x20c net/bluetooth/hci_core.c:956
rfkill_set_block+0x18c/0x37c net/rfkill/core.c:345
rfkill_fop_write+0x578/0x734 net/rfkill/core.c:1286
vfs_write+0x2a4/0x914 fs/read_write.c:582
ksys_write+0x15c/0x26c fs/read_write.c:637
__do_sys_write fs/read_write.c:649 [inline]
__se_sys_write fs/read_write.c:646 [inline]
__arm64_sys_write+0x7c/0x90 fs/read_write.c:646
__invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
invoke_syscall+0x98/0x2c0 arch/arm64/kernel/syscall.c:52
el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
do_el0_svc+0x64/0x218 arch/arm64/kernel/syscall.c:206
el0_svc+0x58/0x168 arch/arm64/kernel/entry-common.c:637
el0t_64_sync_handler+0x84/0xf0 arch/arm64/kernel/entry-common.c:655
el0t_64_sync+0x18c/0x190 arch/arm64/kernel/entry.S:585
(work_completion)(&hdev->tx_work) --> rfkill_global_mutex --> &hdev->req_lock
lock(&hdev->req_lock);
lock(rfkill_global_mutex);
lock(&hdev->req_lock);
lock((work_completion)(&hdev->tx_work));

*** DEADLOCK ***

2 locks held by syz-executor477/4222:
#0: ffff80001808ab48 (rfkill_global_mutex){+.+.}-{3:3}, at: rfkill_fop_write+0x234/0x734 net/rfkill/core.c:1278
#1: ffff0000cf8c90b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close net/bluetooth/hci_core.c:552 [inline]
#1: ffff0000cf8c90b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_rfkill_set_block+0xe8/0x20c net/bluetooth/hci_core.c:956

stack backtrace:
CPU: 0 PID: 4222 Comm: syz-executor477 Not tainted 6.1.60-syzkaller #0
Call trace:
dump_backtrace+0x1c8/0x1f4 arch/arm64/kernel/stacktrace.c:158
show_stack+0x2c/0x3c arch/arm64/kernel/stacktrace.c:165
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x108/0x170 lib/dump_stack.c:106
dump_stack+0x1c/0x58 lib/dump_stack.c:113
print_circular_bug+0x150/0x1b8 kernel/locking/lockdep.c:2048
check_noncircular+0x2cc/0x378 kernel/locking/lockdep.c:2170
validate_chain kernel/locking/lockdep.c:3824 [inline]
__lock_acquire+0x3338/0x764c kernel/locking/lockdep.c:5048
lock_acquire+0x26c/0x7cc kernel/locking/lockdep.c:5661
__flush_work+0xf8/0x1c0 kernel/workqueue.c:3072
flush_work+0x24/0x38 kernel/workqueue.c:3097
hci_dev_close_sync+0x1c8/0xf1c net/bluetooth/hci_sync.c:4936
hci_dev_do_close net/bluetooth/hci_core.c:554 [inline]
hci_rfkill_set_block+0xf0/0x20c net/bluetooth/hci_core.c:956
rfkill_set_block+0x18c/0x37c net/rfkill/core.c:345
rfkill_fop_write+0x578/0x734 net/rfkill/core.c:1286
vfs_write+0x2a4/0x914 fs/read_write.c:582
ksys_write+0x15c/0x26c fs/read_write.c:637
__do_sys_write fs/read_write.c:649 [inline]
__se_sys_write fs/read_write.c:646 [inline]
__arm64_sys_write+0x7c/0x90 fs/read_write.c:646
__invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
invoke_syscall+0x98/0x2c0 arch/arm64/kernel/syscall.c:52
el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
do_el0_svc+0x64/0x218 arch/arm64/kernel/syscall.c:206
el0_svc+0x58/0x168 arch/arm64/kernel/entry-common.c:637
el0t_64_sync_handler+0x84/0xf0 arch/arm64/kernel/entry-common.c:655
el0t_64_sync+0x18c/0x190 arch/arm64/kernel/entry.S:585


---
If you want syzbot to run the reproducer, reply with:
#syz test: git://repo/address.git branch-or-commit-hash
If you attach or paste a git patch, syzbot will apply it before testing.

syzbot suspects this issue was fixed by commit:

commit fc64715105825b9822dd17416830df50355aad08
Author: Ying Hsu <[email protected]>
Date: Fri Nov 10 01:46:05 2023 +0000

Bluetooth: Fix deadlock in vhci_send_frame

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=15be0a9fe80000
start commit: 6c6a6c7e211c Linux 6.1.66
git tree: linux-6.1.y
kernel config: https://syzkaller.appspot.com/x/.config?x=8fa519fe1c08a54
dashboard link: https://syzkaller.appspot.com/bug?extid=1cd9f78203c5a5d74187
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=12673b8ce80000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=119c5c0ae80000

If the result looks correct, please mark the issue as fixed by replying with:

#syz fix: Bluetooth: Fix deadlock in vhci_send_frame

For information about bisection process see: https://goo.gl/tpsmEJ#bisection