Bluetooth: hci1: unexpected event 0x09 length: 4 > 3 BUG: workqueue leaked atomic, lock or RCU: kworker/u33:2[5369] preempt=0x00000000 lock=0->1 RCU=0->0 workfn=hci_rx_work 1 lock held by kworker/u33:2/5369: CPU: 1 UID: 0 PID: 5369 Comm: kworker/u33:2 Not tainted 6.10.0-syzkaller-12562-g1722389b0d86 #0 Call Trace: __dump_stack lib/dump_stack.c:93 [inline] dump_stack_lvl+0x16c/0x1f0 lib/dump_stack.c:119 process_one_work+0x11ea/0x1b40 kernel/workqueue.c:3252 process_scheduled_works kernel/workqueue.c:3312 [inline] worker_thread+0x6c8/0xf20 kernel/workqueue.c:3390 kthread+0x2c1/0x3a0 kernel/kthread.c:389 ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244 ====================================================== WARNING: possible circular locking dependency detected 6.10.0-syzkaller-12562-g1722389b0d86 #0 Not tainted ------------------------------------------------------ kworker/u33:2/5369 is trying to acquire lock: ffff88801f3d1948 ((wq_completion)hci5#2){+.+.}-{0:0}, at: process_one_work+0x1277/0x1b40 kernel/workqueue.c:3206 but task is already holding lock: ffff888046089518 (&chan->lock/1){+.+.}-{3:3}, at: l2cap_chan_lock include/net/bluetooth/l2cap.h:827 [inline] ffff888046089518 (&chan->lock/1){+.+.}-{3:3}, at: l2cap_conless_channel net/bluetooth/l2cap_core.c:6764 [inline] ffff888046089518 (&chan->lock/1){+.+.}-{3:3}, at: l2cap_recv_frame+0x14f6/0x8eb0 net/bluetooth/l2cap_core.c:6830 which lock already depends on the new lock. the existing dependency chain (in reverse order) is: -> #2 (&chan->lock/1){+.+.}-{3:3}: __mutex_lock_common kernel/locking/mutex.c:608 [inline] __mutex_lock+0x175/0x9c0 kernel/locking/mutex.c:752 l2cap_chan_lock include/net/bluetooth/l2cap.h:827 [inline] l2cap_conless_channel net/bluetooth/l2cap_core.c:6764 [inline] l2cap_recv_frame+0x14f6/0x8eb0 net/bluetooth/l2cap_core.c:6830 l2cap_recv_acldata+0x9b4/0xb70 net/bluetooth/l2cap_core.c:7513 hci_acldata_packet net/bluetooth/hci_core.c:3797 [inline] hci_rx_work+0xaab/0x1610 net/bluetooth/hci_core.c:4034 process_one_work+0x9c5/0x1b40 kernel/workqueue.c:3231 process_scheduled_works kernel/workqueue.c:3312 [inline] worker_thread+0x6c8/0xf20 kernel/workqueue.c:3390 kthread+0x2c1/0x3a0 kernel/kthread.c:389 ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244 -> #1 ((work_completion)(&hdev->rx_work)){+.+.}-{0:0}: process_one_work+0x927/0x1b40 kernel/workqueue.c:3207 process_scheduled_works kernel/workqueue.c:3312 [inline] worker_thread+0x6c8/0xf20 kernel/workqueue.c:3390 kthread+0x2c1/0x3a0 kernel/kthread.c:389 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 ((wq_completion)hci5#2){+.+.}-{0:0}: check_prev_add kernel/locking/lockdep.c:3133 [inline] check_prevs_add kernel/locking/lockdep.c:3252 [inline] validate_chain kernel/locking/lockdep.c:3868 [inline] __lock_acquire+0x24ed/0x3cb0 kernel/locking/lockdep.c:5142 lock_acquire kernel/locking/lockdep.c:5759 [inline] lock_acquire+0x1b1/0x560 kernel/locking/lockdep.c:5724 process_one_work+0x12a6/0x1b40 kernel/workqueue.c:3206 process_scheduled_works kernel/workqueue.c:3312 [inline] worker_thread+0x6c8/0xf20 kernel/workqueue.c:3390 kthread+0x2c1/0x3a0 kernel/kthread.c:389 ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244 other info that might help us debug this: Chain exists of: (wq_completion)hci5#2 --> (work_completion)(&hdev->rx_work) --> &chan->lock/1 Possible unsafe locking scenario: CPU0 CPU1 ---- ---- lock(&chan->lock/1); lock((work_completion)(&hdev->rx_work)); lock(&chan->lock/1); lock((wq_completion)hci5#2); *** DEADLOCK *** 1 lock held by kworker/u33:2/5369: #0: ffff888046089518 (&chan->lock/1){+.+.}-{3:3}, at: l2cap_chan_lock include/net/bluetooth/l2cap.h:827 [inline] #0: ffff888046089518 (&chan->lock/1){+.+.}-{3:3}, at: l2cap_conless_channel net/bluetooth/l2cap_core.c:6764 [inline] #0: ffff888046089518 (&chan->lock/1){+.+.}-{3:3}, at: l2cap_recv_frame+0x14f6/0x8eb0 net/bluetooth/l2cap_core.c:6830 stack backtrace: CPU: 1 UID: 0 PID: 5369 Comm: kworker/u33:2 Not tainted 6.10.0-syzkaller-12562-g1722389b0d86 #0 Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.3-debian-1.16.3-2~bpo12+1 04/01/2014 Workqueue: hci5 hci_cmd_timeout Call Trace: __dump_stack lib/dump_stack.c:93 [inline] dump_stack_lvl+0x116/0x1f0 lib/dump_stack.c:119 check_noncircular+0x31a/0x400 kernel/locking/lockdep.c:2186 check_prev_add kernel/locking/lockdep.c:3133 [inline] check_prevs_add kernel/locking/lockdep.c:3252 [inline] validate_chain kernel/locking/lockdep.c:3868 [inline] __lock_acquire+0x24ed/0x3cb0 kernel/locking/lockdep.c:5142 lock_acquire kernel/locking/lockdep.c:5759 [inline] lock_acquire+0x1b1/0x560 kernel/locking/lockdep.c:5724 process_one_work+0x12a6/0x1b40 kernel/workqueue.c:3206 process_scheduled_works kernel/workqueue.c:3312 [inline] worker_thread+0x6c8/0xf20 kernel/workqueue.c:3390 kthread+0x2c1/0x3a0 kernel/kthread.c:389 ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244 Bluetooth: hci5: command tx timeout preempt=0x00000000 lock=1->0 RCU=0->0 workfn=hci_cmd_timeout INFO: lockdep is turned off. Call Trace: __dump_stack lib/dump_stack.c:93 [inline] dump_stack_lvl+0x16c/0x1f0 lib/dump_stack.c:119 process_one_work+0x11ea/0x1b40 kernel/workqueue.c:3252 process_scheduled_works kernel/workqueue.c:3312 [inline] worker_thread+0x6c8/0xf20 kernel/workqueue.c:3390 kthread+0x2c1/0x3a0 kernel/kthread.c:389 ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244 Bluetooth: hci1: Injecting HCI hardware error event Bluetooth: hci1: hardware error 0x00 Bluetooth: hci1: Opcode 0x0c03 failed: -110