lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [day] [month] [year] [list]
Message-ID: <202404301424.203ace84-oliver.sang@intel.com>
Date: Tue, 30 Apr 2024 14:44:13 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Marco Elver <elver@...gle.com>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>, <linux-kernel@...r.kernel.org>,
	Kees Cook <keescook@...omium.org>, <linux-arm-kernel@...ts.infradead.org>,
	<kvmarm@...ts.linux.dev>, <oliver.sang@...el.com>
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@...el.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


Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ