There is a pr_info() to dump information about newly loaded microcode.
The code intends this pr_info() to be just once, but the check to ensure
is racy. Unfortunately this happens quite often in with this new change
resulting in multiple redundant prints on the console.

microcode_init()->schedule_on_each_cpu(setup_online_cpu)->collect_cpu_info

[   33.688639] microcode: sig=0x50654, pf=0x80, revision=0x2006e05
[   33.688659] microcode: sig=0x50654, pf=0x80, revision=0x2006e05
[   33.688660] microcode: sig=0x50654, pf=0x80, revision=0x2006e05

There is already a pr_info() in microcode/core.c as shown below:

microcode: Reload completed, microcode revision: 0x2b000041 -> 0x2b000070

The sig and pf aren't that useful to end user, they are available via
/proc/cpuinfo and this never changes between microcode loads.

Remove the redundant pr_info() and the racy single print checks. This
removes the race entirely, zap the duplicated pr_info() spam and
simplify the code.

Fixes: b6f86689d5b7 ("x86/microcode: Rip out the subsys interface gunk")
Reported-by: Tony Luck <tony.luck@intel.com>
Signed-off-by: Ashok Raj <ashok.raj@intel.com>
---
 arch/x86/kernel/cpu/microcode/intel.c | 8 --------
 1 file changed, 8 deletions(-)

diff --git a/arch/x86/kernel/cpu/microcode/intel.c b/arch/x86/kernel/cpu/microcode/intel.c
index c4a00fb97f61..4f93875f57b4 100644
--- a/arch/x86/kernel/cpu/microcode/intel.c
+++ b/arch/x86/kernel/cpu/microcode/intel.c
@@ -554,7 +554,6 @@ void reload_ucode_intel(void)
 
 static int collect_cpu_info(int cpu_num, struct cpu_signature *csig)
 {
-	static struct cpu_signature prev;
 	struct cpuinfo_x86 *c = &cpu_data(cpu_num);
 	unsigned int val[2];
 
@@ -570,13 +569,6 @@ static int collect_cpu_info(int cpu_num, struct cpu_signature *csig)
 
 	csig->rev = c->microcode;
 
-	/* No extra locking on prev, races are harmless. */
-	if (csig->sig != prev.sig || csig->pf != prev.pf || csig->rev != prev.rev) {
-		pr_info("sig=0x%x, pf=0x%x, revision=0x%x\n",
-			csig->sig, csig->pf, csig->rev);
-		prev = *csig;
-	}
-
 	return 0;
 }
 
-- 
2.34.1

Ashok!

On Tue, Nov 29 2022 at 13:08, Ashok Raj wrote:
> There is a pr_info() to dump information about newly loaded microcode.

There... Somewhere, right?

> The code intends this pr_info() to be just once, but the check to ensure
> is racy. Unfortunately this happens quite often in with this new change
> resulting in multiple redundant prints on the console.

-ENOPARSE. Can you try to express that in coherent sentences please?

> microcode_init()->schedule_on_each_cpu(setup_online_cpu)->collect_cpu_info
>
> [   33.688639] microcode: sig=0x50654, pf=0x80, revision=0x2006e05
> [   33.688659] microcode: sig=0x50654, pf=0x80, revision=0x2006e05
> [   33.688660] microcode: sig=0x50654, pf=0x80, revision=0x2006e05
>
> There is already a pr_info() in microcode/core.c as shown below:
>
> microcode: Reload completed, microcode revision: 0x2b000041 -> 0x2b000070

There are quite some pr_info()'s in microcode/core.c...

$function_name() prints the new and the previous microcode revision once
when the load has completed:

  microcode: Reload completed, microcode revision: 0x2b000041 -> 0x2b000070

Hmm?

> The sig and pf aren't that useful to end user, they are available via

The sig and pf ?!? Come on, you really can do better.

> /proc/cpuinfo and this never changes between microcode loads.
>
> Remove the redundant pr_info() and the racy single print checks. This
> removes the race entirely, zap the duplicated pr_info() spam and
> simplify the code.

The last sentence does not qualify as coherent either.

Other than that. Nice cleanup.

Thanks,

        tglx

On Fri, Dec 02, 2022 at 07:58:42PM +0100, Thomas Gleixner wrote:
> Ashok!
> 
> On Tue, Nov 29 2022 at 13:08, Ashok Raj wrote:
> > There is a pr_info() to dump information about newly loaded microcode.
> 
> There... Somewhere, right?

I'll make it clear, updated commit log below.

> 
> > The code intends this pr_info() to be just once, but the check to ensure
> > is racy. Unfortunately this happens quite often in with this new change
> > resulting in multiple redundant prints on the console.
> 
> -ENOPARSE. Can you try to express that in coherent sentences please?

:-)

> 
> > microcode_init()->schedule_on_each_cpu(setup_online_cpu)->collect_cpu_info
> >
> > [   33.688639] microcode: sig=0x50654, pf=0x80, revision=0x2006e05
> > [   33.688659] microcode: sig=0x50654, pf=0x80, revision=0x2006e05
> > [   33.688660] microcode: sig=0x50654, pf=0x80, revision=0x2006e05
> >
> > There is already a pr_info() in microcode/core.c as shown below:
> >
> > microcode: Reload completed, microcode revision: 0x2b000041 -> 0x2b000070
> 
> There are quite some pr_info()'s in microcode/core.c...
> 
> $function_name() prints the new and the previous microcode revision once
> when the load has completed:
> 
>   microcode: Reload completed, microcode revision: 0x2b000041 -> 0x2b000070
> 
> Hmm?

Agreed!

> 
> > The sig and pf aren't that useful to end user, they are available via
> 
> The sig and pf ?!? Come on, you really can do better.
> 
> > /proc/cpuinfo and this never changes between microcode loads.
> >
> > Remove the redundant pr_info() and the racy single print checks. This
> > removes the race entirely, zap the duplicated pr_info() spam and
> > simplify the code.
> 
> The last sentence does not qualify as coherent either.
> 
> Other than that. Nice cleanup.
> 
Thanks!. I'll try to get better at the commit log stuff 

Updated commit log looks like below. Hope it doesn't get a -ENOPARSE this
time. :-)

------------------------

This code in collect_cpu_info() simply checks with a static variable "prev",
but when multiple CPUs are running this in parallel it is racy and we notice
the pr_info() couple times. The original intend was to print this just once.

New sequence shown below:

microcode_init()->schedule_on_each_cpu(setup_online_cpu)->collect_cpu_info

Resulting multiple prints below:

[   33.688639] microcode: sig=0x50654, pf=0x80, revision=0x2006e05
[   33.688659] microcode: sig=0x50654, pf=0x80, revision=0x2006e05
[   33.688660] microcode: sig=0x50654, pf=0x80, revision=0x2006e05

There is already a pr_info() in microcode_reload_late() that shows both the
old and new revisions as shown below.

microcode: Reload completed, microcode revision: 0x2b000041 -> 0x2b000070

The CPU signature (sig=0x50654) and Processor Flags (pf=0x80) above aren't
that useful to end user, they are available via /proc/cpuinfo and this never
changes between microcode loads.

Remove the redundant pr_info().

On Fri, Dec 02, 2022 at 04:26:58PM -0800, Ashok Raj wrote:
> This code in collect_cpu_info() simply checks with a static variable "prev",
> but when multiple CPUs are running this in parallel it is racy and we notice

For the future:

Please use passive voice in your commit message: no "we" or "I", etc,
and describe your changes in imperative mood.

I've fixed it up and the rest now.

-- 
Regards/Gruss,
    Boris.

https://people.kernel.org/tglx/notes-about-netiquette