[<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