[linus:master] [sched/eevdf] eab03c23c2: WARNING:possible_circular_locking_dependency_detected

From: kernel test robot
Date: Mon Apr 01 2024 - 11:22:43 EST




Hello,

kernel test robot noticed "WARNING:possible_circular_locking_dependency_detected" on:

commit: eab03c23c2a162085b13200d7942fc5a00b5ccc8 ("sched/eevdf: Fix vruntime adjustment on reweight")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

[test failed on linus/master 4076fa161217fcd64a578ca04586c4be728cb004]


in testcase: trinity
version:
with following parameters:

runtime: 300s
group: group-01
nr_groups: 5



compiler: clang-17
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

(please refer to attached dmesg/kmsg for entire log/backtrace)


this issue doesn't always happen, 36 times out of 308 runs as below.
but for parent, we never observed this issue.


v6.7-rc1 eab03c23c2a162085b13200d794
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
:308 12% 36:308 dmesg.WARNING:possible_circular_locking_dependency_detected




If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <oliver.sang@xxxxxxxxx>
| Closes: https://lore.kernel.org/oe-lkp/202404012303.41984b81-lkp@xxxxxxxxx


[ 195.727401][ T3470] WARNING: possible circular locking dependency detected
[ 195.727403][ T3470] 6.7.0-rc1-00001-geab03c23c2a1 #1 Tainted: G TN
[ 195.727404][ T3470] ------------------------------------------------------
[ 195.727405][ T3470] trinity-main/3470 is trying to acquire lock:
[ 195.727407][ T3470] cb267a18 (console_owner){-.-.}-{0:0}, at: console_lock_spinning_enable (kernel/printk/printk.c:1854)
[ 195.727416][ T3470]
[ 195.727416][ T3470] but task is already holding lock:
[ 195.727417][ T3470] da2d4350 (&rq->__lock){-.-.}-{2:2}, at: __schedule (arch/x86/include/asm/preempt.h:85 kernel/sched/core.c:560 kernel/sched/sched.h:1349 kernel/sched/sched.h:1663 kernel/sched/core.c:6604)
[ 195.727423][ T3470]
[ 195.727423][ T3470] which lock already depends on the new lock.
[ 195.727423][ T3470]
[ 195.727424][ T3470]
[ 195.727424][ T3470] the existing dependency chain (in reverse order) is:
[ 195.727424][ T3470]
[ 195.727424][ T3470] -> #4 (&rq->__lock){-.-.}-{2:2}:
[ 195.727428][ T3470] _raw_spin_lock_nested (kernel/locking/spinlock.c:378)
[ 195.727431][ T3470] raw_spin_rq_lock_nested (arch/x86/include/asm/preempt.h:85 kernel/sched/core.c:560)
[ 195.727433][ T3470] task_fork_fair (kernel/sched/sched.h:1581)
[ 195.727436][ T3470] sched_cgroup_fork (kernel/sched/core.c:?)
[ 195.727438][ T3470] copy_process (include/linux/timekeeping.h:154 kernel/fork.c:2619)
[ 195.727441][ T3470] kernel_clone (kernel/fork.c:2907)
[ 195.727443][ T3470] user_mode_thread (kernel/fork.c:2985)
[ 195.727445][ T3470] rest_init (init/main.c:695)
[ 195.727447][ T3470] start_kernel (init/main.c:875)
[ 195.727452][ T3470] start_kernel (init/main.c:1072)
[ 195.727454][ T3470] i386_start_kernel (arch/x86/kernel/head32.c:79)
[ 195.727457][ T3470] startup_32_smp (arch/x86/kernel/head_32.S:295)
[ 195.727459][ T3470]
[ 195.727459][ T3470] -> #3 (&p->pi_lock){-.-.}-{2:2}:
[ 195.727461][ T3470] _raw_spin_lock_irqsave (include/linux/spinlock_api_smp.h:110 kernel/locking/spinlock.c:162)
[ 195.727464][ T3470] try_to_wake_up (kernel/sched/core.c:2232)
[ 195.727466][ T3470] default_wake_function (kernel/sched/core.c:7020)
[ 195.727469][ T3470] woken_wake_function (kernel/sched/wait.c:444)
[ 195.727472][ T3470] __wake_up_common_lock (kernel/sched/wait.c:89)
[ 195.727474][ T3470] __wake_up (kernel/sched/wait.c:127)
[ 195.727476][ T3470] tty_wakeup (drivers/tty/tty_io.c:527)
[ 195.727478][ T3470] tty_port_default_wakeup (drivers/tty/tty_port.c:70)
[ 195.727482][ T3470] tty_port_tty_wakeup (drivers/tty/tty_port.c:434)
[ 195.727484][ T3470] uart_write_wakeup (drivers/tty/serial/serial_core.c:121)
[ 195.727486][ T3470] serial8250_tx_chars (drivers/tty/serial/8250/8250_port.c:1842)
[ 195.727490][ T3470] serial8250_handle_irq (include/linux/spinlock.h:406 include/linux/serial_core.h:667 include/linux/serial_core.h:1085 drivers/tty/serial/8250/8250_port.c:1947)
[ 195.727492][ T3470] serial8250_default_handle_irq (drivers/tty/serial/8250/8250_port.c:1962)
[ 195.727495][ T3470] serial8250_interrupt (drivers/tty/serial/8250/8250_core.c:127)
[ 195.727498][ T3470] __handle_irq_event_percpu (kernel/irq/handle.c:158)
[ 195.727500][ T3470] handle_irq_event (kernel/irq/handle.c:193 kernel/irq/handle.c:210)
[ 195.727503][ T3470] handle_edge_irq (kernel/irq/chip.c:833)
[ 195.727505][ T3470] __handle_irq (arch/x86/kernel/irq_32.c:97)
[ 195.727508][ T3470] __common_interrupt (include/asm-generic/irq_regs.h:28 arch/x86/kernel/irq.c:270)
[ 195.727510][ T3470] common_interrupt (arch/x86/kernel/irq.c:247)
[ 195.727512][ T3470] asm_common_interrupt (arch/x86/entry/entry_32.S:636)
[ 195.727515][ T3470] _raw_spin_unlock_irqrestore (kernel/locking/spinlock.c:195)
[ 195.727517][ T3470] __create_object (mm/kmemleak.c:753)
[ 195.727521][ T3470] kmemleak_alloc (mm/kmemleak.c:761 mm/kmemleak.c:1033)
[ 195.727523][ T3470] slab_post_alloc_hook (include/linux/kmemleak.h:42)
[ 195.727527][ T3470] kmem_cache_alloc_bulk (mm/slub.c:4056)
[ 195.727529][ T3470] mas_alloc_nodes (lib/maple_tree.c:165 lib/maple_tree.c:1287)
[ 195.727532][ T3470] mas_expected_entries (lib/maple_tree.c:5633)
[ 195.727534][ T3470] copy_mm (include/linux/mm.h:994 kernel/fork.c:681 kernel/fork.c:1691 kernel/fork.c:1740)
[ 195.727536][ T3470] copy_process (kernel/fork.c:?)
[ 195.727538][ T3470] kernel_clone (kernel/fork.c:2907)
[ 195.727540][ T3470] __ia32_sys_clone (kernel/fork.c:3018)
[ 195.727542][ T3470] do_int80_syscall_32 (arch/x86/entry/common.c:164)
[ 195.727544][ T3470] restore_all_switch_stack (arch/x86/entry/entry_32.S:947)
[ 195.727547][ T3470]
[ 195.727547][ T3470] -> #2 (&tty->write_wait){-.-.}-{2:2}:
[ 195.727550][ T3470] _raw_spin_lock_irqsave (include/linux/spinlock_api_smp.h:110 kernel/locking/spinlock.c:162)
[ 195.727552][ T3470] __wake_up_common_lock (kernel/sched/wait.c:?)
[ 195.727554][ T3470] __wake_up (kernel/sched/wait.c:127)
[ 195.727556][ T3470] tty_wakeup (drivers/tty/tty_io.c:527)
[ 195.727558][ T3470] tty_port_default_wakeup (drivers/tty/tty_port.c:70)
[ 195.727560][ T3470] tty_port_tty_wakeup (drivers/tty/tty_port.c:434)
[ 195.727563][ T3470] uart_write_wakeup (drivers/tty/serial/serial_core.c:121)
[ 195.727564][ T3470] serial8250_tx_chars (drivers/tty/serial/8250/8250_port.c:1842)
[ 195.727567][ T3470] serial8250_handle_irq (include/linux/spinlock.h:406 include/linux/serial_core.h:667 include/linux/serial_core.h:1085 drivers/tty/serial/8250/8250_port.c:1947)
[ 195.727569][ T3470] serial8250_default_handle_irq (drivers/tty/serial/8250/8250_port.c:1962)
[ 195.727572][ T3470] serial8250_interrupt (drivers/tty/serial/8250/8250_core.c:127)
[ 195.727574][ T3470] __handle_irq_event_percpu (kernel/irq/handle.c:158)
[ 195.727577][ T3470] handle_irq_event (kernel/irq/handle.c:193 kernel/irq/handle.c:210)
[ 195.727579][ T3470] handle_edge_irq (kernel/irq/chip.c:833)
[ 195.727581][ T3470] __handle_irq (arch/x86/kernel/irq_32.c:97)
[ 195.727583][ T3470] __common_interrupt (include/asm-generic/irq_regs.h:28 arch/x86/kernel/irq.c:270)
[ 195.727585][ T3470] common_interrupt (arch/x86/kernel/irq.c:247)
[ 195.727586][ T3470] asm_common_interrupt (arch/x86/entry/entry_32.S:636)
[ 195.727588][ T3470] _raw_spin_unlock_irqrestore (kernel/locking/spinlock.c:195)
[ 195.727590][ T3470] uart_write (drivers/tty/serial/serial_core.c:74 drivers/tty/serial/serial_core.c:617)
[ 195.727592][ T3470] n_tty_write (drivers/tty/n_tty.c:574 drivers/tty/n_tty.c:2379)
[ 195.727594][ T3470] file_tty_write (drivers/tty/tty_io.c:1021)
[ 195.727596][ T3470] redirected_tty_write (drivers/tty/tty_io.c:1113 drivers/tty/tty_io.c:1136)
[ 195.727598][ T3470] vfs_write (fs/read_write.c:492)
[ 195.727600][ T3470] ksys_write (fs/read_write.c:637)
[ 195.727602][ T3470] __ia32_sys_write (fs/read_write.c:646)
[ 195.727604][ T3470] do_int80_syscall_32 (arch/x86/entry/common.c:164)
[ 195.727606][ T3470] restore_all_switch_stack (arch/x86/entry/entry_32.S:947)
[ 195.727608][ T3470]
[ 195.727608][ T3470] -> #1 (&port_lock_key){-.-.}-{2:2}:
[ 195.727611][ T3470] _raw_spin_lock_irqsave (include/linux/spinlock_api_smp.h:110 kernel/locking/spinlock.c:162)
[ 195.727613][ T3470] serial8250_console_write (include/linux/serial_core.h:? drivers/tty/serial/8250/8250_port.c:3403)
[ 195.727615][ T3470] univ8250_console_write (drivers/tty/serial/8250/8250_core.c:601)
[ 195.727618][ T3470] console_flush_all (kernel/printk/printk.c:2905)
[ 195.727620][ T3470] console_unlock (kernel/printk/printk.c:3036)
[ 195.727622][ T3470] vprintk_emit (arch/x86/include/asm/preempt.h:85 kernel/printk/printk.c:2304)
[ 195.727623][ T3470] vprintk_default (kernel/printk/printk.c:2318)
[ 195.727625][ T3470] vprintk (kernel/printk/printk_safe.c:?)
[ 195.727627][ T3470] _printk (kernel/printk/printk.c:2328)
[ 195.727630][ T3470] register_console (kernel/printk/printk.c:3542)
[ 195.727632][ T3470] univ8250_console_init (drivers/tty/serial/8250/8250_core.c:?)
[ 195.727635][ T3470] console_init (include/linux/jump_label.h:270 include/trace/events/initcall.h:48 kernel/printk/printk.c:3689)
[ 195.727637][ T3470] start_kernel (init/main.c:1009)
[ 195.727640][ T3470] i386_start_kernel (arch/x86/kernel/head32.c:79)
[ 195.727642][ T3470] startup_32_smp (arch/x86/kernel/head_32.S:295)
[ 195.727644][ T3470]
[ 195.727644][ T3470] -> #0 (console_owner){-.-.}-{0:0}:
[ 195.727646][ T3470] __lock_acquire (kernel/locking/lockdep.c:?)
[ 195.727649][ T3470] lock_acquire (kernel/locking/lockdep.c:5753)
[ 195.727651][ T3470] console_lock_spinning_enable (kernel/printk/printk.c:1854)
[ 195.727653][ T3470] console_flush_all (kernel/printk/printk.c:2901)
[ 195.727655][ T3470] console_unlock (kernel/printk/printk.c:3036)
[ 195.727657][ T3470] vprintk_emit (arch/x86/include/asm/preempt.h:85 kernel/printk/printk.c:2304)
[ 195.727658][ T3470] vprintk_default (kernel/printk/printk.c:2318)
[ 195.727660][ T3470] vprintk (kernel/printk/printk_safe.c:?)
[ 195.727662][ T3470] _printk (kernel/printk/printk.c:2328)
[ 195.727665][ T3470] pick_eevdf (kernel/sched/fair.c:961)
[ 195.727667][ T3470] pick_next_task_fair (kernel/sched/sched.h:1417 kernel/sched/fair.c:8377)
[ 195.727669][ T3470] __schedule (kernel/sched/core.c:5998)
[ 195.727672][ T3470] schedule (arch/x86/include/asm/preempt.h:85 kernel/sched/core.c:6764 kernel/sched/core.c:6778)
[ 195.727674][ T3470] schedule_hrtimeout_range_clock (kernel/time/hrtimer.c:?)
[ 195.727676][ T3470] schedule_hrtimeout_range (kernel/time/hrtimer.c:2364)
[ 195.727678][ T3470] do_sigtimedwait (kernel/signal.c:3653)
[ 195.727680][ T3470] __ia32_sys_rt_sigtimedwait_time32 (kernel/signal.c:3729)
[ 195.727683][ T3470] __do_fast_syscall_32 (arch/x86/entry/common.c:164)
[ 195.727685][ T3470] do_fast_syscall_32 (arch/x86/entry/common.c:255)
[ 195.727686][ T3470] do_SYSENTER_32 (arch/x86/entry/common.c:293)
[ 195.727688][ T3470] entry_SYSENTER_32 (arch/x86/entry/entry_32.S:840)
[ 195.727690][ T3470]
[ 195.727690][ T3470] other info that might help us debug this:
[ 195.727690][ T3470]
[ 195.727691][ T3470] Chain exists of:
[ 195.727691][ T3470] console_owner --> &p->pi_lock --> &rq->__lock
[ 195.727691][ T3470]
[ 195.727695][ T3470] Possible unsafe locking scenario:
[ 195.727695][ T3470]
[ 195.727695][ T3470] CPU0 CPU1
[ 195.727696][ T3470] ---- ----
[ 195.727696][ T3470] lock(&rq->__lock);
[ 195.727698][ T3470] lock(&p->pi_lock);
[ 195.727699][ T3470] lock(&rq->__lock);
[ 195.727701][ T3470] lock(console_owner);
[ 195.727702][ T3470]
[ 195.727702][ T3470] *** DEADLOCK ***
[ 195.727702][ T3470]
[ 195.727703][ T3470] 3 locks held by trinity-main/3470:


The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240401/202404012303.41984b81-lkp@xxxxxxxxx



--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki