syzbot


possible deadlock in hci_conn_hash_flush (2)

Status: upstream: reported syz repro on 2024/01/23 23:43
Bug presence: origin:lts-only
[Documentation on labels]
Reported-by: syzbot+6540c42c3d5224a370e8@syzkaller.appspotmail.com
First crash: 302d, last: 178d
Fix bisection: failed (error log, bisect log)
  
Bug presence (2)
Date Name Commit Repro Result
2024/05/13 linux-5.15.y (ToT) 284087d4f7d5 C [report] possible deadlock in hci_conn_hash_flush
2024/05/13 upstream (ToT) a38297e3fb01 C Didn't crash
Similar bugs (4)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-6.1 possible deadlock in hci_conn_hash_flush (2) origin:lts-only syz done 13 192d 268d 0/3 upstream: reported syz repro on 2024/02/27 07:43
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-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
Last patch testing requests (1)
Created Duration User Patch Repo Result
2024/10/01 14:01 9m retest repro linux-5.15.y report log
Fix bisection attempts (2)
Created Duration User Patch Repo Result
2024/10/15 02:35 0m bisect fix linux-5.15.y error job log
2024/05/27 12:37 54m fix candidate upstream OK (0) job log log

Sample crash report:
======================================================
WARNING: possible circular locking dependency detected
5.15.158-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.0/3553 is trying to acquire lock:
ffff8880795ee270 ((work_completion)(&(&conn->timeout_work)->work)){+.+.}-{0:0}, at: __flush_work+0xcf/0x1a0 kernel/workqueue.c:3090

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

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+0x1db/0x4f0 kernel/locking/lockdep.c:5623
       __mutex_lock_common+0x1da/0x25a0 kernel/locking/mutex.c:596
       __mutex_lock kernel/locking/mutex.c:729 [inline]
       mutex_lock_nested+0x17/0x20 kernel/locking/mutex.c:743
       hci_connect_cfm include/net/bluetooth/hci_core.h:1507 [inline]
       hci_remote_features_evt+0x52f/0xb50 net/bluetooth/hci_event.c:3352
       hci_event_packet+0x6fe/0x1550 net/bluetooth/hci_event.c:6421
       hci_rx_work+0x232/0x990 net/bluetooth/hci_core.c:5156
       process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
       worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
       kthread+0x3f6/0x4f0 kernel/kthread.c:334
       ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:300

-> #2 (&hdev->lock){+.+.}-{3:3}:
       lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5623
       __mutex_lock_common+0x1da/0x25a0 kernel/locking/mutex.c:596
       __mutex_lock kernel/locking/mutex.c:729 [inline]
       mutex_lock_nested+0x17/0x20 kernel/locking/mutex.c:743
       sco_sock_connect+0x181/0x8e0 net/bluetooth/sco.c:587
       __sys_connect_file net/socket.c:1918 [inline]
       __sys_connect+0x38b/0x410 net/socket.c:1935
       __do_sys_connect net/socket.c:1945 [inline]
       __se_sys_connect net/socket.c:1942 [inline]
       __x64_sys_connect+0x76/0x80 net/socket.c:1942
       do_syscall_x64 arch/x86/entry/common.c:50 [inline]
       do_syscall_64+0x3b/0xb0 arch/x86/entry/common.c:80
       entry_SYSCALL_64_after_hwframe+0x66/0xd0

-> #1 (sk_lock-AF_BLUETOOTH-BTPROTO_SCO){+.+.}-{0:0}:
       lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5623
       lock_sock_nested+0x44/0x100 net/core/sock.c:3250
       lock_sock include/net/sock.h:1668 [inline]
       sco_sock_timeout+0xbd/0x230 net/bluetooth/sco.c:96
       process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
       worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
       kthread+0x3f6/0x4f0 kernel/kthread.c:334
       ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:300

-> #0 ((work_completion)(&(&conn->timeout_work)->work)){+.+.}-{0:0}:
       check_prev_add kernel/locking/lockdep.c:3053 [inline]
       check_prevs_add kernel/locking/lockdep.c:3172 [inline]
       validate_chain+0x1649/0x5930 kernel/locking/lockdep.c:3788
       __lock_acquire+0x1295/0x1ff0 kernel/locking/lockdep.c:5012
       lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5623
       __flush_work+0xeb/0x1a0 kernel/workqueue.c:3090
       __cancel_work_timer+0x519/0x6a0 kernel/workqueue.c:3181
       sco_conn_del+0x205/0x300 net/bluetooth/sco.c:204
       hci_disconn_cfm include/net/bluetooth/hci_core.h:1525 [inline]
       hci_conn_hash_flush+0x10d/0x220 net/bluetooth/hci_conn.c:1622
       hci_dev_do_close+0x9f6/0x1070 net/bluetooth/hci_core.c:1795
       hci_unregister_dev+0x2a7/0x550 net/bluetooth/hci_core.c:4036
       vhci_release+0x73/0xc0 drivers/bluetooth/hci_vhci.c:345
       __fput+0x3bf/0x890 fs/file_table.c:280
       task_work_run+0x129/0x1a0 kernel/task_work.c:164
       exit_task_work include/linux/task_work.h:32 [inline]
       do_exit+0x6a3/0x2480 kernel/exit.c:872
       do_group_exit+0x144/0x310 kernel/exit.c:994
       get_signal+0xc66/0x14e0 kernel/signal.c:2889
       arch_do_signal_or_restart+0xc3/0x1890 arch/x86/kernel/signal.c:867
       handle_signal_work kernel/entry/common.c:154 [inline]
       exit_to_user_mode_loop+0x97/0x130 kernel/entry/common.c:178
       exit_to_user_mode_prepare+0xb1/0x140 kernel/entry/common.c:214
       __syscall_exit_to_user_mode_work kernel/entry/common.c:296 [inline]
       syscall_exit_to_user_mode+0x5d/0x240 kernel/entry/common.c:307
       do_syscall_64+0x47/0xb0 arch/x86/entry/common.c:86
       entry_SYSCALL_64_after_hwframe+0x66/0xd0

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/3553:
 #0: ffff888014fb4ff0 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close+0x63/0x1070 net/bluetooth/hci_core.c:1737
 #1: ffff888014fb4078 (&hdev->lock){+.+.}-{3:3}, at: hci_dev_do_close+0x431/0x1070 net/bluetooth/hci_core.c:1782
 #2: ffffffff8db30de8 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1522 [inline]
 #2: ffffffff8db30de8 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_conn_hash_flush+0xb8/0x220 net/bluetooth/hci_conn.c:1622

stack backtrace:
CPU: 0 PID: 3553 Comm: syz-executor.0 Not tainted 5.15.158-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/02/2024
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e3/0x2d0 lib/dump_stack.c:106
 check_noncircular+0x2f8/0x3b0 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+0x1649/0x5930 kernel/locking/lockdep.c:3788
 __lock_acquire+0x1295/0x1ff0 kernel/locking/lockdep.c:5012
 lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5623
 __flush_work+0xeb/0x1a0 kernel/workqueue.c:3090
 __cancel_work_timer+0x519/0x6a0 kernel/workqueue.c:3181
 sco_conn_del+0x205/0x300 net/bluetooth/sco.c:204
 hci_disconn_cfm include/net/bluetooth/hci_core.h:1525 [inline]
 hci_conn_hash_flush+0x10d/0x220 net/bluetooth/hci_conn.c:1622
 hci_dev_do_close+0x9f6/0x1070 net/bluetooth/hci_core.c:1795
 hci_unregister_dev+0x2a7/0x550 net/bluetooth/hci_core.c:4036
 vhci_release+0x73/0xc0 drivers/bluetooth/hci_vhci.c:345
 __fput+0x3bf/0x890 fs/file_table.c:280
 task_work_run+0x129/0x1a0 kernel/task_work.c:164
 exit_task_work include/linux/task_work.h:32 [inline]
 do_exit+0x6a3/0x2480 kernel/exit.c:872
 do_group_exit+0x144/0x310 kernel/exit.c:994
 get_signal+0xc66/0x14e0 kernel/signal.c:2889
 arch_do_signal_or_restart+0xc3/0x1890 arch/x86/kernel/signal.c:867
 handle_signal_work kernel/entry/common.c:154 [inline]
 exit_to_user_mode_loop+0x97/0x130 kernel/entry/common.c:178
 exit_to_user_mode_prepare+0xb1/0x140 kernel/entry/common.c:214
 __syscall_exit_to_user_mode_work kernel/entry/common.c:296 [inline]
 syscall_exit_to_user_mode+0x5d/0x240 kernel/entry/common.c:307
 do_syscall_64+0x47/0xb0 arch/x86/entry/common.c:86
 entry_SYSCALL_64_after_hwframe+0x66/0xd0
RIP: 0033:0x7f79d92bdd69
Code: Unable to access opcode bytes at RIP 0x7f79d92bdd3f.
RSP: 002b:00007f79d861d0c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
RAX: fffffffffffffe00 RBX: 00007f79d93ec050 RCX: 00007f79d92bdd69
RDX: 0000000020000040 RSI: 0000000020000240 RDI: 0000000000000000
RBP: 00007f79d930a49e R08: 0000000020000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007f79d93ec050 R15: 00007ffdb6bc9e58
 </TASK>

Crashes (5):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/05/13 12:31 linux-5.15.y 284087d4f7d5 9026e142 .config console log report syz [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan possible deadlock in hci_conn_hash_flush
2024/05/13 10:01 linux-5.15.y 284087d4f7d5 9026e142 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan possible deadlock in hci_conn_hash_flush
2024/05/04 18:31 linux-5.15.y 284087d4f7d5 610f2a54 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan possible deadlock in hci_conn_hash_flush
2024/02/26 21:32 linux-5.15.y 458ce51d0356 da36a36b .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan possible deadlock in hci_conn_hash_flush
2024/01/23 23:42 linux-5.15.y ddcaf4999061 1e153dc8 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan possible deadlock in hci_conn_hash_flush
* Struck through repros no longer work on HEAD.