syzbot


possible deadlock in hci_conn_hash_flush (2)

Status: upstream: reported syz repro on 2024/02/27 07:43
Bug presence: origin:lts-only
[Documentation on labels]
Reported-by: syzbot+5f8bd15002bf22f8adf4@syzkaller.appspotmail.com
First crash: 268d, last: 192d
Fix commit to backport (bisect log) :
tree: upstream
commit 9a8ec9e8ebb5a7c0cfbce2d6b4a6b67b2b78e8f3
Author: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
Date: Thu Mar 30 21:15:50 2023 +0000

  Bluetooth: SCO: Fix possible circular locking dependency on sco_connect_cfm

[report pending]
  
Bug presence (2)
Date Name Commit Repro Result
2024/05/07 linux-6.1.y (ToT) 909ba1f1b414 C [report] possible deadlock in hci_conn_hash_flush
2024/05/07 upstream (ToT) dccb07f2914c C Didn't crash
Similar bugs (4)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream possible deadlock in hci_conn_hash_flush bluetooth 4 643d 773d 0/28 auto-obsoleted due to no activity on 2023/06/17 14:27
linux-5.15 possible deadlock in hci_conn_hash_flush 9 460d 537d 0/3 auto-obsoleted due to no activity on 2023/11/27 03:55
linux-5.15 possible deadlock in hci_conn_hash_flush (2) origin:lts-only syz error 5 178d 302d 0/3 upstream: reported syz repro on 2024/01/23 23:43
linux-6.1 possible deadlock in hci_conn_hash_flush 5 484d 589d 0/3 auto-obsoleted due to no activity on 2023/11/03 12:59
Fix bisection attempts (1)
Created Duration User Patch Repo Result
2024/06/28 13:37 6h33m fix candidate upstream OK (1) job log

Sample crash report:
======================================================
WARNING: possible circular locking dependency detected
6.1.90-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.0/3595 is trying to acquire lock:
ffff88814124fe70 ((work_completion)(&(&conn->timeout_work)->work)){+.+.}-{0:0}, at: __flush_work+0xe5/0xad0 kernel/workqueue.c:3072

but task is already holding lock:
ffffffff8e3f1968 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1805 [inline]
ffffffff8e3f1968 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_conn_hash_flush+0xb8/0x2a0 net/bluetooth/hci_conn.c:2441

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (hci_cb_list_lock){+.+.}-{3:3}:
       lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
       __mutex_lock_common kernel/locking/mutex.c:603 [inline]
       __mutex_lock+0x132/0xd80 kernel/locking/mutex.c:747
       hci_connect_cfm include/net/bluetooth/hci_core.h:1790 [inline]
       hci_remote_features_evt+0x664/0xab0 net/bluetooth/hci_event.c:3803
       hci_event_func net/bluetooth/hci_event.c:7539 [inline]
       hci_event_packet+0xa9d/0x1510 net/bluetooth/hci_event.c:7591
       hci_rx_work+0x3cd/0xce0 net/bluetooth/hci_core.c:4130
       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:308

-> #2 (&hdev->lock){+.+.}-{3:3}:
       lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
       __mutex_lock_common kernel/locking/mutex.c:603 [inline]
       __mutex_lock+0x132/0xd80 kernel/locking/mutex.c:747
       sco_sock_connect+0x181/0x8f0 net/bluetooth/sco.c:593
       __sys_connect_file net/socket.c:2006 [inline]
       __sys_connect+0x2c9/0x300 net/socket.c:2023
       __do_sys_connect net/socket.c:2033 [inline]
       __se_sys_connect net/socket.c:2030 [inline]
       __x64_sys_connect+0x76/0x80 net/socket.c:2030
       do_syscall_x64 arch/x86/entry/common.c:51 [inline]
       do_syscall_64+0x3b/0xb0 arch/x86/entry/common.c:81
       entry_SYSCALL_64_after_hwframe+0x68/0xd2

-> #1 (sk_lock-AF_BLUETOOTH-BTPROTO_SCO){+.+.}-{0:0}:
       lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
       lock_sock_nested+0x44/0x100 net/core/sock.c:3485
       lock_sock include/net/sock.h:1748 [inline]
       sco_sock_timeout+0xbd/0x230 net/bluetooth/sco.c:97
       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:308

-> #0 ((work_completion)(&(&conn->timeout_work)->work)){+.+.}-{0:0}:
       check_prev_add kernel/locking/lockdep.c:3090 [inline]
       check_prevs_add kernel/locking/lockdep.c:3209 [inline]
       validate_chain+0x1661/0x5950 kernel/locking/lockdep.c:3825
       __lock_acquire+0x125b/0x1f80 kernel/locking/lockdep.c:5049
       lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
       __flush_work+0xfe/0xad0 kernel/workqueue.c:3072
       __cancel_work_timer+0x519/0x6a0 kernel/workqueue.c:3163
       sco_conn_del+0x205/0x300 net/bluetooth/sco.c:205
       hci_disconn_cfm include/net/bluetooth/hci_core.h:1808 [inline]
       hci_conn_hash_flush+0x10e/0x2a0 net/bluetooth/hci_conn.c:2441
       hci_dev_close_sync+0x9a9/0x1020 net/bluetooth/hci_sync.c:5018
       hci_dev_do_close net/bluetooth/hci_core.c:554 [inline]
       hci_unregister_dev+0x1df/0x4d0 net/bluetooth/hci_core.c:2738
       vhci_release+0x7f/0xd0 drivers/bluetooth/hci_vhci.c:573
       __fput+0x3b7/0x890 fs/file_table.c:320
       task_work_run+0x246/0x300 kernel/task_work.c:179
       exit_task_work include/linux/task_work.h:38 [inline]
       do_exit+0xa73/0x26a0 kernel/exit.c:869
       do_group_exit+0x202/0x2b0 kernel/exit.c:1019
       get_signal+0x16f7/0x17d0 kernel/signal.c:2862
       arch_do_signal_or_restart+0xb0/0x1a10 arch/x86/kernel/signal.c:871
       exit_to_user_mode_loop+0x6a/0x100 kernel/entry/common.c:174
       exit_to_user_mode_prepare+0xb1/0x140 kernel/entry/common.c:210
       __syscall_exit_to_user_mode_work kernel/entry/common.c:292 [inline]
       syscall_exit_to_user_mode+0x60/0x270 kernel/entry/common.c:303
       do_syscall_64+0x47/0xb0 arch/x86/entry/common.c:87
       entry_SYSCALL_64_after_hwframe+0x68/0xd2

other info that might help us debug this:

Chain exists of:
  (work_completion)(&(&conn->timeout_work)->work) --> &hdev->lock --> hci_cb_list_lock

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(hci_cb_list_lock);
                               lock(&hdev->lock);
                               lock(hci_cb_list_lock);
  lock((work_completion)(&(&conn->timeout_work)->work));

 *** DEADLOCK ***

3 locks held by syz-executor.0/3595:
 #0: ffff888075a810b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close net/bluetooth/hci_core.c:552 [inline]
 #0: ffff888075a810b8 (&hdev->req_lock){+.+.}-{3:3}, at: hci_unregister_dev+0x1d7/0x4d0 net/bluetooth/hci_core.c:2738
 #1: ffff888075a80078 (&hdev->lock){+.+.}-{3:3}, at: hci_dev_close_sync+0x48d/0x1020 net/bluetooth/hci_sync.c:5005
 #2: ffffffff8e3f1968 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1805 [inline]
 #2: ffffffff8e3f1968 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_conn_hash_flush+0xb8/0x2a0 net/bluetooth/hci_conn.c:2441

stack backtrace:
CPU: 0 PID: 3595 Comm: syz-executor.0 Not tainted 6.1.90-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/27/2024
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+0x1661/0x5950 kernel/locking/lockdep.c:3825
 __lock_acquire+0x125b/0x1f80 kernel/locking/lockdep.c:5049
 lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
 __flush_work+0xfe/0xad0 kernel/workqueue.c:3072
 __cancel_work_timer+0x519/0x6a0 kernel/workqueue.c:3163
 sco_conn_del+0x205/0x300 net/bluetooth/sco.c:205
 hci_disconn_cfm include/net/bluetooth/hci_core.h:1808 [inline]
 hci_conn_hash_flush+0x10e/0x2a0 net/bluetooth/hci_conn.c:2441
 hci_dev_close_sync+0x9a9/0x1020 net/bluetooth/hci_sync.c:5018
 hci_dev_do_close net/bluetooth/hci_core.c:554 [inline]
 hci_unregister_dev+0x1df/0x4d0 net/bluetooth/hci_core.c:2738
 vhci_release+0x7f/0xd0 drivers/bluetooth/hci_vhci.c:573
 __fput+0x3b7/0x890 fs/file_table.c:320
 task_work_run+0x246/0x300 kernel/task_work.c:179
 exit_task_work include/linux/task_work.h:38 [inline]
 do_exit+0xa73/0x26a0 kernel/exit.c:869
 do_group_exit+0x202/0x2b0 kernel/exit.c:1019
 get_signal+0x16f7/0x17d0 kernel/signal.c:2862
 arch_do_signal_or_restart+0xb0/0x1a10 arch/x86/kernel/signal.c:871
 exit_to_user_mode_loop+0x6a/0x100 kernel/entry/common.c:174
 exit_to_user_mode_prepare+0xb1/0x140 kernel/entry/common.c:210
 __syscall_exit_to_user_mode_work kernel/entry/common.c:292 [inline]
 syscall_exit_to_user_mode+0x60/0x270 kernel/entry/common.c:303
 do_syscall_64+0x47/0xb0 arch/x86/entry/common.c:87
 entry_SYSCALL_64_after_hwframe+0x68/0xd2
RIP: 0033:0x7ff168e7dca9
Code: Unable to access opcode bytes at 0x7ff168e7dc7f.
RSP: 002b:00007ff169bd20c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
RAX: fffffffffffffe00 RBX: 00007ff168fac050 RCX: 00007ff168e7dca9
RDX: 0000000020000040 RSI: 0000000020000240 RDI: 0000000000000000
RBP: 00007ff168ec947e R08: 0000000020000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007ff168fac050 R15: 00007ffd2797fe88
 </TASK>

Crashes (13):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/05/04 21:59 linux-6.1.y 909ba1f1b414 610f2a54 .config console log report syz [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/05/13 10:00 linux-6.1.y 909ba1f1b414 9026e142 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/05/07 07:06 linux-6.1.y 909ba1f1b414 fa7a5cf0 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/05/07 06:06 linux-6.1.y 909ba1f1b414 fa7a5cf0 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/05/07 06:05 linux-6.1.y 909ba1f1b414 fa7a5cf0 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/05/06 04:48 linux-6.1.y 909ba1f1b414 610f2a54 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/05/05 20:15 linux-6.1.y 909ba1f1b414 610f2a54 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/05/05 17:17 linux-6.1.y 909ba1f1b414 610f2a54 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/05/04 18:16 linux-6.1.y 909ba1f1b414 610f2a54 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/05/04 18:14 linux-6.1.y 909ba1f1b414 610f2a54 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/04/04 06:59 linux-6.1.y 347385861c50 51c4dcff .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/02/27 23:08 linux-6.1.y 81e1dc2f7001 d367cbe5 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
2024/02/27 07:43 linux-6.1.y 81e1dc2f7001 05e69c83 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan possible deadlock in hci_conn_hash_flush
* Struck through repros no longer work on HEAD.