[PATCH v3] panic: add an option to replay all the printk message in buffer

[PATCH v3] panic: add an option to replay all the printk message in buffer

[Feng Tang]

Currently on panic, kernel will lower the loglevel and print out
pending printk msg only with console_flush_on_panic().

Add an option for users to configure the "panic_print" to replay
all dmesg in buffer, some of which they may have never seen due
to the loglevel setting, which will help panic debugging .

Signed-off-by: Feng Tang <feng.tang@intel.com>
Cc: Aaro Koskinen <aaro.koskinen@nokia.com>
Cc: Petr Mladek <pmladek@suse.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
Cc: Kees Cook <keescook@chromium.org>
Cc: Borislav Petkov <bp@suse.de>
---
Changelog:

  v3:
    - Solve the compile issue when CONFIG_PRINTK=n, found by
      Andrew Morton
    - Add enum for parameter of console_flush_on_panic()
    - move the printk replay code to console_flush_on_panic()

  v2:
    - Add a new func in printk.c dedicated for the replaying, as
      suggested by Petr Mladek
    - Combine the 2 patches in v1 into one suggested by both Petr
      and Sergey

 Documentation/admin-guide/kernel-parameters.txt | 1 +
 arch/powerpc/kernel/traps.c                     | 2 +-
 include/linux/console.h                         | 7 ++++++-
 kernel/panic.c                                  | 8 ++++++--
 kernel/printk/printk.c                          | 8 +++++++-
 5 files changed, 21 insertions(+), 5 deletions(-)

diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
index 858b6c0..e56fe86 100644
--- a/Documentation/admin-guide/kernel-parameters.txt
+++ b/Documentation/admin-guide/kernel-parameters.txt
@@ -3104,6 +3104,7 @@
 			bit 2: print timer info
 			bit 3: print locks info if CONFIG_LOCKDEP is on
 			bit 4: print ftrace buffer
+			bit 5: print all printk messages in buffer
 
 	panic_on_warn	panic() instead of WARN().  Useful to cause kdump
 			on a WARN().
diff --git a/arch/powerpc/kernel/traps.c b/arch/powerpc/kernel/traps.c
index 64936b6..852362c 100644
--- a/arch/powerpc/kernel/traps.c
+++ b/arch/powerpc/kernel/traps.c
@@ -178,7 +178,7 @@ extern void panic_flush_kmsg_end(void)
 	kmsg_dump(KMSG_DUMP_PANIC);
 	bust_spinlocks(0);
 	debug_locks_off();
-	console_flush_on_panic();
+	console_flush_on_panic(CONSOLE_FLUSH_PENDING);
 }
 
 static unsigned long oops_begin(struct pt_regs *regs)
diff --git a/include/linux/console.h b/include/linux/console.h
index ec9bdb3..d09951d 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -166,6 +166,11 @@ struct console {
 extern int console_set_on_cmdline;
 extern struct console *early_console;
 
+enum con_flush_mode {
+	CONSOLE_FLUSH_PENDING,
+	CONSOLE_REPLAY_ALL,
+};
+
 extern int add_preferred_console(char *name, int idx, char *options);
 extern void register_console(struct console *);
 extern int unregister_console(struct console *);
@@ -175,7 +180,7 @@ extern int console_trylock(void);
 extern void console_unlock(void);
 extern void console_conditional_schedule(void);
 extern void console_unblank(void);
-extern void console_flush_on_panic(void);
+extern void console_flush_on_panic(enum con_flush_mode mode);
 extern struct tty_driver *console_device(int *);
 extern void console_stop(struct console *);
 extern void console_start(struct console *);
diff --git a/kernel/panic.c b/kernel/panic.c
index b9f004e..b9c0eb3 100644
--- a/kernel/panic.c
+++ b/kernel/panic.c
@@ -53,6 +53,7 @@ int panic_suppress_printk;
 #define PANIC_PRINT_TIMER_INFO		0x00000004
 #define PANIC_PRINT_LOCK_INFO		0x00000008
 #define PANIC_PRINT_FTRACE_INFO		0x00000010
+#define PANIC_PRINT_ALL_PRINTK_MSG	0x00000020
 unsigned long panic_print;
 
 ATOMIC_NOTIFIER_HEAD(panic_notifier_list);
@@ -136,6 +137,11 @@ EXPORT_SYMBOL(nmi_panic);
 
 static void panic_print_sys_info(void)
 {
+	if (panic_print & PANIC_PRINT_ALL_PRINTK_MSG)
+		console_flush_on_panic(CONSOLE_REPLAY_ALL);
+	else
+		console_flush_on_panic(CONSOLE_FLUSH_PENDING);
+
 	if (panic_print & PANIC_PRINT_TASK_INFO)
 		show_state();
 
@@ -279,8 +285,6 @@ void panic(const char *fmt, ...)
 	 * panic() is not being callled from OOPS.
 	 */
 	debug_locks_off();
-	console_flush_on_panic();
-
 	panic_print_sys_info();
 
 	if (!panic_blink)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index d460144..237191b 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2485,10 +2485,11 @@ void console_unblank(void)
 
 /**
  * console_flush_on_panic - flush console content on panic
+ * @mode: flush all messages in buffer or just the pending ones
  *
  * Immediately output all pending messages no matter what.
  */
-void console_flush_on_panic(void)
+void console_flush_on_panic(enum con_flush_mode mode)
 {
 	/*
 	 * If someone else is holding the console lock, trylock will fail
@@ -2499,6 +2500,11 @@ void console_flush_on_panic(void)
 	 */
 	console_trylock();
 	console_may_schedule = 0;
+
+	if (mode == CONSOLE_REPLAY_ALL) {
+		console_seq = log_first_seq;
+		console_idx = log_first_idx;
+	}
 	console_unlock();
 }
 
-- 
2.7.4

Re: [PATCH v3] panic: add an option to replay all the printk message in buffer

[Petr Mladek]

On Wed 2019-04-24 16:51:12, Feng Tang wrote:
> Currently on panic, kernel will lower the loglevel and print out
> pending printk msg only with console_flush_on_panic().
> 
> Add an option for users to configure the "panic_print" to replay
> all dmesg in buffer, some of which they may have never seen due
> to the loglevel setting, which will help panic debugging .
> 
> diff --git a/kernel/panic.c b/kernel/panic.c
> index b9f004e..b9c0eb3 100644
> --- a/kernel/panic.c
> +++ b/kernel/panic.c
> @@ -53,6 +53,7 @@ int panic_suppress_printk;
>  #define PANIC_PRINT_TIMER_INFO		0x00000004
>  #define PANIC_PRINT_LOCK_INFO		0x00000008
>  #define PANIC_PRINT_FTRACE_INFO		0x00000010
> +#define PANIC_PRINT_ALL_PRINTK_MSG	0x00000020
>  unsigned long panic_print;
>  
>  ATOMIC_NOTIFIER_HEAD(panic_notifier_list);
> @@ -136,6 +137,11 @@ EXPORT_SYMBOL(nmi_panic);
>  
>  static void panic_print_sys_info(void)
>  {
> +	if (panic_print & PANIC_PRINT_ALL_PRINTK_MSG)
> +		console_flush_on_panic(CONSOLE_REPLAY_ALL);
> +	else
> +		console_flush_on_panic(CONSOLE_FLUSH_PENDING);
> +
>  	if (panic_print & PANIC_PRINT_TASK_INFO)
>  		show_state();
>  
> @@ -279,8 +285,6 @@ void panic(const char *fmt, ...)
>  	 * panic() is not being callled from OOPS.
>  	 */
>  	debug_locks_off();
> -	console_flush_on_panic();

I would prefer if we keep it here. It is a very important
operation that plays a role in many panic/printk related
bugs. We should not hide it in an "unrelated"
function.

The name "panic_print_sys_info" suggests that it
just shows some additional information.

I guess that you wanted to avoid flushing some messages
twice. IMHO, it is not a big deal. In many situations,
console_flush_on_panic(CONSOLE_FLUSH_PENDING) will
do nothing or it would handle just few lines.

Also people might decide to do a forced reboot when
the console is slow and it takes ages to print
everything. Then it might be useful to handle
the few "most" important lines before starting
from beginning.

Other than that I am fine with the patch. I give up
on bike shedding about the header line ;-)

Best Regards,
Petr

Re: [PATCH v3] panic: add an option to replay all the printk message in buffer

[Feng Tang]

Hi Petr,

On Thu, Apr 25, 2019 at 01:05:17PM +0200, Petr Mladek wrote:
> On Wed 2019-04-24 16:51:12, Feng Tang wrote:
> > Currently on panic, kernel will lower the loglevel and print out
> > pending printk msg only with console_flush_on_panic().
> > 
> > Add an option for users to configure the "panic_print" to replay
> > all dmesg in buffer, some of which they may have never seen due
> > to the loglevel setting, which will help panic debugging .
> > 
> > diff --git a/kernel/panic.c b/kernel/panic.c
> > index b9f004e..b9c0eb3 100644
> > --- a/kernel/panic.c
> > +++ b/kernel/panic.c
> > @@ -53,6 +53,7 @@ int panic_suppress_printk;
> >  #define PANIC_PRINT_TIMER_INFO		0x00000004
> >  #define PANIC_PRINT_LOCK_INFO		0x00000008
> >  #define PANIC_PRINT_FTRACE_INFO		0x00000010
> > +#define PANIC_PRINT_ALL_PRINTK_MSG	0x00000020
> >  unsigned long panic_print;
> >  
> >  ATOMIC_NOTIFIER_HEAD(panic_notifier_list);
> > @@ -136,6 +137,11 @@ EXPORT_SYMBOL(nmi_panic);
> >  
> >  static void panic_print_sys_info(void)
> >  {
> > +	if (panic_print & PANIC_PRINT_ALL_PRINTK_MSG)
> > +		console_flush_on_panic(CONSOLE_REPLAY_ALL);
> > +	else
> > +		console_flush_on_panic(CONSOLE_FLUSH_PENDING);
> > +
> >  	if (panic_print & PANIC_PRINT_TASK_INFO)
> >  		show_state();
> >  
> > @@ -279,8 +285,6 @@ void panic(const char *fmt, ...)
> >  	 * panic() is not being callled from OOPS.
> >  	 */
> >  	debug_locks_off();
> > -	console_flush_on_panic();
> 
> I would prefer if we keep it here. It is a very important
> operation that plays a role in many panic/printk related
> bugs. We should not hide it in an "unrelated"
> function.
> 
> The name "panic_print_sys_info" suggests that it
> just shows some additional information.
> 
> I guess that you wanted to avoid flushing some messages
> twice. IMHO, it is not a big deal. In many situations,
> console_flush_on_panic(CONSOLE_FLUSH_PENDING) will
> do nothing or it would handle just few lines.

Yes, that was one of my consideration. I got your point
and will send a v4, though Andrew has taken the v3.

> 
> Also people might decide to do a forced reboot when
> the console is slow and it takes ages to print
> everything. Then it might be useful to handle
> the few "most" important lines before starting
> from beginning.
> 
> Other than that I am fine with the patch. I give up
> on bike shedding about the header line ;-)
	:)

Thanks,
Feng