Skip to contentSkip to conversation

x86/MSR: Improve unhandled MSR access error message

PATCH In review Borislav Petkov 3 participants 8 messages Jun 24, 2016 – Jun 27, 2016

Subsystems (4)
lore
Share & tools
lore

Borislav Petkov

author maintainer
#0 lore raw

cover x86/MSR: Improve unhandled MSR access error message

From: Borislav Petkov <[email protected]>

Hi all,

here's a simple patchset improving the error message we're dumping when an unchecked MSR is being done. Patch 3 has an example which explains the improvement in detail.

Thanks.

Andy Lutomirski (1):
x86/dumpstack: Honor supplied @regs arg

Borislav Petkov (2):
printk: Make the printk*once() variants return a value x86/dumpstack: Add show_stack_regs() and use it

 arch/x86/include/asm/kdebug.h  |  1 +
 arch/x86/kernel/dumpstack.c    |  5 +++++
 arch/x86/kernel/dumpstack_32.c |  4 +++-
 arch/x86/kernel/dumpstack_64.c |  4 +++-
 arch/x86/mm/extable.c          | 13 ++++++++-----
 include/linux/printk.h         | 17 ++++++++++++-----
 6 files changed, 32 insertions(+), 12 deletions(-)
Signature · 1 line
2.8.4
author maintainer
#1 lore raw

PATCH 1/3 x86/dumpstack: Honor supplied @regs arg

From: Andy Lutomirski <[email protected]>

The comment suggests that show_stack(NULL, NULL) should backtrace the current context, but the code doesn't match the comment. If regs are given, start the "Stack:" hexdump at regs->sp.

---
 arch/x86/kernel/dumpstack_32.c | 4 +++-
 arch/x86/kernel/dumpstack_64.c | 4 +++-
 2 files changed, 6 insertions(+), 2 deletions(-)
arch/x86/kernel/dumpstack_32.c +3 -1
index 464ffd69b92e..91069ebe3c87 100644
@@ -98,7 +98,9 @@ show_stack_log_lvl(struct task_struct *task, struct pt_regs *regs,
 	int i;
 
 	if (sp == NULL) {
-		if (task)
+		if (regs)
+			sp = (unsigned long *)regs->sp;
+		else if (task)
 			sp = (unsigned long *)task->thread.sp;
 		else
 			sp = (unsigned long *)&sp;
arch/x86/kernel/dumpstack_64.c +3 -1
index 5f1c6266eb30..603356a5597a 100644
@@ -266,7 +266,9 @@ show_stack_log_lvl(struct task_struct *task, struct pt_regs *regs,
 	 * back trace for this cpu:
 	 */
 	if (sp == NULL) {
-		if (task)
+		if (regs)
+			sp = (unsigned long *)regs->sp;
+		else if (task)
 			sp = (unsigned long *)task->thread.sp;
 		else
 			sp = (unsigned long *)&sp;
Signature · 1 line
2.8.4
author maintainer
#2 lore raw

PATCH 2/3 printk: Make the printk*once() variants return a value

In reply to Borislav Petkov

From: Borislav Petkov <[email protected]>

Have printk*once() return a bool which denotes whether the string was printed or not so that calling code can react accordingly.

---
 include/linux/printk.h | 17 ++++++++++++-----
 1 file changed, 12 insertions(+), 5 deletions(-)
include/linux/printk.h +12 -5
index f4da695fd615..464fcdddb359 100644
@@ -108,11 +108,14 @@ struct va_format {
  * Dummy printk for disabled debugging statements to use whilst maintaining
  * gcc's format checking.
  */
-#define no_printk(fmt, ...)			\
-do {						\
-	if (0)					\
-		printk(fmt, ##__VA_ARGS__);	\
-} while (0)
+#define no_printk(fmt, ...)				\
+({							\
+	do {						\
+		if (0)					\
+			printk(fmt, ##__VA_ARGS__);	\
+	} while (0);					\
+	0;						\
+})
 
 #ifdef CONFIG_EARLY_PRINTK
 extern asmlinkage __printf(1, 2)
@@ -309,20 +312,24 @@ extern asmlinkage void dump_stack(void) __cold;
 #define printk_once(fmt, ...)					\
 ({								\
 	static bool __print_once __read_mostly;			\
+	bool __ret_print_once = !__print_once;			\
 								\
 	if (!__print_once) {					\
 		__print_once = true;				\
 		printk(fmt, ##__VA_ARGS__);			\
 	}							\
+	__ret_print_once;					\
 })
 #define printk_deferred_once(fmt, ...)				\
 ({								\
 	static bool __print_once __read_mostly;			\
+	bool __ret_print_once = !__print_once;			\
 								\
 	if (!__print_once) {					\
 		__print_once = true;				\
 		printk_deferred(fmt, ##__VA_ARGS__);		\
 	}							\
+	__ret_print_once;					\
 })
 #else
 #define printk_once(fmt, ...)					\
Signature · 1 line
2.8.4
#3 lore raw

Re: [PATCH 2/3] printk: Make the printk*once() variants return a value

Quoted 4 lines · Borislav Petkov

From: Borislav Petkov <[email protected]>

Have printk*once() return a bool which denotes whether the string was printed or not so that calling code can react accordingly.

I expected object size to either increase or stay the same with just this change.

Oddly, at least with gcc 5.3, some defconfig x86-64 objects _decrease_ in size.

for example: drivers/gpu/drm/i915/intel_opregion.o

I presume there's some curiosity in the gcc optimizer with the evaluation of statement expression macros that don't return a value.

Perhaps the printk_once macros should end with

	unlikely(__ret_print_once);

like the WARN_ONCE variants.

Quoted 55 lines

---
 include/linux/printk.h | 17 ++++++++++++-----

 1 file changed, 12 insertions(+), 5 deletions(-)
include/linux/printk.h +8 -5
index f4da695fd615..464fcdddb359 100644
@@ -108,11 +108,14 @@ struct va_format {
   * Dummy printk for disabled debugging statements to use whilst maintaining
   * gcc's format checking.
   */
-#define no_printk(fmt, ...)			\
-do {						\
-	if (0)					\
-		printk(fmt, ##__VA_ARGS__);	\
-} while (0)
+#define no_printk(fmt, ...)				\
+({							\
+	do {						\
+		if (0)					\
+			printk(fmt, ##__VA_ARGS__);	\
+	} while (0);					\
+	0;						\
+})


 #ifdef CONFIG_EARLY_PRINTK
 extern asmlinkage __printf(1, 2)

include/linux/printk.h +4 -0
@@ -309,20 +312,24 @@ extern asmlinkage void dump_stack(void) __cold;
  #define printk_once(fmt, ...)					\
  ({								\
  	static bool __print_once __read_mostly;			\
+	bool __ret_print_once = !__print_once;			\
  								\
  	if (!__print_once) {					\
  		__print_once = true;				\
  		printk(fmt, ##__VA_ARGS__);			\
  	}							\
+	__ret_print_once;					\
  })
  #define printk_deferred_once(fmt, ...)				\
  ({								\
  	static bool __print_once __read_mostly;			\
+	bool __ret_print_once = !__print_once;			\
  								\
  	if (!__print_once) {					\
  		__print_once = true;				\
  		printk_deferred(fmt, ##__VA_ARGS__);		\
  	}							\
+	__ret_print_once;					\
  })
  #else
  #define printk_once(fmt, ...)					\
author maintainer
#4 lore raw

Re: [PATCH 2/3] printk: Make the printk*once() variants return a value

Quoted 3 lines · Joe Perches

Perhaps the printk_once macros should end with

	unlikely(__ret_print_once);

like the WARN_ONCE variants.

Done, thanks.

Signature · 5 lines
Regards/Gruss,
    Boris.

ECO tip #101: Trim your mails when you reply.
--
author maintainer
#5 lore raw

PATCH 2/3 printk: Make the printk*once() variants return a value

From: Borislav Petkov <[email protected]>
Date: Thu, 23 Jun 2016 10:41:30 +0200
Subject: [PATCH] printk: Make the printk*once() variants return a value

Have printk*once() return a bool which denotes whether the string was printed or not so that calling code can react accordingly.

---

v2: Wrap __ret_print_once in unlikely.

 include/linux/printk.h | 17 ++++++++++++-----
 1 file changed, 12 insertions(+), 5 deletions(-)
include/linux/printk.h +12 -5
index f4da695fd615..f136b22c7772 100644
@@ -108,11 +108,14 @@ struct va_format {
  * Dummy printk for disabled debugging statements to use whilst maintaining
  * gcc's format checking.
  */
-#define no_printk(fmt, ...)			\
-do {						\
-	if (0)					\
-		printk(fmt, ##__VA_ARGS__);	\
-} while (0)
+#define no_printk(fmt, ...)				\
+({							\
+	do {						\
+		if (0)					\
+			printk(fmt, ##__VA_ARGS__);	\
+	} while (0);					\
+	0;						\
+})
 
 #ifdef CONFIG_EARLY_PRINTK
 extern asmlinkage __printf(1, 2)
@@ -309,20 +312,24 @@ extern asmlinkage void dump_stack(void) __cold;
 #define printk_once(fmt, ...)					\
 ({								\
 	static bool __print_once __read_mostly;			\
+	bool __ret_print_once = !__print_once;			\
 								\
 	if (!__print_once) {					\
 		__print_once = true;				\
 		printk(fmt, ##__VA_ARGS__);			\
 	}							\
+	unlikely(__ret_print_once);				\
 })
 #define printk_deferred_once(fmt, ...)				\
 ({								\
 	static bool __print_once __read_mostly;			\
+	bool __ret_print_once = !__print_once;			\
 								\
 	if (!__print_once) {					\
 		__print_once = true;				\
 		printk_deferred(fmt, ##__VA_ARGS__);		\
 	}							\
+	unlikely(__ret_print_once);				\
 })
 #else
 #define printk_once(fmt, ...)					\
Signature · 8 lines
2.8.4

-- 
Regards/Gruss,
    Boris.

ECO tip #101: Trim your mails when you reply.
--
author maintainer
#6 lore raw

PATCH 3/3 x86/dumpstack: Add show_stack_regs() and use it

In reply to Borislav Petkov

From: Borislav Petkov <[email protected]>

Add a helper to dump supplied pt_regs and use it in the MSR exception handling code to have precise stack traces pointing to the actual function causing the MSR access exception and not the stack frame of the exception handler itself.

The new output looks like this:

unchecked MSR access error: RDMSR from 0xdeadbeef at rIP: 0xffffffff8102ddb6 (early_init_intel+0x16/0x3a0)
00000000756e6547 ffffffff81c03f68 ffffffff81dd0940 ffffffff81c03f10
ffffffff81d42e65 0000000001000000 ffffffff81c03f58 ffffffff81d3e5a3
0000800000000000 ffffffff81800080 ffffffffffffffff 0000000000000000

 Call Trace:
  [<ffffffff81d42e65>] early_cpu_init+0xe7/0x136
  [<ffffffff81d3e5a3>] setup_arch+0xa5/0x9df
  [<ffffffff81d38bb9>] start_kernel+0x9f/0x43a
  [<ffffffff81d38294>] x86_64_start_reservations+0x2f/0x31
  [<ffffffff81d383fe>] x86_64_start_kernel+0x168/0x176
---
 arch/x86/include/asm/kdebug.h |  1 +
 arch/x86/kernel/dumpstack.c   |  5 +++++
 arch/x86/mm/extable.c         | 13 ++++++++-----
 3 files changed, 14 insertions(+), 5 deletions(-)
arch/x86/include/asm/kdebug.h +1 -0
index e5f5dc9787d5..1ef9d581b5d9 100644
@@ -26,6 +26,7 @@ extern void die(const char *, struct pt_regs *,long);
 extern int __must_check __die(const char *, struct pt_regs *, long);
 extern void show_trace(struct task_struct *t, struct pt_regs *regs,
 		       unsigned long *sp, unsigned long bp);
+extern void show_stack_regs(struct pt_regs *regs);
 extern void __show_regs(struct pt_regs *regs, int all);
 extern unsigned long oops_begin(void);
 extern void oops_end(unsigned long, struct pt_regs *, int signr);
arch/x86/kernel/dumpstack.c +5 -0
index 2bb25c3fe2e8..3e52272b024b 100644
@@ -199,6 +199,11 @@ void show_stack(struct task_struct *task, unsigned long *sp)
 	show_stack_log_lvl(task, NULL, sp, bp, "");
 }
 
+void show_stack_regs(struct pt_regs *regs)
+{
+	show_stack_log_lvl(current, regs, (unsigned long *)regs->sp, regs->bp, "");
+}
+
 static arch_spinlock_t die_lock = __ARCH_SPIN_LOCK_UNLOCKED;
 static int die_owner = -1;
 static unsigned int die_nest_count;
arch/x86/mm/extable.c +8 -5
index 4bb53b89f3c5..fafc771568c7 100644
@@ -1,6 +1,7 @@
 #include <linux/module.h>
 #include <asm/uaccess.h>
 #include <asm/traps.h>
+#include <asm/kdebug.h>
 
 typedef bool (*ex_handler_t)(const struct exception_table_entry *,
 			    struct pt_regs *, int);
@@ -46,8 +47,9 @@ EXPORT_SYMBOL(ex_handler_ext);
 bool ex_handler_rdmsr_unsafe(const struct exception_table_entry *fixup,
 			     struct pt_regs *regs, int trapnr)
 {
-	WARN_ONCE(1, "unchecked MSR access error: RDMSR from 0x%x\n",
-		  (unsigned int)regs->cx);
+	if (pr_warn_once("unchecked MSR access error: RDMSR from 0x%x at rIP: 0x%lx (%pF)\n",
+			 (unsigned int)regs->cx, regs->ip, (void *)regs->ip))
+		show_stack_regs(regs);
 
 	/* Pretend that the read succeeded and returned 0. */
 	regs->ip = ex_fixup_addr(fixup);
@@ -60,9 +62,10 @@ EXPORT_SYMBOL(ex_handler_rdmsr_unsafe);
 bool ex_handler_wrmsr_unsafe(const struct exception_table_entry *fixup,
 			     struct pt_regs *regs, int trapnr)
 {
-	WARN_ONCE(1, "unchecked MSR access error: WRMSR to 0x%x (tried to write 0x%08x%08x)\n",
-		  (unsigned int)regs->cx,
-		  (unsigned int)regs->dx, (unsigned int)regs->ax);
+	if (pr_warn_once("unchecked MSR access error: WRMSR to 0x%x (tried to write 0x%08x%08x) at rIP: 0x%lx (%pF)\n",
+			 (unsigned int)regs->cx, (unsigned int)regs->dx,
+			 (unsigned int)regs->ax,  regs->ip, (void *)regs->ip))
+		show_stack_regs(regs);
 
 	/* Pretend that the write succeeded. */
 	regs->ip = ex_fixup_addr(fixup);
Signature · 1 line
2.8.4
Reviewed-by on v1 3/3
#7 lore raw

Re: [PATCH 3/3] x86/dumpstack: Add show_stack_regs() and use it

Quoted 13 lines · Borislav Petkov

From: Borislav Petkov <[email protected]>

Add a helper to dump supplied pt_regs and use it in the MSR exception handling code to have precise stack traces pointing to the actual function causing the MSR access exception and not the stack frame of the exception handler itself.

The new output looks like this:

unchecked MSR access error: RDMSR from 0xdeadbeef at rIP: 0xffffffff8102ddb6 (early_init_intel+0x16/0x3a0)
00000000756e6547 ffffffff81c03f68 ffffffff81dd0940 ffffffff81c03f10
ffffffff81d42e65 0000000001000000 ffffffff81c03f58 ffffffff81d3e5a3
0000800000000000 ffffffff81800080 ffffffffffffffff 0000000000000000

Quoted 6 lines
 Call Trace:
  [<ffffffff81d42e65>] early_cpu_init+0xe7/0x136
  [<ffffffff81d3e5a3>] setup_arch+0xa5/0x9df
  [<ffffffff81d38bb9>] start_kernel+0x9f/0x43a
  [<ffffffff81d38294>] x86_64_start_reservations+0x2f/0x31
  [<ffffffff81d383fe>] x86_64_start_kernel+0x168/0x176