Re: [PATCH v3 2/2] slub: Introduce CONFIG_SLUB_RCU_DEBUG

From: kernel test robot
Date: Mon Jul 29 2024 - 00:38:24 EST




Hello,

kernel test robot noticed "WARNING:possible_circular_locking_dependency_detected" on:

commit: 17049be0e1bcf0aa8809faf84f3ddd8529cd6c4c ("[PATCH v3 2/2] slub: Introduce CONFIG_SLUB_RCU_DEBUG")
url: https://github.com/intel-lab-lkp/linux/commits/Jann-Horn/kasan-catch-invalid-free-before-SLUB-reinitializes-the-object/20240726-045709
patch link: https://lore.kernel.org/all/20240725-kasan-tsbrcu-v3-2-51c92f8f1101@xxxxxxxxxx/
patch subject: [PATCH v3 2/2] slub: Introduce CONFIG_SLUB_RCU_DEBUG

in testcase: rcutorture
version:
with following parameters:

runtime: 300s
test: cpuhotplug
torture_type: tasks-rude



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

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



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/202407291014.2ead1e72-oliver.sang@xxxxxxxxx


[ 136.014616][ C1] WARNING: possible circular locking dependency detected
[ 136.014618][ C1] 6.10.0-00002-g17049be0e1bc #1 Not tainted
[ 136.014621][ C1] ------------------------------------------------------
[ 136.014622][ C1] swapper/1/0 is trying to acquire lock:
[ 136.014625][ C1] ffffffff868f04a0 (console_owner){-.-.}-{0:0}, at: console_flush_all (include/linux/rcupdate.h:? include/linux/srcu.h:232 kernel/printk/printk.c:286 kernel/printk/printk.c:2971)
[ 136.014668][ C1]
[ 136.014668][ C1] but task is already holding lock:
[ 136.014670][ C1] ffff888102658518 (&n->list_lock){-.-.}-{2:2}, at: free_to_partial_list (mm/slub.c:?)
[ 136.014685][ C1]
[ 136.014685][ C1] which lock already depends on the new lock.
[ 136.014685][ C1]
[ 136.014687][ C1]
[ 136.014687][ C1] the existing dependency chain (in reverse order) is:
[ 136.014688][ C1]
[ 136.014688][ C1] -> #4 (&n->list_lock){-.-.}-{2:2}:
[ 136.014694][ C1] _raw_spin_lock_irqsave (include/linux/spinlock_api_smp.h:110 kernel/locking/spinlock.c:162)
[ 136.014704][ C1] ___slab_alloc (mm/slub.c:2717)
[ 136.014709][ C1] kmem_cache_alloc_noprof (mm/slub.c:3797 mm/slub.c:3850 mm/slub.c:4030 mm/slub.c:4049)
[ 136.014712][ C1] debug_objects_fill_pool (lib/debugobjects.c:168)
[ 136.014717][ C1] debug_object_activate (lib/debugobjects.c:492 lib/debugobjects.c:706)
[ 136.014721][ C1] enqueue_hrtimer (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 include/trace/events/timer.h:222 kernel/time/hrtimer.c:479 kernel/time/hrtimer.c:1085)
[ 136.014726][ C1] hrtimer_start_range_ns (kernel/time/hrtimer.c:1302)
[ 136.014730][ C1] __enqueue_rt_entity (kernel/sched/rt.c:122)
[ 136.014735][ C1] enqueue_task_rt (kernel/sched/rt.c:1453)
[ 136.014738][ C1] __sched_setscheduler (kernel/sched/core.c:?)
[ 136.014742][ C1] sched_set_fifo (kernel/sched/core.c:8024)
[ 136.014745][ C1] drm_vblank_worker_init (drivers/gpu/drm/drm_vblank_work.c:?)
[ 136.014750][ C1] drm_vblank_init (drivers/gpu/drm/drm_vblank.c:555)
[ 136.014755][ C1] vkms_init (drivers/gpu/drm/vkms/vkms_drv.c:210)
[ 136.014759][ C1] do_one_initcall (init/main.c:1267)
[ 136.014762][ C1] do_initcall_level (init/main.c:1328)
[ 136.014766][ C1] do_initcalls (init/main.c:1342)
[ 136.014769][ C1] kernel_init_freeable (init/main.c:1582)
[ 136.014772][ C1] kernel_init (init/main.c:1469)
[ 136.014776][ C1] ret_from_fork (arch/x86/kernel/process.c:153)
[ 136.014783][ C1] ret_from_fork_asm (arch/x86/entry/entry_64.S:257)
[ 136.014786][ C1]
[ 136.014786][ C1] -> #3 (hrtimer_bases.lock){-.-.}-{2:2}:
[ 136.014792][ C1] _raw_spin_lock_irqsave (include/linux/spinlock_api_smp.h:110 kernel/locking/spinlock.c:162)
[ 136.014798][ C1] hrtimer_start_range_ns (kernel/time/hrtimer.c:?)
[ 136.014801][ C1] rpm_suspend (drivers/base/power/runtime.c:?)
[ 136.014807][ C1] rpm_resume (drivers/base/power/runtime.c:?)
[ 136.014810][ C1] pm_runtime_work (drivers/base/power/runtime.c:?)
[ 136.014814][ C1] process_scheduled_works (kernel/workqueue.c:?)
[ 136.014818][ C1] worker_thread (include/linux/list.h:373 kernel/workqueue.c:947 kernel/workqueue.c:3410)
[ 136.014820][ C1] kthread (kernel/kthread.c:391)
[ 136.014824][ C1] ret_from_fork (arch/x86/kernel/process.c:153)
[ 136.014826][ C1] ret_from_fork_asm (arch/x86/entry/entry_64.S:257)
[ 136.014832][ C1]
[ 136.014832][ C1] -> #2 (&dev->power.lock){-.-.}-{2:2}:
[ 136.014837][ C1] _raw_spin_lock_irqsave (include/linux/spinlock_api_smp.h:110 kernel/locking/spinlock.c:162)
[ 136.014840][ C1] __pm_runtime_resume (drivers/base/power/runtime.c:1171)
[ 136.014843][ C1] __uart_start (drivers/tty/serial/serial_core.c:149)
[ 136.014849][ C1] uart_write (include/linux/spinlock.h:406 include/linux/serial_core.h:669 drivers/tty/serial/serial_core.c:634)
[ 136.014851][ C1] n_tty_write (drivers/tty/n_tty.c:574 drivers/tty/n_tty.c:2389)
[ 136.014855][ C1] file_tty_write (drivers/tty/tty_io.c:1021)
[ 136.014859][ C1] do_iter_readv_writev (fs/read_write.c:742)
[ 136.014864][ C1] vfs_writev (fs/read_write.c:971)
[ 136.014867][ C1] do_writev (fs/read_write.c:1018)
[ 136.014870][ C1] __do_fast_syscall_32 (arch/x86/entry/common.c:?)
[ 136.014874][ C1] do_fast_syscall_32 (arch/x86/entry/common.c:411)
[ 136.014877][ C1] entry_SYSENTER_compat_after_hwframe (arch/x86/entry/entry_64_compat.S:127)
[ 136.014883][ C1]
[ 136.014883][ C1] -> #1 (&port_lock_key){-.-.}-{2:2}:
[ 136.014888][ C1] _raw_spin_lock_irqsave (include/linux/spinlock_api_smp.h:110 kernel/locking/spinlock.c:162)
[ 136.014891][ C1] serial8250_console_write (include/linux/serial_core.h:? drivers/tty/serial/8250/8250_port.c:3352)
[ 136.014894][ C1] console_flush_all (kernel/printk/printk.c:2917)
[ 136.014897][ C1] console_unlock (kernel/printk/printk.c:3048)
[ 136.014900][ C1] vprintk_emit (kernel/printk/printk.c:?)
[ 136.014903][ C1] _printk (kernel/printk/printk.c:2376)
[ 136.014907][ C1] register_console (kernel/printk/printk.c:3537)
[ 136.014910][ C1] univ8250_console_init (drivers/tty/serial/8250/8250_core.c:?)
[ 136.014914][ C1] console_init (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 include/trace/events/initcall.h:48 kernel/printk/printk.c:3728)
[ 136.014919][ C1] start_kernel (init/main.c:1039)
[ 136.014922][ C1] x86_64_start_reservations (??:?)
[ 136.014926][ C1] x86_64_start_kernel (??:?)
[ 136.014931][ C1] common_startup_64 (arch/x86/kernel/head_64.S:421)
[ 136.014935][ C1]
[ 136.014935][ C1] -> #0 (console_owner){-.-.}-{0:0}:
[ 136.014940][ C1] __lock_acquire (kernel/locking/lockdep.c:3135)
[ 136.014947][ C1] lock_acquire (kernel/locking/lockdep.c:5754)
[ 136.014951][ C1] console_flush_all (kernel/printk/printk.c:1873)
[ 136.014955][ C1] console_unlock (kernel/printk/printk.c:3048)
[ 136.014958][ C1] vprintk_emit (kernel/printk/printk.c:?)
[ 136.014961][ C1] _printk (kernel/printk/printk.c:2376)
[ 136.014964][ C1] slab_bug (mm/slub.c:1030)
[ 136.014968][ C1] slab_err (mm/slub.c:967 mm/slub.c:1131)
[ 136.014970][ C1] free_to_partial_list (mm/slub.c:3337)
[ 136.014974][ C1] slab_free_after_rcu_debug (mm/slub.c:? mm/slub.c:4528)
[ 136.014978][ C1] rcu_do_batch (include/linux/rcupdate.h:339 kernel/rcu/tree.c:2537)
[ 136.014984][ C1] rcu_core (kernel/rcu/tree.c:2811)
[ 136.014987][ C1] handle_softirqs (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 include/trace/events/irq.h:142 kernel/softirq.c:555)
[ 136.014991][ C1] __irq_exit_rcu (kernel/softirq.c:617 kernel/softirq.c:639)
[ 136.014994][ C1] irq_exit_rcu (kernel/softirq.c:651)
[ 136.014996][ C1] sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1043)
[ 136.015000][ C1] asm_sysvec_apic_timer_interrupt (arch/x86/include/asm/idtentry.h:702)
[ 136.015003][ C1] default_idle (arch/x86/include/asm/irqflags.h:37 arch/x86/include/asm/irqflags.h:72 arch/x86/kernel/process.c:743)
[ 136.015007][ C1] default_idle_call (include/linux/cpuidle.h:143 kernel/sched/idle.c:118)
[ 136.015010][ C1] do_idle (kernel/sched/idle.c:? kernel/sched/idle.c:332)
[ 136.015014][ C1] cpu_startup_entry (kernel/sched/idle.c:429)
[ 136.015017][ C1] start_secondary (arch/x86/kernel/smpboot.c:313)
[ 136.015021][ C1] common_startup_64 (arch/x86/kernel/head_64.S:421)
[ 136.015024][ C1]
[ 136.015024][ C1] other info that might help us debug this:
[ 136.015024][ C1]
[ 136.015025][ C1] Chain exists of:
[ 136.015025][ C1] console_owner --> hrtimer_bases.lock --> &n->list_lock
[ 136.015025][ C1]
[ 136.015031][ C1] Possible unsafe locking scenario:
[ 136.015031][ C1]
[ 136.015032][ C1] CPU0 CPU1
[ 136.015033][ C1] ---- ----
[ 136.015034][ C1] lock(&n->list_lock);
[ 136.015037][ C1] lock(hrtimer_bases.lock);
[ 136.015039][ C1] lock(&n->list_lock);
[ 136.015042][ C1] lock(console_owner);
[ 136.015044][ C1]
[ 136.015044][ C1] *** DEADLOCK ***
[ 136.015044][ C1]
[ 136.015045][ C1] 4 locks held by swapper/1/0:
[ 136.015048][ C1] #0: ffffffff868fb5a0 (rcu_callback){....}-{0:0}, at: rcu_do_batch (kernel/rcu/tree.c:?)
[ 136.015057][ C1] #1: ffff888102658518 (&n->list_lock){-.-.}-{2:2}, at: free_to_partial_list (mm/slub.c:?)
[ 136.015065][ C1] #2: ffffffff864ffd60 (console_lock){+.+.}-{0:0}, at: _printk (kernel/printk/printk.c:2376)
[ 136.015075][ C1] #3: ffffffff864ff950 (console_srcu){....}-{0:0}, at: console_flush_all (include/linux/rcupdate.h:? include/linux/srcu.h:232 kernel/printk/printk.c:286 kernel/printk/printk.c:2971)
[ 136.015086][ C1]
[ 136.015086][ C1] stack backtrace:
[ 136.015088][ C1] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 6.10.0-00002-g17049be0e1bc #1
[ 136.015093][ C1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 136.015099][ C1] Call Trace:
[ 136.015102][ C1] <IRQ>
[ 136.015104][ C1] dump_stack_lvl (lib/dump_stack.c:116)
[ 136.015109][ C1] check_noncircular (kernel/locking/lockdep.c:?)
[ 136.015115][ C1] __lock_acquire (kernel/locking/lockdep.c:3135)
[ 136.015126][ C1] lock_acquire (kernel/locking/lockdep.c:5754)
[ 136.015133][ C1] ? console_flush_all (include/linux/rcupdate.h:? include/linux/srcu.h:232 kernel/printk/printk.c:286 kernel/printk/printk.c:2971)
[ 136.015138][ C1] ? do_raw_spin_unlock (arch/x86/include/asm/atomic.h:23)
[ 136.015143][ C1] console_flush_all (kernel/printk/printk.c:1873)
[ 136.015147][ C1] ? console_flush_all (include/linux/rcupdate.h:? include/linux/srcu.h:232 kernel/printk/printk.c:286 kernel/printk/printk.c:2971)
[ 136.015152][ C1] ? console_flush_all (include/linux/rcupdate.h:? include/linux/srcu.h:232 kernel/printk/printk.c:286 kernel/printk/printk.c:2971)
[ 136.015158][ C1] console_unlock (kernel/printk/printk.c:3048)
[ 136.015163][ C1] vprintk_emit (kernel/printk/printk.c:?)
[ 136.015168][ C1] _printk (kernel/printk/printk.c:2376)
[ 136.015173][ C1] ? __asan_memcpy (mm/kasan/shadow.c:105)
[ 136.015178][ C1] slab_bug (mm/slub.c:1030)
[ 136.015184][ C1] slab_err (mm/slub.c:967 mm/slub.c:1131)
[ 136.015192][ C1] free_to_partial_list (mm/slub.c:3337)
[ 136.015197][ C1] ? slab_free_after_rcu_debug (mm/slub.c:4423 mm/slub.c:4528)
[ 136.015202][ C1] ? rcu_do_batch (include/linux/rcupdate.h:339 kernel/rcu/tree.c:2537)
[ 136.015206][ C1] slab_free_after_rcu_debug (mm/slub.c:? mm/slub.c:4528)
[ 136.015211][ C1] ? rcu_do_batch (kernel/rcu/tree.c:?)
[ 136.015214][ C1] ? __cfi_slab_free_after_rcu_debug (mm/slub.c:4508)


The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240729/202407291014.2ead1e72-oliver.sang@xxxxxxxxx



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