Date:   Fri, 22 Feb 2019 14:09:59 +0800
From:   Feng Tang <feng.tang@...el.com>
To:     Andrew Morton <akpm@...ux-foundation.org>,
        LKML <linux-kernel@...r.kernel.org>,
        Petr Mladek <pmladek@...e.com>
Cc:     Thomas Gleixner <tglx@...utronix.de>,
        Kees Cook <keescook@...omium.org>,
        Borislav Petkov <bp@...e.de>,
        Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>,
        Steven Rostedt <rostedt@...dmis.org>,
        Andi Kleen <ak@...ux.intel.com>,
        Peter Zijlstra <peterz@...radead.org>,
        Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
        Jiri Slaby <jslaby@...e.com>, Sasha Levin <sashal@...nel.org>
Subject: Re: [PATCH v5] panic: Avoid the extra noise dmesg

One small cleanup of unneeded change in last post:


>From 4ecbdfe1b398aa2285a696392eddeffb109d5463 Mon Sep 17 00:00:00 2001
From: Feng Tang <feng.tang@...el.com>
Date: Thu, 21 Feb 2019 16:23:32 +0800
Subject: [PATCH v5] panic: Avoid the extra noise dmesg

When kernel panic happens, it will first print the panic call stack,
then the ending msg like:

[   35.743249] ---[ end Kernel panic - not syncing: Fatal exception
[   35.749975] ------------[ cut here ]------------

The above message are very useful for debugging.

But if system is configured to not reboot on panic, say the "panic_timeout"
parameter equals 0, it will likely print out many noisy message like
WARN() call stack for each and every CPU except the panic one, messages
like below:

	WARNING: CPU: 1 PID: 280 at kernel/sched/core.c:1198 set_task_cpu+0x183/0x190
	Call Trace:
	<IRQ>
	try_to_wake_up
	default_wake_function
	autoremove_wake_function
	__wake_up_common
	__wake_up_common_lock
	__wake_up
	wake_up_klogd_work_func
	irq_work_run_list
	irq_work_tick
	update_process_times
	tick_sched_timer
	__hrtimer_run_queues
	hrtimer_interrupt
	smp_apic_timer_interrupt
	apic_timer_interrupt

For people working in console mode, the screen will first show the panic
call stack, but immediately overridden by these noisy extra messages, which
makes debugging much more difficult, as the original context gets lost on
screen.

Also these noisy messages will confuse some users, as I have seen many bug
reporters posted the noisy message into bugzilla, instead of the real panic
call stack and context.

Adding a flag panic_suppress_printk to avoid those noisy message, without
changing the current kernel behavior that both panic blinking and sysrq
magic key can work as is, suggested by Petr Mladek.

To verify this, make sure kernel is not configured to reboot on panic and
in console
 # echo c > /proc/sysrq-trigger
to see if console only prints out the panic call stack.

Suggested-by: Petr Mladek <pmladek@...e.com>
Signed-off-by: Feng Tang <feng.tang@...el.com>
Cc: Thomas Gleixner <tglx@...utronix.de>
Cc: Kees Cook <keescook@...omium.org>
Cc: Borislav Petkov <bp@...e.de>
Cc: Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>
Cc: Petr Mladek <pmladek@...e.com>
Cc: Steven Rostedt <rostedt@...dmis.org>
Cc: Andi Kleen <ak@...ux.intel.com>
Cc: Peter Zijlstra <peterz@...radead.org>
Cc: Greg Kroah-Hartman <gregkh@...uxfoundation.org>
Cc: Jiri Slaby <jslaby@...e.com>
Cc: Sasha Levin <sashal@...nel.org>
---
Change log:

  v5:
    - use a flag to notify printk not to print unimportant
      messages, while keep panic blinking and sysrq working,
      as suggested by Petr Mladek

  v4:
    - make the local_irq_enable conditional and default off
    to cover possible use of interrupt/scheduling, as
    mentioned by Sergey and Petr

  v3:
    - Make the change log clearer as suggested by Andrew Morton

  v2:
    - Move the solution from hacking arch/scheduler code back
    to panic.c



 drivers/tty/sysrq.c    | 6 ++++++
 include/linux/kernel.h | 1 +
 kernel/panic.c         | 5 +++++
 kernel/printk/printk.c | 4 ++++
 4 files changed, 16 insertions(+)

diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c
index 1f03078..763e24c 100644
--- a/drivers/tty/sysrq.c
+++ b/drivers/tty/sysrq.c
@@ -527,8 +527,12 @@ void __handle_sysrq(int key, bool check_mask)
 {
 	struct sysrq_key_op *op_p;
 	int orig_log_level;
+	int orig_panic_suppress_printk;
 	int i;
 
+	orig_panic_suppress_printk = panic_suppress_printk;
+	panic_suppress_printk = 0;
+
 	rcu_sysrq_start();
 	rcu_read_lock();
 	/*
@@ -574,6 +578,8 @@ void __handle_sysrq(int key, bool check_mask)
 	}
 	rcu_read_unlock();
 	rcu_sysrq_end();
+
+	panic_suppress_printk = orig_panic_suppress_printk;
 }
 
 void handle_sysrq(int key)
diff --git a/include/linux/kernel.h b/include/linux/kernel.h
index 8f0e68e..4120f3a 100644
--- a/include/linux/kernel.h
+++ b/include/linux/kernel.h
@@ -534,6 +534,7 @@ extern int panic_on_io_nmi;
 extern int panic_on_warn;
 extern int sysctl_panic_on_rcu_stall;
 extern int sysctl_panic_on_stackoverflow;
+extern int panic_suppress_printk;
 
 extern bool crash_kexec_post_notifiers;
 
diff --git a/kernel/panic.c b/kernel/panic.c
index f121e6b..b9f004e 100644
--- a/kernel/panic.c
+++ b/kernel/panic.c
@@ -46,6 +46,8 @@ int panic_on_warn __read_mostly;
 int panic_timeout = CONFIG_PANIC_TIMEOUT;
 EXPORT_SYMBOL_GPL(panic_timeout);
 
+int panic_suppress_printk;
+
 #define PANIC_PRINT_TASK_INFO		0x00000001
 #define PANIC_PRINT_MEM_INFO		0x00000002
 #define PANIC_PRINT_TIMER_INFO		0x00000004
@@ -326,6 +328,9 @@ void panic(const char *fmt, ...)
 	}
 #endif
 	pr_emerg("---[ end Kernel panic - not syncing: %s ]---\n", buf);
+
+	/* Do not scroll important messages printed above */
+	panic_suppress_printk = 1;
 	local_irq_enable();
 	for (i = 0; ; i += PANIC_TIMER_STEP) {
 		touch_softlockup_watchdog();
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index d3d1703..d460144 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1899,6 +1899,10 @@ asmlinkage int vprintk_emit(int facility, int level,
 	unsigned long flags;
 	u64 curr_log_seq;
 
+	/* Suppress unimportant messages after panic happens */
+	if (unlikely(panic_suppress_printk))
+		return 0;
+
 	if (level == LOGLEVEL_SCHED) {
 		level = LOGLEVEL_DEFAULT;
 		in_sched = true;
-- 
2.7.4

Powered by blists - more mailing lists