Message-ID: <202407291014.2ead1e72-oliver.sang@intel.com>
Date: Mon, 29 Jul 2024 12:37:37 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Jann Horn <jannh@...gle.com>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>, <kasan-dev@...glegroups.com>,
	<linux-mm@...ck.org>, Andrey Ryabinin <ryabinin.a.a@...il.com>, "Alexander
 Potapenko" <glider@...gle.com>, Andrey Konovalov <andreyknvl@...il.com>,
	Dmitry Vyukov <dvyukov@...gle.com>, Vincenzo Frascino
	<vincenzo.frascino@....com>, Andrew Morton <akpm@...ux-foundation.org>,
	Christoph Lameter <cl@...ux.com>, Pekka Enberg <penberg@...nel.org>, "David
 Rientjes" <rientjes@...gle.com>, Joonsoo Kim <iamjoonsoo.kim@....com>,
	Vlastimil Babka <vbabka@...e.cz>, Roman Gushchin <roman.gushchin@...ux.dev>,
	Hyeonggon Yoo <42.hyeyoo@...il.com>, Marco Elver <elver@...gle.com>,
	<linux-kernel@...r.kernel.org>, Jann Horn <jannh@...gle.com>,
	<oliver.sang@...el.com>
Subject: Re: [PATCH v3 2/2] slub: Introduce CONFIG_SLUB_RCU_DEBUG



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@google.com/
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@...el.com>
| Closes: https://lore.kernel.org/oe-lkp/202407291014.2ead1e72-oliver.sang@intel.com


[  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@intel.com



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

Powered by blists - more mailing lists