[v5.15] possible deadlock in hci_dev_do_close

0 views
Skip to first unread message

syzbot

unread,
Oct 25, 2023, 8:11:01 AM10/25/23
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: 12952a23a5da Linux 5.15.137
git tree: linux-5.15.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1365940d680000
kernel config: https://syzkaller.appspot.com/x/.config?x=d5d31a3160e35771
dashboard link: https://syzkaller.appspot.com/bug?extid=517ea4fe8e9e2e8c9a6a
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
userspace arch: arm64

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

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/a52e721f848f/disk-12952a23.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/f568d3b2b0c4/vmlinux-12952a23.xz
kernel image: https://storage.googleapis.com/syzbot-assets/5c8641a162ac/Image-12952a23.gz.xz

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

======================================================
WARNING: possible circular locking dependency detected
5.15.137-syzkaller #0 Not tainted
------------------------------------------------------
kworker/1:3/1953 is trying to acquire lock:
ffff0000c0d6cb98 ((work_completion)(&hdev->tx_work)){+.+.}-{0:0}, at: __flush_work+0xd0/0x1c0 kernel/workqueue.c:3090

but task is already holding lock:
ffff0000c0d6cff0 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close+0x64/0x1060 net/bluetooth/hci_core.c:1737

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&hdev->req_lock){+.+.}-{3:3}:
__mutex_lock_common+0x194/0x2154 kernel/locking/mutex.c:596
__mutex_lock kernel/locking/mutex.c:729 [inline]
mutex_lock_nested+0xa4/0xf8 kernel/locking/mutex.c:743
hci_dev_do_close+0x64/0x1060 net/bluetooth/hci_core.c:1737
hci_rfkill_set_block+0xdc/0x1d0 net/bluetooth/hci_core.c:2235
rfkill_set_block+0x18c/0x37c net/rfkill/core.c:345
rfkill_epo+0x8c/0x158 net/rfkill/core.c:454
__rfkill_handle_global_op net/rfkill/input.c:60 [inline]
rfkill_op_handler+0x170/0x288 net/rfkill/input.c:108
process_one_work+0x790/0x11b8 kernel/workqueue.c:2310
worker_thread+0x910/0x1034 kernel/workqueue.c:2457
kthread+0x37c/0x45c kernel/kthread.c:319
ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:870

-> #2 (rfkill_global_mutex){+.+.}-{3:3}:
__mutex_lock_common+0x194/0x2154 kernel/locking/mutex.c:596
__mutex_lock kernel/locking/mutex.c:729 [inline]
mutex_lock_nested+0xa4/0xf8 kernel/locking/mutex.c:743
rfkill_register+0x44/0x7a4 net/rfkill/core.c:1045
hci_register_dev+0x3e0/0x880 net/bluetooth/hci_core.c:3959
__vhci_create_device drivers/bluetooth/hci_vhci.c:129 [inline]
vhci_create_device+0x2c4/0x568 drivers/bluetooth/hci_vhci.c:153
vhci_get_user drivers/bluetooth/hci_vhci.c:210 [inline]
vhci_write+0x318/0x3b8 drivers/bluetooth/hci_vhci.c:290
call_write_iter include/linux/fs.h:2103 [inline]
new_sync_write fs/read_write.c:507 [inline]
vfs_write+0x87c/0xb3c fs/read_write.c:594
ksys_write+0x15c/0x26c fs/read_write.c:647
__do_sys_write fs/read_write.c:659 [inline]
__se_sys_write fs/read_write.c:656 [inline]
__arm64_sys_write+0x7c/0x90 fs/read_write.c:656
__invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:52
el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
do_el0_svc+0x58/0x14c arch/arm64/kernel/syscall.c:181
el0_svc+0x7c/0x1f0 arch/arm64/kernel/entry-common.c:608
el0t_64_sync_handler+0x84/0xe4 arch/arm64/kernel/entry-common.c:626
el0t_64_sync+0x1a0/0x1a4 arch/arm64/kernel/entry.S:584

-> #1 (&data->open_mutex){+.+.}-{3:3}:
__mutex_lock_common+0x194/0x2154 kernel/locking/mutex.c:596
__mutex_lock kernel/locking/mutex.c:729 [inline]
mutex_lock_nested+0xa4/0xf8 kernel/locking/mutex.c:743
vhci_send_frame+0x8c/0x10c drivers/bluetooth/hci_vhci.c:71
hci_send_frame+0x194/0x2f0 net/bluetooth/hci_core.c:4251
hci_sched_acl_pkt net/bluetooth/hci_core.c:4776 [inline]
hci_sched_acl net/bluetooth/hci_core.c:4861 [inline]
hci_tx_work+0x8d8/0x157c net/bluetooth/hci_core.c:4932
process_one_work+0x790/0x11b8 kernel/workqueue.c:2310
worker_thread+0x910/0x1034 kernel/workqueue.c:2457
kthread+0x37c/0x45c kernel/kthread.c:319
ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:870

-> #0 ((work_completion)(&hdev->tx_work)){+.+.}-{0:0}:
check_prev_add kernel/locking/lockdep.c:3053 [inline]
check_prevs_add kernel/locking/lockdep.c:3172 [inline]
validate_chain kernel/locking/lockdep.c:3787 [inline]
__lock_acquire+0x32cc/0x7620 kernel/locking/lockdep.c:5011
lock_acquire+0x240/0x77c kernel/locking/lockdep.c:5622
__flush_work+0xf8/0x1c0 kernel/workqueue.c:3090
flush_work+0x24/0x38 kernel/workqueue.c:3115
hci_dev_do_close+0x16c/0x1060 net/bluetooth/hci_core.c:1756
hci_rfkill_set_block+0xdc/0x1d0 net/bluetooth/hci_core.c:2235
rfkill_set_block+0x18c/0x37c net/rfkill/core.c:345
rfkill_epo+0x8c/0x158 net/rfkill/core.c:454
__rfkill_handle_global_op net/rfkill/input.c:60 [inline]
rfkill_op_handler+0x170/0x288 net/rfkill/input.c:108
process_one_work+0x790/0x11b8 kernel/workqueue.c:2310
worker_thread+0x910/0x1034 kernel/workqueue.c:2457
kthread+0x37c/0x45c kernel/kthread.c:319
ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:870

other info that might help us debug this:

Chain exists of:
(work_completion)(&hdev->tx_work) --> rfkill_global_mutex --> &hdev->req_lock

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&hdev->req_lock);
lock(rfkill_global_mutex);
lock(&hdev->req_lock);
lock((work_completion)(&hdev->tx_work));

*** DEADLOCK ***

4 locks held by kworker/1:3/1953:
#0: ffff0000c0020d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x66c/0x11b8 kernel/workqueue.c:2283
#1: ffff800022057c00 ((rfkill_op_work).work){+.+.}-{0:0}, at: process_one_work+0x6ac/0x11b8 kernel/workqueue.c:2285
#2: ffff800016c8cc08 (rfkill_global_mutex){+.+.}-{3:3}, at: rfkill_epo+0x58/0x158 net/rfkill/core.c:450
#3: ffff0000c0d6cff0 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close+0x64/0x1060 net/bluetooth/hci_core.c:1737

stack backtrace:
CPU: 1 PID: 1953 Comm: kworker/1:3 Not tainted 5.15.137-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/06/2023
Workqueue: events rfkill_op_handler
Call trace:
dump_backtrace+0x0/0x530 arch/arm64/kernel/stacktrace.c:152
show_stack+0x2c/0x3c arch/arm64/kernel/stacktrace.c:216
__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:2011
check_noncircular+0x2cc/0x378 kernel/locking/lockdep.c:2133
check_prev_add kernel/locking/lockdep.c:3053 [inline]
check_prevs_add kernel/locking/lockdep.c:3172 [inline]
validate_chain kernel/locking/lockdep.c:3787 [inline]
__lock_acquire+0x32cc/0x7620 kernel/locking/lockdep.c:5011
lock_acquire+0x240/0x77c kernel/locking/lockdep.c:5622
__flush_work+0xf8/0x1c0 kernel/workqueue.c:3090
flush_work+0x24/0x38 kernel/workqueue.c:3115
hci_dev_do_close+0x16c/0x1060 net/bluetooth/hci_core.c:1756
hci_rfkill_set_block+0xdc/0x1d0 net/bluetooth/hci_core.c:2235
rfkill_set_block+0x18c/0x37c net/rfkill/core.c:345
rfkill_epo+0x8c/0x158 net/rfkill/core.c:454
__rfkill_handle_global_op net/rfkill/input.c:60 [inline]
rfkill_op_handler+0x170/0x288 net/rfkill/input.c:108
process_one_work+0x790/0x11b8 kernel/workqueue.c:2310
worker_thread+0x910/0x1034 kernel/workqueue.c:2457
kthread+0x37c/0x45c kernel/kthread.c:319
ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:870


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

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

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

unread,
Oct 26, 2023, 3:21:26 PM10/26/23
to syzkaller...@googlegroups.com
syzbot has found a reproducer for the following issue on:

HEAD commit: 12952a23a5da Linux 5.15.137
git tree: linux-5.15.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1556c4a5680000
kernel config: https://syzkaller.appspot.com/x/.config?x=d5d31a3160e35771
dashboard link: https://syzkaller.appspot.com/bug?extid=517ea4fe8e9e2e8c9a6a
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
userspace arch: arm64
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=13c2581b680000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=132a95b9680000

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/a52e721f848f/disk-12952a23.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/f568d3b2b0c4/vmlinux-12952a23.xz
kernel image: https://storage.googleapis.com/syzbot-assets/5c8641a162ac/Image-12952a23.gz.xz

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

======================================================
WARNING: possible circular locking dependency detected
5.15.137-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor306/3966 is trying to acquire lock:
ffff0000c8d4cb98 ((work_completion)(&hdev->tx_work)){+.+.}-{0:0}, at: __flush_work+0xd0/0x1c0 kernel/workqueue.c:3090

but task is already holding lock:
ffff0000c8d4cff0 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close+0x64/0x1060 net/bluetooth/hci_core.c:1737

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&hdev->req_lock){+.+.}-{3:3}:
__mutex_lock_common+0x194/0x2154 kernel/locking/mutex.c:596
__mutex_lock kernel/locking/mutex.c:729 [inline]
mutex_lock_nested+0xa4/0xf8 kernel/locking/mutex.c:743
hci_dev_do_close+0x64/0x1060 net/bluetooth/hci_core.c:1737
hci_rfkill_set_block+0xdc/0x1d0 net/bluetooth/hci_core.c:2235
rfkill_set_block+0x18c/0x37c net/rfkill/core.c:345
rfkill_fop_write+0x594/0x750 net/rfkill/core.c:1274
vfs_write+0x280/0xb3c fs/read_write.c:592
rfkill_fop_write+0x594/0x750 net/rfkill/core.c:1274
vfs_write+0x280/0xb3c fs/read_write.c:592
ksys_write+0x15c/0x26c fs/read_write.c:647
__do_sys_write fs/read_write.c:659 [inline]
__se_sys_write fs/read_write.c:656 [inline]
__arm64_sys_write+0x7c/0x90 fs/read_write.c:656
__invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:52
el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
do_el0_svc+0x58/0x14c arch/arm64/kernel/syscall.c:181
el0_svc+0x7c/0x1f0 arch/arm64/kernel/entry-common.c:608
el0t_64_sync_handler+0x84/0xe4 arch/arm64/kernel/entry-common.c:626
el0t_64_sync+0x1a0/0x1a4 arch/arm64/kernel/entry.S:584

other info that might help us debug this:

Chain exists of:
(work_completion)(&hdev->tx_work) --> rfkill_global_mutex --> &hdev->req_lock

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&hdev->req_lock);
lock(rfkill_global_mutex);
lock(&hdev->req_lock);
lock((work_completion)(&hdev->tx_work));

*** DEADLOCK ***

2 locks held by syz-executor306/3966:
#0: ffff800016c8cc08 (rfkill_global_mutex){+.+.}-{3:3}, at: rfkill_fop_write+0x250/0x750 net/rfkill/core.c:1266
#1: ffff0000c8d4cff0 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close+0x64/0x1060 net/bluetooth/hci_core.c:1737

stack backtrace:
CPU: 1 PID: 3966 Comm: syz-executor306 Not tainted 5.15.137-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/06/2023
Call trace:
dump_backtrace+0x0/0x530 arch/arm64/kernel/stacktrace.c:152
show_stack+0x2c/0x3c arch/arm64/kernel/stacktrace.c:216
__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:2011
check_noncircular+0x2cc/0x378 kernel/locking/lockdep.c:2133
check_prev_add kernel/locking/lockdep.c:3053 [inline]
check_prevs_add kernel/locking/lockdep.c:3172 [inline]
validate_chain kernel/locking/lockdep.c:3787 [inline]
__lock_acquire+0x32cc/0x7620 kernel/locking/lockdep.c:5011
lock_acquire+0x240/0x77c kernel/locking/lockdep.c:5622
__flush_work+0xf8/0x1c0 kernel/workqueue.c:3090
flush_work+0x24/0x38 kernel/workqueue.c:3115
hci_dev_do_close+0x16c/0x1060 net/bluetooth/hci_core.c:1756
hci_rfkill_set_block+0xdc/0x1d0 net/bluetooth/hci_core.c:2235
rfkill_set_block+0x18c/0x37c net/rfkill/core.c:345
rfkill_fop_write+0x594/0x750 net/rfkill/core.c:1274
vfs_write+0x280/0xb3c fs/read_write.c:592
ksys_write+0x15c/0x26c fs/read_write.c:647
__do_sys_write fs/read_write.c:659 [inline]
__se_sys_write fs/read_write.c:656 [inline]
__arm64_sys_write+0x7c/0x90 fs/read_write.c:656
__invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:52
el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
do_el0_svc+0x58/0x14c arch/arm64/kernel/syscall.c:181
el0_svc+0x7c/0x1f0 arch/arm64/kernel/entry-common.c:608
el0t_64_sync_handler+0x84/0xe4 arch/arm64/kernel/entry-common.c:626
el0t_64_sync+0x1a0/0x1a4 arch/arm64/kernel/entry.S:584


---
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.
Reply all
Reply to author
Forward
0 new messages