Hello,
kernel test robot noticed "WARNING:inconsistent_lock_state" on:
commit: a785bd692830a550059b5a7d45c29a1411fa6f03 ("mm, slub: cheaper locking for percpu sheaves")
https://git.kernel.org/cgit/linux/kernel/git/vbabka/linux.git slub-percpu-sheaves-v1r3
in testcase: boot
compiler: gcc-12
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
(please refer to attached dmesg/kmsg for entire log/backtrace)
+-------------------------------------------------+------------+------------+
| | 07f91c64db | a785bd6928 |
+-------------------------------------------------+------------+------------+
| WARNING:inconsistent_lock_state | 0 | 6 |
| inconsistent{SOFTIRQ-ON-W}->{IN-SOFTIRQ-W}usage | 0 | 6 |
+-------------------------------------------------+------------+------------+
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/202409042217.1a3005e-oliver.sang@xxxxxxxxx
[ 1.603339][ C0] WARNING: inconsistent lock state
[ 1.603854][ C0] 6.10.0-rc1-00013-ga785bd692830 #1 Not tainted
[ 1.604494][ C0] --------------------------------
[ 1.605033][ C0] inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
[ 1.605514][ C0] swapper/1 [HC0[0]:SC1[1]:HE1:SE0] takes:
[ 1.605514][ C0] eaf78664 (&pcs->lock.llock){+.?.}-{2:2}, at: kfree (arch/x86/include/asm/preempt.h:79 mm/slub.c:5013 mm/slub.c:5411 mm/slub.c:5558)
[ 1.605514][ C0] {SOFTIRQ-ON-W} state was registered at:
[ 1.605514][ C0] __lock_acquire (kernel/locking/lockdep.c:5091)
[ 1.605514][ C0] lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5756 kernel/locking/lockdep.c:5719)
[ 1.605514][ C0] kmem_cache_alloc_node_noprof (include/linux/local_lock_internal.h:30 mm/slub.c:4449 mm/slub.c:4638 mm/slub.c:4696)
[ 1.605514][ C0] alloc_vmap_area (mm/vmalloc.c:1985)
[ 1.605514][ C0] __get_vm_area_node+0x8e/0xf8
[ 1.605514][ C0] get_vm_area_caller (mm/vmalloc.c:3155)
[ 1.605514][ C0] __ioremap_caller+0x1c0/0x2b4
[ 1.605514][ C0] ioremap_cache (arch/x86/mm/ioremap.c:438)
[ 1.605514][ C0] acpi_os_map_iomem (drivers/acpi/osl.c:296 drivers/acpi/osl.c:355)
[ 1.605514][ C0] acpi_os_map_memory (drivers/acpi/osl.c:379)
[ 1.605514][ C0] acpi_tb_acquire_table (drivers/acpi/acpica/tbdata.c:158)
[ 1.605514][ C0] acpi_tb_verify_temp_table (drivers/acpi/acpica/tbdata.c:320 drivers/acpi/acpica/tbdata.c:308 drivers/acpi/acpica/tbdata.c:400 drivers/acpi/acpica/tbdata.c:504)
[ 1.605514][ C0] acpi_reallocate_root_table (drivers/acpi/acpica/tbxface.c:182)
[ 1.605514][ C0] acpi_early_init (drivers/acpi/bus.c:1257)
[ 1.605514][ C0] start_kernel (init/main.c:1064)
[ 1.605514][ C0] i386_start_kernel (??:?)
[ 1.605514][ C0] startup_32_smp (arch/x86/kernel/head_32.S:292)
[ 1.605514][ C0] irq event stamp: 190
[ 1.605514][ C0] hardirqs last enabled at (190): rcu_process_callbacks (arch/x86/include/asm/irqflags.h:26 (discriminator 1) arch/x86/include/asm/irqflags.h:67 (discriminator 1) arch/x86/include/asm/irqflags.h:127 (discriminator 1) kernel/rcu/tiny.c:126 (discriminator 1))
[ 1.605514][ C0] hardirqs last disabled at (189): rcu_process_callbacks (kernel/rcu/tiny.c:115 (discriminator 1))
[ 1.605514][ C0] softirqs last enabled at (0): copy_process (kernel/fork.c:2336)
[ 1.605514][ C0] softirqs last disabled at (187): __do_softirq (kernel/softirq.c:589)
[ 1.605514][ C0]
[ 1.605514][ C0] other info that might help us debug this:
[ 1.605514][ C0] Possible unsafe locking scenario:
[ 1.605514][ C0]
[ 1.605514][ C0] CPU0
[ 1.605514][ C0] ----
[ 1.605514][ C0] lock(&pcs->lock.llock);
[ 1.605514][ C0] <Interrupt>
[ 1.605514][ C0] lock(&pcs->lock.llock);
[ 1.605514][ C0]
[ 1.605514][ C0] *** DEADLOCK ***
[ 1.605514][ C0]
[ 1.605514][ C0] 1 lock held by swapper/1:
[ 1.605514][ C0] #0: da2faddc (rcu_callback){....}-{0:0}, at: rcu_process_callbacks (kernel/rcu/tiny.c:130)
[ 1.605514][ C0]
[ 1.605514][ C0] stack backtrace:
[ 1.605514][ C0] CPU: 0 PID: 1 Comm: swapper Not tainted 6.10.0-rc1-00013-ga785bd692830 #1 d4ae42ad2625ef0b26b1eff40697d310314756c0
[ 1.605514][ C0] Call Trace:
[ 1.605514][ C0] <SOFTIRQ>
[ 1.605514][ C0] dump_stack_lvl (arch/x86/include/asm/irqflags.h:26 arch/x86/include/asm/irqflags.h:67 arch/x86/include/asm/irqflags.h:127 lib/dump_stack.c:117)
[ 1.605514][ C0] dump_stack (lib/dump_stack.c:124)
[ 1.605514][ C0] print_usage_bug+0x1ff/0x2d8
[ 1.605514][ C0] mark_lock_irq (kernel/locking/lockdep.c:3971 kernel/locking/lockdep.c:4013 kernel/locking/lockdep.c:4216)
[ 1.605514][ C0] mark_lock (kernel/locking/lockdep.c:4678)
[ 1.605514][ C0] mark_usage (kernel/locking/lockdep.c:4567)
[ 1.605514][ C0] __lock_acquire (kernel/locking/lockdep.c:5091)
[ 1.605514][ C0] lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5756 kernel/locking/lockdep.c:5719)
[ 1.605514][ C0] ? kfree (arch/x86/include/asm/preempt.h:79 mm/slub.c:5013 mm/slub.c:5411 mm/slub.c:5558)
[ 1.605514][ C0] ? lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5756 kernel/locking/lockdep.c:5719)
[ 1.605514][ C0] ? rcu_process_callbacks (kernel/rcu/tiny.c:130)
[ 1.605514][ C0] kfree (include/linux/local_lock_internal.h:30 mm/slub.c:5013 mm/slub.c:5411 mm/slub.c:5558)
[ 1.605514][ C0] ? kfree (arch/x86/include/asm/preempt.h:79 mm/slub.c:5013 mm/slub.c:5411 mm/slub.c:5558)
[ 1.605514][ C0] ? kvfree (mm/util.c:681)
[ 1.605514][ C0] kvfree (mm/util.c:681)
[ 1.605514][ C0] rcu_process_callbacks (include/linux/rcupdate.h:339 kernel/rcu/tiny.c:94 kernel/rcu/tiny.c:133)
[ 1.605514][ C0] handle_softirqs (arch/x86/include/asm/atomic.h:23 include/linux/atomic/atomic-arch-fallback.h:457 include/linux/jump_label.h:261 include/linux/jump_label.h:273 include/trace/events/irq.h:142 kernel/softirq.c:555)
[ 1.605514][ C0] ? __lock_text_end (kernel/softirq.c:587)
[ 1.605514][ C0] __do_softirq (kernel/softirq.c:589)
[ 1.605514][ C0] call_on_stack (arch/x86/kernel/irq_32.c:57)
[ 1.605514][ C0] </SOFTIRQ>
[ 1.605514][ C0] ? irq_exit_rcu (kernel/softirq.c:647)
[ 1.605514][ C0] ? sysvec_irq_work (arch/x86/kernel/irq_work.c:17)
[ 1.605514][ C0] ? handle_exception (arch/x86/entry/entry_32.S:1054)
[ 1.605514][ C0] ? __refill_cfs_bandwidth_runtime (kernel/sched/fair.c:5600)
[ 1.605514][ C0] ? exc_nmi (arch/x86/kernel/irq_work.c:17)
[ 1.605514][ C0] ? default_send_IPI_self (arch/x86/kernel/apic/ipi.c:248)
[ 1.605514][ C0] ? exc_nmi (arch/x86/kernel/irq_work.c:17)
[ 1.605514][ C0] ? default_send_IPI_self (arch/x86/kernel/apic/ipi.c:248)
[ 1.605514][ C0] ? arch_irq_work_raise (arch/x86/include/asm/apic.h:465 arch/x86/kernel/irq_work.c:32)
[ 1.605514][ C0] ? irq_work_queue (kernel/irq_work.c:85 kernel/irq_work.c:112 kernel/irq_work.c:124 kernel/irq_work.c:116)
[ 1.605514][ C0] ? call_rcu_tasks_generic (kernel/rcu/tasks.h:383)
[ 1.605514][ C0] ? call_rcu_tasks (kernel/rcu/tasks.h:1113)
[ 1.605514][ C0] ? __wait_rcu_gp (kernel/rcu/update.c:430)
[ 1.605514][ C0] ? console_unlock (kernel/printk/printk.c:3082)
[ 1.605514][ C0] ? rest_init (init/main.c:1459)
[ 1.605514][ C0] ? synchronize_rcu_tasks_generic (kernel/rcu/tasks.h:645)
[ 1.605514][ C0] ? call_rcu_tasks_generic (kernel/rcu/tasks.h:1111)
[ 1.605514][ C0] ? rcu_tasks_pregp_step (kernel/rcu/update.c:403)
[ 1.605514][ C0] ? rcu_init_tasks_generic (kernel/rcu/tasks.h:1112 kernel/rcu/tasks.h:2100 kernel/rcu/tasks.h:2207)
[ 1.605514][ C0] ? kernel_init_freeable (arch/x86/include/asm/atomic.h:23 include/linux/atomic/atomic-arch-fallback.h:457 include/linux/jump_label.h:261 include/linux/jump_label.h:273 include/trace/events/initcall.h:10 init/main.c:1371 init/main.c:1567)
[ 1.605514][ C0] ? kernel_init (init/main.c:1469)
[ 1.605514][ C0] ? ret_from_fork (arch/x86/kernel/process.c:153)
[ 1.605514][ C0] ? rest_init (init/main.c:1459)
[ 1.605514][ C0] ? ret_from_fork_asm (arch/x86/entry/entry_32.S:737)
[ 1.605514][ C0] ? entry_INT80_32 (arch/x86/entry/entry_32.S:944)
[ 1.605552][ T1] Running RCU Tasks Rude wait API self tests
[ 1.606243][ T1] Running RCU Tasks Trace wait API self tests
[ 1.606879][ T1] Performance Events: unsupported p6 CPU model 42 no PMU driver, software events only.
[ 1.609554][ T1] signal: max sigframe size: 1760
[ 1.610998][ T1] devtmpfs: initialized
[ 1.615226][ T1] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 1.616356][ T1] futex hash table entries: 256 (order: 1, 12288 bytes, linear)
The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240904/202409042217.1a3005e-oliver.sang@xxxxxxxxx
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
