Bug 2037601 - 5.16.0-rc8 deadlock at rfcomm_sk_state_change
Summary: 5.16.0-rc8 deadlock at rfcomm_sk_state_change
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: rawhide
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2022-01-06 04:17 UTC by Chris Murphy
Modified: 2022-02-11 21:15 UTC (History)
18 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-02-11 21:15:04 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
dmesg (175.66 KB, text/plain)
2022-01-06 04:18 UTC, Chris Murphy
no flags Details

Description Chris Murphy 2022-01-06 04:17:24 UTC
Hang at login window following wake from suspend-to-ram.

5.16.0-0.rc8.55.fc36.x86_64+debug

Haven't seen this previously, and I don't yet have a reproducer.

No out of tree modules, SB enabled, lockdown enabled.

[14655.200468] kernel: ======================================================
[14655.200470] kernel: WARNING: possible circular locking dependency detected
[14655.200472] kernel: 5.16.0-0.rc8.55.fc36.x86_64+debug #1 Not tainted
[14655.200475] kernel: ------------------------------------------------------
[14655.200476] kernel: krfcommd/1358 is trying to acquire lock:
[14655.200479] kernel: ffff9e662103d130 (sk_lock-AF_BLUETOOTH-BTPROTO_RFCOMM){+.+.}-{0:0}, at: rfcomm_sk_state_change+0x4d/0x110 [rfcomm]
[14655.200494] kernel: 
                       but task is already holding lock:
[14655.200495] kernel: ffff9e672a54bb40 (&d->lock){+.+.}-{3:3}, at: __rfcomm_dlc_close+0x88/0x230 [rfcomm]
[14655.200506] kernel: 
                       which lock already depends on the new lock.
[14655.200508] kernel: 
                       the existing dependency chain (in reverse order) is:
[14655.200509] kernel: 
                       -> #2 (&d->lock){+.+.}-{3:3}:
[14655.200515] kernel:        __mutex_lock+0x93/0x910
[14655.200521] kernel:        __rfcomm_dlc_close+0x88/0x230 [rfcomm]
[14655.200527] kernel:        rfcomm_run+0x765/0x1820 [rfcomm]
[14655.200533] kernel:        kthread+0x17a/0x1a0
[14655.200538] kernel:        ret_from_fork+0x1f/0x30
[14655.200543] kernel: 
                       -> #1 (rfcomm_mutex){+.+.}-{3:3}:
[14655.200548] kernel:        __mutex_lock+0x93/0x910
[14655.200551] kernel:        rfcomm_dlc_open+0x31/0x350 [rfcomm]
[14655.200557] kernel:        rfcomm_sock_connect+0xd3/0x130 [rfcomm]
[14655.200564] kernel:        __sys_connect+0x9f/0xd0
[14655.200569] kernel:        __x64_sys_connect+0x14/0x20
[14655.200573] kernel:        do_syscall_64+0x38/0x90
[14655.200578] kernel:        entry_SYSCALL_64_after_hwframe+0x44/0xae
[14655.200581] kernel: 
                       -> #0 (sk_lock-AF_BLUETOOTH-BTPROTO_RFCOMM){+.+.}-{0:0}:
[14655.200586] kernel:        __lock_acquire+0x11c7/0x1de0
[14655.200590] kernel:        lock_acquire+0xd3/0x2f0
[14655.200593] kernel:        lock_sock_nested+0x2e/0x80
[14655.200597] kernel:        rfcomm_sk_state_change+0x4d/0x110 [rfcomm]
[14655.200603] kernel:        __rfcomm_dlc_close+0xa2/0x230 [rfcomm]
[14655.200609] kernel:        rfcomm_run+0x765/0x1820 [rfcomm]
[14655.200615] kernel:        kthread+0x17a/0x1a0
[14655.200618] kernel:        ret_from_fork+0x1f/0x30
[14655.200622] kernel: 
                       other info that might help us debug this:
[14655.200624] kernel: Chain exists of:
                         sk_lock-AF_BLUETOOTH-BTPROTO_RFCOMM --> rfcomm_mutex --> &d->lock
[14655.200630] kernel:  Possible unsafe locking scenario:
[14655.200632] kernel:        CPU0                    CPU1
[14655.200633] kernel:        ----                    ----
[14655.200635] kernel:   lock(&d->lock);
[14655.200638] kernel:                                lock(rfcomm_mutex);
[14655.200640] kernel:                                lock(&d->lock);
[14655.200643] kernel:   lock(sk_lock-AF_BLUETOOTH-BTPROTO_RFCOMM);
[14655.200646] kernel: 
                        *** DEADLOCK ***
[14655.200648] kernel: 2 locks held by krfcommd/1358:
[14655.200650] kernel:  #0: ffffffffc141d130 (rfcomm_mutex){+.+.}-{3:3}, at: rfcomm_run+0x135/0x1820 [rfcomm]
[14655.200661] kernel:  #1: ffff9e672a54bb40 (&d->lock){+.+.}-{3:3}, at: __rfcomm_dlc_close+0x88/0x230 [rfcomm]
[14655.200671] kernel: 
                       stack backtrace:
[14655.200673] kernel: CPU: 3 PID: 1358 Comm: krfcommd Not tainted 5.16.0-0.rc8.55.fc36.x86_64+debug #1
[14655.200677] kernel: Hardware name: LENOVO 20QDS3E200/20QDS3E200, BIOS N2HET64W (1.47 ) 07/19/2021
[14655.200680] kernel: Call Trace:
[14655.200682] kernel:  <TASK>
[14655.200686] kernel:  dump_stack_lvl+0x59/0x73
[14655.200692] kernel:  check_noncircular+0xdf/0x100
[14655.200699] kernel:  __lock_acquire+0x11c7/0x1de0
[14655.200706] kernel:  lock_acquire+0xd3/0x2f0
[14655.200710] kernel:  ? rfcomm_sk_state_change+0x4d/0x110 [rfcomm]
[14655.200719] kernel:  ? __rfcomm_dlc_close+0x88/0x230 [rfcomm]
[14655.200728] kernel:  lock_sock_nested+0x2e/0x80
[14655.200731] kernel:  ? rfcomm_sk_state_change+0x4d/0x110 [rfcomm]
[14655.200737] kernel:  rfcomm_sk_state_change+0x4d/0x110 [rfcomm]
[14655.200744] kernel:  __rfcomm_dlc_close+0xa2/0x230 [rfcomm]
[14655.200752] kernel:  rfcomm_run+0x765/0x1820 [rfcomm]
[14655.200762] kernel:  ? __init_waitqueue_head+0x60/0x60
[14655.200768] kernel:  ? _raw_spin_unlock_irqrestore+0x3e/0x60
[14655.200772] kernel:  ? rfcomm_check_accept+0xa0/0xa0 [rfcomm]
[14655.200780] kernel:  kthread+0x17a/0x1a0
[14655.200783] kernel:  ? set_kthread_struct+0x40/0x40
[14655.200788] kernel:  ret_from_fork+0x1f/0x30
[14655.200796] kernel:  </TASK>

Comment 1 Chris Murphy 2022-01-06 04:18:57 UTC
Created attachment 1849142 [details]
dmesg

journalctl -b-1 -k -o short-monotonic --no-hostname | grep -v drm > dmesg.txt

Using drm.debug=0x1e which makes the dmesg over 150M, so filtered it.

Comment 3 Chris Murphy 2022-01-06 04:35:11 UTC
54: USB 00.0: 11500 Bluetooth Device
  [Created at usb.122]
  Unique ID: fHJ1.l3v0gVevrhC
  Parent ID: k4bc.2DFUsyrieMD
  SysFS ID: /devices/pci0000:00/0000:00:14.0/usb1/1-10/1-10:1.0
  SysFS BusID: 1-10:1.0
  Hardware Class: bluetooth
  Model: "Intel Bluetooth Device"
  Hotplug: USB
  Vendor: usb 0x8087 "Intel Corp."
  Device: usb 0x0aaa 
  Revision: "0.02"
  Driver: "btusb"
  Driver Modules: "btusb"
  Speed: 12 Mbps
  Module Alias: "usb:v8087p0AAAd0002dcE0dsc01dp01icE0isc01ip01in00"
  Driver Info #0:
    Driver Status: btusb is active
    Driver Activation Cmd: "modprobe btusb"
  Config Status: cfg=new, avail=yes, need=no, active=unknown
  Attached to: #60 (Hub)

Comment 4 Chris Murphy 2022-02-11 21:15:04 UTC
I'm not seeing this in 5.17-rc3.


Note You need to log in before you can comment on or make changes to this bug.