Hello,
kernel test robot noticed "WARNING:inconsistent_lock_state" on:
commit: 30ebdbe58c5be457f329cb81487df2a9eae886b4 ("Re: [PATCH] kernel: Introduce a write lock/unlock wrapper for tasklist_lock")
url: https://github.com/intel-lab-lkp/linux/commits/Matthew-Wilcox/Re-PATCH-kernel-Introduce-a-write-lock-unlock-wrapper-for-tasklist_lock/20231229-062352
base: https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git a51749ab34d9e5dec548fe38ede7e01e8bb26454
patch link: https://lore.kernel.org/all/ZY30k7OCtxrdR9oP@xxxxxxxxxxxxxxxxxxxx/
patch subject: Re: [PATCH] kernel: Introduce a write lock/unlock wrapper for tasklist_lock
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)
+-----------------------------------------------------+------------+------------+
| | a51749ab34 | 30ebdbe58c |
+-----------------------------------------------------+------------+------------+
| WARNING:inconsistent_lock_state | 0 | 10 |
| inconsistent{IN-HARDIRQ-R}->{HARDIRQ-ON-W}usage | 0 | 10 |
+-----------------------------------------------------+------------+------------+
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/202401031032.b7d5324-oliver.sang@xxxxxxxxx
[ 75.968288][ T141] WARNING: inconsistent lock state
[ 75.968550][ T141] 6.7.0-rc1-00006-g30ebdbe58c5b #1 Tainted: G W N
[ 75.968946][ T141] --------------------------------
[ 75.969208][ T141] inconsistent {IN-HARDIRQ-R} -> {HARDIRQ-ON-W} usage.
[ 75.969556][ T141] systemd-udevd/141 [HC0[0]:SC0[0]:HE0:SE1] takes:
[ 75.969889][ T141] ffff888113a9d958 (&ep->lock){+-.-}-{2:2}, at: ep_start_scan (include/linux/list.h:373 (discriminator 31) include/linux/list.h:571 (discriminator 31) fs/eventpoll.c:628 (discriminator 31))
[ 75.970329][ T141] {IN-HARDIRQ-R} state was registered at:
[ 75.970620][ T141] __lock_acquire (kernel/locking/lockdep.c:5090)
[ 75.970873][ T141] lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5755)
[ 75.971113][ T141] _raw_read_lock_irqsave (include/linux/rwlock_api_smp.h:161 kernel/locking/spinlock.c:236)
[ 75.971387][ T141] ep_poll_callback (include/net/busy_poll.h:37 fs/eventpoll.c:434 fs/eventpoll.c:1178)
[ 75.971638][ T141] __wake_up_common (kernel/sched/wait.c:90)
[ 75.971894][ T141] __wake_up (include/linux/spinlock.h:406 kernel/sched/wait.c:108 kernel/sched/wait.c:127)
[ 75.972110][ T141] irq_work_single (kernel/irq_work.c:222)
[ 75.972363][ T141] irq_work_run_list (kernel/irq_work.c:251 (discriminator 3))
[ 75.972619][ T141] update_process_times (kernel/time/timer.c:2074)
[ 75.972895][ T141] tick_nohz_highres_handler (kernel/time/tick-sched.c:257 kernel/time/tick-sched.c:1516)
[ 75.973188][ T141] __hrtimer_run_queues (kernel/time/hrtimer.c:1688 kernel/time/hrtimer.c:1752)
[ 75.973460][ T141] hrtimer_interrupt (kernel/time/hrtimer.c:1817)
[ 75.973719][ T141] __sysvec_apic_timer_interrupt (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 arch/x86/include/asm/trace/irq_vectors.h:41 arch/x86/kernel/apic/apic.c:1083)
[ 75.974031][ T141] sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1076 (discriminator 14))
[ 75.974324][ T141] asm_sysvec_apic_timer_interrupt (arch/x86/include/asm/idtentry.h:645)
[ 75.974636][ T141] kasan_check_range (mm/kasan/generic.c:186)
[ 75.974888][ T141] trace_preempt_off (arch/x86/include/asm/bitops.h:227 arch/x86/include/asm/bitops.h:239 include/asm-generic/bitops/instrumented-non-atomic.h:142 include/linux/cpumask.h:504 include/linux/cpumask.h:1104 include/trace/events/preemptirq.h:51 kernel/trace/trace_preemptirq.c:109)
[ 75.975144][ T141] _raw_spin_lock (include/linux/spinlock_api_smp.h:133 kernel/locking/spinlock.c:154)
[ 75.975383][ T141] __change_page_attr_set_clr (arch/x86/mm/pat/set_memory.c:1765)
[ 75.975683][ T141] change_page_attr_set_clr (arch/x86/mm/pat/set_memory.c:1849)
[ 75.975971][ T141] set_memory_ro (arch/x86/mm/pat/set_memory.c:2077)
[ 75.976206][ T141] module_enable_ro (kernel/module/strict_rwx.c:19 kernel/module/strict_rwx.c:47)
[ 75.976460][ T141] do_init_module (kernel/module/main.c:2572)
[ 75.976715][ T141] load_module (kernel/module/main.c:2981)
[ 75.976959][ T141] init_module_from_file (kernel/module/main.c:3148)
[ 75.977233][ T141] idempotent_init_module (kernel/module/main.c:3165)
[ 75.977514][ T141] __ia32_sys_finit_module (include/linux/file.h:45 kernel/module/main.c:3187 kernel/module/main.c:3169 kernel/module/main.c:3169)
[ 75.977796][ T141] __do_fast_syscall_32 (arch/x86/entry/common.c:164 arch/x86/entry/common.c:230)
[ 75.978060][ T141] do_fast_syscall_32 (arch/x86/entry/common.c:255)
[ 75.978315][ T141] entry_SYSENTER_compat_after_hwframe (arch/x86/entry/entry_64_compat.S:121)
[ 75.978644][ T141] irq event stamp: 226426
[ 75.978866][ T141] hardirqs last enabled at (226425): syscall_enter_from_user_mode_prepare (arch/x86/include/asm/irqflags.h:42 arch/x86/include/asm/irqflags.h:77 kernel/entry/common.c:122)
[ 75.979436][ T141] hardirqs last disabled at (226426): _raw_write_lock_irq (include/linux/rwlock_api_smp.h:193 kernel/locking/spinlock.c:326)
[ 75.979932][ T141] softirqs last enabled at (225118): __do_softirq (arch/x86/include/asm/preempt.h:27 kernel/softirq.c:400 kernel/softirq.c:582)
[ 75.980407][ T141] softirqs last disabled at (225113): irq_exit_rcu (kernel/softirq.c:427 kernel/softirq.c:632 kernel/softirq.c:644)
[ 75.980892][ T141]
[ 75.980892][ T141] other info that might help us debug this:
[ 75.981299][ T141] Possible unsafe locking scenario:
[ 75.981299][ T141]
[ 75.981676][ T141] CPU0
[ 75.981848][ T141] ----
[ 75.982019][ T141] lock(&ep->lock);
[ 75.982224][ T141] <Interrupt>
[ 75.982405][ T141] lock(&ep->lock);
[ 75.982617][ T141]
[ 75.982617][ T141] *** DEADLOCK ***
[ 75.982617][ T141]
[ 75.983028][ T141] 2 locks held by systemd-udevd/141:
[ 75.983299][ T141] #0: ffff888113a9d868 (&ep->mtx){+.+.}-{3:3}, at: ep_send_events (fs/eventpoll.c:1695)
[ 75.983758][ T141] #1: ffff888113a9d958 (&ep->lock){+-.-}-{2:2}, at: ep_start_scan (include/linux/list.h:373 (discriminator 31) include/linux/list.h:571 (discriminator 31) fs/eventpoll.c:628 (discriminator 31))
[ 75.984215][ T141]
[ 75.984215][ T141] stack backtrace:
[ 75.984517][ T141] CPU: 1 PID: 141 Comm: systemd-udevd Tainted: G W N 6.7.0-rc1-00006-g30ebdbe58c5b #1 f53d658e8913bcc30100423f807a4e1a31eca25f
[ 75.985251][ T141] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 75.985777][ T141] Call Trace:
[ 75.985950][ T141] <TASK>
[ 75.986105][ T141] dump_stack_lvl (lib/dump_stack.c:107)
[ 75.986344][ T141] mark_lock_irq (kernel/locking/lockdep.c:4216)
[ 75.986591][ T141] ? print_usage_bug (kernel/locking/lockdep.c:4206)
[ 75.986847][ T141] ? stack_trace_snprint (kernel/stacktrace.c:114)
[ 75.987115][ T141] ? save_trace (kernel/locking/lockdep.c:586)
[ 75.987350][ T141] mark_lock (kernel/locking/lockdep.c:4677)
[ 75.987576][ T141] ? mark_lock_irq (kernel/locking/lockdep.c:4638)
[ 75.987836][ T141] mark_held_locks (kernel/locking/lockdep.c:4273)
[ 75.988077][ T141] lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4291 kernel/locking/lockdep.c:4358)
[ 75.988377][ T141] trace_hardirqs_on (kernel/trace/trace_preemptirq.c:62)
[ 75.988631][ T141] queued_write_lock_slowpath (arch/x86/include/asm/irqflags.h:42 arch/x86/include/asm/irqflags.h:77 kernel/locking/qrwlock.c:87)
[ 75.988926][ T141] ? queued_read_lock_slowpath (kernel/locking/qrwlock.c:68)
[ 75.989226][ T141] ? lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5755)
[ 75.989473][ T141] ? lock_sync (kernel/locking/lockdep.c:5721)
[ 75.989706][ T141] do_raw_write_lock_irq (include/asm-generic/qrwlock.h:115 kernel/locking/spinlock_debug.c:217)
[ 75.989980][ T141] ? do_raw_write_lock (kernel/locking/spinlock_debug.c:215)
[ 75.990245][ T141] ? _raw_write_lock_irq (include/linux/rwlock_api_smp.h:195 kernel/locking/spinlock.c:326)
[ 75.990512][ T141] ep_start_scan (include/linux/list.h:373 (discriminator 31) include/linux/list.h:571 (discriminator 31) fs/eventpoll.c:628 (discriminator 31))
[ 75.990749][ T141] ep_send_events (fs/eventpoll.c:1701)
[ 75.990995][ T141] ? _copy_from_iter_nocache (lib/iov_iter.c:181)
[ 75.991296][ T141] ? __ia32_sys_epoll_create (fs/eventpoll.c:1678)
[ 75.991579][ T141] ? mark_lock (arch/x86/include/asm/bitops.h:227 (discriminator 3) arch/x86/include/asm/bitops.h:239 (discriminator 3) include/asm-generic/bitops/instrumented-non-atomic.h:142 (discriminator 3) kernel/locking/lockdep.c:228 (discriminator 3) kernel/locking/lockdep.c:4655 (discriminator 3))
[ 75.991813][ T141] ep_poll (fs/eventpoll.c:1865)
[ 75.992030][ T141] ? ep_send_events (fs/eventpoll.c:1827)
[ 75.992290][ T141] do_epoll_wait (fs/eventpoll.c:2318)
[ 75.992532][ T141] __ia32_sys_epoll_wait (fs/eventpoll.c:2325)
[ 75.992810][ T141] ? clockevents_program_event (kernel/time/clockevents.c:336 (discriminator 3))
[ 75.993112][ T141] ? do_epoll_wait (fs/eventpoll.c:2325)
[ 75.993366][ T141] __do_fast_syscall_32 (arch/x86/entry/common.c:164 arch/x86/entry/common.c:230)
[ 75.993627][ T141] do_fast_syscall_32 (arch/x86/entry/common.c:255)
[ 75.993879][ T141] entry_SYSENTER_compat_after_hwframe (arch/x86/entry/entry_64_compat.S:121)
[ 75.994204][ T141] RIP: 0023:0xf7f55579
[ 75.994417][ T141] Code: b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 00 00 00 00 00 00 00 00 00 00 00 00 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d b4 26 00 00 00 00 8d b4 26 00 00 00 00
All code
========
0: b8 01 10 06 03 mov $0x3061001,%eax
5: 74 b4 je 0xffffffffffffffbb
7: 01 10 add %edx,(%rax)
9: 07 (bad)
a: 03 74 b0 01 add 0x1(%rax,%rsi,4),%esi
e: 10 08 adc %cl,(%rax)
10: 03 74 d8 01 add 0x1(%rax,%rbx,8),%esi
...
20: 00 51 52 add %dl,0x52(%rcx)
23: 55 push %rbp
24:* 89 e5 mov %esp,%ebp <-- trapping instruction
26: 0f 34 sysenter
28: cd 80 int $0x80
2a: 5d pop %rbp
2b: 5a pop %rdx
2c: 59 pop %rcx
2d: c3 ret
2e: 90 nop
2f: 90 nop
30: 90 nop
31: 90 nop
32: 8d b4 26 00 00 00 00 lea 0x0(%rsi,%riz,1),%esi
39: 8d b4 26 00 00 00 00 lea 0x0(%rsi,%riz,1),%esi
Code starting with the faulting instruction
===========================================
0: 5d pop %rbp
1: 5a pop %rdx
2: 59 pop %rcx
3: c3 ret
4: 90 nop
5: 90 nop
6: 90 nop
7: 90 nop
8: 8d b4 26 00 00 00 00 lea 0x0(%rsi,%riz,1),%esi
f: 8d b4 26 00 00 00 00 lea 0x0(%rsi,%riz,1),%esi
The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240103/202401031032.b7d5324-oliver.sang@xxxxxxxxx
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
