BUG: unable to handle kernel paging request in hrtimer_update_next_event

Status: auto-obsoleted due to no activity on 2022/09/21 13:03
Subsystems: kernel
[Documentation on labels]
Reported-by: syzbot+56ca986b9fd739fa779a@syzkaller.appspotmail.com
First crash: 1502d, last: 1502d
▶ ▼ Similar bugs (1)
Kernel Title Rank 🛈 Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream KMSAN: uninit-value in hrtimer_update_next_event kernel 7 1 1271d 1271d 0/29 auto-obsoleted due to no activity on 2023/05/10 19:26

Sample crash report:
Unable to handle kernel paging request at virtual address ffffffff8011115c

======================================================
WARNING: possible circular locking dependency detected
5.17.0-rc1-syzkaller-00002-g0966d385830d #0 Not tainted
------------------------------------------------------
sshd/2022 is trying to acquire lock:
ffffffff84a888e0 (console_owner){-...}-{0:0}, at: console_unlock+0x2b2/0x97a kernel/printk/printk.c:2707

but task is already holding lock:
ffffaf805a9e7418 (hrtimer_bases.lock){-.-.}-{2:2}, at: __run_hrtimer kernel/time/hrtimer.c:1689 [inline]
ffffaf805a9e7418 (hrtimer_bases.lock){-.-.}-{2:2}, at: __hrtimer_run_queues+0x262/0xa16 kernel/time/hrtimer.c:1749

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #6 (hrtimer_bases.lock){-.-.}-{2:2}:
       lock_acquire.part.0+0x1d0/0x424 kernel/locking/lockdep.c:5639
       lock_acquire+0x54/0x6a kernel/locking/lockdep.c:5612
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x3e/0x62 kernel/locking/spinlock.c:162
       lock_hrtimer_base kernel/time/hrtimer.c:173 [inline]
       hrtimer_start_range_ns+0x9e/0x6dc kernel/time/hrtimer.c:1296
       hrtimer_start_expires include/linux/hrtimer.h:432 [inline]
       do_start_rt_bandwidth kernel/sched/rt.c:69 [inline]
       start_rt_bandwidth kernel/sched/rt.c:80 [inline]
       inc_rt_group kernel/sched/rt.c:1208 [inline]
       inc_rt_tasks kernel/sched/rt.c:1252 [inline]
       __enqueue_rt_entity kernel/sched/rt.c:1428 [inline]
       enqueue_rt_entity kernel/sched/rt.c:1474 [inline]
       enqueue_task_rt+0x520/0x568 kernel/sched/rt.c:1509
       enqueue_task+0x66/0x136 kernel/sched/core.c:2010
       __sched_setscheduler.constprop.0+0x704/0xdd4 kernel/sched/core.c:7475
       _sched_setscheduler kernel/sched/core.c:7521 [inline]
       sched_setscheduler_nocheck kernel/sched/core.c:7568 [inline]
       sched_set_fifo+0xc8/0x108 kernel/sched/core.c:7592
       drm_vblank_worker_init+0xea/0x10c drivers/gpu/drm/drm_vblank_work.c:263
       drm_vblank_init+0xec/0x24e drivers/gpu/drm/drm_vblank.c:551
       vkms_create drivers/gpu/drm/vkms/vkms_drv.c:194 [inline]
       vkms_init+0x272/0x45c drivers/gpu/drm/vkms/vkms_drv.c:233
       do_one_initcall+0x13a/0x7ea init/main.c:1300
       do_initcall_level init/main.c:1373 [inline]
       do_initcalls init/main.c:1389 [inline]
       do_basic_setup init/main.c:1408 [inline]
       kernel_init_freeable+0x510/0x5b4 init/main.c:1613
       kernel_init+0x28/0x21c init/main.c:1502
       ret_from_exception+0x0/0x10

-> #5 (&rt_b->rt_runtime_lock){-...}-{2:2}:
       lock_acquire.part.0+0x1d0/0x424 kernel/locking/lockdep.c:5639
       lock_acquire+0x54/0x6a kernel/locking/lockdep.c:5612
       __raw_spin_lock include/linux/spinlock_api_smp.h:133 [inline]
       _raw_spin_lock+0x32/0x48 kernel/locking/spinlock.c:154
       __enable_runtime kernel/sched/rt.c:840 [inline]
       rq_online_rt+0x78/0x1b8 kernel/sched/rt.c:2431
       set_rq_online.part.0+0xaa/0xc2 kernel/sched/core.c:8965
       set_rq_online kernel/sched/core.c:9075 [inline]
       sched_cpu_activate+0x1c0/0x250 kernel/sched/core.c:9070
       cpuhp_invoke_callback+0x282/0x504 kernel/cpu.c:191
       cpuhp_thread_fun+0x2f6/0x4b0 kernel/cpu.c:791
       smpboot_thread_fn+0x448/0x6cc kernel/smpboot.c:164
       kthread+0x19e/0x1fa kernel/kthread.c:377
       ret_from_exception+0x0/0x10

-> #4 (&rq->__lock){-.-.}-{2:2}:
       lock_acquire.part.0+0x1d0/0x424 kernel/locking/lockdep.c:5639
       lock_acquire+0x54/0x6a kernel/locking/lockdep.c:5612
       _raw_spin_lock_nested+0x36/0x4e kernel/locking/spinlock.c:378
       raw_spin_rq_lock_nested+0x22/0x34 kernel/sched/core.c:489
       raw_spin_rq_lock kernel/sched/sched.h:1318 [inline]
       rq_lock kernel/sched/sched.h:1616 [inline]
       task_fork_fair+0xa8/0x218 kernel/sched/fair.c:11146
       sched_post_fork+0x16e/0x196 kernel/sched/core.c:4462
       copy_process+0x3378/0x3c34 kernel/fork.c:2379
       kernel_clone+0xee/0x920 kernel/fork.c:2555
       kernel_thread+0xf8/0x130 kernel/fork.c:2607
       rest_init+0x34/0x3f2 init/main.c:690
       arch_call_rest_init+0x18/0x20 init/main.c:881
       start_kernel+0x66a/0x698 init/main.c:1138

-> #3 (&p->pi_lock){-.-.}-{2:2}:
       lock_acquire.part.0+0x1d0/0x424 kernel/locking/lockdep.c:5639
       lock_acquire+0x54/0x6a kernel/locking/lockdep.c:5612
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x3e/0x62 kernel/locking/spinlock.c:162
       try_to_wake_up+0xa4/0x748 kernel/sched/core.c:4017
       default_wake_function+0x28/0x36 kernel/sched/core.c:6723
       woken_wake_function+0x38/0x48 kernel/sched/wait.c:481
       __wake_up_common+0xb6/0x236 kernel/sched/wait.c:108
       __wake_up_common_lock+0xd6/0x136 kernel/sched/wait.c:138
       __wake_up+0x10/0x18 kernel/sched/wait.c:157
       tty_wakeup+0x58/0xbe drivers/tty/tty_io.c:534
       tty_port_default_wakeup+0x2c/0x44 drivers/tty/tty_port.c:51
       tty_port_tty_wakeup+0x3a/0x46 drivers/tty/tty_port.c:413
       uart_write_wakeup+0x34/0x48 drivers/tty/serial/serial_core.c:106
       serial8250_tx_chars+0x322/0x592 drivers/tty/serial/8250/8250_port.c:1845
       serial8250_handle_irq.part.0+0x284/0x286 drivers/tty/serial/8250/8250_port.c:1932
       serial8250_handle_irq drivers/tty/serial/8250/8250_port.c:1905 [inline]
       serial8250_default_handle_irq+0xac/0x142 drivers/tty/serial/8250/8250_port.c:1949
       serial8250_interrupt+0xbe/0x1a6 drivers/tty/serial/8250/8250_core.c:126
       __handle_irq_event_percpu+0x16e/0x6ec kernel/irq/handle.c:158
       handle_irq_event_percpu kernel/irq/handle.c:193 [inline]
       handle_irq_event+0x6a/0xfa kernel/irq/handle.c:210
       handle_fasteoi_irq+0x1c0/0x4d6 kernel/irq/chip.c:715
       generic_handle_irq_desc include/linux/irqdesc.h:158 [inline]
       handle_irq_desc kernel/irq/irqdesc.c:646 [inline]
       generic_handle_domain_irq+0x7c/0x9c kernel/irq/irqdesc.c:680
       plic_handle_irq+0x122/0x242 drivers/irqchip/irq-sifive-plic.c:242
       generic_handle_irq_desc include/linux/irqdesc.h:158 [inline]
       handle_irq_desc kernel/irq/irqdesc.c:646 [inline]
       generic_handle_domain_irq+0x7c/0x9c kernel/irq/irqdesc.c:680
       riscv_intc_irq+0x7e/0xc8 drivers/irqchip/irq-riscv-intc.c:40
       generic_handle_arch_irq+0x36/0x54 kernel/irq/handle.c:238
       ret_from_exception+0x0/0x10
       rcu_gp_cleanup+0x182/0xa90 kernel/rcu/tree.c:2036

-> #2 (&tty->write_wait){-.-.}-{2:2}:
       lock_acquire.part.0+0x1d0/0x424 kernel/locking/lockdep.c:5639
       lock_acquire+0x54/0x6a kernel/locking/lockdep.c:5612
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x3e/0x62 kernel/locking/spinlock.c:162
       __wake_up_common_lock+0xc4/0x136 kernel/sched/wait.c:137
       __wake_up+0x10/0x18 kernel/sched/wait.c:157
       tty_wakeup+0x58/0xbe drivers/tty/tty_io.c:534
       tty_port_default_wakeup+0x2c/0x44 drivers/tty/tty_port.c:51
       tty_port_tty_wakeup+0x3a/0x46 drivers/tty/tty_port.c:413
       uart_write_wakeup+0x34/0x48 drivers/tty/serial/serial_core.c:106
       serial8250_tx_chars+0x322/0x592 drivers/tty/serial/8250/8250_port.c:1845
       serial8250_handle_irq.part.0+0x284/0x286 drivers/tty/serial/8250/8250_port.c:1932
       serial8250_handle_irq drivers/tty/serial/8250/8250_port.c:1905 [inline]
       serial8250_default_handle_irq+0xac/0x142 drivers/tty/serial/8250/8250_port.c:1949
       serial8250_interrupt+0xbe/0x1a6 drivers/tty/serial/8250/8250_core.c:126
       __handle_irq_event_percpu+0x16e/0x6ec kernel/irq/handle.c:158
       handle_irq_event_percpu kernel/irq/handle.c:193 [inline]
       handle_irq_event+0x6a/0xfa kernel/irq/handle.c:210
       handle_fasteoi_irq+0x1c0/0x4d6 kernel/irq/chip.c:715
       generic_handle_irq_desc include/linux/irqdesc.h:158 [inline]
       handle_irq_desc kernel/irq/irqdesc.c:646 [inline]
       generic_handle_domain_irq+0x7c/0x9c kernel/irq/irqdesc.c:680
       plic_handle_irq+0x122/0x242 drivers/irqchip/irq-sifive-plic.c:242
       generic_handle_irq_desc include/linux/irqdesc.h:158 [inline]
       handle_irq_desc kernel/irq/irqdesc.c:646 [inline]
       generic_handle_domain_irq+0x7c/0x9c kernel/irq/irqdesc.c:680
       riscv_intc_irq+0x7e/0xc8 drivers/irqchip/irq-riscv-intc.c:40
       generic_handle_arch_irq+0x36/0x54 kernel/irq/handle.c:238
       ret_from_exception+0x0/0x10
       __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:151 [inline]
       _raw_spin_unlock_irqrestore+0x68/0x98 kernel/locking/spinlock.c:194

-> #1 (&port_lock_key){-.-.}-{2:2}:
       lock_acquire.part.0+0x1d0/0x424 kernel/locking/lockdep.c:5639
       lock_acquire+0x54/0x6a kernel/locking/lockdep.c:5612
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x3e/0x62 kernel/locking/spinlock.c:162
       serial8250_console_write+0x848/0x8e6 drivers/tty/serial/8250/8250_port.c:3387
       univ8250_console_write+0x46/0x54 drivers/tty/serial/8250/8250_core.c:575
       call_console_drivers kernel/printk/printk.c:1929 [inline]
       console_unlock+0x666/0x97a kernel/printk/printk.c:2711
       register_console+0x250/0x534 kernel/printk/printk.c:3054
       uart_configure_port drivers/tty/serial/serial_core.c:2402 [inline]
       uart_add_one_port+0xbf2/0xc14 drivers/tty/serial/serial_core.c:2917
       serial8250_register_8250_port+0x8ce/0xc6e drivers/tty/serial/8250/8250_core.c:1082
       of_platform_serial_probe+0x7ae/0xa9c drivers/tty/serial/8250/8250_of.c:232
       platform_probe+0xc8/0x172 drivers/base/platform.c:1416
       call_driver_probe drivers/base/dd.c:517 [inline]
       really_probe+0x1a6/0x89e drivers/base/dd.c:596
       __driver_probe_device+0x24a/0x2d4 drivers/base/dd.c:752
       driver_probe_device+0x60/0x1a4 drivers/base/dd.c:782
       __driver_attach+0x178/0x33e drivers/base/dd.c:1141
       bus_for_each_dev+0x122/0x194 drivers/base/bus.c:301
       driver_attach+0x32/0x3c drivers/base/dd.c:1158
       bus_add_driver+0x2c6/0x41a drivers/base/bus.c:618
       driver_register+0x144/0x286 drivers/base/driver.c:171
       __platform_driver_register+0x46/0x52 drivers/base/platform.c:863
       of_platform_serial_driver_init+0x22/0x2a drivers/tty/serial/8250/8250_of.c:341
       do_one_initcall+0x13a/0x7ea init/main.c:1300
       do_initcall_level init/main.c:1373 [inline]
       do_initcalls init/main.c:1389 [inline]
       do_basic_setup init/main.c:1408 [inline]
       kernel_init_freeable+0x510/0x5b4 init/main.c:1613
       kernel_init+0x28/0x21c init/main.c:1502
       ret_from_exception+0x0/0x10

-> #0 (console_owner){-...}-{0:0}:
       check_noncircular+0x1de/0x1fe kernel/locking/lockdep.c:2143
       check_prev_add kernel/locking/lockdep.c:3063 [inline]
       check_prevs_add kernel/locking/lockdep.c:3186 [inline]
       validate_chain kernel/locking/lockdep.c:3801 [inline]
       __lock_acquire+0x19a4/0x333e kernel/locking/lockdep.c:5027
       lock_acquire.part.0+0x1d0/0x424 kernel/locking/lockdep.c:5639
       lock_acquire+0x54/0x6a kernel/locking/lockdep.c:5612
       console_lock_spinning_enable kernel/printk/printk.c:1781 [inline]
       console_unlock+0x304/0x97a kernel/printk/printk.c:2708
       vprintk_emit+0xd2/0x416 kernel/printk/printk.c:2245
       vprintk_default+0x22/0x2e kernel/printk/printk.c:2256
       vprintk+0x108/0x13e kernel/printk/printk_safe.c:50
       _printk+0xa0/0xc8 kernel/printk/printk.c:2266
       die_kernel_fault+0x3a/0x60 arch/riscv/mm/fault.c:29
       no_context arch/riscv/mm/fault.c:58 [inline]
       no_context arch/riscv/mm/fault.c:37 [inline]
       mm_fault_error arch/riscv/mm/fault.c:77 [inline]
       do_page_fault+0x5b2/0xa3c arch/riscv/mm/fault.c:348
       ret_from_exception+0x0/0x10
       __hrtimer_get_next_event kernel/time/hrtimer.c:577 [inline]
       hrtimer_update_next_event+0x9e/0x12c kernel/time/hrtimer.c:604

other info that might help us debug this:

Chain exists of:
  console_owner --> &rt_b->rt_runtime_lock --> hrtimer_bases.lock

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(hrtimer_bases.lock);
                               lock(&rt_b->rt_runtime_lock);
                               lock(hrtimer_bases.lock);
  lock(console_owner);

 *** DEADLOCK ***

2 locks held by sshd/2022:
 #0: ffffaf805a9e7418 (hrtimer_bases.lock){-.-.}-{2:2}, at: __run_hrtimer kernel/time/hrtimer.c:1689 [inline]
 #0: ffffaf805a9e7418 (hrtimer_bases.lock){-.-.}-{2:2}, at: __hrtimer_run_queues+0x262/0xa16 kernel/time/hrtimer.c:1749
 #1: ffffffff84a88600 (console_lock){+.+.}-{0:0}, at: vprintk_default+0x22/0x2e kernel/printk/printk.c:2256

stack backtrace:
CPU: 1 PID: 2022 Comm: sshd Not tainted 5.17.0-rc1-syzkaller-00002-g0966d385830d #0
Hardware name: riscv-virtio,qemu (DT)
Call Trace:
[<ffffffff8000a228>] dump_backtrace+0x2e/0x3c arch/riscv/kernel/stacktrace.c:113
[<ffffffff831668cc>] show_stack+0x34/0x40 arch/riscv/kernel/stacktrace.c:119
[<ffffffff831756ba>] __dump_stack lib/dump_stack.c:88 [inline]
[<ffffffff831756ba>] dump_stack_lvl+0xe4/0x150 lib/dump_stack.c:106
[<ffffffff83175742>] dump_stack+0x1c/0x24 lib/dump_stack.c:113
[<ffffffff8010f7b8>] print_circular_bug+0x34e/0x3d8 kernel/locking/lockdep.c:2021
[<ffffffff8010fa20>] check_noncircular+0x1de/0x1fe kernel/locking/lockdep.c:2143
[<ffffffff80113c26>] check_prev_add kernel/locking/lockdep.c:3063 [inline]
[<ffffffff80113c26>] check_prevs_add kernel/locking/lockdep.c:3186 [inline]
[<ffffffff80113c26>] validate_chain kernel/locking/lockdep.c:3801 [inline]
[<ffffffff80113c26>] __lock_acquire+0x19a4/0x333e kernel/locking/lockdep.c:5027
[<ffffffff80116582>] lock_acquire.part.0+0x1d0/0x424 kernel/locking/lockdep.c:5639
[<ffffffff8011682a>] lock_acquire+0x54/0x6a kernel/locking/lockdep.c:5612
[<ffffffff8011ee1c>] console_lock_spinning_enable kernel/printk/printk.c:1781 [inline]
[<ffffffff8011ee1c>] console_unlock+0x304/0x97a kernel/printk/printk.c:2708
[<ffffffff8012183e>] vprintk_emit+0xd2/0x416 kernel/printk/printk.c:2245
[<ffffffff80121ba4>] vprintk_default+0x22/0x2e kernel/printk/printk.c:2256
[<ffffffff8012254a>] vprintk+0x108/0x13e kernel/printk/printk_safe.c:50
[<ffffffff83169c5c>] _printk+0xa0/0xc8 kernel/printk/printk.c:2266
[<ffffffff80011232>] die_kernel_fault+0x3a/0x60 arch/riscv/mm/fault.c:29
[<ffffffff80011b38>] no_context arch/riscv/mm/fault.c:58 [inline]
[<ffffffff80011b38>] no_context arch/riscv/mm/fault.c:37 [inline]
[<ffffffff80011b38>] mm_fault_error arch/riscv/mm/fault.c:77 [inline]
[<ffffffff80011b38>] do_page_fault+0x5b2/0xa3c arch/riscv/mm/fault.c:348
[<ffffffff80005724>] ret_from_exception+0x0/0x10
[<ffffffff8016c636>] __hrtimer_get_next_event kernel/time/hrtimer.c:577 [inline]
[<ffffffff8016c636>] hrtimer_update_next_event+0x9e/0x12c kernel/time/hrtimer.c:604
Oops [#1]
Modules linked in:
CPU: 1 PID: 2022 Comm: sshd Not tainted 5.17.0-rc1-syzkaller-00002-g0966d385830d #0
Hardware name: riscv-virtio,qemu (DT)
epc : __hrtimer_get_next_event kernel/time/hrtimer.c:577 [inline]
epc : hrtimer_update_next_event+0xaa/0x12c kernel/time/hrtimer.c:604
 ra : __hrtimer_get_next_event kernel/time/hrtimer.c:577 [inline]
 ra : hrtimer_update_next_event+0x9e/0x12c kernel/time/hrtimer.c:604
epc : ffffffff8016c642 ra : ffffffff8016c636 sp : ffffaf800cb936b0
 gp : ffffffff85863ac0 tp : ffffaf800cf5c8c0 t0 : 0000000000046000
 t1 : 3bc8d578b96e3e00 t2 : ffffffff83604ca0 s0 : ffffaf800cb936f0
 s1 : ffffffff801110e4 a0 : 0000000000000000 a1 : 0000000000000000
 a2 : 0000000000000050 a3 : 7fffffffffffffff a4 : 0000000000000000
 a5 : ffffffff8011115c a6 : 0000000000f00000 a7 : ffffffff80b09d26
 s2 : 0000000000000000 s3 : ffffffff80111128 s4 : 000000007bb67b56
 s5 : ffffffff8011115c s6 : ffffffffffffffff s7 : ffffffff801110e4
 s8 : ffffaf800cb93860 s9 : ffffaf805a9e7460 s10: ffffaf805a9e7768
 s11: ffffaf805a9e7448 t3 : fffffffff3f3f300 t4 : ffffffff80112282
 t5 : 1ffff5f001972638 t6 : 0000000000040000
status: 0000000000000100 badaddr: ffffffff8011115c cause: 000000000000000f
[<ffffffff8016f4ae>] hrtimer_interrupt+0x1da/0x3ea kernel/time/hrtimer.c:1814
[<ffffffff823375da>] riscv_timer_interrupt+0x5c/0x6a drivers/clocksource/timer-riscv.c:97

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2022/06/23 13:03 git://git.kernel.org/pub/scm/linux/kernel/git/riscv/linux.git fixes 0966d385830d 912f5df7 .config console log report info ci-qemu2-riscv64 BUG: unable to handle kernel paging request in hrtimer_update_next_event
* Struck through repros no longer work on HEAD.