Re: [PATCH 2/3] x86/dumpstack: Add log_lvl to __show_regs()

2020-06-25 Thread Dmitry Safonov
On 6/23/20 5:45 PM, Jann Horn wrote:
> On Tue, Jun 23, 2020 at 6:30 PM Dmitry Safonov  wrote:
>> show_trace_log_lvl() provides x86 platform-specific way to unwind
>> backtrace with a given log level. Unfortunately, registers dump(s) are
>> not printed with the same log level - instead, KERN_DEFAULT is always
>> used.
>>
>> Arista's switches uses quite common setup with rsyslog, where only
>> urgent messages goes to console (console_log_level=KERN_ERR), everything
>> else goes into /var/log/ as the console baud-rate often is indecently
>> slow (9600 bps).
>>
>> Backtrace dumps without registers printed have proven to be as useful as
>> morning standups. Furthermore, in order to introduce KERN_UNSUPPRESSED
>> (which I believe is still the most elegant way to fix raciness of sysrq[1])
>> the log level should be passed down the stack to register dumping
>> functions. Besides, I have a potential use-case for printing traces
>> with KERN_DEBUG level [2] (where registers dump shouldn't appear with
>> higher log level).
>>
>> Add log_lvl parameter to __show_regs().
>> Keep the used log level intact to separate visible change.
> 
> This change seems like a good idea to me; just one small nit:
> 
> [...]
>>  void show_regs(struct pt_regs *regs)
>>  {
>> +   int print_kernel_regs;
>> +
>> show_regs_print_info(KERN_DEFAULT);
>>
>> -   __show_regs(regs, user_mode(regs) ? SHOW_REGS_USER : SHOW_REGS_ALL);
>> +   print_kernel_regs = user_mode(regs) ? SHOW_REGS_USER : SHOW_REGS_ALL;
>> +   __show_regs(regs, print_kernel_regs, KERN_DEFAULT);
> 
> print_kernel_regs should probably have type "enum show_regs_mode"? 

Makes sense, will fix in v2.

Thanks,
  Dmitry


Re: [PATCH 2/3] x86/dumpstack: Add log_lvl to __show_regs()

2020-06-23 Thread Jann Horn
On Tue, Jun 23, 2020 at 6:30 PM Dmitry Safonov  wrote:
> show_trace_log_lvl() provides x86 platform-specific way to unwind
> backtrace with a given log level. Unfortunately, registers dump(s) are
> not printed with the same log level - instead, KERN_DEFAULT is always
> used.
>
> Arista's switches uses quite common setup with rsyslog, where only
> urgent messages goes to console (console_log_level=KERN_ERR), everything
> else goes into /var/log/ as the console baud-rate often is indecently
> slow (9600 bps).
>
> Backtrace dumps without registers printed have proven to be as useful as
> morning standups. Furthermore, in order to introduce KERN_UNSUPPRESSED
> (which I believe is still the most elegant way to fix raciness of sysrq[1])
> the log level should be passed down the stack to register dumping
> functions. Besides, I have a potential use-case for printing traces
> with KERN_DEBUG level [2] (where registers dump shouldn't appear with
> higher log level).
>
> Add log_lvl parameter to __show_regs().
> Keep the used log level intact to separate visible change.

This change seems like a good idea to me; just one small nit:

[...]
>  void show_regs(struct pt_regs *regs)
>  {
> +   int print_kernel_regs;
> +
> show_regs_print_info(KERN_DEFAULT);
>
> -   __show_regs(regs, user_mode(regs) ? SHOW_REGS_USER : SHOW_REGS_ALL);
> +   print_kernel_regs = user_mode(regs) ? SHOW_REGS_USER : SHOW_REGS_ALL;
> +   __show_regs(regs, print_kernel_regs, KERN_DEFAULT);

print_kernel_regs should probably have type "enum show_regs_mode"?


[PATCH 2/3] x86/dumpstack: Add log_lvl to __show_regs()

2020-06-23 Thread Dmitry Safonov
show_trace_log_lvl() provides x86 platform-specific way to unwind
backtrace with a given log level. Unfortunately, registers dump(s) are
not printed with the same log level - instead, KERN_DEFAULT is always
used.

Arista's switches uses quite common setup with rsyslog, where only
urgent messages goes to console (console_log_level=KERN_ERR), everything
else goes into /var/log/ as the console baud-rate often is indecently
slow (9600 bps).

Backtrace dumps without registers printed have proven to be as useful as
morning standups. Furthermore, in order to introduce KERN_UNSUPPRESSED
(which I believe is still the most elegant way to fix raciness of sysrq[1])
the log level should be passed down the stack to register dumping
functions. Besides, I have a potential use-case for printing traces
with KERN_DEBUG level [2] (where registers dump shouldn't appear with
higher log level).

Add log_lvl parameter to __show_regs().
Keep the used log level intact to separate visible change.

[1]: https://lore.kernel.org/lkml/20190528002412.1625-1-d...@arista.com/
[2]: https://lore.kernel.org/linux-doc/20190724170249.9644-1-d...@arista.com/
Signed-off-by: Dmitry Safonov 
---
 arch/x86/include/asm/kdebug.h |  3 ++-
 arch/x86/kernel/dumpstack.c   |  9 ---
 arch/x86/kernel/process_32.c  | 29 ++--
 arch/x86/kernel/process_64.c  | 51 ++-
 4 files changed, 49 insertions(+), 43 deletions(-)

diff --git a/arch/x86/include/asm/kdebug.h b/arch/x86/include/asm/kdebug.h
index da024bbda6f4..d1514e70477b 100644
--- a/arch/x86/include/asm/kdebug.h
+++ b/arch/x86/include/asm/kdebug.h
@@ -36,7 +36,8 @@ extern void die(const char *, struct pt_regs *,long);
 void die_addr(const char *str, struct pt_regs *regs, long err, long gp_addr);
 extern int __must_check __die(const char *, struct pt_regs *, long);
 extern void show_stack_regs(struct pt_regs *regs);
-extern void __show_regs(struct pt_regs *regs, enum show_regs_mode);
+extern void __show_regs(struct pt_regs *regs, enum show_regs_mode,
+   const char *log_lvl);
 extern void show_iret_regs(struct pt_regs *regs, const char *log_lvl);
 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 c36d629a25a8..ec90d71979f4 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -146,7 +146,7 @@ static void show_regs_if_on_stack(struct stack_info *info, 
struct pt_regs *regs,
 * they can be printed in the right context.
 */
if (!partial && on_stack(info, regs, sizeof(*regs))) {
-   __show_regs(regs, SHOW_REGS_SHORT);
+   __show_regs(regs, SHOW_REGS_SHORT, KERN_DEFAULT);
 
} else if (partial && on_stack(info, (void *)regs + IRET_FRAME_OFFSET,
   IRET_FRAME_SIZE)) {
@@ -345,7 +345,7 @@ void oops_end(unsigned long flags, struct pt_regs *regs, 
int signr)
oops_exit();
 
/* Executive summary in case the oops scrolled away */
-   __show_regs(_summary_regs, SHOW_REGS_ALL);
+   __show_regs(_summary_regs, SHOW_REGS_ALL, KERN_DEFAULT);
 
if (!signr)
return;
@@ -437,9 +437,12 @@ void die_addr(const char *str, struct pt_regs *regs, long 
err, long gp_addr)
 
 void show_regs(struct pt_regs *regs)
 {
+   int print_kernel_regs;
+
show_regs_print_info(KERN_DEFAULT);
 
-   __show_regs(regs, user_mode(regs) ? SHOW_REGS_USER : SHOW_REGS_ALL);
+   print_kernel_regs = user_mode(regs) ? SHOW_REGS_USER : SHOW_REGS_ALL;
+   __show_regs(regs, print_kernel_regs, KERN_DEFAULT);
 
/*
 * When in-kernel, we also print out the stack at the time of the 
fault..
diff --git a/arch/x86/kernel/process_32.c b/arch/x86/kernel/process_32.c
index acfd6d2a0cbf..4f2f54e1281c 100644
--- a/arch/x86/kernel/process_32.c
+++ b/arch/x86/kernel/process_32.c
@@ -56,7 +56,8 @@
 
 #include "process.h"
 
-void __show_regs(struct pt_regs *regs, enum show_regs_mode mode)
+void __show_regs(struct pt_regs *regs, enum show_regs_mode mode,
+const char *log_lvl)
 {
unsigned long cr0 = 0L, cr2 = 0L, cr3 = 0L, cr4 = 0L;
unsigned long d0, d1, d2, d3, d6, d7;
@@ -67,14 +68,14 @@ void __show_regs(struct pt_regs *regs, enum show_regs_mode 
mode)
else
savesegment(gs, gs);
 
-   show_ip(regs, KERN_DEFAULT);
+   show_ip(regs, log_lvl);
 
-   printk(KERN_DEFAULT "EAX: %08lx EBX: %08lx ECX: %08lx EDX: %08lx\n",
-   regs->ax, regs->bx, regs->cx, regs->dx);
-   printk(KERN_DEFAULT "ESI: %08lx EDI: %08lx EBP: %08lx ESP: %08lx\n",
-   regs->si, regs->di, regs->bp, regs->sp);
-   printk(KERN_DEFAULT "DS: %04x ES: %04x FS: %04x GS: %04x SS: %04x 
EFLAGS: %08lx\n",
-  (u16)regs->ds, (u16)regs->es, (u16)regs->fs, gs, regs->ss, 
regs->flags);
+   printk("%sEAX: %08lx EBX: