Adding some DRM people into Cc. On Sun 2026-01-04 11:51:35, 王志 wrote: > Dear Developers, > > I am reporting an RCU CPU stall detected by Syzkaller on Linux 6.18.0. The > issue involves a deadlock-like scenario in the VKMS driver when memory > allocation warnings occur. > > Analysis: CPU 2 is executing a DRM ioctl and enters warn_alloc, which invokes > printk. While flushing the console, an hrtimer interrupt fires and runs > vkms_vblank_simulate. > > The interrupt handler stalls at drm_handle_vblank trying to acquire a > spinlock, which appears to be held by CPU 1 (running drm_file_free). Since > this happens in hard IRQ context, CPU 2 spins indefinitely, leading to the > RCU stall.
If it spins indefinitelly then it looks like a deadlock. But it seems that both CPU1 and CPU2 are waiting for the (same?) lock, see below. > Stack Trace Highlights: > > RIP: native_queued_spin_lock_slowpath > <IRQ> > drm_handle_vblank+0x125/0xc70 > vkms_vblank_simulate+0xa8/0x390 > hrtimer_interrupt > <TASK> > console_flush_all > warn_alloc > __kvmalloc_node_noprof > drm_property_create_blob > drm_ioctl > Environment: > > Kernel: 6.18.0 #1 PREEMPT(full) > > Config: KASAN enabled > > Hardware: QEMU (i440FX) > > It seems like the combination of PREEMPT(full) and the long duration of > warn_alloc's printk cycle makes the system vulnerable to this interrupt-level > contention. > > rcu: INFO: rcu_preempt detected stalls on CPUs/tasks: > rcu: 2-...!: (10 ticks this GP) idle=4f7c/1/0x4000000000000000 > softirq=64211/64211 fqs=13 > rcu: (detected by 0, t=10505 jiffies, g=77557, q=966 ncpus=4) > Sending NMI from CPU 0 to CPUs 2: > NMI backtrace for cpu 2 > CPU: 2 UID: 0 PID: 27050 Comm: syz.2.6110 Not tainted 6.18.0 #1 PREEMPT(full) > Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS > rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 > RIP: 0010:native_queued_spin_lock_slowpath+0x23e/0x9c0 This is spin_lock_slowpath on CPU2 => CPU2 is spinning and waiting for a lock. Code: 02 48 89 e8 83 e0 07 83 c0 01 38 d0 7c 08 84 d2 0f 85 1c 07 00 00 b8 01 00 00 00 66 89 45 00 e9 c2 fe ff ff 89 44 24 40 f3 90 <e9> 5e fe ff ff 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 > RSP: 0018:ffffc90000658b78 EFLAGS: 00000002 > RAX: 0000000000000001 RBX: 0000000000000001 RCX: ffffffff8b43f32e > RDX: ffffed10044eac6b RSI: 0000000000000004 RDI: ffff888022756350 > RBP: ffff888022756350 R08: 0000000000000000 R09: ffffed10044eac6a > R10: ffff888022756353 R11: 0000000000000000 R12: 1ffff920000cb171 > R13: 0000000000000003 R14: ffffed10044eac6a R15: ffffc90000658bb8 > FS: 00007f1a7d7f6640(0000) GS:ffff8880cf101000(0000) knlGS:0000000000000000 > CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > CR2: 00007f2e53b8fff0 CR3: 0000000061616000 CR4: 00000000000006f0 > Call Trace: > <IRQ> > debug_spin_lock_before > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/locking/spinlock_debug.c:87 > [inline] > do_raw_spin_lock+0x20d/0x2b0 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/locking/spinlock_debug.c:115 > __raw_spin_lock_irqsave > home/wmy/Fuzzer/third_tool/linux-6.18/include/linux/spinlock_api_smp.h:110 > [inline] > _raw_spin_lock_irqsave+0x45/0x60 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/locking/spinlock.c:162 > drm_handle_vblank+0x125/0xc70 > vkms_vblank_simulate+0xa8/0x390 > __run_hrtimer > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/time/hrtimer.c:1779 [inline] > __hrtimer_run_queues+0x1f5/0xb30 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/time/hrtimer.c:1841 > hrtimer_interrupt+0x39a/0x880 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/time/hrtimer.c:1912 > instrument_atomic_read > home/wmy/Fuzzer/third_tool/linux-6.18/include/linux/instrumented.h:68 [inline] > _test_bit > home/wmy/Fuzzer/third_tool/linux-6.18/include/asm-generic/bitops/instrumented-non-atomic.h:141 > [inline] > cpumask_test_cpu > home/wmy/Fuzzer/third_tool/linux-6.18/include/linux/cpumask.h:646 [inline] > cpu_online > home/wmy/Fuzzer/third_tool/linux-6.18/include/linux/cpumask.h:1205 [inline] > __do_trace_local_timer_exit > home/wmy/Fuzzer/third_tool/linux-6.18/arch/x86/include/asm/trace/irq_vectors.h:40 > [inline] > trace_local_timer_exit > home/wmy/Fuzzer/third_tool/linux-6.18/arch/x86/include/asm/trace/irq_vectors.h:40 > [inline] > __sysvec_apic_timer_interrupt+0x10d/0x400 > home/wmy/Fuzzer/third_tool/linux-6.18/arch/x86/kernel/apic/apic.c:1059 > sysvec_apic_timer_interrupt+0xa3/0xc0 > home/wmy/Fuzzer/third_tool/linux-6.18/arch/x86/kernel/apic/apic.c:2145 > </IRQ> > <TASK> > asm_sysvec_apic_timer_interrupt+0x1a/0x20 > home/wmy/Fuzzer/third_tool/linux-6.18/arch/x86/include/asm/idtentry.h:697 > RIP: 0010:srcu_read_unlock_nmisafe > home/wmy/Fuzzer/third_tool/linux-6.18/include/linux/srcu.h:449 [inline] > RIP: 0010:console_srcu_read_unlock > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/printk/printk.c:303 [inline] > RIP: 0010:console_flush_all+0x905/0xbe0 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/printk/printk.c:3225 > Code: 24 08 48 8d 68 01 4c 89 e8 48 c1 e8 03 42 80 3c 30 00 0f 85 ab 02 00 00 > 49 89 6f 58 e9 3a ff ff ff e8 ef c7 20 00 fb 4c 89 e8 <48> c1 e8 03 42 80 3c > 30 00 0f 84 1e ff ff ff 4c 89 ef e8 c4 20 87 > RSP: 0018:ffffc90002dd7138 EFLAGS: 00000246 > RAX: ffffffff8ee702d8 RBX: 0000000000000001 RCX: ffffc90007631000 > RDX: 0000000000080000 RSI: ffffffff81999011 RDI: 0000000000000007 > RBP: 0000000000000200 R08: 0000000000000001 R09: 0000000000000001 > R10: 0000000000000200 R11: 0000000000000000 R12: 0000000000000000 > R13: ffffffff8ee702d8 R14: dffffc0000000000 R15: ffffffff8ee70280 > __console_flush_and_unlock > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/printk/printk.c:3258 [inline] > console_unlock+0xc2/0x1f0 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/printk/printk.c:3298 > console_trylock > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/printk/printk.c:2843 [inline] > console_trylock > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/printk/printk.c:2836 [inline] > console_trylock_spinning > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/printk/printk.c:1982 [inline] > vprintk_emit+0x3e7/0x670 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/printk/printk.c:2422 > _printk+0xbe/0xf0 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/printk/printk.c:2447 > show_free_areas+0x121d/0x2140 > home/wmy/Fuzzer/third_tool/linux-6.18/mm/show_mem.c:299 > __show_mem+0x34/0x150 home/wmy/Fuzzer/third_tool/linux-6.18/mm/show_mem.c:408 > warn_alloc_show_mem > home/wmy/Fuzzer/third_tool/linux-6.18/mm/page_alloc.c:3938 [inline] > warn_alloc+0x278/0x360 > home/wmy/Fuzzer/third_tool/linux-6.18/mm/page_alloc.c:3963 > free_vm_area home/wmy/Fuzzer/third_tool/linux-6.18/mm/vmalloc.c:4619 [inline] > __vmalloc_area_node home/wmy/Fuzzer/third_tool/linux-6.18/mm/vmalloc.c:3709 > [inline] > __vmalloc_node_range_noprof+0xfaa/0x13b0 > home/wmy/Fuzzer/third_tool/linux-6.18/mm/vmalloc.c:3897 > __vmalloc_node_noprof+0xac/0xf0 > home/wmy/Fuzzer/third_tool/linux-6.18/mm/vmalloc.c:3960 > set_vm_area_page_order > home/wmy/Fuzzer/third_tool/linux-6.18/mm/vmalloc.c:3089 [inline] > __vmalloc_area_node home/wmy/Fuzzer/third_tool/linux-6.18/mm/vmalloc.c:3713 > [inline] > __vmalloc_node_range_noprof+0x40d/0x13b0 > home/wmy/Fuzzer/third_tool/linux-6.18/mm/vmalloc.c:3897 > slab_want_init_on_free home/wmy/Fuzzer/third_tool/linux-6.18/mm/slab.h:644 > [inline] > slab_want_init_on_free home/wmy/Fuzzer/third_tool/linux-6.18/mm/slab.h:640 > [inline] > maybe_wipe_obj_freeptr home/wmy/Fuzzer/third_tool/linux-6.18/mm/slub.c:4918 > [inline] > slab_alloc_node home/wmy/Fuzzer/third_tool/linux-6.18/mm/slub.c:5278 [inline] > __do_kmalloc_node home/wmy/Fuzzer/third_tool/linux-6.18/mm/slub.c:5649 > [inline] > __kvmalloc_node_noprof+0x41f/0x9d0 > home/wmy/Fuzzer/third_tool/linux-6.18/mm/slub.c:7112 > drm_property_create_blob.part.0+0x34/0x320 > drm_mode_createblob_ioctl+0x139/0x490 > drm_ioctl_kernel+0x1ed/0x3e0 > drm_ioctl+0x574/0xb90 > vfs_ioctl home/wmy/Fuzzer/third_tool/linux-6.18/fs/ioctl.c:51 [inline] > __do_sys_ioctl home/wmy/Fuzzer/third_tool/linux-6.18/fs/ioctl.c:597 [inline] > __se_sys_ioctl home/wmy/Fuzzer/third_tool/linux-6.18/fs/ioctl.c:583 [inline] > __x64_sys_ioctl+0x18f/0x210 > home/wmy/Fuzzer/third_tool/linux-6.18/fs/ioctl.c:583 > do_syscall_64+0xcb/0xfa0 > home/wmy/Fuzzer/third_tool/linux-6.18/arch/x86/entry/syscall_64.c:99 > entry_SYSCALL_64_after_hwframe+0x77/0x7f > RIP: 0033:0x7f1a7f5b059d > Code: 02 b8 ff ff ff ff c3 66 0f 1f 44 00 00 f3 0f 1e fa 48 89 f8 48 89 f7 48 > 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 > 01 c3 48 c7 c1 a8 ff ff ff f7 d8 64 89 01 48 > RSP: 002b:00007f1a7d7f5f98 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 > RAX: ffffffffffffffda RBX: 00007f1a7f825fa0 RCX: 00007f1a7f5b059d > RDX: 0000200000000000 RSI: 00000000c01064bd RDI: 000000000000000a > RBP: 00007f1a7f64e078 R08: 0000000000000000 R09: 0000000000000000 > R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000 > R13: 00007f1a7f826038 R14: 00007f1a7f825fa0 R15: 00007f1a7d7d6000 > </TASK> > rcu: rcu_preempt kthread timer wakeup didn't happen for 10449 jiffies! g77557 > f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 > rcu: Possible timer handling issue on cpu=1 timer-softirq=43340 > rcu: rcu_preempt kthread starved for 10450 jiffies! g77557 f0x0 > RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=1 > rcu: Unless rcu_preempt kthread gets sufficient CPU time, OOM is now > expected behavior. > rcu: RCU grace-period kthread stack dump: > task:rcu_preempt state:I stack:28424 pid:16 tgid:16 ppid:2 > task_flags:0x208040 flags:0x00080000 > Call Trace: > <TASK> > sched_info_arrive > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/sched/stats.h:267 [inline] > sched_info_switch > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/sched/stats.h:330 [inline] > prepare_task_switch > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/sched/core.c:5122 [inline] > context_switch > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/sched/core.c:5272 [inline] > __schedule+0x1044/0x5bb0 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/sched/core.c:6929 > __schedule_loop > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/sched/core.c:7011 [inline] > schedule+0xe7/0x3a0 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/sched/core.c:7026 > schedule_timeout+0x113/0x280 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/time/sleep_timeout.c:98 > rcu_gp_fqs_check_wake > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/rcu/tree.c:2007 [inline] > rcu_gp_fqs_loop+0x18c/0xa00 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/rcu/tree.c:2083 > rcu_gp_kthread+0x26f/0x370 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/rcu/tree.c:2280 > kthread+0x3d0/0x780 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/kthread.c:463 > ret_from_fork+0x676/0x7d0 > home/wmy/Fuzzer/third_tool/linux-6.18/arch/x86/kernel/process.c:195 > ret_from_fork_asm+0x1a/0x30 > home/wmy/Fuzzer/third_tool/linux-6.18/arch/x86/entry/entry_64.S:245 > </TASK> > rcu: Stack dump where RCU GP kthread last ran: > Sending NMI from CPU 0 to CPUs 1: > NMI backtrace for cpu 1 > CPU: 1 UID: 0 PID: 27261 Comm: syz.1.6200 Not tainted 6.18.0 #1 PREEMPT(full) > Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS > rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 > RIP: 0010:native_queued_spin_lock_slowpath+0x23e/0x9c0 This is spin_lock_slowpath on CPU1 => Also CPU1 seems to be spinning and waiting for a lock. On CPU2, in IRQ context, it seems that drm_handle_vblank() tries to take: + dev->event_lock + dev->vblank_time_lock On CPU1, in TASK context, it seems that drm_file_free() in drm_events_release() tries to take: + dev->event_lock So, I guess that that contention/deadlock is on dev->event_lock. But who owns the lock, please? It is not obvious to me. On CPU2, in TASK context, drm_property_create_blob() seems to take a mutex. So, it should not be holding any spin lock. What is going on CPU0? Could you please provice a (more) complete kernel log? And if there is a deadlock scenario then it might get reported by lockdep. Could you please try to enable CONFIG_PROVE_LOCKING? > Code: 02 48 89 e8 83 e0 07 83 c0 01 38 d0 7c 08 84 d2 0f 85 1c 07 00 00 b8 01 > 00 00 00 66 89 45 00 e9 c2 fe ff ff 89 44 24 40 f3 90 <e9> 5e fe ff ff 48 b8 > 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 > RSP: 0018:ffffc90002d97b48 EFLAGS: 00000002 > RAX: 0000000000000001 RBX: 0000000000000001 RCX: ffffffff8b43f32e > RDX: ffffed10044eac6b RSI: 0000000000000004 RDI: ffff888022756350 > RBP: ffff888022756350 R08: 0000000000000000 R09: ffffed10044eac6a > R10: ffff888022756353 R11: 0000000000000000 R12: 1ffff920005b2f6b > R13: 0000000000000003 R14: ffffed10044eac6a R15: ffffc90002d97b88 > FS: 000055557fb21500(0000) GS:ffff8881a2601000(0000) knlGS:0000000000000000 > CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > CR2: 00007f4e64fa3fc8 CR3: 0000000131d68000 CR4: 00000000000006f0 > Call Trace: > <TASK> > debug_spin_lock_before > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/locking/spinlock_debug.c:87 > [inline] > do_raw_spin_lock+0x20d/0x2b0 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/locking/spinlock_debug.c:115 > __raw_spin_lock_irqsave > home/wmy/Fuzzer/third_tool/linux-6.18/include/linux/spinlock_api_smp.h:110 > [inline] > _raw_spin_lock_irqsave+0x45/0x60 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/locking/spinlock.c:162 > drm_file_free.part.0+0x2fd/0xcf0 > drm_close_helper.isra.0+0x183/0x1f0 > drm_release+0x1ab/0x360 > __fput+0x402/0xb50 home/wmy/Fuzzer/third_tool/linux-6.18/fs/file_table.c:468 > task_work_run+0x16b/0x260 > home/wmy/Fuzzer/third_tool/linux-6.18/kernel/task_work.c:227 > exit_to_user_mode_loop+0xf9/0x130 > do_syscall_64+0x424/0xfa0 > home/wmy/Fuzzer/third_tool/linux-6.18/arch/x86/entry/syscall_32.c:308 > entry_SYSCALL_64_after_hwframe+0x77/0x7f > RIP: 0033:0x7f4e641b059d > Code: 02 b8 ff ff ff ff c3 66 0f 1f 44 00 00 f3 0f 1e fa 48 89 f8 48 89 f7 48 > 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 > 01 c3 48 c7 c1 a8 ff ff ff f7 d8 64 89 01 48 > RSP: 002b:00007fff56b8c5b8 EFLAGS: 00000246 ORIG_RAX: 00000000000001b4 > RAX: 0000000000000000 RBX: 00007f4e64427da0 RCX: 00007f4e641b059d > RDX: 0000000000000000 RSI: 000000000000001e RDI: 0000000000000003 > RBP: 00007fff56b8c658 R08: 0000001b33b205bc R09: 0000000000000000 > R10: 0000001b33f20000 R11: 0000000000000246 R12: ffffffffffffffff > R13: 00007f4e6442609c R14: 00007f4e64427da0 R15: 00007fff56b8c680 > </TASK> Best Regards, Petr
