Re: [PATCH v4] Bluetooth: RFCOMM: connect the session socket without rfcomm_mutex

[Eugene Siegel]

Hi,

With this patch on 3857c2fe54, I can hit a similar deadlock in
rfcomm_security_cfm.

Eugene Siegel

======================================================
WARNING: possible circular locking dependency detected
7.3.0-rc6 #1-NixOS Not tainted
------------------------------------------------------
kworker/u5:2/178 is trying to acquire lock:
ffffffff8eff81c0 (rfcomm_mutex){+.+.}-{4:4}, at:
rfcomm_security_cfm+0x37/0x5a0 net/bluetooth/rfcomm/core.c:2279

but task is already holding lock:
ffffffff8efe4d60 (hci_cb_list_lock){+.+.}-{4:4}, at:
hci_encrypt_cfm+0x4ab/0x720 include/net/bluetooth/hci_core.h:2240

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (hci_cb_list_lock){+.+.}-{4:4}:
     (inlined __mutex_lock_common kernel/locking/mutex.c:646)
       __mutex_lock+0x19c/0x1620 kernel/locking/mutex.c:821
     (inlined hci_connect_cfm include/net/bluetooth/hci_core.h:2164)
       hci_remote_features_evt+0x35b/0x8a0 net/bluetooth/hci_event.c:3786
     (inlined hci_event_func net/bluetooth/hci_event.c:7887)
       hci_event_packet+0x7f1/0xe10 net/bluetooth/hci_event.c:7938
       hci_rx_work+0x3cc/0x8d0 net/bluetooth/hci_core.c:4087
     (inlined process_one_work kernel/workqueue.c:3396)
       process_scheduled_works+0xc99/0x1900 kernel/workqueue.c:3479
       worker_thread+0x8a2/0xda0 kernel/workqueue.c:3560
       kthread+0x38b/0x470 kernel/kthread.c:436
       ret_from_fork+0x43b/0x8f0 arch/x86/kernel/process.c:158
       ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:245

-> #1 (&hdev->lock){+.+.}-{4:4}:
     (inlined __mutex_lock_common kernel/locking/mutex.c:646)
       __mutex_lock+0x19c/0x1620 kernel/locking/mutex.c:821
       hci_release_dev+0x123/0x14b0 net/bluetooth/hci_core.c:2731
       bt_host_release+0x93/0xa0 net/bluetooth/hci_sysfs.c:100
       device_release+0xc4/0x1f0 drivers/base/core.c:2644
     (inlined kobject_cleanup lib/kobject.c:689)
     (inlined kobject_release lib/kobject.c:720)
     (inlined kref_put include/linux/kref.h:65)
       kobject_put+0x16c/0x270 lib/kobject.c:737
       device_release+0xc4/0x1f0 drivers/base/core.c:2644
     (inlined kobject_cleanup lib/kobject.c:689)
     (inlined kobject_release lib/kobject.c:720)
     (inlined kref_put include/linux/kref.h:65)
       kobject_put+0x16c/0x270 lib/kobject.c:737
     (inlined hci_conn_put include/net/bluetooth/hci_core.h:1690)
     (inlined l2cap_conn_free net/bluetooth/l2cap_core.c:1856)
     (inlined kref_put include/linux/kref.h:65)
     (inlined l2cap_conn_put net/bluetooth/l2cap_core.c:1869)
     (inlined l2cap_chan_destroy net/bluetooth/l2cap_core.c:494)
     (inlined kref_put include/linux/kref.h:65)
       l2cap_chan_put+0x1e9/0x260 net/bluetooth/l2cap_core.c:521
       l2cap_sock_release+0x198/0x1e0 net/bluetooth/l2cap_sock.c:1533
     (inlined __sock_release net/socket.c:735)
       sock_release+0x85/0x150 net/socket.c:763
     (inlined rfcomm_session_del net/bluetooth/rfcomm/core.c:782)
       rfcomm_session_close+0x1f6/0x250 net/bluetooth/rfcomm/core.c:821
     (inlined rfcomm_process_rx net/bluetooth/rfcomm/core.c:2086)
     (inlined rfcomm_process_sessions net/bluetooth/rfcomm/core.c:2171)
       rfcomm_run+0x7481/0x91d0 net/bluetooth/rfcomm/core.c:2261
       kthread+0x38b/0x470 kernel/kthread.c:436
       ret_from_fork+0x43b/0x8f0 arch/x86/kernel/process.c:158
       ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:245

-> #0 (rfcomm_mutex){+.+.}-{4:4}:
     (inlined check_prev_add kernel/locking/lockdep.c:3209)
     (inlined check_prevs_add kernel/locking/lockdep.c:3328)
     (inlined validate_chain kernel/locking/lockdep.c:3952)
       __lock_acquire+0x17b9/0x2db0 kernel/locking/lockdep.c:5288
       lock_acquire+0x115/0x350 kernel/locking/lockdep.c:5942
     (inlined __mutex_lock_common kernel/locking/mutex.c:646)
       __mutex_lock+0x19c/0x1620 kernel/locking/mutex.c:821
       rfcomm_security_cfm+0x37/0x5a0 net/bluetooth/rfcomm/core.c:2279
       hci_encrypt_cfm+0x516/0x720 include/net/bluetooth/hci_core.h:2243
       hci_encrypt_change_evt+0x6c9/0xde0 net/bluetooth/hci_event.c:3674
     (inlined hci_event_func net/bluetooth/hci_event.c:7887)
       hci_event_packet+0x7f1/0xe10 net/bluetooth/hci_event.c:7938
       hci_rx_work+0x3cc/0x8d0 net/bluetooth/hci_core.c:4087
     (inlined process_one_work kernel/workqueue.c:3396)
       process_scheduled_works+0xc99/0x1900 kernel/workqueue.c:3479
       worker_thread+0x8a2/0xda0 kernel/workqueue.c:3560
       kthread+0x38b/0x470 kernel/kthread.c:436
       ret_from_fork+0x43b/0x8f0 arch/x86/kernel/process.c:158
       ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:245

other info that might help us debug this:

Chain exists of:
  rfcomm_mutex --> &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(rfcomm_mutex);

 *** DEADLOCK ***

locks held by kworker/u5:2/178: 4, last CPU#0:
     (inlined rcu_lock_acquire include/linux/rcupdate.h:309)
     (inlined rcu_read_lock include/linux/rcupdate.h:849)
     (inlined process_one_work kernel/workqueue.c:3361)
 #0: ffff8880271f6940 ((wq_completion)hci1#2){+.+.}-{0:0}, at:
process_scheduled_works+0x94e/0x1900 kernel/workqueue.c:3479
     (inlined rcu_lock_acquire include/linux/rcupdate.h:309)
     (inlined rcu_read_lock include/linux/rcupdate.h:849)
     (inlined process_one_work kernel/workqueue.c:3361)
 #1: ffffc90001b87c60 ((work_completion)(&hdev->rx_work)){+.+.}-{0:0},
at: process_scheduled_works+0x94e/0x1900 kernel/workqueue.c:3479
 #2: ffff88802deec0b8 (&hdev->lock){+.+.}-{4:4}, at:
hci_encrypt_change_evt+0x84/0xde0 net/bluetooth/hci_event.c:3627
 #3: ffffffff8efe4d60 (hci_cb_list_lock){+.+.}-{4:4}, at:
hci_encrypt_cfm+0x4ab/0x720 include/net/bluetooth/hci_core.h:2240

stack backtrace:
CPU: 0 UID: 0 PID: 178 Comm: kworker/u5:2 Not tainted 7.3.0-rc6
#1-NixOS PREEMPT(full)
Workqueue: hci1 hci_rx_work
Call Trace:
 <TASK>
 dump_stack_lvl+0xe8/0x150 lib/dump_stack.c:120
 print_circular_bug+0x2e2/0x300 kernel/locking/lockdep.c:2087
 check_noncircular+0x12f/0x150 kernel/locking/lockdep.c:2219
     (inlined check_prev_add kernel/locking/lockdep.c:3209)
     (inlined check_prevs_add kernel/locking/lockdep.c:3328)
     (inlined validate_chain kernel/locking/lockdep.c:3952)
 __lock_acquire+0x17b9/0x2db0 kernel/locking/lockdep.c:5288
 lock_acquire+0x115/0x350 kernel/locking/lockdep.c:5942
     (inlined __mutex_lock_common kernel/locking/mutex.c:646)
 __mutex_lock+0x19c/0x1620 kernel/locking/mutex.c:821
 rfcomm_security_cfm+0x37/0x5a0 net/bluetooth/rfcomm/core.c:2279
 hci_encrypt_cfm+0x516/0x720 include/net/bluetooth/hci_core.h:2243
 hci_encrypt_change_evt+0x6c9/0xde0 net/bluetooth/hci_event.c:3674
     (inlined hci_event_func net/bluetooth/hci_event.c:7887)
 hci_event_packet+0x7f1/0xe10 net/bluetooth/hci_event.c:7938
 hci_rx_work+0x3cc/0x8d0 net/bluetooth/hci_core.c:4087
     (inlined process_one_work kernel/workqueue.c:3396)
 process_scheduled_works+0xc99/0x1900 kernel/workqueue.c:3479
 worker_thread+0x8a2/0xda0 kernel/workqueue.c:3560
 kthread+0x38b/0x470 kernel/kthread.c:436
 ret_from_fork+0x43b/0x8f0 arch/x86/kernel/process.c:158
 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:245
 </TASK>