possible deadlock in hci_error_reset

Status: closed as dup on 2024/02/02 20:07
Subsystems: bluetooth
[Documentation on labels]
Reported-by: syzbot+47d22a47f6bd21399c93@syzkaller.appspotmail.com
First crash: 1004d, last: 1004d
▶ ▼ Duplicate of
Title Rank 🛈 Repro Cause bisect Fix bisect Count Last Reported
possible deadlock in hci_rfkill_set_block bluetooth 4 syz, C done 3391 950d 1023d
▶ ▼ Discussions (1)
Title Replies (including bot) Last reply
[syzbot] [bluetooth?] possible deadlock in hci_error_reset 0 (2) 2024/02/02 20:07

Sample crash report:
Bluetooth: hci5: hardware error 0x00
======================================================
WARNING: possible circular locking dependency detected
6.6.0-rc7-syzkaller-g8de1e7afcc1c #0 Not tainted
------------------------------------------------------
kworker/u5:3/6132 is trying to acquire lock:
ffff0000d5a40dc0 ((work_completion)(&hdev->tx_work)){+.+.}-{0:0}, at: __flush_work+0xd0/0x1c0 kernel/workqueue.c:3403

but task is already holding lock:
ffff0000d5a410b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close net/bluetooth/hci_core.c:552 [inline]
ffff0000d5a410b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_error_reset+0xec/0x248 net/bluetooth/hci_core.c:1059

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+0x190/0x21a0 kernel/locking/mutex.c:603
       __mutex_lock kernel/locking/mutex.c:747 [inline]
       mutex_lock_nested+0x2c/0x38 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:346
       rfkill_fop_write+0x578/0x734 net/rfkill/core.c:1305
       vfs_write+0x2a0/0x93c 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:37 [inline]
       invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:51
       el0_svc_common+0x130/0x23c arch/arm64/kernel/syscall.c:136
       do_el0_svc+0x48/0x58 arch/arm64/kernel/syscall.c:155
       el0_svc+0x54/0x158 arch/arm64/kernel/entry-common.c:678
       el0t_64_sync_handler+0x84/0xfc arch/arm64/kernel/entry-common.c:696
       el0t_64_sync+0x190/0x194 arch/arm64/kernel/entry.S:595

-> #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+0x2c/0x38 kernel/locking/mutex.c:799
       rfkill_register+0x44/0x7d4 net/rfkill/core.c:1075
       hci_register_dev+0x3e0/0x954 net/bluetooth/hci_core.c:2656
       __vhci_create_device drivers/bluetooth/hci_vhci.c:437 [inline]
       vhci_create_device+0x358/0x6c4 drivers/bluetooth/hci_vhci.c:478
       vhci_get_user drivers/bluetooth/hci_vhci.c:535 [inline]
       vhci_write+0x318/0x3b8 drivers/bluetooth/hci_vhci.c:615
       call_write_iter include/linux/fs.h:1956 [inline]
       new_sync_write fs/read_write.c:491 [inline]
       vfs_write+0x628/0x93c 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:37 [inline]
       invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:51
       el0_svc_common+0x130/0x23c arch/arm64/kernel/syscall.c:136
       do_el0_svc+0x48/0x58 arch/arm64/kernel/syscall.c:155
       el0_svc+0x54/0x158 arch/arm64/kernel/entry-common.c:678
       el0t_64_sync_handler+0x84/0xfc arch/arm64/kernel/entry-common.c:696
       el0t_64_sync+0x190/0x194 arch/arm64/kernel/entry.S:595

-> #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+0x2c/0x38 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:3039
       hci_sched_acl_pkt net/bluetooth/hci_core.c:3651 [inline]
       hci_sched_acl net/bluetooth/hci_core.c:3736 [inline]
       hci_tx_work+0xba0/0x18e4 net/bluetooth/hci_core.c:3835
       process_one_work+0x694/0x1204 kernel/workqueue.c:2630
       process_scheduled_works kernel/workqueue.c:2703 [inline]
       worker_thread+0x938/0xef4 kernel/workqueue.c:2784
       kthread+0x288/0x310 kernel/kthread.c:388
       ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:857

-> #0 ((work_completion)(&hdev->tx_work)){+.+.}-{0:0}:
       check_prev_add kernel/locking/lockdep.c:3134 [inline]
       check_prevs_add kernel/locking/lockdep.c:3253 [inline]
       validate_chain kernel/locking/lockdep.c:3868 [inline]
       __lock_acquire+0x3370/0x75e8 kernel/locking/lockdep.c:5136
       lock_acquire+0x23c/0x71c kernel/locking/lockdep.c:5753
       __flush_work+0xf8/0x1c0 kernel/workqueue.c:3403
       flush_work+0x24/0x38 kernel/workqueue.c:3428
       hci_dev_close_sync+0x1c8/0xf2c net/bluetooth/hci_sync.c:4982
       hci_dev_do_close net/bluetooth/hci_core.c:554 [inline]
       hci_error_reset+0xf4/0x248 net/bluetooth/hci_core.c:1059
       process_one_work+0x694/0x1204 kernel/workqueue.c:2630
       process_scheduled_works kernel/workqueue.c:2703 [inline]
       worker_thread+0x938/0xef4 kernel/workqueue.c:2784
       kthread+0x288/0x310 kernel/kthread.c:388
       ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:857

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 ***

3 locks held by kworker/u5:3/6132:
 #0: ffff0000d425d938 ((wq_completion)hci5){+.+.}-{0:0}, at: process_one_work+0x560/0x1204 kernel/workqueue.c:2603
 #1: ffff800096f07c20 ((work_completion)(&hdev->error_reset)){+.+.}-{0:0}, at: process_one_work+0x5a0/0x1204 kernel/workqueue.c:2605
 #2: ffff0000d5a410b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close net/bluetooth/hci_core.c:552 [inline]
 #2: ffff0000d5a410b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_error_reset+0xec/0x248 net/bluetooth/hci_core.c:1059

stack backtrace:
CPU: 1 PID: 6132 Comm: kworker/u5:3 Not tainted 6.6.0-rc7-syzkaller-g8de1e7afcc1c #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/09/2023
Workqueue: hci5 hci_error_reset
Call trace:
 dump_backtrace+0x1b8/0x1e4 arch/arm64/kernel/stacktrace.c:233
 show_stack+0x2c/0x44 arch/arm64/kernel/stacktrace.c:240
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xd0/0x124 lib/dump_stack.c:106
 dump_stack+0x1c/0x28 lib/dump_stack.c:113
 print_circular_bug+0x150/0x1b8 kernel/locking/lockdep.c:2060
 check_noncircular+0x310/0x404 kernel/locking/lockdep.c:2187
 check_prev_add kernel/locking/lockdep.c:3134 [inline]
 check_prevs_add kernel/locking/lockdep.c:3253 [inline]
 validate_chain kernel/locking/lockdep.c:3868 [inline]
 __lock_acquire+0x3370/0x75e8 kernel/locking/lockdep.c:5136
 lock_acquire+0x23c/0x71c kernel/locking/lockdep.c:5753
 __flush_work+0xf8/0x1c0 kernel/workqueue.c:3403
 flush_work+0x24/0x38 kernel/workqueue.c:3428
 hci_dev_close_sync+0x1c8/0xf2c net/bluetooth/hci_sync.c:4982
 hci_dev_do_close net/bluetooth/hci_core.c:554 [inline]
 hci_error_reset+0xf4/0x248 net/bluetooth/hci_core.c:1059
 process_one_work+0x694/0x1204 kernel/workqueue.c:2630
 process_scheduled_works kernel/workqueue.c:2703 [inline]
 worker_thread+0x938/0xef4 kernel/workqueue.c:2784
 kthread+0x288/0x310 kernel/kthread.c:388
 ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:857
Bluetooth: hci5: Opcode 0x c03 failed: -110

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2023/11/11 18:54 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci 8de1e7afcc1c 6d6dbf8a .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-gce-arm64 possible deadlock in hci_error_reset
* Struck through repros no longer work on HEAD.