syzbot


INFO: rcu detected stall in pm_runtime_work

Status: auto-obsoleted due to no activity on 2025/01/19 19:51
Subsystems: usb
[Documentation on labels]
First crash: 91d, last: 91d

Sample crash report:
rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { 0-...D
 } 2692 jiffies s: 18365 root: 0x1/.
rcu: blocking rcu_node structures (internal RCU debug):
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 UID: 0 PID: 2511 Comm: kworker/0:2 Not tainted 6.12.0-rc4-syzkaller-00052-gc6d9e43954bf #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
Workqueue: pm pm_runtime_work
RIP: 0010:io_serial_out+0x8f/0xb0 drivers/tty/serial/8250/8250_port.c:413
Code: 48 8d 7d 40 44 89 e1 48 b8 00 00 00 00 00 fc ff df 48 89 fa d3 e3 48 c1 ea 03 80 3c 02 00 75 1c 66 03 5d 40 44 89 e8 89 da ee <5b> 5d 41 5c 41 5d c3 cc cc cc cc e8 31 f0 0d ff eb a0 e8 ba f0 0d
RSP: 0000:ffffc90000006f38 EFLAGS: 00000006
RAX: 0000000000000000 RBX: 00000000000003f9 RCX: 0000000000000000
RDX: 00000000000003f9 RSI: ffffffff82a08975 RDI: ffffffff93637660
RBP: ffffffff93637620 R08: 0000000000000001 R09: 000000000000001f
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: ffffffff93637670 R15: 000000000000004f
FS:  0000000000000000(0000) GS:ffff8881f5800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007feee1991000 CR3: 0000000120844000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <NMI>
 </NMI>
 <IRQ>
 serial_out drivers/tty/serial/8250/8250.h:142 [inline]
 serial8250_clear_IER+0x9b/0xc0 drivers/tty/serial/8250/8250_port.c:699
 serial8250_console_write+0x243/0x17c0 drivers/tty/serial/8250/8250_port.c:3358
 console_emit_next_record kernel/printk/printk.c:3092 [inline]
 console_flush_all+0x800/0xc60 kernel/printk/printk.c:3180
 __console_flush_and_unlock kernel/printk/printk.c:3239 [inline]
 console_unlock+0xd9/0x210 kernel/printk/printk.c:3279
 vprintk_emit+0x424/0x6f0 kernel/printk/printk.c:2407
 vprintk+0x7f/0xa0 kernel/printk/printk_safe.c:68
 _printk+0xc8/0x100 kernel/printk/printk.c:2432
 printk_stack_address arch/x86/kernel/dumpstack.c:72 [inline]
 show_trace_log_lvl+0x1b7/0x3d0 arch/x86/kernel/dumpstack.c:285
 sched_show_task kernel/sched/core.c:7604 [inline]
 sched_show_task+0x3f0/0x5f0 kernel/sched/core.c:7579
 show_state_filter+0xee/0x320 kernel/sched/core.c:7649
 k_spec drivers/tty/vt/keyboard.c:667 [inline]
 k_spec+0xed/0x150 drivers/tty/vt/keyboard.c:656
 kbd_keycode drivers/tty/vt/keyboard.c:1522 [inline]
 kbd_event+0xcbd/0x17a0 drivers/tty/vt/keyboard.c:1541
 input_handler_events_default+0x116/0x1b0 drivers/input/input.c:2549
 input_pass_values+0x777/0x8e0 drivers/input/input.c:126
 input_event_dispose drivers/input/input.c:352 [inline]
 input_handle_event+0xb30/0x14d0 drivers/input/input.c:369
 input_event drivers/input/input.c:398 [inline]
 input_event+0x83/0xa0 drivers/input/input.c:390
 hidinput_hid_event+0xa12/0x2410 drivers/hid/hid-input.c:1719
 hid_process_event+0x4b7/0x5e0 drivers/hid/hid-core.c:1540
 hid_input_array_field+0x535/0x710 drivers/hid/hid-core.c:1652
 hid_process_report drivers/hid/hid-core.c:1694 [inline]
 hid_report_raw_event+0xa02/0x11c0 drivers/hid/hid-core.c:2040
 __hid_input_report.constprop.0+0x341/0x440 drivers/hid/hid-core.c:2110
 hid_irq_in+0x35e/0x870 drivers/hid/usbhid/hid-core.c:285
 __usb_hcd_giveback_urb+0x389/0x6e0 drivers/usb/core/hcd.c:1650
 usb_hcd_giveback_urb+0x396/0x450 drivers/usb/core/hcd.c:1734
 dummy_timer+0x17f0/0x3930 drivers/usb/gadget/udc/dummy_hcd.c:1993
 __run_hrtimer kernel/time/hrtimer.c:1691 [inline]
 __hrtimer_run_queues+0x20a/0xae0 kernel/time/hrtimer.c:1755
 hrtimer_run_softirq+0x17d/0x350 kernel/time/hrtimer.c:1772
 handle_softirqs+0x206/0x8d0 kernel/softirq.c:554
 __do_softirq kernel/softirq.c:588 [inline]
 invoke_softirq kernel/softirq.c:428 [inline]
 __irq_exit_rcu kernel/softirq.c:637 [inline]
 irq_exit_rcu+0xac/0x110 kernel/softirq.c:649
 instr_sysvec_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1049 [inline]
 sysvec_apic_timer_interrupt+0x90/0xb0 arch/x86/kernel/apic/apic.c:1049
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x1a/0x20 arch/x86/include/asm/idtentry.h:702
RIP: 0010:__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:152 [inline]
RIP: 0010:_raw_spin_unlock_irqrestore+0x31/0x80 kernel/locking/spinlock.c:194
Code: f5 53 48 8b 74 24 10 48 89 fb 48 83 c7 18 e8 f6 82 42 fa 48 89 df e8 0e 00 43 fa f7 c5 00 02 00 00 75 23 9c 58 f6 c4 02 75 37 <bf> 01 00 00 00 e8 b5 2f 37 fa 65 8b 05 56 ed 12 79 85 c0 74 16 5b
RSP: 0000:ffffc9000519f6c8 EFLAGS: 00000246
RAX: 0000000000000006 RBX: ffffffff899d2840 RCX: 1ffffffff1f59bc9
RDX: 0000000000000000 RSI: ffffffff8727f220 RDI: ffffffff8746ebc0
RBP: 0000000000000282 R08: 0000000000000001 R09: fffffbfff1f561bd
R10: ffffffff8fab0def R11: 0000000000000000 R12: ffffffff813040b7
R13: ffffffff899d2840 R14: 0000000000000282 R15: ffffc9000519f788
 spin_unlock_irqrestore include/linux/spinlock.h:406 [inline]
 prepare_to_wait_event+0xce/0x6a0 kernel/sched/wait.c:300
 usb_kill_urb.part.0+0x1e3/0x250 drivers/usb/core/urb.c:713
 usb_kill_urb+0x83/0xa0 drivers/usb/core/urb.c:702
 hub_quiesce+0x1de/0x310 drivers/usb/core/hub.c:1388
 hub_suspend+0x545/0xa80 drivers/usb/core/hub.c:3962
 usb_suspend_interface drivers/usb/core/driver.c:1328 [inline]
 usb_suspend_both+0x297/0x9c0 drivers/usb/core/driver.c:1433
 usb_runtime_suspend+0x49/0x180 drivers/usb/core/driver.c:1968
 __rpm_callback+0xc5/0x4c0 drivers/base/power/runtime.c:394
 rpm_callback+0x192/0x1d0 drivers/base/power/runtime.c:448
 rpm_suspend+0x2e7/0x1200 drivers/base/power/runtime.c:672
 __pm_runtime_suspend+0xbc/0x160 drivers/base/power/runtime.c:1142
 pm_runtime_autosuspend include/linux/pm_runtime.h:342 [inline]
 usb_runtime_idle+0x4c/0x60 drivers/usb/core/driver.c:2005
 rpm_idle+0x2f7/0x740 drivers/base/power/runtime.c:524
 pm_runtime_work+0x120/0x150 drivers/base/power/runtime.c:970
 process_one_work+0x9c5/0x1ba0 kernel/workqueue.c:3229
 process_scheduled_works kernel/workqueue.c:3310 [inline]
 worker_thread+0x6c8/0xf00 kernel/workqueue.c:3391
 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
 </TASK>
 </TASK>
task:modprobe        state:R  running task     stack:24720 pid:9905  tgid:9905  ppid:9218   flags:0x00000002
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5328 [inline]
 __schedule+0x105f/0x34b0 kernel/sched/core.c:6690
 preempt_schedule_common+0x44/0xc0 kernel/sched/core.c:6869
 __cond_resched+0x1b/0x30 kernel/sched/core.c:7214
 might_resched include/linux/kernel.h:73 [inline]
 down_write+0x74/0x200 kernel/locking/rwsem.c:1576
 anon_vma_lock_write include/linux/rmap.h:121 [inline]
 __anon_vma_prepare+0x107/0x5e0 mm/rmap.c:210
 __vmf_anon_prepare+0x11c/0x240 mm/memory.c:3307
 vmf_anon_prepare mm/internal.h:326 [inline]
 do_anonymous_page mm/memory.c:4769 [inline]
 do_pte_missing mm/memory.c:3963 [inline]
 handle_pte_fault mm/memory.c:5755 [inline]
 __handle_mm_fault+0x15b5/0x3390 mm/memory.c:5898
 handle_mm_fault+0x3fa/0xaa0 mm/memory.c:6066
 do_user_addr_fault+0x613/0x12c0 arch/x86/mm/fault.c:1338
 handle_page_fault arch/x86/mm/fault.c:1481 [inline]
 exc_page_fault+0x5c/0xc0 arch/x86/mm/fault.c:1539
 asm_exc_page_fault+0x26/0x30 arch/x86/include/asm/idtentry.h:623
RIP: 0033:0x7f760f01db9d
RSP: 002b:00007ffe62d74c48 EFLAGS: 00010206
RAX: 00007f760f234a80 RBX: 00007f760ef8a000 RCX: 0000000000dc0000
RDX: 00000000014a0000 RSI: 00007f760efa8540 RDI: 0000000000000000
RBP: 00007ffe62d74d50 R08: 00007ffe62d70000 R09: 00007f760f235ab0
R10: 00007f760ef8eab8 R11: 0000000000000025 R12: 00007f760f1fe5c0
R13: 00007f760f229eda R14: 00007f760f12b8c8 R15: 00007f760ef8eab8
 </TASK>
task:modprobe        state:R  running task     stack:25424 pid:9906  tgid:9906  ppid:7537   flags:0x00000002
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5328 [inline]
 __schedule+0x105f/0x34b0 kernel/sched/core.c:6690
 preempt_schedule_common+0x44/0xc0 kernel/sched/core.c:6869
 __cond_resched+0x1b/0x30 kernel/sched/core.c:7214
 might_resched include/linux/kernel.h:73 [inline]
 might_alloc include/linux/sched/mm.h:321 [inline]
 might_alloc include/linux/sched/mm.h:316 [inline]
 slab_pre_alloc_hook mm/slub.c:4036 [inline]
 slab_alloc_node mm/slub.c:4114 [inline]
 kmem_cache_alloc_noprof+0x24c/0x2b0 mm/slub.c:4141
 anon_vma_alloc mm/rmap.c:95 [inline]
 __anon_vma_prepare+0x344/0x5e0 mm/rmap.c:203
 __vmf_anon_prepare+0x11c/0x240 mm/memory.c:3307
 vmf_anon_prepare mm/internal.h:326 [inline]
 do_anonymous_page mm/memory.c:4769 [inline]
 do_pte_missing mm/memory.c:3963 [inline]
 handle_pte_fault mm/memory.c:5755 [inline]
 __handle_mm_fault+0x15b5/0x3390 mm/memory.c:5898
 handle_mm_fault+0x3fa/0xaa0 mm/memory.c:6066
 do_user_addr_fault+0x613/0x12c0 arch/x86/mm/fault.c:1338
 handle_page_fault arch/x86/mm/fault.c:1481 [inline]
 exc_page_fault+0x5c/0xc0 arch/x86/mm/fault.c:1539
 asm_exc_page_fault+0x26/0x30 arch/x86/include/asm/idtentry.h:623
RIP: 0033:0x7f1219c59b9d
RSP: 002b:00007ffcdc27f238 EFLAGS: 00010206
RAX: 00007f1219e70a80 RBX: 00007f1219bc6000 RCX: 0000000000dc0000
RDX: 00000000014a0000 RSI: 00007f1219be4540 RDI: 0000000000000000
RBP: 00007ffcdc27f340 R08: 00007ffcdc270000 R09: 00007f1219e71ab0
R10: 00007f1219bcaab8 R11: 0000000000000025 R12: 00007f1219e3a5c0
R13: 00007f1219e65eda R14: 00007f1219d678c8 R15: 00007f1219bcaab8
 </TASK>
task:kworker/u8:7    state:R  running task     stack:32568 pid:9907  tgid:9907  ppid:3775   flags:0x00004000
Call Trace:
 <TASK>
 __switch_to_asm+0x70/0x70
 </TASK>

Showing all locks held in the system:
2 locks held by kworker/u8:5/355:
 #0: ffff888100089148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x129b/0x1ba0 kernel/workqueue.c:3204
 #1: ffffc9000173fd80 (connector_reaper_work){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3205
2 locks held by kworker/u8:6/1555:
 #0: ffff888100089148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x129b/0x1ba0 kernel/workqueue.c:3204
 #1: ffffc900032bfd80 ((reaper_work).work){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3205
6 locks held by kworker/0:2/2511:
 #0: ffff888100eed548 ((wq_completion)pm){+.+.}-{0:0}, at: process_one_work+0x129b/0x1ba0 kernel/workqueue.c:3204
 #1: ffffc9000519fd80 ((work_completion)(&dev->power.work)){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3205
 #2: ffff88812d89c230 (&dev->event_lock){..-.}-{2:2}, at: input_event drivers/input/input.c:397 [inline]
 #2: ffff88812d89c230 (&dev->event_lock){..-.}-{2:2}, at: input_event+0x70/0xa0 drivers/input/input.c:390
 #3: ffffffff88ebb140 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire include/linux/rcupdate.h:337 [inline]
 #3: ffffffff88ebb140 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock include/linux/rcupdate.h:849 [inline]
 #3: ffffffff88ebb140 (rcu_read_lock){....}-{1:2}, at: input_pass_values+0x8b/0x8e0 drivers/input/input.c:118
 #4: ffffffff89387a58 (kbd_event_lock){..-.}-{2:2}, at: spin_lock include/linux/spinlock.h:351 [inline]
 #4: ffffffff89387a58 (kbd_event_lock){..-.}-{2:2}, at: kbd_event+0x8a/0x17a0 drivers/tty/vt/keyboard.c:1535
 #5: ffffffff88ebb140 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire include/linux/rcupdate.h:337 [inline]
 #5: ffffffff88ebb140 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock include/linux/rcupdate.h:849 [inline]
 #5: ffffffff88ebb140 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x7f/0x390 kernel/locking/lockdep.c:6720
2 locks held by getty/2606:
 #0: ffff88810f3f90a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x24/0x80 drivers/tty/tty_ldisc.c:243
 #1: ffffc900000432f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xfba/0x1480 drivers/tty/n_tty.c:2211
1 lock held by syz-executor/2640:
2 locks held by kworker/u8:7/3775:
 #0: ffff888100089148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x129b/0x1ba0 kernel/workqueue.c:3204
 #1: ffffc90001dbfd80 ((work_completion)(&sub_info->work)){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3205
3 locks held by kworker/0:5/4935:
6 locks held by kworker/1:4/4993:
 #0: ffff888105efad48 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x129b/0x1ba0 kernel/workqueue.c:3204
 #1: ffffc9000265fd80 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3205
 #2: ffff888105bcf190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:1014 [inline]
 #2: ffff888105bcf190 (&dev->mutex){....}-{3:3}, at: hub_event+0x1be/0x4f40 drivers/usb/core/hub.c:5849
 #3: ffff88811aaf4190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:1014 [inline]
 #3: ffff88811aaf4190 (&dev->mutex){....}-{3:3}, at: usb_disconnect+0x10a/0x920 drivers/usb/core/hub.c:2295
 #4: ffff88811b931160 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:1014 [inline]
 #4: ffff88811b931160 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1095 [inline]
 #4: ffff88811b931160 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa4/0x610 drivers/base/dd.c:1293
 #5: ffff88811c2d5a20 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:1014 [inline]
 #5: ffff88811c2d5a20 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1095 [inline]
 #5: ffff88811c2d5a20 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa4/0x610 drivers/base/dd.c:1293
2 locks held by kworker/u8:0/7537:
 #0: ffff888100089148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x129b/0x1ba0 kernel/workqueue.c:3204
 #1: ffffc9000fbb7d80 ((work_completion)(&sub_info->work)){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3205
1 lock held by syz.2.1232/9169:
 #0: ffffffff88ec6a38 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock+0x282/0x3b0 kernel/rcu/tree_exp.h:297
1 lock held by syz.1.1233/9171:
 #0: ffffffff88ec6a38 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock+0x1a4/0x3b0 kernel/rcu/tree_exp.h:329
2 locks held by kworker/u8:2/9218:
 #0: ffff888100089148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x129b/0x1ba0 kernel/workqueue.c:3204
 #1: ffffc9000175fd80 ((work_completion)(&sub_info->work)){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3205
2 locks held by kworker/u8:3/9222:
 #0: ffff888100089148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x129b/0x1ba0 kernel/workqueue.c:3204
 #1: ffffc9000160fd80 ((work_completion)(&sub_info->work)){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3205
1 lock held by kworker/u8:3/9614:
2 locks held by modprobe/9905:
2 locks held by modprobe/9906:

=============================================

keytouch 0003:0926:3333.00AB: can't resubmit intr, dummy_hcd.3-1/input0, status -19

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/10/21 19:47 https://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb.git usb-testing c6d9e43954bf f1e4447c .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-usb INFO: rcu detected stall in pm_runtime_work
* Struck through repros no longer work on HEAD.