Re: Re: [PATCH] kernel: Introduce a write lock/unlock wrapper for tasklist_lock

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 




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





[Index of Archives]     [Linux ARM Kernel]     [Linux ARM]     [Linux Omap]     [Fedora ARM]     [IETF Annouce]     [Bugtraq]     [Linux OMAP]     [Linux MIPS]     [eCos]     [Asterisk Internet PBX]     [Linux API]

  Powered by Linux