[PATCH 0/3] x86/MSR: Improve unhandled MSR access error message

[PATCH 0/3] x86/MSR: Improve unhandled MSR access error message

[Borislav Petkov]

From: Borislav Petkov <bp@suse.de>

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(-)

-- 
2.8.4

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

[Borislav Petkov]

From: Andy Lutomirski <luto@kernel.org>

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.

Signed-off-by: Andy Lutomirski <luto@kernel.org>
Cc: Brian Gerst <brgerst@gmail.com>
Cc: "H. Peter Anvin" <hpa@zytor.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Kees Cook <keescook@chromium.org>
Cc: Linus Torvalds <torvalds@linux-foundation.org>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: x86-ml <x86@kernel.org>
Link: http://lkml.kernel.org/r/efcd79bf4106d61f1cd258c2caa87f3a0618eeac.1466036668.git.luto@kernel.org
Signed-off-by: Borislav Petkov <bp@suse.de>
---
 arch/x86/kernel/dumpstack_32.c | 4 +++-
 arch/x86/kernel/dumpstack_64.c | 4 +++-
 2 files changed, 6 insertions(+), 2 deletions(-)

diff --git a/arch/x86/kernel/dumpstack_32.c b/arch/x86/kernel/dumpstack_32.c
index 464ffd69b92e..91069ebe3c87 100644
--- a/arch/x86/kernel/dumpstack_32.c
+++ b/arch/x86/kernel/dumpstack_32.c
@@ -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;
diff --git a/arch/x86/kernel/dumpstack_64.c b/arch/x86/kernel/dumpstack_64.c
index 5f1c6266eb30..603356a5597a 100644
--- a/arch/x86/kernel/dumpstack_64.c
+++ b/arch/x86/kernel/dumpstack_64.c
@@ -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;
-- 
2.8.4

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

[Borislav Petkov]

From: Borislav Petkov <bp@suse.de>

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

Signed-off-by: Borislav Petkov <bp@suse.de>
Cc: Andrew Morton <akpm@linux-foundation.org>
---
 include/linux/printk.h | 17 ++++++++++++-----
 1 file changed, 12 insertions(+), 5 deletions(-)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index f4da695fd615..464fcdddb359 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -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, ...)					\
-- 
2.8.4

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

[Joe Perches]

On Fri, 2016-06-24 at 10:30 +0200, Borislav Petkov wrote:
> From: Borislav Petkov <bp@suse.de>
> 
> 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.

> Signed-off-by: Borislav Petkov <bp@suse.de>
> Cc: Andrew Morton <akpm@linux-foundation.org>
> ---
>  include/linux/printk.h | 17 ++++++++++++-----
>  1 file changed, 12 insertions(+), 5 deletions(-)
> 
> diff --git a/include/linux/printk.h b/include/linux/printk.h
> index f4da695fd615..464fcdddb359 100644
> --- a/include/linux/printk.h
> +++ b/include/linux/printk.h
> @@ -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, ...)					\

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

[Borislav Petkov]

On Fri, Jun 24, 2016 at 06:43:04AM -0700, Joe Perches wrote:
> Perhaps the printk_once macros should end with
> 	unlikely(__ret_print_once);
> like the WARN_ONCE variants.

Done, thanks.

-- 
Regards/Gruss,
    Boris.

ECO tip #101: Trim your mails when you reply.
--

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

[Borislav Petkov]

From: Borislav Petkov <bp@suse.de>
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.

Signed-off-by: Borislav Petkov <bp@suse.de>
Cc: Andrew Morton <akpm@linux-foundation.org>
---

v2: Wrap __ret_print_once in unlikely.

 include/linux/printk.h | 17 ++++++++++++-----
 1 file changed, 12 insertions(+), 5 deletions(-)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index f4da695fd615..f136b22c7772 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -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, ...)					\
-- 
2.8.4

-- 
Regards/Gruss,
    Boris.

ECO tip #101: Trim your mails when you reply.
--

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

[Borislav Petkov]

From: Borislav Petkov <bp@suse.de>

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

Signed-off-by: Borislav Petkov <bp@suse.de>
---
 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(-)

diff --git a/arch/x86/include/asm/kdebug.h b/arch/x86/include/asm/kdebug.h
index e5f5dc9787d5..1ef9d581b5d9 100644
--- a/arch/x86/include/asm/kdebug.h
+++ b/arch/x86/include/asm/kdebug.h
@@ -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);
diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 2bb25c3fe2e8..3e52272b024b 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -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;
diff --git a/arch/x86/mm/extable.c b/arch/x86/mm/extable.c
index 4bb53b89f3c5..fafc771568c7 100644
--- a/arch/x86/mm/extable.c
+++ b/arch/x86/mm/extable.c
@@ -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);
-- 
2.8.4

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

[Andy Lutomirski]

On Fri, Jun 24, 2016 at 1:30 AM, Borislav Petkov <bp@alien8.de> wrote:
> From: Borislav Petkov <bp@suse.de>
>
> 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

Reviewed-by: Andy Lutomirski <luto@kernel.org>