Messages in this thread | | | Date | Tue, 30 Apr 2024 14:44:13 +0800 | From | kernel test robot <> | Subject | [linus:master] [list_debug] b16c42c8fd: WARNING:at_lib/list_debug.c:#__list_add_valid_or_report |
| |
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@intel.com> | Closes: https://lore.kernel.org/oe-lkp/202404301424.203ace84-oliver.sang@intel.com
[ 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@intel.com
-- 0-DAY CI Kernel Test Service https://github.com/intel/lkp-tests/wiki
| |