[PATCH 2/2] x86/mce: Print each MCE record line in a single printk()

[Breno Leitao]

I am looking at a bunch of MCE recently, and I found __print_mce()
assembles two of its four output lines from pr_cont() pieces.

A continuation only appends to the previous record when the newest entry
in the printk ring buffer has the same caller_id, so a printk from
another CPU in between breaks the line in two.

The tail then loses both prefixes, because pr_cont() does not apply
pr_fmt() and HW_ERR is only in the format string of the first piece.
Injecting an error while the other CPUs write to /dev/kmsg:

  [    1.869789] mce: [Hardware Error]: TSC d00792e9
  [    1.869794] ADDR deadb000 MISC 8c00004000010090

Anything collecting on "mce:" drops that second line.

Concurrent printk is the norm for a fatal machine check. Every CPU in
the socket logs the same package-level bank at once, and with
firmware-first the GHES NMI handler prints in parallel, kernel message
becomes hard to read. For instance, on a recent 60-CPU Sapphire Rapids
host a fatal PCU error got as far as

  [57223.636282] [ T635877] mce: [Hardware Error]: RIP !INEXACT! 10:<ffffffff8235b5ff>

before GHES panicked. The "TSC ..." and "PROCESSOR ..." lines never
arrived, taking the timestamp, the socket and APIC ids and the running
microcode revision with them.

Build the variable part into a seq_buf and print it in one go, make the
full message either sent or not. Also, printing all messages with the
same HW_ERR suffix.

Needlessly to say, the output is unchanged, trailing space included, and
mce-inject gives identical records with and without this.

Signed-off-by: Breno Leitao <leitao@xxxxxxxxxx>
---
 arch/x86/kernel/cpu/mce/core.c | 44 ++++++++++++++++++++++++++++--------------
 1 file changed, 30 insertions(+), 14 deletions(-)

diff --git a/arch/x86/kernel/cpu/mce/core.c b/arch/x86/kernel/cpu/mce/core.c
index 4b457c6bed8f5..6e9516731fceb 100644
--- a/arch/x86/kernel/cpu/mce/core.c
+++ b/arch/x86/kernel/cpu/mce/core.c
@@ -46,6 +46,7 @@
 #include <linux/hardirq.h>
 #include <linux/kexec.h>
 #include <linux/vmcore_info.h>
+#include <linux/seq_buf.h>
 
 #include <asm/fred.h>
 #include <asm/cpu_device_id.h>
@@ -173,9 +174,14 @@ void mce_unregister_decode_chain(struct notifier_block *nb)
 }
 EXPORT_SYMBOL_GPL(mce_unregister_decode_chain);
 
+/* 8 fields, widest is "SYND1 " plus 16 hex digits and a space. */
+#define MCE_AUX_LEN	(8 * (sizeof("SYND1 ") + 16 + 1))
+
 static void __print_mce(struct mce_hw_err *err)
 {
 	struct mce *m = &err->m;
+	char aux[MCE_AUX_LEN];
+	struct seq_buf s;
 
 	pr_emerg(HW_ERR "CPU %d: Machine Check%s: %llx Bank %d: %016llx\n",
 		 m->extcpu,
@@ -183,35 +189,45 @@ static void __print_mce(struct mce_hw_err *err)
 		 m->mcgstatus, m->bank, m->status);
 
 	if (m->ip) {
-		pr_emerg(HW_ERR "RIP%s %02x:<%016llx> ",
-			 !(m->mcgstatus & MCG_STATUS_EIPV) ? " !INEXACT!" : "",
-			 m->cs, m->ip);
+		const char *inexact = "";
+
+		if (!(m->mcgstatus & MCG_STATUS_EIPV))
+			inexact = " !INEXACT!";
 
+		/* The space after '>' is part of the existing output. */
 		if (m->cs == __KERNEL_CS)
-			pr_cont("{%pS}", (void *)(unsigned long)m->ip);
-		pr_cont("\n");
+			pr_emerg(HW_ERR "RIP%s %02x:<%016llx> {%pS}\n",
+				 inexact, m->cs, m->ip,
+				 (void *)(unsigned long)m->ip);
+		else
+			pr_emerg(HW_ERR "RIP%s %02x:<%016llx> \n",
+				 inexact, m->cs, m->ip);
 	}
 
-	pr_emerg(HW_ERR "TSC %llx ", m->tsc);
+	seq_buf_init(&s, aux, sizeof(aux));
+
+	seq_buf_printf(&s, "TSC %llx ", m->tsc);
 	if (m->addr)
-		pr_cont("ADDR %llx ", m->addr);
+		seq_buf_printf(&s, "ADDR %llx ", m->addr);
 	if (m->misc)
-		pr_cont("MISC %llx ", m->misc);
+		seq_buf_printf(&s, "MISC %llx ", m->misc);
 	if (m->ppin)
-		pr_cont("PPIN %llx ", m->ppin);
+		seq_buf_printf(&s, "PPIN %llx ", m->ppin);
 
 	if (mce_flags.smca) {
 		if (m->synd)
-			pr_cont("SYND %llx ", m->synd);
+			seq_buf_printf(&s, "SYND %llx ", m->synd);
 		if (err->vendor.amd.synd1)
-			pr_cont("SYND1 %llx ", err->vendor.amd.synd1);
+			seq_buf_printf(&s, "SYND1 %llx ",
+				       err->vendor.amd.synd1);
 		if (err->vendor.amd.synd2)
-			pr_cont("SYND2 %llx ", err->vendor.amd.synd2);
+			seq_buf_printf(&s, "SYND2 %llx ",
+				       err->vendor.amd.synd2);
 		if (m->ipid)
-			pr_cont("IPID %llx ", m->ipid);
+			seq_buf_printf(&s, "IPID %llx ", m->ipid);
 	}
 
-	pr_cont("\n");
+	pr_emerg(HW_ERR "%s\n", seq_buf_str(&s));
 
 	/*
 	 * Note this output is parsed by external tools and old fields

-- 
2.53.0-Meta