Re: [PATCH] x86/tsc: Fix incorrect enabling of __use_tsc static_key

From: Pavel Tatashin <pasha.tatashin@soleen.com>
To: Waiman Long <longman@redhat.com>
Cc: Thomas Gleixner <tglx@linutronix.de>,
	Ingo Molnar <mingo@redhat.com>, Borislav Petkov <bp@alien8.de>,
	"H. Peter Anvin" <hpa@zytor.com>,
	x86@kernel.org, LKML <linux-kernel@vger.kernel.org>,
	Peter Zijlstra <peterz@infradead.org>,
	Juri Lelli <juri.lelli@redhat.com>,
	Pavel Tatashin <pasha.tatashin@oracle.com>,
	Dou Liyang <douly.fnst@cn.fujitsu.com>
Subject: Re: [PATCH] x86/tsc: Fix incorrect enabling of __use_tsc static_key
Date: Tue, 3 Dec 2019 15:54:53 -0500	[thread overview]
Message-ID: <CA+CK2bBvoM5bb0q2Ha7-+_6Pt5Qx_Vptx7zs2cEYUVuU=vWt7Q@mail.gmail.com> (raw)
In-Reply-To: <20191203204053.12956-1-longman@redhat.com>

On Tue, Dec 3, 2019 at 3:41 PM Waiman Long <longman@redhat.com> wrote:
>
> After applying the commit 4763f03d3d18 ("x86/tsc: Use TSC as sched clock
> early") and the commit 608008a45798 ("x86/tsc: Consolidate init code"),
> some x86 systems boot up with the following warnings:
>
> [    0.000000] tsc: Fast TSC calibration using PIT
> [    0.000000] tsc: Detected 2599.853 MHz processor
> [    0.000000] ------------[ cut here ]------------
> [    0.000000] static_key_enable_cpuslocked(): static key
> '__use_tsc+0x0/0x10' used before call to jump_label_init()
> [    0.000000] WARNING: CPU: 0 PID: 0 at kernel/jump_label.c:132 static_key_enable_cpuslocked+0x7b/0x80
> [    0.000000] Modules linked in:
> [    0.000000] CPU: 0 PID: 0 Comm: swapper Not tainted 4.18.0-154.el8.x86_64 #1
> [    0.000000] Hardware name: Dell Inc. PowerEdge R730/072T6D, BIOS 2.4.3 01/17/2017
> [    0.000000] RIP: 0010:static_key_enable_cpuslocked+0x7b/0x80
>   :
> [    0.000000] Call Trace:
> [    0.000000]  ? static_key_enable+0x16/0x20
> [    0.000000]  ? setup_arch+0x43f/0xf68
> [    0.000000]  ? printk+0x58/0x6f
> [    0.000000]  ? start_kernel+0x63/0x55b
> [    0.000000]  ? load_ucode_bsp+0xfb/0x12e
> [    0.000000]  ? secondary_startup_64+0xb7/0xc0
> [    0.000000] ---[ end trace fc2166797a50a8e0 ]---
>   :
> [ 1781.404905] INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.000 msecs
> [ 1781.409905] INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.000 msecs
> [ 1781.412905] INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.000 msecs
> [ 1781.578905] INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.000 msecs
> [ 1781.973905] INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.000 msecs
>   :
>
> In this particular case,
>
>   setup_arch() => tsc_early_init()
>                => tsc_enable_sched_clock()
>                => static_branch_enable()
>
> However, jump_label_init() is called after setup_arch(). Before the
> 2 commits listed above, static_branch_enable() was only called in
> tsc_init() which is after jump_label_init().

Hi Waiman,

jump_label_init() is called from setup_arch():
https://soleen.com/source/xref/linux/arch/x86/kernel/setup.c?r=11a98f37#911

 tsc_early_init() early init is also called from setup_arch() but later:
https://soleen.com/source/xref/linux/arch/x86/kernel/setup.c?r=11a98f37#1053

I think that the kernel where this problem is seen, might be missing
8990cac6e5ea7fa57607736019fe8dca961b998f x86/jump_label: Initialize
static branching early
Or some other patches from that series.

Thank you,
Pasha