syzbot


possible deadlock in mgmt_remove_adv_monitor_complete

Status: upstream: reported on 2024/05/03 01:13
Subsystems: bluetooth
[Documentation on labels]
Reported-by: syzbot+e8651419c44dbc2b8768@syzkaller.appspotmail.com
First crash: 58d, last: 58d
Discussions (1)
Title Replies (including bot) Last reply
[syzbot] [bluetooth?] possible deadlock in mgmt_remove_adv_monitor_complete 0 (1) 2024/05/03 01:13

Sample crash report:
read_mapping_page failed!
diRead: read_metapage failed
jfs_lookup: iget failed on inum 32
======================================================
WARNING: possible circular locking dependency detected
6.9.0-rc5-syzkaller-00370-g245c8e81741b #0 Not tainted
------------------------------------------------------
syz-executor.1/7334 is trying to acquire lock:
ffff888065ad4078 (&hdev->lock){+.+.}-{3:3}, at: mgmt_remove_adv_monitor_complete+0x9e/0x2e0 net/bluetooth/mgmt.c:5438

but task is already holding lock:
ffff888065ad4970 (&hdev->cmd_sync_work_lock){+.+.}-{3:3}, at: hci_cmd_sync_clear+0x4a/0x100 net/bluetooth/hci_sync.c:591

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #1 (&hdev->cmd_sync_work_lock){+.+.}-{3:3}:
       __mutex_lock_common kernel/locking/mutex.c:608 [inline]
       __mutex_lock+0x175/0x9c0 kernel/locking/mutex.c:752
       hci_cmd_sync_lookup_entry net/bluetooth/hci_sync.c:733 [inline]
       hci_cmd_sync_queue_once net/bluetooth/hci_sync.c:715 [inline]
       hci_update_passive_scan+0x206/0x380 net/bluetooth/hci_sync.c:3085
       le_conn_complete_evt+0x1d2/0x1de0 net/bluetooth/hci_event.c:5911
       hci_le_conn_complete_evt+0x23c/0x370 net/bluetooth/hci_event.c:5922
       hci_le_meta_evt+0x2e2/0x5d0 net/bluetooth/hci_event.c:7231
       hci_event_func net/bluetooth/hci_event.c:7542 [inline]
       hci_event_packet+0x664/0x1190 net/bluetooth/hci_event.c:7597
       hci_rx_work+0x2c4/0x1610 net/bluetooth/hci_core.c:4171
       process_one_work+0x902/0x1a30 kernel/workqueue.c:3254
       process_scheduled_works kernel/workqueue.c:3335 [inline]
       worker_thread+0x6c8/0xf70 kernel/workqueue.c:3416
       kthread+0x2c1/0x3a0 kernel/kthread.c:388
       ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
       ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244

-> #0 (&hdev->lock){+.+.}-{3:3}:
       check_prev_add kernel/locking/lockdep.c:3134 [inline]
       check_prevs_add kernel/locking/lockdep.c:3253 [inline]
       validate_chain kernel/locking/lockdep.c:3869 [inline]
       __lock_acquire+0x2478/0x3b30 kernel/locking/lockdep.c:5137
       lock_acquire kernel/locking/lockdep.c:5754 [inline]
       lock_acquire+0x1b1/0x560 kernel/locking/lockdep.c:5719
       __mutex_lock_common kernel/locking/mutex.c:608 [inline]
       __mutex_lock+0x175/0x9c0 kernel/locking/mutex.c:752
       mgmt_remove_adv_monitor_complete+0x9e/0x2e0 net/bluetooth/mgmt.c:5438
       _hci_cmd_sync_cancel_entry.constprop.0+0x6c/0x1d0 net/bluetooth/hci_sync.c:578
       hci_cmd_sync_clear+0xac/0x100 net/bluetooth/hci_sync.c:593
       hci_unregister_dev+0x188/0x600 net/bluetooth/hci_core.c:2767
       vhci_release+0x7f/0x100 drivers/bluetooth/hci_vhci.c:674
       __fput+0x270/0xb80 fs/file_table.c:422
       task_work_run+0x14e/0x250 kernel/task_work.c:180
       exit_task_work include/linux/task_work.h:38 [inline]
       do_exit+0xa7d/0x2c10 kernel/exit.c:878
       do_group_exit+0xd3/0x2a0 kernel/exit.c:1027
       __do_sys_exit_group kernel/exit.c:1038 [inline]
       __se_sys_exit_group kernel/exit.c:1036 [inline]
       __ia32_sys_exit_group+0x3e/0x50 kernel/exit.c:1036
       do_syscall_32_irqs_on arch/x86/entry/common.c:165 [inline]
       __do_fast_syscall_32+0x75/0x120 arch/x86/entry/common.c:386
       do_fast_syscall_32+0x32/0x80 arch/x86/entry/common.c:411
       entry_SYSENTER_compat_after_hwframe+0x84/0x8e

other info that might help us debug this:

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&hdev->cmd_sync_work_lock);
                               lock(&hdev->lock);
                               lock(&hdev->cmd_sync_work_lock);
  lock(&hdev->lock);

 *** DEADLOCK ***

1 lock held by syz-executor.1/7334:
 #0: ffff888065ad4970 (&hdev->cmd_sync_work_lock){+.+.}-{3:3}, at: hci_cmd_sync_clear+0x4a/0x100 net/bluetooth/hci_sync.c:591

stack backtrace:
CPU: 2 PID: 7334 Comm: syz-executor.1 Not tainted 6.9.0-rc5-syzkaller-00370-g245c8e81741b #0
Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x116/0x1f0 lib/dump_stack.c:114
 check_noncircular+0x31a/0x400 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:3869 [inline]
 __lock_acquire+0x2478/0x3b30 kernel/locking/lockdep.c:5137
 lock_acquire kernel/locking/lockdep.c:5754 [inline]
 lock_acquire+0x1b1/0x560 kernel/locking/lockdep.c:5719
 __mutex_lock_common kernel/locking/mutex.c:608 [inline]
 __mutex_lock+0x175/0x9c0 kernel/locking/mutex.c:752
 mgmt_remove_adv_monitor_complete+0x9e/0x2e0 net/bluetooth/mgmt.c:5438
 _hci_cmd_sync_cancel_entry.constprop.0+0x6c/0x1d0 net/bluetooth/hci_sync.c:578
 hci_cmd_sync_clear+0xac/0x100 net/bluetooth/hci_sync.c:593
 hci_unregister_dev+0x188/0x600 net/bluetooth/hci_core.c:2767
 vhci_release+0x7f/0x100 drivers/bluetooth/hci_vhci.c:674
 __fput+0x270/0xb80 fs/file_table.c:422
 task_work_run+0x14e/0x250 kernel/task_work.c:180
 exit_task_work include/linux/task_work.h:38 [inline]
 do_exit+0xa7d/0x2c10 kernel/exit.c:878
 do_group_exit+0xd3/0x2a0 kernel/exit.c:1027
 __do_sys_exit_group kernel/exit.c:1038 [inline]
 __se_sys_exit_group kernel/exit.c:1036 [inline]
 __ia32_sys_exit_group+0x3e/0x50 kernel/exit.c:1036
 do_syscall_32_irqs_on arch/x86/entry/common.c:165 [inline]
 __do_fast_syscall_32+0x75/0x120 arch/x86/entry/common.c:386
 do_fast_syscall_32+0x32/0x80 arch/x86/entry/common.c:411
 entry_SYSENTER_compat_after_hwframe+0x84/0x8e
RIP: 0023:0xf72e7579
Code: Unable to access opcode bytes at 0xf72e754f.
RSP: 002b:00000000ffa973cc EFLAGS: 00000282 ORIG_RAX: 00000000000000fc
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00000000ffa974d0
RDX: 00000000f73130c7 RSI: 0000000000000000 RDI: 00000000f738e1b5
RBP: 00000000ffa97428 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
 </TASK>
metapage_write_end_io: I/O error
metapage_write_end_io: I/O error
metapage_write_end_io: I/O error
metapage_write_end_io: I/O error
metapage_write_end_io: I/O error
lbmIODone: I/O error in JFS log
lbmIODone: I/O error in JFS log
lbmIODone: I/O error in JFS log
lmLogShutdown: exit(-5)
jfs_umount failed with return code -5

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/04/29 01:09 upstream 245c8e81741b 07b455f9 .config console log report info [disk image (non-bootable)] [vmlinux] [kernel image] ci-qemu-upstream-386 possible deadlock in mgmt_remove_adv_monitor_complete
* Struck through repros no longer work on HEAD.