On 11/22/2016 06:06 AM, Felix Miata wrote: > I ask about this on account of boot delays reported in the following: > http://www.spinics.net/lists/linux-initramfs/msg04173.html > http://www.spinics.net/lists/linux-initramfs/msg04175.html > http://www.spinics.net/lists/linux-initramfs/msg04275.html > > I was looking at early portions of dmesg for anything resembling clues and > noticed that early microcode messages are not always reported for every core > present. Here are examples of 'dmesg | grep croco', all taken from machines with > two cpu cores. Notice that some refer to two different cores, while others make > no mention of the existence of more than one core: > > Linux big31 4.7.4-200.fc24.x86_64 #1 SMP Thu Sep 15 18:42:09 UTC 2016 x86_64 > x86_64 x86_64 GNU/Linux > [ 0.000000] microcode: microcode updated early to revision 0xa0b, date = > 2010-09-28 > [ 0.835393] microcode: CPU0 sig=0x1067a, pf=0x1, revision=0xa0b > [ 0.840090] microcode: CPU1 sig=0x1067a, pf=0x1, revision=0xa0b > > Linux big31 4.8.8-200.fc24.x86_64 #1 SMP Tue Nov 15 19:41:51 UTC 2016 x86_64 > x86_64 x86_64 GNU/Linux > [ 0.000000] microcode: microcode updated early to revision 0xa0b, date = > 2010-09-28 > [ 0.851345] microcode: sig=0x1067a, pf=0x1, revision=0xa0b > > Linux big31 4.8.0-0.rc8.git0.1.fc25.x86_64 #1 SMP Mon Sep 26 17:12:24 UTC 2016 > x86_64 x86_64 x86_64 GNU/Linux > [ 0.000000] microcode: microcode updated early to revision 0xa0b, date = > 2010-09-28 > [ 0.830256] microcode: sig=0x1067a, pf=0x1, revision=0xa0b > > Linux big31 4.8.8-300.fc25.x86_64 #1 SMP Tue Nov 15 18:10:06 UTC 2016 x86_64 > x86_64 x86_64 GNU/Linux > [ 0.000000] microcode: microcode updated early to revision 0xa0b, date = > 2010-09-28 > [ 0.601683] microcode: sig=0x1067a, pf=0x1, revision=0xa0b > > Linux big31 4.8.0-0.rc1.git3.1.fc26.x86_64 #1 SMP Thu Aug 11 01:00:58 UTC 2016 > x86_64 x86_64 x86_64 GNU/Linux > [ 0.000000] microcode: microcode updated early to revision 0xa0b, date = > 2010-09-28 > [ 1.157172] microcode: sig=0x1067a, pf=0x1, revision=0xa0b > > Linux big31 4.8.0-0.rc8.git1.1.fc26.x86_64 #1 SMP Wed Sep 28 23:21:40 UTC 2016 > x86_64 x86_64 x86_64 GNU/Linux > [ 0.000000] microcode: microcode updated early to revision 0xa0b, date = > 2010-09-28 > [ 0.965454] microcode: sig=0x1067a, pf=0x1, revision=0xa0b > > Linux big31 4.9.0-0.rc5.git4.1.fc26.x86_64 #1 SMP Fri Nov 18 17:52:58 UTC 2016 > x86_64 x86_64 x86_64 GNU/Linux > [ 0.000000] microcode: microcode updated early to revision 0xa0b, date = > 2010-09-28 > [ 1.146158] microcode: sig=0x1067a, pf=0x1, revision=0xa0b > > Linux big41 4.6.5-300.fc24.x86_64 #1 SMP Thu Jul 28 01:10:12 UTC 2016 x86_64 > x86_64 x86_64 GNU/Linux > [ 0.000000] microcode: microcode updated early to revision 0xa0b, date = > 2010-09-28 > [ 0.716008] microcode: CPU0 sig=0x1067a, pf=0x1, revision=0xa0b > [ 0.716801] microcode: CPU1 sig=0x1067a, pf=0x1, revision=0xa0b > > Linux big41 4.8.7-200.fc24.x86_64 #1 SMP Fri Nov 11 15:44:18 UTC 2016 x86_64 > x86_64 x86_64 GNU/Linux > [ 0.000000] microcode: microcode updated early to revision 0xa0b, date = > 2010-09-28 > [ 0.617156] microcode: sig=0x1067a, pf=0x1, revision=0xa0b > > Is it possible that the varying reference or not to CPUx is indicative of some > kind of installation mishandling lurking in microcode installation, possibly > causing microcode to be installed in only one of the two cores, which could be > at root of or affecting the boot initialization delay described in my > linux-initramfs posts? If so, should I file a bug? If yes, in which tracker, and > against which component (kernel? dracut? microcode_ctl? other?). The problem you have above is that you haven't organized the output above relative to the kernel versions you're booting. If you did that you would see that a change went in ~4.8. It is important to keep kernel versions in mind when looking at issues like this. This isn't a bug. The messaging was changed in the commit below to only output a single message instead of one for each cpu. Sorry for the cut-and-paste of this output. [prarit@prarit ~]$ cd git-kernel/linux [prarit@prarit linux]$ git grep revision | grep sig | grep pf arch/x86/kernel/cpu/microcode/intel.c:874: pr_info("sig=0x%x, pf=0x%x, revision=0x%x\n", [prarit@prarit linux]$ git wtf arch/x86/kernel/cpu/microcode/intel.c:874 354542d034ab2 (Andi Kleen 2016-06-09 06:41:41 -0700 874) pr_info("sig=0x%x, pf=0x%x, revision=0x%x\n", [prarit@prarit linux]$ git show 354542d034ab2 commit 354542d034ab2a849a284edcc661e76b753a57dc Author: Andi Kleen <ak@xxxxxxxxxxxxxxx> Date: Thu Jun 9 06:41:41 2016 -0700 x86/microcode/intel: Do not issue microcode updates messages on each CPU On large systems the microcode driver is very noisy, because it prints a line for each CPU. The lines are redundant because usually all CPUs are updated to the same microcode revision. All other subsystems have been patched previously to not print a line for each CPU. Only the microcode driver is left. Only print an microcode revision update when something changed. This results in typically only a single line being printed. Signed-off-by: Andi Kleen <ak@xxxxxxxxxxxxxxx> Signed-off-by: Borislav Petkov <bp@xxxxxxx> Cc: Andy Lutomirski <luto@xxxxxxxxxxxxxx> Cc: Borislav Petkov <bp@xxxxxxxxx> Cc: Brian Gerst <brgerst@xxxxxxxxx> Cc: Denys Vlasenko <dvlasenk@xxxxxxxxxx> Cc: H. Peter Anvin <hpa@xxxxxxxxx> Cc: Linus Torvalds <torvalds@xxxxxxxxxxxxxxxxxxxx> Cc: Peter Zijlstra <peterz@xxxxxxxxxxxxx> Cc: Thomas Gleixner <tglx@xxxxxxxxxxxxx> Cc: Tony Luck <tony.luck@xxxxxxxxx> Cc: elliott@xxxxxxx Cc: hmh@xxxxxxxxxx Link: http://lkml.kernel.org/r/20160609134141.5981-1-andi@xxxxxxxxxxxxxx Signed-off-by: Ingo Molnar <mingo@xxxxxxxxxx> diff --git a/arch/x86/kernel/cpu/microcode/intel.c b/arch/x86/kernel/cpu/microco index 8962d6acee39..6515c802346a 100644 --- a/arch/x86/kernel/cpu/microcode/intel.c +++ b/arch/x86/kernel/cpu/microcode/intel.c @@ -843,6 +843,7 @@ 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]; @@ -857,8 +858,13 @@ static int collect_cpu_info(int cpu_num, struct cpu_signatu } csig->rev = c->microcode; - pr_info("CPU%d sig=0x%x, pf=0x%x, revision=0x%x\n", - cpu_num, csig->sig, csig->pf, csig->rev); + + /* No extra locking on prev, races are harmless. */ + if (csig->sig != prev.sig || csig->pf != prev.pf || csig->rev != prev.re + pr_info("sig=0x%x, pf=0x%x, revision=0x%x\n", + csig->sig, csig->pf, csig->rev); + prev = *csig; + } return 0; } @@ -887,6 +893,7 @@ static int apply_microcode_intel(int cpu) struct ucode_cpu_info *uci; struct cpuinfo_x86 *c; unsigned int val[2]; + static int prev_rev; struct ucode_cpu_info *uci; struct cpuinfo_x86 *c; unsigned int val[2]; + static int prev_rev; /* We should bind the task to the CPU */ if (WARN_ON(raw_smp_processor_id() != cpu)) @@ -921,11 +928,14 @@ static int apply_microcode_intel(int cpu) return -1; } - pr_info("CPU%d updated to revision 0x%x, date = %04x-%02x-%02x\n", - cpu, val[1], - mc->hdr.date & 0xffff, - mc->hdr.date >> 24, - (mc->hdr.date >> 16) & 0xff); + if (val[1] != prev_rev) { + pr_info("updated to revision 0x%x, date = %04x-%02x-%02x\n", + val[1], + mc->hdr.date & 0xffff, + mc->hdr.date >> 24, + (mc->hdr.date >> 16) & 0xff); + prev_rev = val[1]; [prarit@prarit linux]$ git describe --contains 354542d034ab2 v4.8-rc1~88^2~5 [prarit@prarit linux]$ HTH, P. _______________________________________________ kernel mailing list -- kernel@xxxxxxxxxxxxxxxxxxxxxxx To unsubscribe send an email to kernel-leave@xxxxxxxxxxxxxxxxxxxxxxx
