2019-04-01 10:48:56

by Feng Tang

[permalink] [raw]
Subject: [PATCH 1/2] printk: Add an option to flush all messages on panic

Current console_flush_on_panic() will only dump the new messages
in buffer, and users may need an opportunity to check all the
messages on panic which could help debugging, as user may haven't
seen the log before panic due to loglevel settings.

Add a flag for console_flush_on_panic() to chose whether to
dump all messages.

Signed-off-by: Feng Tang <[email protected]>
---
arch/powerpc/kernel/traps.c | 2 +-
include/linux/console.h | 2 +-
kernel/panic.c | 2 +-
kernel/printk/printk.c | 9 ++++++++-
4 files changed, 11 insertions(+), 4 deletions(-)

diff --git a/arch/powerpc/kernel/traps.c b/arch/powerpc/kernel/traps.c
index 1fd45a8..58d9580 100644
--- a/arch/powerpc/kernel/traps.c
+++ b/arch/powerpc/kernel/traps.c
@@ -179,7 +179,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(false);
}

static unsigned long oops_begin(struct pt_regs *regs)
diff --git a/include/linux/console.h b/include/linux/console.h
index ec9bdb3..825ecf5 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -175,7 +175,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(bool flush_all);
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 0ae0d73..fb77e01 100644
--- a/kernel/panic.c
+++ b/kernel/panic.c
@@ -277,7 +277,7 @@ void panic(const char *fmt, ...)
* panic() is not being callled from OOPS.
*/
debug_locks_off();
- console_flush_on_panic();
+ console_flush_on_panic(false);

panic_print_sys_info();

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 02ca827..8ff099b 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2525,10 +2525,11 @@ void console_unblank(void)

/**
* console_flush_on_panic - flush console content on panic
+ * @flush_all: whether to print all messages in buffer
*
* Immediately output all pending messages no matter what.
*/
-void console_flush_on_panic(void)
+void console_flush_on_panic(bool flush_all)
{
/*
* If someone else is holding the console lock, trylock will fail
@@ -2539,6 +2540,12 @@ void console_flush_on_panic(void)
*/
console_trylock();
console_may_schedule = 0;
+
+ /* User may want to see all the printk messages on panic */
+ if (flush_all) {
+ console_seq = log_first_seq;
+ console_idx = log_first_idx;
+ }
console_unlock();
}

--
2.7.4


2019-04-01 10:48:20

by Feng Tang

[permalink] [raw]
Subject: [PATCH 2/2] panic: Enable to print out all printk msg in buffer

Currently on panic, kernel will lower the loglevel and print out
new printk msg only. With this patch, user can configure the
"panic_print" to see all dmesg in buffer, some of which they may
have never seen due to the loglevel setting.

Signed-off-by: Feng Tang <[email protected]>
---
Documentation/admin-guide/kernel-parameters.txt | 1 +
kernel/panic.c | 9 ++++++++-
2 files changed, 9 insertions(+), 1 deletion(-)

diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
index 2b8ee90..7b15c94 100644
--- a/Documentation/admin-guide/kernel-parameters.txt
+++ b/Documentation/admin-guide/kernel-parameters.txt
@@ -3135,6 +3135,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/kernel/panic.c b/kernel/panic.c
index fb77e01..afe023e 100644
--- a/kernel/panic.c
+++ b/kernel/panic.c
@@ -51,6 +51,7 @@ EXPORT_SYMBOL_GPL(panic_timeout);
#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);
@@ -134,6 +135,13 @@ EXPORT_SYMBOL(nmi_panic);

static void panic_print_sys_info(void)
{
+ bool flush_all_dmesg = false;
+
+ if (panic_print & PANIC_PRINT_ALL_PRINTK_MSG)
+ flush_all_dmesg = true;
+
+ console_flush_on_panic(flush_all_dmesg);
+
if (panic_print & PANIC_PRINT_TASK_INFO)
show_state();

@@ -277,7 +285,6 @@ void panic(const char *fmt, ...)
* panic() is not being callled from OOPS.
*/
debug_locks_off();
- console_flush_on_panic(false);

panic_print_sys_info();

--
2.7.4

2019-04-01 11:52:01

by Mukesh Ojha

[permalink] [raw]
Subject: Re: [PATCH 1/2] printk: Add an option to flush all messages on panic


On 4/1/2019 4:18 PM, Feng Tang wrote:
> Current console_flush_on_panic() will only dump the new messages
> in buffer, and users may need an opportunity to check all the
> messages on panic which could help debugging, as user may haven't
> seen the log before panic due to loglevel settings.
>
> Add a flag for console_flush_on_panic() to chose whether to
> dump all messages.
>
> Signed-off-by: Feng Tang <[email protected]>


Looks good to me.


But, Will it not be good if put it under a config and not change the
prototype, as it is a debug feature?

Thanks,
Mukesh

> ---
> arch/powerpc/kernel/traps.c | 2 +-
> include/linux/console.h | 2 +-
> kernel/panic.c | 2 +-
> kernel/printk/printk.c | 9 ++++++++-
> 4 files changed, 11 insertions(+), 4 deletions(-)
>
> diff --git a/arch/powerpc/kernel/traps.c b/arch/powerpc/kernel/traps.c
> index 1fd45a8..58d9580 100644
> --- a/arch/powerpc/kernel/traps.c
> +++ b/arch/powerpc/kernel/traps.c
> @@ -179,7 +179,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(false);
> }
>
> static unsigned long oops_begin(struct pt_regs *regs)
> diff --git a/include/linux/console.h b/include/linux/console.h
> index ec9bdb3..825ecf5 100644
> --- a/include/linux/console.h
> +++ b/include/linux/console.h
> @@ -175,7 +175,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(bool flush_all);
> 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 0ae0d73..fb77e01 100644
> --- a/kernel/panic.c
> +++ b/kernel/panic.c
> @@ -277,7 +277,7 @@ void panic(const char *fmt, ...)
> * panic() is not being callled from OOPS.
> */
> debug_locks_off();
> - console_flush_on_panic();
> + console_flush_on_panic(false);
>
> panic_print_sys_info();
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 02ca827..8ff099b 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2525,10 +2525,11 @@ void console_unblank(void)
>
> /**
> * console_flush_on_panic - flush console content on panic
> + * @flush_all: whether to print all messages in buffer
> *
> * Immediately output all pending messages no matter what.
> */
> -void console_flush_on_panic(void)
> +void console_flush_on_panic(bool flush_all)
> {
> /*
> * If someone else is holding the console lock, trylock will fail
> @@ -2539,6 +2540,12 @@ void console_flush_on_panic(void)
> */
> console_trylock();
> console_may_schedule = 0;
> +
> + /* User may want to see all the printk messages on panic */
> + if (flush_all) {
> + console_seq = log_first_seq;
> + console_idx = log_first_idx;
> + }
> console_unlock();
> }
>

2019-04-02 02:16:44

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH 1/2] printk: Add an option to flush all messages on panic

On (04/01/19 18:48), Feng Tang wrote:
> diff --git a/arch/powerpc/kernel/traps.c b/arch/powerpc/kernel/traps.c
> index 1fd45a8..58d9580 100644
> --- a/arch/powerpc/kernel/traps.c
> +++ b/arch/powerpc/kernel/traps.c
> @@ -179,7 +179,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(false);
> }
[..]
> @@ -277,7 +277,7 @@ void panic(const char *fmt, ...)
> * panic() is not being callled from OOPS.
> */
> debug_locks_off();
> - console_flush_on_panic();
> + console_flush_on_panic(false);
[..]
> -void console_flush_on_panic(void)
> +void console_flush_on_panic(bool flush_all)
> {
> /*
> * If someone else is holding the console lock, trylock will fail
> @@ -2539,6 +2540,12 @@ void console_flush_on_panic(void)
> */
> console_trylock();
> console_may_schedule = 0;
> +
> + /* User may want to see all the printk messages on panic */
> + if (flush_all) {
> + console_seq = log_first_seq;
> + console_idx = log_first_idx;
> + }
> console_unlock();

So my first thought was - let's not add a `bool flag', but instead add
an `enum' with clear flag names, e.g. DUMP_ALL/DUMP_PENDING, etc. Something
similar to what ftrace_dump(DUMP_ALL) does. And we already have panic_print
bit-mask and panic_print_sys_info(), which controls what we print when in
panic. So we can move console_flush_on_panic() to panic_print_sys_info()
and handle different types of console_flush_on_panic() there:

---

diff --git a/kernel/panic.c b/kernel/panic.c
index 0ae0d7332f12..e142faaebbcd 100644
--- a/kernel/panic.c
+++ b/kernel/panic.c
@@ -134,6 +134,11 @@ EXPORT_SYMBOL(nmi_panic);

static void panic_print_sys_info(void)
{
+ if (panic_print & PANIC_PRINT_REPLAY_LOGBUF)
+ console_flush_on_panic(DUMP_ALL);
+ else
+ console_flush_on_panic(DUMP_PENDING);
+
if (panic_print & PANIC_PRINT_TASK_INFO)
show_state();

@@ -277,7 +282,6 @@ void panic(const char *fmt, ...)
* panic() is not being callled from OOPS.
*/
debug_locks_off();
- console_flush_on_panic();

panic_print_sys_info();

---

After looking at this more - DUMP_ALL/DUMP_PENDING clearly depend
on panic_print. So... May be we can move panic_print_sys_info() to
printk.c, and for PANIC_PRINT_REPLAY_LOGBUF case just reset console
seq/idx (console seq/idx are internal to printk) before we
flush_on_panic. This way we would not need to modify
console_flush_on_panic() prototype at all.

Let's hear from people.

-ss

2019-04-02 02:26:32

by Feng Tang

[permalink] [raw]
Subject: Re: [PATCH 1/2] printk: Add an option to flush all messages on panic

Hi Sergey,

Thanks for the review.

On Tue, Apr 02, 2019 at 11:14:19AM +0900, Sergey Senozhatsky wrote:
> On (04/01/19 18:48), Feng Tang wrote:
> > diff --git a/arch/powerpc/kernel/traps.c b/arch/powerpc/kernel/traps.c
> > index 1fd45a8..58d9580 100644
> > --- a/arch/powerpc/kernel/traps.c
> > +++ b/arch/powerpc/kernel/traps.c
> > @@ -179,7 +179,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(false);
> > }
> [..]
> > @@ -277,7 +277,7 @@ void panic(const char *fmt, ...)
> > * panic() is not being callled from OOPS.
> > */
> > debug_locks_off();
> > - console_flush_on_panic();
> > + console_flush_on_panic(false);
> [..]
> > -void console_flush_on_panic(void)
> > +void console_flush_on_panic(bool flush_all)
> > {
> > /*
> > * If someone else is holding the console lock, trylock will fail
> > @@ -2539,6 +2540,12 @@ void console_flush_on_panic(void)
> > */
> > console_trylock();
> > console_may_schedule = 0;
> > +
> > + /* User may want to see all the printk messages on panic */
> > + if (flush_all) {
> > + console_seq = log_first_seq;
> > + console_idx = log_first_idx;
> > + }
> > console_unlock();
>
> So my first thought was - let's not add a `bool flag', but instead add
> an `enum' with clear flag names, e.g. DUMP_ALL/DUMP_PENDING, etc. Something
> similar to what ftrace_dump(DUMP_ALL) does. And we already have panic_print
> bit-mask and panic_print_sys_info(), which controls what we print when in
> panic. So we can move console_flush_on_panic() to panic_print_sys_info()
> and handle different types of console_flush_on_panic() there:
>
> ---
>
> diff --git a/kernel/panic.c b/kernel/panic.c
> index 0ae0d7332f12..e142faaebbcd 100644
> --- a/kernel/panic.c
> +++ b/kernel/panic.c
> @@ -134,6 +134,11 @@ EXPORT_SYMBOL(nmi_panic);
>
> static void panic_print_sys_info(void)
> {
> + if (panic_print & PANIC_PRINT_REPLAY_LOGBUF)
> + console_flush_on_panic(DUMP_ALL);
> + else
> + console_flush_on_panic(DUMP_PENDING);
> +
> if (panic_print & PANIC_PRINT_TASK_INFO)
> show_state();
>
> @@ -277,7 +282,6 @@ void panic(const char *fmt, ...)
> * panic() is not being callled from OOPS.
> */
> debug_locks_off();
> - console_flush_on_panic();
>
> panic_print_sys_info();
>

I guess this is what my 2/2 patch exactly does :)


> ---
>
> After looking at this more - DUMP_ALL/DUMP_PENDING clearly depend
> on panic_print. So... May be we can move panic_print_sys_info() to
> printk.c, and for PANIC_PRINT_REPLAY_LOGBUF case just reset console
> seq/idx (console seq/idx are internal to printk) before we
> flush_on_panic. This way we would not need to modify
> console_flush_on_panic() prototype at all.

My thought is panic_print_sys_info() may be more related to panic, but
I'm fine with either way.

Thanks,
Feng

>
> Let's hear from people.
>
> -ss

2019-04-02 02:31:18

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH 1/2] printk: Add an option to flush all messages on panic

On (04/02/19 10:28), Feng Tang wrote:
> > So my first thought was - let's not add a `bool flag', but instead add
> > an `enum' with clear flag names, e.g. DUMP_ALL/DUMP_PENDING, etc. Something
> > similar to what ftrace_dump(DUMP_ALL) does. And we already have panic_print
> > bit-mask and panic_print_sys_info(), which controls what we print when in
> > panic. So we can move console_flush_on_panic() to panic_print_sys_info()
> > and handle different types of console_flush_on_panic() there:
> >
> > ---
> >
> > diff --git a/kernel/panic.c b/kernel/panic.c
> > index 0ae0d7332f12..e142faaebbcd 100644
> > --- a/kernel/panic.c
> > +++ b/kernel/panic.c
> > @@ -134,6 +134,11 @@ EXPORT_SYMBOL(nmi_panic);
> >
> > static void panic_print_sys_info(void)
> > {
> > + if (panic_print & PANIC_PRINT_REPLAY_LOGBUF)
> > + console_flush_on_panic(DUMP_ALL);
> > + else
> > + console_flush_on_panic(DUMP_PENDING);
> > +
> > if (panic_print & PANIC_PRINT_TASK_INFO)
> > show_state();
> >
> > @@ -277,7 +282,6 @@ void panic(const char *fmt, ...)
> > * panic() is not being callled from OOPS.
> > */
> > debug_locks_off();
> > - console_flush_on_panic();
> >
> > panic_print_sys_info();
> >
>
> I guess this is what my 2/2 patch exactly does :)

Oh, indeed... I didn't check 2/2.

-ss

2019-04-02 03:16:29

by Feng Tang

[permalink] [raw]
Subject: Re: [PATCH 1/2] printk: Add an option to flush all messages on panic

Hi Mukesh,

On Mon, Apr 01, 2019 at 05:20:33PM +0530, Mukesh Ojha wrote:
>
> On 4/1/2019 4:18 PM, Feng Tang wrote:
> > Current console_flush_on_panic() will only dump the new messages
> > in buffer, and users may need an opportunity to check all the
> > messages on panic which could help debugging, as user may haven't
> > seen the log before panic due to loglevel settings.
> >
> > Add a flag for console_flush_on_panic() to chose whether to
> > dump all messages.
> >
> > Signed-off-by: Feng Tang <[email protected]>
>
>
> Looks good to me.

Thanks for the review.

>
>
> But, Will it not be good if put it under a config and not change the
> prototype, as it is a debug feature?

My understanding is the console_flush_on_panic() is also a debug
feature too :), and my 2/2 patch will has a bitmask (either controlled
by kernel cmdline or sysctl) to turn on this.

Thanks,
Feng


>
> Thanks,
> Mukesh
>
> > ---
> > arch/powerpc/kernel/traps.c | 2 +-
> > include/linux/console.h | 2 +-
> > kernel/panic.c | 2 +-
> > kernel/printk/printk.c | 9 ++++++++-
> > 4 files changed, 11 insertions(+), 4 deletions(-)
> >
> > diff --git a/arch/powerpc/kernel/traps.c b/arch/powerpc/kernel/traps.c
> > index 1fd45a8..58d9580 100644
> > --- a/arch/powerpc/kernel/traps.c
> > +++ b/arch/powerpc/kernel/traps.c
> > @@ -179,7 +179,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(false);
> > }
> > static unsigned long oops_begin(struct pt_regs *regs)
> > diff --git a/include/linux/console.h b/include/linux/console.h
> > index ec9bdb3..825ecf5 100644
> > --- a/include/linux/console.h
> > +++ b/include/linux/console.h
> > @@ -175,7 +175,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(bool flush_all);
> > 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 0ae0d73..fb77e01 100644
> > --- a/kernel/panic.c
> > +++ b/kernel/panic.c
> > @@ -277,7 +277,7 @@ void panic(const char *fmt, ...)
> > * panic() is not being callled from OOPS.
> > */
> > debug_locks_off();
> > - console_flush_on_panic();
> > + console_flush_on_panic(false);
> > panic_print_sys_info();
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index 02ca827..8ff099b 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -2525,10 +2525,11 @@ void console_unblank(void)
> > /**
> > * console_flush_on_panic - flush console content on panic
> > + * @flush_all: whether to print all messages in buffer
> > *
> > * Immediately output all pending messages no matter what.
> > */
> > -void console_flush_on_panic(void)
> > +void console_flush_on_panic(bool flush_all)
> > {
> > /*
> > * If someone else is holding the console lock, trylock will fail
> > @@ -2539,6 +2540,12 @@ void console_flush_on_panic(void)
> > */
> > console_trylock();
> > console_may_schedule = 0;
> > +
> > + /* User may want to see all the printk messages on panic */
> > + if (flush_all) {
> > + console_seq = log_first_seq;
> > + console_idx = log_first_idx;
> > + }
> > console_unlock();
> > }

2019-04-09 13:42:48

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH 1/2] printk: Add an option to flush all messages on panic

On Tue 2019-04-02 11:29:00, Sergey Senozhatsky wrote:
> On (04/02/19 10:28), Feng Tang wrote:
> > > So my first thought was - let's not add a `bool flag', but instead add
> > > an `enum' with clear flag names, e.g. DUMP_ALL/DUMP_PENDING, etc. Something
> > > similar to what ftrace_dump(DUMP_ALL) does. And we already have panic_print
> > > bit-mask and panic_print_sys_info(), which controls what we print when in
> > > panic. So we can move console_flush_on_panic() to panic_print_sys_info()
> > > and handle different types of console_flush_on_panic() there:
> > >
> > > ---
> > >
> > > diff --git a/kernel/panic.c b/kernel/panic.c
> > > index 0ae0d7332f12..e142faaebbcd 100644
> > > --- a/kernel/panic.c
> > > +++ b/kernel/panic.c
> > > @@ -134,6 +134,11 @@ EXPORT_SYMBOL(nmi_panic);
> > >
> > > static void panic_print_sys_info(void)
> > > {
> > > + if (panic_print & PANIC_PRINT_REPLAY_LOGBUF)
> > > + console_flush_on_panic(DUMP_ALL);
> > > + else
> > > + console_flush_on_panic(DUMP_PENDING);
> > > +
> > > if (panic_print & PANIC_PRINT_TASK_INFO)
> > > show_state();
> > >
> > > @@ -277,7 +282,6 @@ void panic(const char *fmt, ...)
> > > * panic() is not being callled from OOPS.
> > > */
> > > debug_locks_off();
> > > - console_flush_on_panic();
> > >
> > > panic_print_sys_info();
> > >
> >
> > I guess this is what my 2/2 patch exactly does :)
>
> Oh, indeed... I didn't check 2/2.

I suggest to merge the two patches into one. It will
still be rather small and easier to review.

Best Regards,
Petr

2019-04-09 14:15:31

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH 2/2] panic: Enable to print out all printk msg in buffer

On Mon 2019-04-01 18:48:04, Feng Tang wrote:
> Currently on panic, kernel will lower the loglevel and print out
> new printk msg only. With this patch, user can configure the
> "panic_print" to see all dmesg in buffer, some of which they may
> have never seen due to the loglevel setting.
>
> Signed-off-by: Feng Tang <[email protected]>
> ---
> Documentation/admin-guide/kernel-parameters.txt | 1 +
> kernel/panic.c | 9 ++++++++-
> 2 files changed, 9 insertions(+), 1 deletion(-)
>
> diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
> index 2b8ee90..7b15c94 100644
> --- a/Documentation/admin-guide/kernel-parameters.txt
> +++ b/Documentation/admin-guide/kernel-parameters.txt
> @@ -3135,6 +3135,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/kernel/panic.c b/kernel/panic.c
> index fb77e01..afe023e 100644
> --- a/kernel/panic.c
> +++ b/kernel/panic.c
> @@ -51,6 +51,7 @@ EXPORT_SYMBOL_GPL(panic_timeout);
> #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);
> @@ -134,6 +135,13 @@ EXPORT_SYMBOL(nmi_panic);
>
> static void panic_print_sys_info(void)
> {
> + bool flush_all_dmesg = false;
> +
> + if (panic_print & PANIC_PRINT_ALL_PRINTK_MSG)
> + flush_all_dmesg = true;
> +
> + console_flush_on_panic(flush_all_dmesg);

We should:

+ Flush the latest messages before we replay the log.

+ Show some header line before replaing the log.


Therefore, I would keep console_flush_on_panic() as is.
Then I would add:

int console_replay;

void console_replay_on_panic(void)
{
/*
* If someone else is holding the console lock, trylock will fail
* and may_schedule may be set. Ignore and proceed to unlock so
* that messages are flushed out. As this can be called from any
* context and we don't want to get preempted while flushing,
* ensure may_schedule is cleared.
*/
console_trylock();
console_may_schedule = 0;
console_replay = 1;
console_unlock();
}

Then I would update cosole_unlock() with something like:

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 02ca827b8fac..14ef4e2431e7 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2386,21 +2386,32 @@ void console_unlock(void)

for (;;) {
struct printk_log *msg;
+ int reset_idx = 0;
size_t ext_len = 0;
- size_t len;
+ size_t len = 0;

printk_safe_enter_irqsave(flags);
raw_spin_lock(&logbuf_lock);
+
if (console_seq < log_first_seq) {
len = sprintf(text,
"** %llu printk messages dropped **\n",
log_first_seq - console_seq);

/* messages are gone, move to first one */
+ reset_idx = 1;
+ }
+
+ if (console_replay) {
+ len += sprintf(text + len,
+ "Replaying the entire log:\n");
+ reset_idx = 1;
+ console_replay = 0;
+ }
+
+ if (reset_idx) {
console_seq = log_first_seq;
console_idx = log_first_idx;
- } else {
- len = 0;
}
skip:
if (console_seq == log_next_seq)


Finally, it can get called from panic_print_sys_info(void)
the following way:

/* Replay existing messages before adding other sys info. */
if (panic_print & PANIC_PRINT_ALL_PRINTK_MSG)
console_replay_on_panic();



Best Regards,
Petr

2019-04-10 01:48:11

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH 1/2] printk: Add an option to flush all messages on panic

On (04/09/19 15:41), Petr Mladek wrote:
> I suggest to merge the two patches into one. It will
> still be rather small and easier to review.

Agreed, was going to suggest the same.

-ss

2019-04-10 02:00:34

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH 2/2] panic: Enable to print out all printk msg in buffer

On (04/09/19 16:14), Petr Mladek wrote:
> We should:
>
> + Flush the latest messages before we replay the log.

Do you mean the pending messages? When we replay the log we also should
print "header line" and panic-cpu backtrace. So we will print panic-cpu
oops twice

// from panic-cpu flush_on_panic
[header]
backtrace
[end of header]

// from console_replay
then all logbuf messages
and then the same header/backtrace one more time

[header]
backtrace]
[end of backtrace]

Is there any particular reason to flush pending messages before
we play the buffer? Replaying the logbuf can take some time, so
my guess would be that you want to print panic-cpu backtrace as
soon as possible. Is there something else?

[..]
> Then I would update cosole_unlock() with something like:
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 02ca827b8fac..14ef4e2431e7 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2386,21 +2386,32 @@ void console_unlock(void)
>
> for (;;) {
> struct printk_log *msg;
> + int reset_idx = 0;
> size_t ext_len = 0;
> - size_t len;
> + size_t len = 0;
>
> printk_safe_enter_irqsave(flags);
> raw_spin_lock(&logbuf_lock);
> +
> if (console_seq < log_first_seq) {
> len = sprintf(text,
> "** %llu printk messages dropped **\n",
> log_first_seq - console_seq);
>
> /* messages are gone, move to first one */
> + reset_idx = 1;
> + }
> +
> + if (console_replay) {
> + len += sprintf(text + len,
> + "Replaying the entire log:\n");
> + reset_idx = 1;
> + console_replay = 0;
> + }
> +
> + if (reset_idx) {
> console_seq = log_first_seq;
> console_idx = log_first_idx;
> - } else {
> - len = 0;
> }

The printing loop becomes a bit complex with one more state, I should
say; but can do. We handle exclusive consoles there, dropped messages,
panic reset. But I see what you are trying to do.

-ss

2019-04-10 02:20:39

by Feng Tang

[permalink] [raw]
Subject: Re: [PATCH 1/2] printk: Add an option to flush all messages on panic

Hi Petr and Sergey,

On Wed, Apr 10, 2019 at 10:47:05AM +0900, Sergey Senozhatsky wrote:
> On (04/09/19 15:41), Petr Mladek wrote:
> > I suggest to merge the two patches into one. It will
> > still be rather small and easier to review.
>
> Agreed, was going to suggest the same.

Ok, will merge. Splitting to 2 patches did confuse people.

Thanks,
Feng

2019-04-10 08:08:19

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH 2/2] panic: Enable to print out all printk msg in buffer

On Wed 2019-04-10 10:59:26, Sergey Senozhatsky wrote:
> On (04/09/19 16:14), Petr Mladek wrote:
> > We should:
> >
> > + Flush the latest messages before we replay the log.
>
> Do you mean the pending messages? When we replay the log we also should
> print "header line" and panic-cpu backtrace. So we will print panic-cpu
> oops twice

console_flush_on_panic() is just the last resort. I believe
that the panic header and backtrace reach the console even
without it in most cases. Explicit flush before reply
would just make it consistent.

> // from panic-cpu flush_on_panic
> [header]
> backtrace
> [end of header]
>
> // from console_replay
> then all logbuf messages
> and then the same header/backtrace one more time
>
> [header]
> backtrace]
> [end of backtrace]
>
> Is there any particular reason to flush pending messages before
> we play the buffer? Replaying the logbuf can take some time, so
> my guess would be that you want to print panic-cpu backtrace as
> soon as possible. Is there something else?

The panic() message is usually the most important one for debugging.
I feel a bit uneasy that we would delay it until full replay that
might get killed from several reasons:

+ external monitoring system would force reboot

+ user might realize, e.g. after 20 minutes, that the full
log reply was probably not worth it.

I understand that people enabling this option would most likely
wait but still. I do not see it as a big deal to repeat
the messages.

Best Regards,
Petr

2019-04-10 09:18:59

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH 2/2] panic: Enable to print out all printk msg in buffer

On (04/10/19 10:02), Petr Mladek wrote:
> On Wed 2019-04-10 10:59:26, Sergey Senozhatsky wrote:
> > On (04/09/19 16:14), Petr Mladek wrote:
> > > We should:
> > >
> > > + Flush the latest messages before we replay the log.
> >
> > Do you mean the pending messages? When we replay the log we also should
> > print "header line" and panic-cpu backtrace. So we will print panic-cpu
> > oops twice
>
> console_flush_on_panic() is just the last resort. I believe
> that the panic header and backtrace reach the console even
> without it in most cases. Explicit flush before reply
> would just make it consistent.

I would agree. On big systems console_sem is usually unlocked (no fbcon,
no DRI, no tty writers, etc.) On desktops, laptops, and embedded device,
however, killing the kernel with console_sem locked is not entirely
uncommon.

> The panic() message is usually the most important one for debugging.
> I feel a bit uneasy that we would delay it until full replay that
> might get killed from several reasons:
>
> + external monitoring system would force reboot
>
> + user might realize, e.g. after 20 minutes, that the full
> log reply was probably not worth it.
>
> I understand that people enabling this option would most likely
> wait but still. I do not see it as a big deal to repeat
> the messages.

Well, OK, this sounds reasonable. At the same time this option
depends on panic_print, which is probably debugging option anyway
and panic_print output can get a bit large and time consuming, so
maybe external monitors are not part of the picture when panic_print
is used. But no real objections; need to make sure that no one else,
except panic, will ever use that new symbol.

-ss

2019-04-10 10:25:25

by Feng Tang

[permalink] [raw]
Subject: Re: [PATCH 2/2] panic: Enable to print out all printk msg in buffer

Hi Petr,

On Tue, Apr 09, 2019 at 04:14:30PM +0200, Petr Mladek wrote:
> On Mon 2019-04-01 18:48:04, Feng Tang wrote:
> > Currently on panic, kernel will lower the loglevel and print out
> > new printk msg only. With this patch, user can configure the
> > "panic_print" to see all dmesg in buffer, some of which they may
> > have never seen due to the loglevel setting.
> >
> > Signed-off-by: Feng Tang <[email protected]>
> > ---
> > diff --git a/kernel/panic.c b/kernel/panic.c
> > index fb77e01..afe023e 100644
> > --- a/kernel/panic.c
> > +++ b/kernel/panic.c
> > @@ -51,6 +51,7 @@ EXPORT_SYMBOL_GPL(panic_timeout);
> > #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);
> > @@ -134,6 +135,13 @@ EXPORT_SYMBOL(nmi_panic);
> >
> > static void panic_print_sys_info(void)
> > {
> > + bool flush_all_dmesg = false;
> > +
> > + if (panic_print & PANIC_PRINT_ALL_PRINTK_MSG)
> > + flush_all_dmesg = true;
> > +
> > + console_flush_on_panic(flush_all_dmesg);
>
> We should:
>
> + Flush the latest messages before we replay the log.
>
> + Show some header line before replaing the log.
>
>
> Therefore, I would keep console_flush_on_panic() as is.
> Then I would add:
>
> int console_replay;
>
> void console_replay_on_panic(void)
> {
> /*
> * If someone else is holding the console lock, trylock will fail
> * and may_schedule may be set. Ignore and proceed to unlock so
> * that messages are flushed out. As this can be called from any
> * context and we don't want to get preempted while flushing,
> * ensure may_schedule is cleared.
> */
> console_trylock();
> console_may_schedule = 0;
> console_replay = 1;
> console_unlock();
> }

Many thanks for the review and detailed sample codes.

Your code of moving the console_seq and console_index changing
code into concole_unlock() is much safer, which is protected by
the locl.

Initially I thought of adding a new function similar to this, but
was afraid that it is too similar to the console_flush_on_panic() :)

>
> Then I would update cosole_unlock() with something like:
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 02ca827b8fac..14ef4e2431e7 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2386,21 +2386,32 @@ void console_unlock(void)
>
> for (;;) {
> struct printk_log *msg;
> + int reset_idx = 0;
> size_t ext_len = 0;
> - size_t len;
> + size_t len = 0;
>
> printk_safe_enter_irqsave(flags);
> raw_spin_lock(&logbuf_lock);
> +
> if (console_seq < log_first_seq) {
> len = sprintf(text,
> "** %llu printk messages dropped **\n",
> log_first_seq - console_seq);
>
> /* messages are gone, move to first one */
> + reset_idx = 1;
> + }
> +
> + if (console_replay) {
> + len += sprintf(text + len,
> + "Replaying the entire log:\n");
> + reset_idx = 1;
> + console_replay = 0;
> + }
> +
> + if (reset_idx) {
> console_seq = log_first_seq;
> console_idx = log_first_idx;
> - } else {
> - len = 0;
> }
> skip:
> if (console_seq == log_next_seq)
>
>
> Finally, it can get called from panic_print_sys_info(void)
> the following way:
>
> /* Replay existing messages before adding other sys info. */
> if (panic_print & PANIC_PRINT_ALL_PRINTK_MSG)
> console_replay_on_panic();

Yes, it should be the first inside panic_print_sys_info().

Thanks,
Feng