[<prev] [next>] [day] [month] [year] [list]
Message-ID: <202209131658.a3549a75-yujie.liu@intel.com>
Date: Tue, 13 Sep 2022 17:13:01 +0800
From: kernel test robot <yujie.liu@...el.com>
To: Peter Zijlstra <peterz@...radead.org>
CC: <lkp@...ts.01.org>, <lkp@...el.com>,
Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
Tim Chen <tim.c.chen@...ux.intel.com>,
Borislav Petkov <bp@...e.de>,
Josh Poimboeuf <jpoimboe@...nel.org>,
"Thadeu Lima de Souza Cascardo" <cascardo@...onical.com>,
Ben Hutchings <ben@...adent.org.uk>,
<linux-kernel@...r.kernel.org>, <linux-pm@...r.kernel.org>
Subject: [intel_idle] 55bba093fd: WARNING:suspicious_RCU_usage
Greeting,
FYI, we noticed the following commit (built with gcc-11):
commit: 55bba093fd91a76971134e3a4e3576e536c08f5c ("intel_idle: Disable IBRS during long idle")
https://git.kernel.org/cgit/linux/kernel/git/stable/linux-stable-rc.git linux-5.10.y
in testcase: kernel-selftests
version: kernel-selftests-x86_64-700a8991-1_20220823
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: 8 threads Intel(R) Core(TM) i7-6700 CPU @ 3.40GHz (Skylake) with 16G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
[ 247.216403][ T0] =============================
[ 247.221176][ T0] WARNING: suspicious RCU usage
[ 247.225953][ T0] 5.10.132-00105-g55bba093fd91 #1 Tainted: G W
[ 247.233367][ T0] -----------------------------
[ 247.238143][ T0] arch/x86/include/asm/msr-trace.h:45 suspicious rcu_dereference_check() usage!
[ 247.247136][ T0]
[ 247.247136][ T0] other info that might help us debug this:
[ 247.247136][ T0]
[ 247.257350][ T0]
[ 247.257350][ T0] rcu_scheduler_active = 2, debug_locks = 1
[ 247.265377][ T0] RCU used illegally from extended quiescent state!
[ 247.271911][ T0] no locks held by swapper/6/0.
[ 247.276687][ T0]
[ 247.276687][ T0] stack backtrace:
[ 247.282521][ T0] CPU: 6 PID: 0 Comm: swapper/6 Tainted: G W 5.10.132-00105-g55b\
ba093fd91 #1
[ 247.292587][ T0] Hardware name: HP HP Z240 SFF Workstation/802E, BIOS N51 Ver. 01.63 10/05/201\
7
[ 247.301668][ T0] Call Trace:
[ 247.304880][ T0] dump_stack+0x9a/0xd0
[ 247.308968][ T0] trace_write_msr+0x12f/0x140
[ 247.313679][ T0] intel_idle_ibrs+0x11e/0x180
[ 247.318384][ T0] cpuidle_enter_state+0x174/0xbc0
[ 247.323465][ T0] cpuidle_enter+0x4a/0xc0
[ 247.327826][ T0] cpuidle_idle_call+0x280/0x400
[ 247.332703][ T0] ? arch_cpu_idle_exit+0xc0/0xc0
[ 247.337653][ T0] ? trace_hardirqs_off+0x53/0x140
[ 247.342709][ T0] ? do_idle+0xd0/0x1c0
[ 247.346785][ T0] ? rcu_nmi_exit+0x4c/0xc0
[ 247.351210][ T0] ? tsc_verify_tsc_adjust+0x61/0x240
[ 247.356563][ T0] do_idle+0xd7/0x1c0
[ 247.360478][ T0] cpu_startup_entry+0x19/0x40
[ 247.365180][ T0] start_secondary+0x247/0x340
[ 247.369878][ T0] ? set_cpu_sibling_map+0x24c0/0x24c0
[ 247.375319][ T0] secondary_startup_64_no_verify+0xc2/0xcb
[ 247.381266][ C6]
[ 247.381270][ C6] =============================
[ 247.381273][ C6] WARNING: suspicious RCU usage
[ 247.381277][ C6] 5.10.132-00105-g55bba093fd91 #1 Tainted: G W
[ 247.381280][ C6] -----------------------------
[ 247.381284][ C6] include/trace/events/lock.h:13 suspicious rcu_dereference_check() usage!
[ 247.381287][ C6]
[ 247.381290][ C6] other info that might help us debug this:
[ 247.381293][ C6]
[ 247.381296][ C6]
[ 247.381299][ C6] rcu_scheduler_active = 2, debug_locks = 1
[ 247.381303][ C6] RCU used illegally from extended quiescent state!
[ 247.381306][ C6] no locks held by swapper/6/0.
[ 247.381309][ C6]
[ 247.381312][ C6] stack backtrace:
[ 247.381316][ C6] CPU: 6 PID: 0 Comm: swapper/6 Tainted: G W 5.10.132-00105-g55b\
ba093fd91 #1
[ 247.381320][ C6] Hardware name: HP HP Z240 SFF Workstation/802E, BIOS N51 Ver. 01.63 10/05/201\
7
[ 247.381323][ C6] Call Trace:
[ 247.381326][ C6] dump_stack+0x9a/0xd0
[ 247.381329][ C6] lock_acquire.cold+0x3b/0x5d
[ 247.381333][ C6] ? rcu_read_unlock+0x80/0x80
[ 247.381337][ C6] ? ring_buffer_unlock_commit+0x13f/0x580
[ 247.381340][ C6] ? tracing_generic_entry_update+0x131/0x240
[ 247.381343][ C6] _raw_spin_lock+0x2c/0x40
[ 247.381346][ C6] ? vprintk_emit+0xba/0x2c0
[ 247.381350][ C6] vprintk_emit+0xba/0x2c0
[ 247.381353][ C6] ? trace_event_buffer_commit+0x17c/0xa40
[ 247.381356][ C6] printk+0xb2/0xe7
[ 247.381359][ C6] ? record_print_text.cold+0x11/0x11
[ 247.381363][ C6] ? trace_write_msr+0x2d/0x140
[ 247.381366][ C6] lockdep_rcu_suspicious+0x25/0x145
[ 247.381369][ C6] trace_write_msr+0x12f/0x140
[ 247.381372][ C6] intel_idle_ibrs+0x11e/0x180
[ 247.381376][ C6] cpuidle_enter_state+0x174/0xbc0
[ 247.381379][ C6] cpuidle_enter+0x4a/0xc0
[ 247.381381][ C6] cpuidle_idle_call+0x280/0x400
[ 247.381383][ C6] ? arch_cpu_idle_exit+0xc0/0xc0
[ 247.381385][ C6] ? trace_hardirqs_off+0x53/0x140
[ 247.381387][ C6] ? do_idle+0xd0/0x1c0
[ 247.381389][ C6] ? rcu_nmi_exit+0x4c/0xc0
[ 247.381391][ C6] ? tsc_verify_tsc_adjust+0x61/0x240
[ 247.381394][ C6] do_idle+0xd7/0x1c0
[ 247.381396][ C6] cpu_startup_entry+0x19/0x40
[ 247.381398][ C6] start_secondary+0x247/0x340
[ 247.381400][ C6] ? set_cpu_sibling_map+0x24c0/0x24c0
[ 247.381402][ C6] secondary_startup_64_no_verify+0xc2/0xcb
[ 247.381404][ C6]
[ 247.381406][ C6] =============================
[ 247.381408][ C6] WARNING: suspicious RCU usage
[ 247.381410][ C6] 5.10.132-00105-g55bba093fd91 #1 Tainted: G W
[ 247.381412][ C6] -----------------------------
[ 247.381414][ C6] include/trace/events/lock.h:58 suspicious rcu_dereference_check() usage!
[ 247.381416][ C6]
[ 247.381419][ C6] other info that might help us debug this:
[ 247.381420][ C6]
[ 247.381422][ C6]
[ 247.381425][ C6] rcu_scheduler_active = 2, debug_locks = 1
[ 247.381427][ C6] RCU used illegally from extended quiescent state!
[ 247.381429][ C6] 1 lock held by swapper/6/0:
[ 247.381431][ C6] #0: ffffffff8513b0d8 (logbuf_lock){-.-.}-{2:2}, at: vprintk_emit+0xba/0x2c0
[ 247.381444][ C6]
[ 247.381446][ C6] stack backtrace:
[ 247.381448][ C6] CPU: 6 PID: 0 Comm: swapper/6 Tainted: G W 5.10.132-00105-g55b\
ba093fd91 #1
[ 247.381450][ C6] Hardware name: HP HP Z240 SFF Workstation/802E, BIOS N51 Ver. 01.63 10/05/201\
7
[ 247.381452][ C6] Call Trace:
[ 247.381454][ C6] dump_stack+0x9a/0xd0
[ 247.381457][ C6] ? vprintk_emit+0xdc/0x2c0
[ 247.381459][ C6] lock_release.cold+0x1f/0x38
[ 247.381461][ C6] _raw_spin_unlock+0x17/0x40
[ 247.381463][ C6] vprintk_emit+0xdc/0x2c0
[ 247.381465][ C6] ? trace_event_buffer_commit+0x17c/0xa40
[ 247.381467][ C6] printk+0xb2/0xe7
[ 247.381470][ C6] ? record_print_text.cold+0x11/0x11
[ 247.381472][ C6] ? trace_write_msr+0x2d/0x140
[ 247.381474][ C6] lockdep_rcu_suspicious+0x25/0x145
[ 247.381476][ C6] trace_write_msr+0x12f/0x140
[ 247.381478][ C6] intel_idle_ibrs+0x11e/0x180
[ 247.381480][ C6] cpuidle_enter_state+0x174/0xbc0
[ 247.381482][ C6] cpuidle_enter+0x4a/0xc0
[ 247.381484][ C6] cpuidle_idle_call+0x280/0x400
[ 247.381486][ C6] ? arch_cpu_idle_exit+0xc0/0xc0
[ 247.381488][ C6] ? trace_hardirqs_off+0x53/0x140
[ 247.381490][ C6] ? do_idle+0xd0/0x1c0
[ 247.381492][ C6] ? rcu_nmi_exit+0x4c/0xc0
[ 247.381494][ C6] ? tsc_verify_tsc_adjust+0x61/0x240
[ 247.381496][ C6] do_idle+0xd7/0x1c0
[ 247.381499][ C6] cpu_startup_entry+0x19/0x40
[ 247.381502][ C6] start_secondary+0x247/0x340
[ 247.381505][ C6] ? set_cpu_sibling_map+0x24c0/0x24c0
[ 247.381508][ C6] secondary_startup_64_no_verify+0xc2/0xcb
[ 247.381511][ C6]
[ 247.381515][ C6] =============================
[ 247.381518][ C6] WARNING: suspicious RCU usage
[ 247.381521][ C6] 5.10.132-00105-g55bba093fd91 #1 Tainted: G W
[ 247.381525][ C6] -----------------------------
[ 247.381529][ C6] include/linux/rcupdate.h:652 rcu_read_lock() used illegally while idle!
[ 247.381532][ C6]
[ 247.381535][ C6] other info that might help us debug this:
[ 247.381538][ C6]
[ 247.381541][ C6]
[ 247.381544][ C6] rcu_scheduler_active = 2, debug_locks = 1
[ 247.381548][ C6] RCU used illegally from extended quiescent state!
[ 247.381551][ C6] 4 locks held by swapper/6/0:
[ 247.381554][ C6] #0: ffffffff8513b1a0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x1c3/0x2c\
0
[ 247.381566][ C6] #1: ffffffff84dbabc0 (console_owner){-.-.}-{0:0}, at: console_unlock+0x255/0\
x5c0
[ 247.381578][ C6] #2: ffffffff8572eaf8 (printing_lock){....}-{2:2}, at: vt_console_print+0x10d\
/0xcc0
[ 247.381590][ C6] #3: ffffffff85162000 (rcu_read_lock){....}-{1:2}, at: atomic_notifier_call_c\
hain+0x5/0x200
[ 247.381603][ C6]
[ 247.381605][ C6] stack backtrace:
[ 247.381607][ C6] CPU: 6 PID: 0 Comm: swapper/6 Tainted: G W 5.10.132-00105-g55b\
ba093fd91 #1
[ 247.381609][ C6] Hardware name: HP HP Z240 SFF Workstation/802E, BIOS N51 Ver. 01.63 10/05/201\
7
[ 247.381611][ C6] Call Trace:
[ 247.381613][ C6] dump_stack+0x9a/0xd0
[ 247.381615][ C6] atomic_notifier_call_chain+0x16d/0x200
[ 247.381618][ C6] vt_console_print+0x4d3/0xcc0
[ 247.381620][ C6] ? lf+0x2c0/0x2c0
[ 247.381622][ C6] call_console_drivers+0x1dd/0x340
[ 247.381624][ C6] console_unlock+0x2d3/0x5c0
[ 247.381626][ C6] ? console_unlock+0x255/0x5c0
[ 247.381628][ C6] ? devkmsg_read+0x680/0x680
[ 247.381630][ C6] ? __lock_release+0x102/0x540
[ 247.381632][ C6] ? __down_trylock_console_sem+0x68/0xc0
[ 247.381634][ C6] ? vprintk_emit+0x1c3/0x2c0
[ 247.381636][ C6] vprintk_emit+0x247/0x2c0
[ 247.381639][ C6] ? trace_event_buffer_commit+0x17c/0xa40
[ 247.381641][ C6] printk+0xb2/0xe7
[ 247.381643][ C6] ? record_print_text.cold+0x11/0x11
[ 247.381645][ C6] ? trace_write_msr+0x2d/0x140
[ 247.381647][ C6] lockdep_rcu_suspicious+0x25/0x145
[ 247.381649][ C6] trace_write_msr+0x12f/0x140
[ 247.381651][ C6] intel_idle_ibrs+0x11e/0x180
[ 247.381653][ C6] cpuidle_enter_state+0x174/0xbc0
[ 247.381655][ C6] cpuidle_enter+0x4a/0xc0
[ 247.381657][ C6] cpuidle_idle_call+0x280/0x400
[ 247.381659][ C6] ? arch_cpu_idle_exit+0xc0/0xc0
[ 247.381661][ C6] ? trace_hardirqs_off+0x53/0x140
[ 247.381663][ C6] ? do_idle+0xd0/0x1c0
[ 247.381665][ C6] ? rcu_nmi_exit+0x4c/0xc0
[ 247.381667][ C6] ? tsc_verify_tsc_adjust+0x61/0x240
[ 247.381669][ C6] do_idle+0xd7/0x1c0
[ 247.381671][ C6] cpu_startup_entry+0x19/0x40
[ 247.381673][ C6] start_secondary+0x247/0x340
[ 247.381676][ C6] ? set_cpu_sibling_map+0x24c0/0x24c0
[ 247.381678][ C6] secondary_startup_64_no_verify+0xc2/0xcb
[ 247.381680][ C6]
[ 247.381682][ C6] =============================
[ 247.381684][ C6] WARNING: suspicious RCU usage
[ 247.381686][ C6] 5.10.132-00105-g55bba093fd91 #1 Tainted: G W
[ 247.381688][ C6] -----------------------------
[ 247.381691][ C6] include/linux/rcupdate.h:701 rcu_read_unlock() used illegally while idle!
[ 247.381692][ C6]
[ 247.381695][ C6] other info that might help us debug this:
[ 247.381697][ C6]
[ 247.381698][ C6]
[ 247.381701][ C6] rcu_scheduler_active = 2, debug_locks = 1
[ 247.381703][ C6] RCU used illegally from extended quiescent state!
[ 247.381705][ C6] 4 locks held by swapper/6/0:
[ 247.381707][ C6] #0: ffffffff8513b1a0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x1c3/0x2c\
0
[ 247.381719][ C6] #1: ffffffff84dbabc0 (console_owner){-.-.}-{0:0}, at: console_unlock+0x255/0\
x5c0
[ 247.381731][ C6] #2: ffffffff8572eaf8 (printing_lock){....}-{2:2}, at: vt_console_print+0x10d\
/0xcc0
[ 247.381743][ C6] #3: ffffffff85162000 (rcu_read_lock){....}-{1:2}, at: atomic_notifier_call_c\
hain+0x5/0x200
[ 247.381755][ C6]
[ 247.381757][ C6] stack backtrace:
[ 247.381759][ C6] CPU: 6 PID: 0 Comm: swapper/6 Tainted: G W 5.10.132-00105-g55b\
ba093fd91 #1
[ 247.381761][ C6] Hardware name: HP HP Z240 SFF Workstation/802E, BIOS N51 Ver. 01.63 10/05/201\
7
[ 247.381763][ C6] Call Trace:
[ 247.381765][ C6] dump_stack+0x9a/0xd0
[ 247.381767][ C6] atomic_notifier_call_chain+0x1b7/0x200
[ 247.381769][ C6] vt_console_print+0x4d3/0xcc0
[ 247.381771][ C6] ? lf+0x2c0/0x2c0
[ 247.381774][ C6] call_console_drivers+0x1dd/0x340
[ 247.381776][ C6] console_unlock+0x2d3/0x5c0
[ 247.381778][ C6] ? console_unlock+0x255/0x5c0
[ 247.381780][ C6] ? devkmsg_read+0x680/0x680
[ 247.381782][ C6] ? __lock_release+0x102/0x540
[ 247.381784][ C6] ? __down_trylock_console_sem+0x68/0xc0
[ 247.381786][ C6] ? vprintk_emit+0x1c3/0x2c0
[ 247.381788][ C6] vprintk_emit+0x247/0x2c0
[ 247.381790][ C6] ? trace_event_buffer_commit+0x17c/0xa40
[ 247.381792][ C6] printk+0xb2/0xe7
[ 247.381794][ C6] ? record_print_text.cold+0x11/0x11
[ 247.381797][ C6] ? trace_write_msr+0x2d/0x140
[ 247.381799][ C6] lockdep_rcu_suspicious+0x25/0x145
[ 247.381801][ C6] trace_write_msr+0x12f/0x140
[ 247.381803][ C6] intel_idle_ibrs+0x11e/0x180
[ 247.381805][ C6] cpuidle_enter_state+0x174/0xbc0
[ 247.381807][ C6] cpuidle_enter+0x4a/0xc0
[ 247.381809][ C6] cpuidle_idle_call+0x280/0x400
[ 247.381811][ C6] ? arch_cpu_idle_exit+0xc0/0xc0
[ 247.381813][ C6] ? trace_hardirqs_off+0x53/0x140
[ 247.381815][ C6] ? do_idle+0xd0/0x1c0
[ 247.381817][ C6] ? rcu_nmi_exit+0x4c/0xc0
[ 247.381819][ C6] ? tsc_verify_tsc_adjust+0x61/0x240
[ 247.381821][ C6] do_idle+0xd7/0x1c0
[ 247.381824][ C6] cpu_startup_entry+0x19/0x40
[ 247.381826][ C6] start_secondary+0x247/0x340
[ 247.381828][ C6] ? set_cpu_sibling_map+0x24c0/0x24c0
[ 247.381830][ C6] secondary_startup_64_no_verify+0xc2/0xcb
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <yujie.liu@...el.com>
Link: https://lore.kernel.org/r/202209131658.a3549a75-yujie.liu@intel.com
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://01.org/lkp
View attachment "config-5.10.132-00105-g55bba093fd91" of type "text/plain" (157861 bytes)
View attachment "job-script" of type "text/plain" (6414 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (33104 bytes)
View attachment "kernel-selftests" of type "text/plain" (7921 bytes)
View attachment "job.yaml" of type "text/plain" (5096 bytes)
View attachment "reproduce" of type "text/plain" (250 bytes)
Powered by blists - more mailing lists