Subject: next-20250327 - lockdep whine and USB issues at boot

From: "Valdis Klētnieks" <[email-masked]>
Date: Fri, 28 Mar 2025 14:10:53 -0400

Saw this during boot on a Dell Inspiron 5559 laptop.  

In addition, the external USB ports all gave up, rendering a USB mouse and a
USB external drive totally dead in the water.  May or may not be related, I didn't
dig too far into it.

[   40.842033] [    T953] io scheduler bfq registered

[   41.022391] [    T817] ======================================================
[   41.103507] [    T817] WARNING: possible circular locking dependency detected
[   41.184587] [    T817] 6.14.0-next-20250327 #110 Tainted: G          I     T  
[   41.265700] [    T817] ------------------------------------------------------
[   41.346832] [    T817] (udev-worker)/817 is trying to acquire lock:
[   41.427952] [    T817] ffff93a2c80ae9f0 (&q->elevator_lock){+.+.}-{4:4}, at: elv_iosched_store+0xe1/0x260
[   41.830112] [    T817] 
                          but task is already holding lock:
[   41.912022] [    T817] ffff93a2c80ae460 (&q->q_usage_counter(io)#10){++++}-{0:0}, at: blk_mq_freeze_queue_nomemsave+0x11/0x20
[   42.394431] [    T817] 
                          which lock already depends on the new lock.

[   42.477193] [    T817] 
                          the existing dependency chain (in reverse order) is:
[   42.559132] [    T817] 
                          -> #2 (&q->q_usage_counter(io)#10){++++}-{0:0}:
[   43.042361] [    T817]        lock_acquire.part.0+0xbe/0x240
[   43.123452] [    T817]        blk_alloc_queue+0x30b/0x350
[   43.204547] [    T817]        blk_mq_alloc_queue+0x62/0xd0
[   43.285646] [    T817]        scsi_alloc_sdev+0x29c/0x3d0
[   43.366744] [    T817]        scsi_probe_and_add_lun+0x1d8/0x2b0
[   43.447847] [    T817]        __scsi_add_device+0x114/0x130
[   43.528950] [    T817]        ata_scsi_scan_host+0x7a/0x190
[   43.610047] [    T817]        async_run_entry_fn+0x24/0xc0
[   43.691137] [    T817]        process_one_work+0x21e/0x5a0
[   43.772226] [    T817]        worker_thread+0x1d5/0x3c0
[   43.853316] [    T817]        kthread+0x114/0x230
[   43.934369] [    T817]        ret_from_fork+0x2c/0x50
[   44.015453] [    T817]        ret_from_fork_asm+0x1a/0x30
[   44.096532] [    T817] 
                          -> #1 (fs_reclaim){+.+.}-{0:0}:
[   44.499438] [    T817]        lock_acquire.part.0+0xbe/0x240
[   44.580476] [    T817]        fs_reclaim_acquire+0xa8/0xe0
[   44.661541] [    T817]        blk_mq_alloc_and_init_hctx+0x16a/0x240
[   44.742613] [    T817]        blk_mq_realloc_hw_ctxs+0x2fb/0x390
[   44.823681] [    T817]        blk_mq_init_allocated_queue+0x13b/0x460
[   44.904744] [    T817]        blk_mq_alloc_queue+0x7b/0xd0
[   44.985800] [    T817]        __blk_mq_alloc_disk+0x13/0x60
[   45.066848] [    T817]        loop_add+0x1fd/0x3e0
[   45.147899] [    T817]        loop_init+0x17b/0x1d0
[   45.228942] [    T817]        do_one_initcall+0x83/0x3c0
[   45.309991] [    T817]        do_initcalls+0x130/0x1b0
[   45.391040] [    T817]        kernel_init_freeable+0x292/0x300
[   45.472088] [    T817]        kernel_init+0x15/0x130
[   45.553131] [    T817]        ret_from_fork+0x2c/0x50
[   45.634147] [    T817]        ret_from_fork_asm+0x1a/0x30
[   45.715192] [    T817] 
                          -> #0 (&q->elevator_lock){+.+.}-{4:4}:
[   46.117972] [    T817]        check_prev_add+0xe1/0xcf0
[   46.198974] [    T817]        __lock_acquire+0x1031/0x13b0
[   46.280004] [    T817]        lock_acquire.part.0+0xbe/0x240
[   46.361026] [    T817]        __mutex_lock+0xcb/0xfc0
[   46.442014] [    T817]        elv_iosched_store+0xe1/0x260
[   46.523029] [    T817]        kernfs_fop_write_iter+0x160/0x240
[   46.604038] [    T817]        vfs_write+0x2ec/0x5c0
[   46.685016] [    T817]        ksys_write+0x7a/0xf0
[   46.766019] [    T817]        do_syscall_64+0x68/0x140
[   46.847024] [    T817]        entry_SYSCALL_64_after_hwframe+0x71/0x79
[   46.927997] [    T817] 
                          other info that might help us debug this:

[   47.010420] [    T817] Chain exists of:
                            &q->elevator_lock --> fs_reclaim --> &q->q_usage_counter(io)#10

[   47.654630] [    T817]  Possible unsafe locking scenario:

[   47.736287] [    T817]        CPU0                    CPU1
[   47.817245] [    T817]        ----                    ----
[   47.898175] [    T817]   lock(&q->q_usage_counter(io)#10);
[   48.219898] [    T817]                                lock(fs_reclaim);
[   48.461357] [    T817]                                lock(&q->q_usage_counter(io)#10);
[   48.783086] [    T817]   lock(&q->elevator_lock);
[   49.024555] [    T817] 
                           *** DEADLOCK ***

[   49.106827] [    T817] 5 locks held by (udev-worker)/817:
[   49.187752] [    T817]  #0: ffff93a2e079a440 (sb_writers#4){.+.+}-{0:0}, at: ksys_write+0x7a/0xf0
[   49.750206] [    T817]  #1: ffff93a2c62c6690 (&of->mutex#2){+.+.}-{4:4}, at: kernfs_fop_write_iter+0x119/0x240
[   50.312697] [    T817]  #2: ffff93a2c2312ad0 (kn->active#89){.+.+}-{0:0}, at: kernfs_fop_write_iter+0x122/0x240
[   50.875194] [    T817]  #3: ffff93a2c80ae460 (&q->q_usage_counter(io)#10){++++}-{0:0}, at: blk_mq_freeze_queue_nomemsave+0x11/0x20
[   51.437693] [    T817]  #4: ffff93a2c80ae4a0 (&q->q_usage_counter(queue)){++++}-{0:0}, at: blk_mq_freeze_queue_nomemsave+0x11/0x20
[   51.919935] [    T817] 
                          stack backtrace:
[   52.001533] [    T817] CPU: 0 UID: 0 PID: 817 Comm: (udev-worker) Tainted: G          I     T   6.14.0-next-20250327 #110 PREEMPT(full)  238541a35a93f433dad83bf02a8fb62af6fea5a1
[   52.081794] [    T817] Tainted: [I]=FIRMWARE_WORKAROUND, [T]=RANDSTRUCT
[   52.162052] [    T817] Hardware name: Dell Inc. Unidentified System/052K07, BIOS 1.9.0 09/07/2020
[   52.242309] [    T817] Call Trace:
[   52.322568] [    T817]  <TASK>
[   52.402828] [    T817]  dump_stack_lvl+0x65/0x90
[   52.483089] [    T817]  print_circular_bug.cold+0x38/0x46
[   52.563351] [    T817]  check_noncircular+0x169/0x190
[   52.643613] [    T817]  check_prev_add+0xe1/0xcf0
[   52.723871] [    T817]  ? add_chain_cache+0x115/0x4c0
[   52.804133] [    T817]  __lock_acquire+0x1031/0x13b0
[   52.884394] [    T817]  ? mark_usage+0x65/0x180
[   52.964654] [    T817]  lock_acquire.part.0+0xbe/0x240
[   53.044913] [    T817]  ? elv_iosched_store+0xe1/0x260
[   53.125175] [    T817]  ? lock_acquire+0xf8/0x140
[   53.205435] [    T817]  __mutex_lock+0xcb/0xfc0
[   53.285695] [    T817]  ? elv_iosched_store+0xe1/0x260
[   53.365955] [    T817]  ? mark_held_locks+0x40/0x70
[   53.446214] [    T817]  ? elv_iosched_store+0xe1/0x260
[   53.526473] [    T817]  ? lockdep_hardirqs_on_prepare.part.0+0x8e/0x170
[   53.606736] [    T817]  ? elv_iosched_store+0xe1/0x260
[   53.686996] [    T817]  elv_iosched_store+0xe1/0x260
[   53.767260] [    T817]  kernfs_fop_write_iter+0x160/0x240
[   53.847520] [    T817]  vfs_write+0x2ec/0x5c0
[   53.927784] [    T817]  ksys_write+0x7a/0xf0
[   54.008044] [    T817]  do_syscall_64+0x68/0x140
[   54.088307] [    T817]  entry_SYSCALL_64_after_hwframe+0x71/0x79
[   54.168565] [    T817] RIP: 0033:0x7fd9f9a7ca06
[   54.248825] [    T817] Code: 5d e8 41 8b 93 08 03 00 00 59 5e 48 83 f8 fc 75 19 83 e2 39 83 fa 08 75 11 e8 26 ff ff ff 66 0f 1f 44 00 00 48 8b 45 10 0f 05 <48> 8b 5d f8 c9 c3 0f 1f 40 00 f3 0f 1e fa 55 48 89 e5 48 83 ec 08
[   54.329083] [    T817] RSP: 002b:00007ffe23386d50 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[   54.489599] [    T817] RAX: ffffffffffffffda RBX: 0000564ed601dff0 RCX: 00007fd9f9a7ca06
[   54.569857] [    T817] RDX: 0000000000000003 RSI: 00007ffe233870a0 RDI: 000000000000001c
[   54.650115] [    T817] RBP: 00007ffe23386d70 R08: 0000000000000000 R09: 0000000000000000
[   54.730373] [    T817] R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000003
[   54.810630] [    T817] R13: 0000000000000003 R14: 00007ffe233870a0 R15: 00007ffe233870a0
[   54.890894] [    T817]  </TASK>
[   54.971553] [     T25] xhci_hcd 0000:00:14.0: xHCI host not responding to stop endpoint command
[   55.051817] [     T25] xhci_hcd 0000:00:14.0: xHCI host controller not responding, assume dead
[   55.132085] [     T25] xhci_hcd 0000:00:14.0: HC died; cleaning up
[   55.212411] [     T59] xhci_hcd 0000:00:14.0: Timeout while waiting for stop endpoint command
[   55.253106] [     T47] kauditd_printk_skb: 81 callbacks suppressed
[   55.354880] [    T984] usb 1-2: USB disconnect, device number 2
[   55.375007] [    T986] usb 2-3: USB disconnect, device number 2
[   55.568668] [    T984] usb 1-3: USB disconnect, device number 3
[   55.784923] [    T984] usb 1-6: USB disconnect, device number 4
[   55.874703] [    T984] usb 1-7: USB disconnect, device number 5