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>] [thread-next>] [day] [month] [year] [list]
Message-ID: <202301192148.58ece903-oliver.sang@intel.com>
Date:   Thu, 19 Jan 2023 22:06:21 +0800
From:   kernel test robot <oliver.sang@...el.com>
To:     Peter Zijlstra <peterz@...radead.org>
CC:     <oe-lkp@...ts.linux.dev>, <lkp@...el.com>,
        <linux-kernel@...r.kernel.org>, <x86@...nel.org>,
        Ingo Molnar <mingo@...nel.org>,
        <linux-trace-kernel@...r.kernel.org>
Subject: [tip:sched/core] [tracing, hardirq]  9aedeaed6f:
 WARNING:suspicious_RCU_usage


Greeting,

FYI, we noticed WARNING:suspicious_RCU_usage due to commit (built with gcc-11):

commit: 9aedeaed6fc6fe8452b9b8225e95cc2b8631ff91 ("tracing, hardirq: No moar _rcuidle() tracing")
https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git sched/core

[test failed on linux-next/master f3381a7baf5ccbd091eb2c4fd2afd84266fcef24]

in testcase: kernel-selftests
version: kernel-selftests-x86_64-d4cf28ee-1_20230110
with following parameters:

	group: ftrace

test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel.
test-url: https://www.kernel.org/doc/Documentation/kselftest.txt


on test machine: 4 threads Intel(R) Xeon(R) CPU E3-1225 v5 @ 3.30GHz (Skylake) with 16G memory

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


If you fix the issue, kindly add following tag
| Reported-by: kernel test robot <oliver.sang@...el.com>
| Link: https://lore.kernel.org/oe-lkp/202301192148.58ece903-oliver.sang@intel.com


[  137.120136][    T0] WARNING: suspicious RCU usage
[  137.120151][    T0] 6.2.0-rc1-00074-g9aedeaed6fc6 #1 Not tainted
[  137.120168][    T0] -----------------------------
[  137.120182][    T0] include/trace/events/lock.h:24 suspicious rcu_dereference_check() usage!
[  137.120198][    T0]
[  137.120198][    T0] other info that might help us debug this:
[  137.120198][    T0]
[  137.120213][    T0]
[  137.120213][    T0] rcu_scheduler_active = 2, debug_locks = 1
[  137.120228][    T0] RCU used illegally from extended quiescent state!
[  137.120242][    T0] no locks held by swapper/0/0.
[  137.120256][    T0]
[  137.120256][    T0] stack backtrace:
[  137.120273][    T0] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 6.2.0-rc1-00074-g9aedeaed6fc6 #1
[  137.120289][    T0] Hardware name: HP HP Z238 Microtower Workstation/8183, BIOS N51 Ver. 01.63 10/05/2017
[  137.120306][    T0] Call Trace:
[  137.120333][    T0]  <TASK>
[ 137.120420][ T0] ? ftrace_regs_caller_end (arch/x86/kernel/ftrace_64.S:345) 
[ 137.120448][ T0] dump_stack_lvl (lib/dump_stack.c:107 (discriminator 4)) 
[ 137.120517][ T0] lock_acquire.cold (include/trace/events/lock.h:24 kernel/locking/lockdep.c:5639) 
[ 137.120620][ T0] ? rcu_read_unlock (include/linux/rcupdate.h:793 (discriminator 5)) 
[  137.120734][    T0] ------------[ cut here ]------------
[ 137.120749][ T0] WARNING: CPU: 0 PID: 0 at kernel/module/internal.h:115 __module_address (kernel/module/main.c:3100 kernel/module/main.c:3081) 
[  137.120778][    T0] Modules linked in: openvswitch nf_conncount nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 btrfs intel_rapl_msr blake2b_generic xor intel_rapl_common raid6_pq zstd_compress libcrc32c x86_pkg_temp_thermal intel_powerclamp coretemp sd_mod t10_pi kvm_intel crc64_rocksoft_generic crc64_rocksoft crc64 kvm sg irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel sha512_ssse3 mei_wdt ipmi_devintf wmi_bmof i915 rapl ipmi_msghandler intel_cstate drm_buddy intel_gtt drm_display_helper i2c_i801 ttm ahci intel_uncore drm_kms_helper libahci mei_me serio_raw i2c_smbus syscopyarea sysfillrect libata ie31200_edac mei sysimgblt intel_pch_thermal video wmi intel_pmc_core acpi_pad tpm_infineon binfmt_misc drm fuse ip_tables [last unloaded: ftrace_direct]
[  137.121813][    T0] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 6.2.0-rc1-00074-g9aedeaed6fc6 #1
[  137.121830][    T0] Hardware name: HP HP Z238 Microtower Workstation/8183, BIOS N51 Ver. 01.63 10/05/2017
[ 137.121848][ T0] RIP: 0010:__module_address (kernel/module/main.c:3100 kernel/module/main.c:3081) 
[ 137.121877][ T0] Code: 01 00 00 48 01 da 48 39 d5 0f 82 69 ff ff ff 0f 0b be ff ff ff ff 48 c7 c7 48 56 9f 84 e8 e6 88 3b 02 85 c0 0f 85 d1 fe ff ff <0f> 0b e9 ca fe ff ff 48 83 c4 08 31 c0 5b 5d c3 48 c7 c7 cc 15 29
All code
========
   0:	01 00                	add    %eax,(%rax)
   2:	00 48 01             	add    %cl,0x1(%rax)
   5:	da 48 39             	fimull 0x39(%rax)
   8:	d5                   	(bad)  
   9:	0f 82 69 ff ff ff    	jb     0xffffffffffffff78
   f:	0f 0b                	ud2    
  11:	be ff ff ff ff       	mov    $0xffffffff,%esi
  16:	48 c7 c7 48 56 9f 84 	mov    $0xffffffff849f5648,%rdi
  1d:	e8 e6 88 3b 02       	callq  0x23b8908
  22:	85 c0                	test   %eax,%eax
  24:	0f 85 d1 fe ff ff    	jne    0xfffffffffffffefb
  2a:*	0f 0b                	ud2    		<-- trapping instruction
  2c:	e9 ca fe ff ff       	jmpq   0xfffffffffffffefb
  31:	48 83 c4 08          	add    $0x8,%rsp
  35:	31 c0                	xor    %eax,%eax
  37:	5b                   	pop    %rbx
  38:	5d                   	pop    %rbp
  39:	c3                   	retq   
  3a:	48                   	rex.W
  3b:	c7                   	.byte 0xc7
  3c:	c7                   	(bad)  
  3d:	cc                   	int3   
  3e:	15                   	.byte 0x15
  3f:	29                   	.byte 0x29

Code starting with the faulting instruction
===========================================
   0:	0f 0b                	ud2    
   2:	e9 ca fe ff ff       	jmpq   0xfffffffffffffed1
   7:	48 83 c4 08          	add    $0x8,%rsp
   b:	31 c0                	xor    %eax,%eax
   d:	5b                   	pop    %rbx
   e:	5d                   	pop    %rbp
   f:	c3                   	retq   
  10:	48                   	rex.W
  11:	c7                   	.byte 0xc7
  12:	c7                   	(bad)  
  13:	cc                   	int3   
  14:	15                   	.byte 0x15
  15:	29                   	.byte 0x29
[  137.121895][    T0] RSP: 0018:ffffffff84406b40 EFLAGS: 00010046
[  137.121924][    T0] RAX: 0000000000000000 RBX: ffffffff84406d38 RCX: 0000000000000001
[  137.121939][    T0] RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffffffff849f5648
[  137.121954][    T0] RBP: ffffffffa03e6086 R08: 0000000000000000 R09: ffff88837f43f943
[  137.121969][    T0] R10: ffffed106fe87f28 R11: 0000000000000001 R12: ffffffff84406c30
[  137.121984][    T0] R13: ffffffff84406c10 R14: ffffffffa03e6086 R15: ffffffff84406c70
[  137.121999][    T0] FS:  0000000000000000(0000) GS:ffff88837f400000(0000) knlGS:0000000000000000
[  137.122014][    T0] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  137.122030][    T0] CR2: 0000000000451c00 CR3: 000000043ce2a003 CR4: 00000000003706f0
[  137.122046][    T0] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  137.122061][    T0] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[  137.122078][    T0] Call Trace:
[  137.122100][    T0]  <TASK>
[  137.122173][    T0]
[  137.122187][    T0] =============================
[  137.122202][    T0] WARNING: suspicious RCU usage
[  137.122217][    T0] 6.2.0-rc1-00074-g9aedeaed6fc6 #1 Not tainted
[  137.122231][    T0] -----------------------------
[  137.122245][    T0] include/linux/rcupdate.h:765 rcu_read_lock() used illegally while idle!
[  137.122260][    T0]
[  137.122260][    T0] other info that might help us debug this:
[  137.122260][    T0]
[  137.122275][    T0]
[  137.122275][    T0] rcu_scheduler_active = 2, debug_locks = 1
[  137.122290][    T0] RCU used illegally from extended quiescent state!
[  137.122304][    T0] 1 lock held by swapper/0/0:
[ 137.122319][ T0] #0: ffffffff84925b40 (rcu_read_lock){....}-{1:2}, at: __bpf_address_lookup (kernel/bpf/core.c:690) 
[  137.122417][    T0]
[  137.122417][    T0] stack backtrace:
[  137.122433][    T0] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 6.2.0-rc1-00074-g9aedeaed6fc6 #1
[  137.122449][    T0] Hardware name: HP HP Z238 Microtower Workstation/8183, BIOS N51 Ver. 01.63 10/05/2017
[  137.122466][    T0] Call Trace:
[  137.122491][    T0]  <TASK>
[ 137.122577][ T0] ? ftrace_regs_caller_end (arch/x86/kernel/ftrace_64.S:345) 
[ 137.122598][ T0] dump_stack_lvl (lib/dump_stack.c:107 (discriminator 4)) 
[  137.122630][    T0]  ? 0xffffffffa03e6085
[ 137.127567][ T0] __bpf_address_lookup (include/linux/rcupdate.h:765 kernel/bpf/core.c:694) 
[  137.127635][    T0]  ? 0xffffffffa03e6085
[ 137.127738][ T0] ? ftrace_regs_caller_end (arch/x86/kernel/ftrace_64.S:345) 
[ 137.127759][ T0] kallsyms_lookup_buildid (include/linux/filter.h:1145 kernel/kallsyms.c:434) 
[  137.127883][    T0]  ? 0xffffffffa03e6086
[ 137.127932][ T0] ? ftrace_regs_caller_end (arch/x86/kernel/ftrace_64.S:345) 
[ 137.127953][ T0] __sprint_symbol+0xaf/0x1c0 
[ 137.127981][ T0] ? prepare_ftrace_return (arch/x86/kernel/ftrace.c:653) 
[ 137.128042][ T0] ? kallsyms_lookup_buildid (kernel/kallsyms.c:517) 
[  137.128144][    T0]  ? 0xffffffffa03e6087
[ 137.128193][ T0] ? ftrace_return_to_handler (arch/x86/include/asm/current.h:41 kernel/trace/fgraph.c:257) 
[  137.128421][    T0]  ? 0xffffffffa03e6086
[ 137.128596][ T0] ? ftrace_regs_caller_end (arch/x86/kernel/ftrace_64.S:345) 
[ 137.128617][ T0] symbol_string (lib/vsprintf.c:994) 
[ 137.128664][ T0] ? rb_handle_head_page (kernel/trace/ring_buffer.c:1411 kernel/trace/ring_buffer.c:1444 kernel/trace/ring_buffer.c:2650) 
[ 137.128724][ T0] ? ip6_addr_string (lib/vsprintf.c:982) 
[ 137.128855][ T0] ? __rb_reserve_next (arch/x86/include/asm/atomic64_64.h:22 include/linux/atomic/atomic-long.h:29 include/linux/atomic/atomic-instrumented.h:1266 kernel/trace/ring_buffer.c:2952 kernel/trace/ring_buffer.c:3709) 
[ 137.129239][ T0] ? __rb_reserve_next (arch/x86/include/asm/atomic64_64.h:22 include/linux/atomic/atomic-long.h:29 include/linux/atomic/atomic-instrumented.h:1266 kernel/trace/ring_buffer.c:2952 kernel/trace/ring_buffer.c:3709) 
[ 137.129575][ T0] ? ring_buffer_lock_reserve (kernel/trace/ring_buffer.c:3781 kernel/trace/ring_buffer.c:3838) 
[ 137.129861][ T0] ? __rb_reserve_next (arch/x86/include/asm/atomic64_64.h:22 include/linux/atomic/atomic-long.h:29 include/linux/atomic/atomic-instrumented.h:1266 kernel/trace/ring_buffer.c:2952 kernel/trace/ring_buffer.c:3709) 
[ 137.130068][ T0] ? __rb_reserve_next (arch/x86/include/asm/atomic64_64.h:22 include/linux/atomic/atomic-long.h:29 include/linux/atomic/atomic-instrumented.h:1266 kernel/trace/ring_buffer.c:2952 kernel/trace/ring_buffer.c:3709) 
[ 137.130331][ T0] ? __rb_reserve_next (arch/x86/include/asm/atomic64_64.h:22 include/linux/atomic/atomic-long.h:29 include/linux/atomic/atomic-instrumented.h:1266 kernel/trace/ring_buffer.c:2952 kernel/trace/ring_buffer.c:3709) 
[ 137.130625][ T0] ? move_right (lib/vsprintf.c:617) 
[  137.130855][    T0]  ? 0xffffffffa03e6086
[ 137.130905][ T0] pointer (lib/vsprintf.c:2394) 
[ 137.131025][ T0] ? resource_string+0x1590/0x1590 
[ 137.131106][ T0] ? rb_commit (arch/x86/include/asm/atomic64_64.h:22 include/linux/atomic/atomic-long.h:29 include/linux/atomic/atomic-instrumented.h:1266 kernel/trace/ring_buffer.c:3181 kernel/trace/ring_buffer.c:3204) 
[ 137.131331][ T0] vsnprintf (lib/vsprintf.c:2802) 
[ 137.131521][ T0] ? pointer (lib/vsprintf.c:2727) 
[ 137.131617][ T0] ? __trace_graph_entry (kernel/trace/trace_functions_graph.c:113) 
[ 137.131820][ T0] vprintk_store (kernel/printk/printk.c:2241) 
[ 137.131956][ T0] ? ftrace_graph_stop (kernel/trace/fgraph.c:124) 
[ 137.132016][ T0] ? printk_sprint (kernel/printk/printk.c:2206) 
[ 137.132040][ T0] ? vprintk (kernel/printk/printk_safe.c:30) 
[ 137.132188][ T0] ? vprintk_store (kernel/printk/printk.c:2206) 
[ 137.132266][ T0] ? prepare_ftrace_return (arch/x86/kernel/ftrace.c:653) 
[  137.132384][    T0]  ? 0xffffffffa03e6086
[  137.132438][    T0]  ? 0xffffffffa03e6087
[  137.132853][    T0]  ? 0xffffffffa03e6086
[ 137.132884][ T0] ? ftrace_regs_caller_end (arch/x86/kernel/ftrace_64.S:345) 
[ 137.132905][ T0] vprintk (kernel/printk/printk_safe.c:44 kernel/printk/printk_safe.c:29) 
[ 137.132950][ T0] ? ftrace_regs_caller_end (arch/x86/kernel/ftrace_64.S:345) 
[ 137.132971][ T0] _printk (kernel/printk/printk.c:2373) 
[ 137.133034][ T0] ? record_print_text.cold (kernel/printk/printk.c:2373) 
[  137.133242][    T0]  ? 0xffffffffa03e6086
[  137.133368][    T0]  ? 0xffffffffa03e6086
[ 137.133471][ T0] ? ftrace_regs_caller_end (arch/x86/kernel/ftrace_64.S:345) 
[ 137.133492][ T0] show_trace_log_lvl (arch/x86/kernel/dumpstack.c:284) 
[  137.133561][    T0]  ? 0xffffffffa03e6086
[  137.133886][    T0]  ? 0xffffffffa03e6086
[ 137.133916][ T0] ? module_address_lookup (kernel/module/kallsyms.c:339) 
[ 137.134048][ T0] ? __module_address (kernel/module/main.c:3100 kernel/module/main.c:3081) 
[ 137.134107][ T0] ? ftrace_regs_caller_end (arch/x86/kernel/ftrace_64.S:345) 
[ 137.134128][ T0] __warn (kernel/panic.c:664) 
[ 137.134210][ T0] ? __module_address (kernel/module/main.c:3100 kernel/module/main.c:3081) 
[ 137.134287][ T0] ? ftrace_regs_caller_end (arch/x86/kernel/ftrace_64.S:345) 
[ 137.134308][ T0] report_bug (lib/bug.c:200) 
[ 137.134480][ T0] handle_bug (arch/x86/kernel/traps.c:324) 
[ 137.134525][ T0] exc_invalid_op (arch/x86/kernel/traps.c:345 (discriminator 1)) 
[ 137.134589][ T0] asm_exc_invalid_op (arch/x86/include/asm/idtentry.h:568) 
[ 137.134615][ T0] RIP: 0010:__module_address (kernel/module/main.c:3100 kernel/module/main.c:3081) 
[ 137.134622][ T0] Code: 01 00 00 48 01 da 48 39 d5 0f 82 69 ff ff ff 0f 0b be ff ff ff ff 48 c7 c7 48 56 9f 84 e8 e6 88 3b 02 85 c0 0f 85 d1 fe ff ff <0f> 0b e9 ca fe ff ff 48 83 c4 08 31 c0 5b 5d c3 48 c7 c7 cc 15 29
All code
========
   0:	01 00                	add    %eax,(%rax)
   2:	00 48 01             	add    %cl,0x1(%rax)
   5:	da 48 39             	fimull 0x39(%rax)
   8:	d5                   	(bad)  
   9:	0f 82 69 ff ff ff    	jb     0xffffffffffffff78
   f:	0f 0b                	ud2    
  11:	be ff ff ff ff       	mov    $0xffffffff,%esi
  16:	48 c7 c7 48 56 9f 84 	mov    $0xffffffff849f5648,%rdi
  1d:	e8 e6 88 3b 02       	callq  0x23b8908
  22:	85 c0                	test   %eax,%eax
  24:	0f 85 d1 fe ff ff    	jne    0xfffffffffffffefb
  2a:*	0f 0b                	ud2    		<-- trapping instruction
  2c:	e9 ca fe ff ff       	jmpq   0xfffffffffffffefb
  31:	48 83 c4 08          	add    $0x8,%rsp
  35:	31 c0                	xor    %eax,%eax
  37:	5b                   	pop    %rbx
  38:	5d                   	pop    %rbp
  39:	c3                   	retq   
  3a:	48                   	rex.W
  3b:	c7                   	.byte 0xc7
  3c:	c7                   	(bad)  
  3d:	cc                   	int3   
  3e:	15                   	.byte 0x15
  3f:	29                   	.byte 0x29

Code starting with the faulting instruction
===========================================
   0:	0f 0b                	ud2    
   2:	e9 ca fe ff ff       	jmpq   0xfffffffffffffed1
   7:	48 83 c4 08          	add    $0x8,%rsp
   b:	31 c0                	xor    %eax,%eax
   d:	5b                   	pop    %rbx
   e:	5d                   	pop    %rbp
   f:	c3                   	retq   
  10:	48                   	rex.W
  11:	c7                   	.byte 0xc7
  12:	c7                   	(bad)  
  13:	cc                   	int3   
  14:	15                   	.byte 0x15
  15:	29                   	.byte 0x29


To reproduce:

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        sudo bin/lkp install job.yaml           # job file is attached in this email
        bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
        sudo bin/lkp run generated-yaml-file

        # if come across any failure that blocks the test,
        # please remove ~/.lkp and /lkp dir to run from a clean state.



-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests



View attachment "config-6.2.0-rc1-00074-g9aedeaed6fc6" of type "text/plain" (169651 bytes)

View attachment "job-script" of type "text/plain" (6267 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (52160 bytes)

View attachment "kernel-selftests" of type "text/plain" (232694 bytes)

View attachment "job.yaml" of type "text/plain" (5111 bytes)

View attachment "reproduce" of type "text/plain" (242 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ