[linus:master] [list_debug] b16c42c8fd: WARNING:at_lib/list_debug.c:#__list_add_valid_or_report
From: kernel test robot
Date: Tue Apr 30 2024 - 02:44:49 EST
Hello,
we see a WARNING in this trinity test with a i386-randconfig.
we think it is not caused by this commit, but just changes the stats like below
by this commit:
7a0fd5e167850553 b16c42c8fde808b4f047d94f1f2
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
6:6 -83% :6 dmesg.EIP:__list_add_valid
:6 83% 6:6 dmesg.EIP:__list_add_valid_or_report
6:6 -83% :6 dmesg.WARNING:at_lib/list_debug.c:#__list_add_valid
:6 83% 6:6 dmesg.WARNING:at_lib/list_debug.c:#__list_add_valid_or_report
however, we failed to bisect "WARNING:at_lib/list_debug.c:#__list_add_valid"
to capture real fbc. so just report on this commit FYI what we observed in our
tests.
below are details.
kernel test robot noticed "WARNING:at_lib/list_debug.c:#__list_add_valid_or_report" on:
commit: b16c42c8fde808b4f047d94f1f2aeda93487670d ("list_debug: Introduce inline wrappers for debug checks")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
[test failed on linus/master a93289b830ce783955b22fbe5d1274a464c05acf]
[test failed on linux-next/master 5e4f84f18c4ee9b0ccdc19e39b7de41df21699dd]
in testcase: trinity
version: trinity-i386-abe9de86-1_20230429
with following parameters:
runtime: 300s
group: group-02
nr_groups: 5
compiler: gcc-13
test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 4G
(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/202404301424.203ace84-oliver.sang@xxxxxxxxx
[ 249.924267][ T3900] INFO: trying to register non-static key.
[ 249.924758][ T3900] The code is fine but needs lockdep annotation, or maybe
[ 249.925363][ T3900] you didn't initialize this object before use?
[ 249.925873][ T3900] turning off the locking correctness validator.
[ 249.926399][ T3900] CPU: 0 PID: 3900 Comm: trinity-c1 Tainted: G W E N 6.5.0-rc2-00011-gb16c42c8fde8 #1
[ 249.927271][ T3900] Call Trace:
[ 249.927544][ T3900] ? dump_stack_lvl (lib/dump_stack.c:107 (discriminator 1))
[ 249.927942][ T3900] ? dump_stack (lib/dump_stack.c:114)
[ 249.928292][ T3900] ? register_lock_class (kernel/locking/lockdep.c:985 kernel/locking/lockdep.c:1297)
[ 249.928726][ T3900] ? find_held_lock (kernel/locking/lockdep.c:5251 (discriminator 1))
[ 249.929118][ T3900] ? __lock_acquire (kernel/locking/lockdep.c:5022)
[ 249.929508][ T3900] ? lock_acquire (kernel/locking/lockdep.c:467 (discriminator 4) kernel/locking/lockdep.c:5763 (discriminator 4) kernel/locking/lockdep.c:5726 (discriminator 4))
[ 249.929906][ T3900] ? __wait_for_common (kernel/sched/completion.c:74 kernel/sched/completion.c:106)
[ 249.930325][ T3900] ? __schedule (kernel/sched/core.c:5384)
[ 249.930710][ T3900] ? _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
[ 249.931119][ T3900] ? __wait_for_common (kernel/sched/completion.c:74 kernel/sched/completion.c:106)
[ 249.931530][ T3900] ? __wait_for_common (kernel/sched/completion.c:74 kernel/sched/completion.c:106)
[ 249.931947][ T3900] ? usleep_range_state (kernel/time/timer.c:2129)
[ 249.932361][ T3900] ? wait_for_common (kernel/sched/completion.c:118)
[ 249.932753][ T3900] ? wait_for_completion_state (kernel/sched/completion.c:256)
[ 249.933216][ T3900] ? kmod_dup_request_exists_wait (kernel/module/dups.c:211)
[ 249.933720][ T3900] ? __request_module (kernel/module/kmod.c:168 (discriminator 1))
[ 249.934154][ T3900] ? __sock_create (net/socket.c:1517)
[ 249.934545][ T3900] ? sock_create (net/socket.c:1588)
[ 249.934918][ T3900] ? __sys_socket_create (net/socket.c:1625)
[ 249.935337][ T3900] ? __sys_socket (net/socket.c:1652)
[ 249.935712][ T3900] ? __do_sys_socketcall (net/socket.c:3015)
[ 249.936145][ T3900] ? __ia32_sys_socketcall (net/socket.c:2986)
[ 249.936576][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:112 (discriminator 1) arch/x86/entry/common.c:178 (discriminator 1))
[ 249.937004][ T3900] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4589)
[ 249.937542][ T3900] ? syscall_exit_to_user_mode (kernel/entry/common.c:300)
[ 249.937989][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.938409][ T3900] ? __lock_release+0x4c/0x118
[ 249.938839][ T3900] ? find_ge_pid (include/linux/rcupdate.h:777)
[ 249.939211][ T3900] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4589)
[ 249.939724][ T3900] ? syscall_exit_to_user_mode (kernel/entry/common.c:300)
[ 249.940165][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.940580][ T3900] ? syscall_exit_to_user_mode (kernel/entry/common.c:300)
[ 249.941029][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.941446][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.941847][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.942253][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.942646][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.943040][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.943459][ T3900] ? irqentry_exit_to_user_mode (kernel/entry/common.c:313)
[ 249.943926][ T3900] ? irqentry_exit (kernel/entry/common.c:413)
[ 249.944307][ T3900] ? do_fast_syscall_32 (arch/x86/entry/common.c:203 (discriminator 1))
[ 249.944708][ T3900] ? do_SYSENTER_32 (arch/x86/entry/common.c:247)
[ 249.945082][ T3900] ? entry_SYSENTER_32 (arch/x86/entry/entry_32.S:840)
[ 249.945502][ T3900] ------------[ cut here ]------------
[ 249.945937][ T3900] list_add corruption. prev is NULL.
[ 249.946397][ T3900] WARNING: CPU: 0 PID: 3900 at lib/list_debug.c:23 __list_add_valid_or_report (lib/list_debug.c:23 (discriminator 1))
[ 249.947178][ T3900] Modules linked in: can_isotp ieee802154_socket ieee802154 af_key mpls_router smc rose qrtr kcm nfc rfkill phonet rxrpc cn ax25 crc32_pclmul crc32c_intel serio_raw floppy rtc_cmos fuse configfs autofs4 ofpart(E) cmdlinepart(E)
[ 249.948959][ T3900] CPU: 0 PID: 3900 Comm: trinity-c1 Tainted: G W E N 6.5.0-rc2-00011-gb16c42c8fde8 #1
[ 249.949823][ T3900] EIP: __list_add_valid_or_report (lib/list_debug.c:23 (discriminator 1))
[ 249.950334][ T3900] Code: e8 9b 14 56 00 83 c4 34 5b 5e 5f 5d 31 d2 31 c9 c3 55 89 e5 56 53 85 d2 74 06 85 c9 75 10 eb 1b 68 17 a7 11 42 e8 ad 8a c6 ff <0f> 0b eb 19 89 c3 89 d0 8b 51 04 39 c2 74 13 eb 19 68 4c a7 11 42
All code
========
0: e8 9b 14 56 00 call 0x5614a0
5: 83 c4 34 add $0x34,%esp
8: 5b pop %rbx
9: 5e pop %rsi
a: 5f pop %rdi
b: 5d pop %rbp
c: 31 d2 xor %edx,%edx
e: 31 c9 xor %ecx,%ecx
10: c3 ret
11: 55 push %rbp
12: 89 e5 mov %esp,%ebp
14: 56 push %rsi
15: 53 push %rbx
16: 85 d2 test %edx,%edx
18: 74 06 je 0x20
1a: 85 c9 test %ecx,%ecx
1c: 75 10 jne 0x2e
1e: eb 1b jmp 0x3b
20: 68 17 a7 11 42 push $0x4211a717
25: e8 ad 8a c6 ff call 0xffffffffffc68ad7
2a:* 0f 0b ud2 <-- trapping instruction
2c: eb 19 jmp 0x47
2e: 89 c3 mov %eax,%ebx
30: 89 d0 mov %edx,%eax
32: 8b 51 04 mov 0x4(%rcx),%edx
35: 39 c2 cmp %eax,%edx
37: 74 13 je 0x4c
39: eb 19 jmp 0x54
3b: 68 4c a7 11 42 push $0x4211a74c
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: eb 19 jmp 0x1d
4: 89 c3 mov %eax,%ebx
6: 89 d0 mov %edx,%eax
8: 8b 51 04 mov 0x4(%rcx),%edx
b: 39 c2 cmp %eax,%edx
d: 74 13 je 0x22
f: eb 19 jmp 0x2a
11: 68 4c a7 11 42 push $0x4211a74c
[ 249.951968][ T3900] EAX: 00000000 EBX: 5538fd44 ECX: 00000000 EDX: 00000000
[ 249.952569][ T3900] ESI: 70b1ae6c EDI: 00000000 EBP: 5538fd14 ESP: 5538fd08
[ 249.953513][ T3900] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068 EFLAGS: 00010046
[ 249.954136][ T3900] CR0: 80050033 CR2: 00000020 CR3: 034051c0 CR4: 000406b0
[ 249.954715][ T3900] DR0: 33ceb000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 249.955298][ T3900] DR6: ffff0ff0 DR7: 00070602
[ 249.955687][ T3900] Call Trace:
[ 249.955972][ T3900] ? show_regs (arch/x86/kernel/dumpstack.c:479 arch/x86/kernel/dumpstack.c:465)
[ 249.956325][ T3900] ? __list_add_valid_or_report (lib/list_debug.c:23 (discriminator 1))
[ 249.956799][ T3900] ? __warn (kernel/panic.c:673)
[ 249.957130][ T3900] ? report_bug (lib/bug.c:201 lib/bug.c:219)
[ 249.957451][ T3900] ? up (kernel/locking/semaphore.c:193)
[ 249.957706][ T3900] ? __list_add_valid_or_report (lib/list_debug.c:23 (discriminator 1))
[ 249.958098][ T3900] ? exc_overflow (arch/x86/kernel/traps.c:337)
[ 249.958418][ T3900] ? handle_bug (arch/x86/kernel/traps.c:324)
[ 249.958740][ T3900] ? exc_invalid_op (arch/x86/kernel/traps.c:345 (discriminator 1))
[ 249.959105][ T3900] ? handle_exception (arch/x86/entry/entry_32.S:1049)
[ 249.959495][ T3900] ? print_usage_bug (kernel/locking/lockdep.c:4017)
[ 249.959953][ T3900] ? emit_ia32_lsh_i64 (arch/x86/net/bpf_jit_comp32.c:899 (discriminator 1))
[ 249.960389][ T3900] ? exc_overflow (arch/x86/kernel/traps.c:337)
[ 249.960768][ T3900] ? __list_add_valid_or_report (lib/list_debug.c:23 (discriminator 1))
[ 249.961248][ T3900] ? emit_ia32_lsh_i64 (arch/x86/net/bpf_jit_comp32.c:899 (discriminator 1))
[ 249.961661][ T3900] ? exc_overflow (arch/x86/kernel/traps.c:337)
[ 249.962034][ T3900] ? __list_add_valid_or_report (lib/list_debug.c:23 (discriminator 1))
[ 249.962501][ T3900] ? list_add_tail (include/linux/list.h:98 (discriminator 1) include/linux/list.h:131 (discriminator 1))
[ 249.962879][ T3900] ? __prepare_to_swait (kernel/sched/swait.c:89)
[ 249.963291][ T3900] ? __wait_for_common (kernel/sched/completion.c:83 (discriminator 1) kernel/sched/completion.c:106 (discriminator 1))
[ 249.963688][ T3900] ? usleep_range_state (kernel/time/timer.c:2129)
[ 249.964083][ T3900] ? wait_for_common (kernel/sched/completion.c:118)
[ 249.964467][ T3900] ? wait_for_completion_state (kernel/sched/completion.c:256)
[ 249.964906][ T3900] ? kmod_dup_request_exists_wait (kernel/module/dups.c:211)
[ 249.965386][ T3900] ? __request_module (kernel/module/kmod.c:168 (discriminator 1))
[ 249.965775][ T3900] ? __sock_create (net/socket.c:1517)
[ 249.966144][ T3900] ? sock_create (net/socket.c:1588)
[ 249.966506][ T3900] ? __sys_socket_create (net/socket.c:1625)
[ 249.966932][ T3900] ? __sys_socket (net/socket.c:1652)
[ 249.967299][ T3900] ? __do_sys_socketcall (net/socket.c:3015)
[ 249.967721][ T3900] ? __ia32_sys_socketcall (net/socket.c:2986)
[ 249.968158][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:112 (discriminator 1) arch/x86/entry/common.c:178 (discriminator 1))
[ 249.968590][ T3900] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4589)
[ 249.969155][ T3900] ? syscall_exit_to_user_mode (kernel/entry/common.c:300)
[ 249.969591][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.969993][ T3900] ? __lock_release+0x4c/0x118
[ 249.970421][ T3900] ? find_ge_pid (include/linux/rcupdate.h:777)
[ 249.970787][ T3900] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4589)
[ 249.971314][ T3900] ? syscall_exit_to_user_mode (kernel/entry/common.c:300)
[ 249.971775][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.972201][ T3900] ? syscall_exit_to_user_mode (kernel/entry/common.c:300)
[ 249.972648][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.973052][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.973473][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.973922][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.974364][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.974805][ T3900] ? __do_fast_syscall_32 (arch/x86/entry/common.c:182)
[ 249.975235][ T3900] ? irqentry_exit_to_user_mode (kernel/entry/common.c:313)
[ 249.975698][ T3900] ? irqentry_exit (kernel/entry/common.c:413)
[ 249.976070][ T3900] ? do_fast_syscall_32 (arch/x86/entry/common.c:203 (discriminator 1))
[ 249.976473][ T3900] ? do_SYSENTER_32 (arch/x86/entry/common.c:247)
[ 249.976838][ T3900] ? entry_SYSENTER_32 (arch/x86/entry/entry_32.S:840)
[ 249.977243][ T3900] irq event stamp: 187890
[ 249.977579][ T3900] hardirqs last enabled at (187889): raw_spin_rq_unlock_irq (arch/x86/include/asm/irqflags.h:42 arch/x86/include/asm/irqflags.h:77 kernel/sched/sched.h:1378)
[ 249.978296][ T3900] hardirqs last disabled at (187890): _raw_spin_lock_irq (arch/x86/include/asm/preempt.h:80 (discriminator 10) include/linux/spinlock_api_smp.h:118 (discriminator 10) kernel/locking/spinlock.c:170 (discriminator 10))
[ 249.979000][ T3900] softirqs last enabled at (114732): __do_softirq (arch/x86/include/asm/preempt.h:27 (discriminator 1) kernel/softirq.c:400 (discriminator 1) kernel/softirq.c:582 (discriminator 1))
[ 249.979690][ T3900] softirqs last disabled at (114723): do_softirq_own_stack (arch/x86/kernel/irq_32.c:57 arch/x86/kernel/irq_32.c:147)
[ 249.980435][ T3900] ---[ end trace 0000000000000000 ]---
[ 250.072040][ T3802] module: module-autoload: duplicate request for module net-pf-27
[ 250.082073][ T3654] module: module-autoload: duplicate request for module net-pf-32
The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240430/202404301424.203ace84-oliver.sang@xxxxxxxxx
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki