[PATCH v3 0/2] Add support to dump printk buffer to console via sysrq

[PATCH v3 0/2] Add support to dump printk buffer to console via sysrq

[Sreenath Vijayan]

Hi,

This patch series does two things:

1) Add function to dump the printk buffer messages directly to
consoles. To do this properly, access to printk private items
like PRINTK_MESSAGE_MAX is required. So, the function is
implemented in printk.c as suggested by John Ogness. This
function may sleep as it needs console related locks.

2) Add code in sysrq.c to call the above mentioned function
when sysrq+D is pressed. As the above function may sleep,
it cannot be called from interrupt context. A work is queued
in the system unbound workqueue to call the function when
the key is pressed.

Link to previous discussion:
- https://lore.kernel.org/linux-serial/20231221133953.1507021-1-sreenath.vijayan@sony.com/

Changelog:
V2 -> V3:
- split the implementation into two commits
- added function in printk.c to dump printk buffer to consoles
- added Suggested-by tag
- removed code to dump printk buffer from sysrq.c and called
  new function

V1 -> V2:
- modified kernel ring buffer to printk ring buffer
- allocated buf dynamically to prevent stack frame size warnings
- used buf of size 2048 to match PRINTK_MESSAGE_MAX and added comment

-- Sreenath

Sreenath Vijayan (2):
  printk: Add function to dump printk buffer directly to consoles
  tty/sysrq: Dump printk ring buffer messages via sysrq

 Documentation/admin-guide/sysrq.rst |  2 ++
 drivers/tty/sysrq.c                 | 20 ++++++++++++++++-
 include/linux/printk.h              |  4 ++++
 kernel/printk/printk.c              | 33 +++++++++++++++++++++++++++++
 4 files changed, 58 insertions(+), 1 deletion(-)

-- 
2.43.0

[PATCH v3 1/2] printk: Add function to dump printk buffer directly to consoles

[Sreenath Vijayan]

It is useful to be able to dump the printk buffer directly to
consoles in some situations so as to not flood the buffer.
This needs access to private items of printk like PRINTK_MESSAGE_MAX.
Add function in printk.c to accomplish this.

Suggested-by: John Ogness <john.ogness@linutronix.de>
Signed-off-by: Sreenath Vijayan <sreenath.vijayan@sony.com>
Signed-off-by: Shimoyashiki Taichi <taichi.shimoyashiki@sony.com>
---
 include/linux/printk.h |  4 ++++
 kernel/printk/printk.c | 33 +++++++++++++++++++++++++++++++++
 2 files changed, 37 insertions(+)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index 8ef499ab3c1e..0896745f31e2 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -192,6 +192,7 @@ void show_regs_print_info(const char *log_lvl);
 extern asmlinkage void dump_stack_lvl(const char *log_lvl) __cold;
 extern asmlinkage void dump_stack(void) __cold;
 void printk_trigger_flush(void);
+void dump_printk_buffer(void);
 #else
 static inline __printf(1, 0)
 int vprintk(const char *s, va_list args)
@@ -271,6 +272,9 @@ static inline void dump_stack(void)
 static inline void printk_trigger_flush(void)
 {
 }
+static inline void dump_printk_buffer(void)
+{
+}
 #endif
 
 #ifdef CONFIG_SMP
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index f2444b581e16..5b11fb377f8f 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -4259,6 +4259,39 @@ void kmsg_dump_rewind(struct kmsg_dump_iter *iter)
 }
 EXPORT_SYMBOL_GPL(kmsg_dump_rewind);
 
+/**
+ * Dump the printk ring buffer directly to consoles
+ */
+void dump_printk_buffer(void)
+{
+	struct kmsg_dump_iter iter;
+	struct console *con;
+	char *buf;
+	size_t len;
+	int cookie;
+
+	buf = kmalloc(PRINTK_MESSAGE_MAX, GFP_KERNEL);
+	if (!buf)
+		return;
+
+	kmsg_dump_rewind(&iter);
+	while (kmsg_dump_get_line(&iter, 1, buf, PRINTK_MESSAGE_MAX, &len)) {
+		/*
+		 * Since using printk() or pr_*() will append the message to the
+		 * printk ring buffer, they cannot be used to display the retrieved
+		 * message. Hence console_write() of serial drivers is used.
+		 */
+		console_lock();
+		cookie = console_srcu_read_lock();
+		for_each_console_srcu(con) {
+			if ((console_srcu_read_flags(con) & CON_ENABLED) && con->write)
+				con->write(con, buf, len);
+		}
+		console_srcu_read_unlock(cookie);
+		console_unlock();
+	}
+	kfree(buf);
+}
 #endif
 
 #ifdef CONFIG_SMP
-- 
2.43.0

Re: [PATCH v3 1/2] printk: Add function to dump printk buffer directly to consoles

[John Ogness]

On 2024-01-17, Sreenath Vijayan <sreenath.vijayan@sony.com> wrote:
> It is useful to be able to dump the printk buffer directly to
> consoles in some situations so as to not flood the buffer.
> This needs access to private items of printk like PRINTK_MESSAGE_MAX.
> Add function in printk.c to accomplish this.
>
> Suggested-by: John Ogness <john.ogness@linutronix.de>
> Signed-off-by: Sreenath Vijayan <sreenath.vijayan@sony.com>
> Signed-off-by: Shimoyashiki Taichi <taichi.shimoyashiki@sony.com>
> ---
>  include/linux/printk.h |  4 ++++
>  kernel/printk/printk.c | 33 +++++++++++++++++++++++++++++++++
>  2 files changed, 37 insertions(+)
>
> diff --git a/include/linux/printk.h b/include/linux/printk.h
> index 8ef499ab3c1e..0896745f31e2 100644
> --- a/include/linux/printk.h
> +++ b/include/linux/printk.h
> @@ -192,6 +192,7 @@ void show_regs_print_info(const char *log_lvl);
>  extern asmlinkage void dump_stack_lvl(const char *log_lvl) __cold;
>  extern asmlinkage void dump_stack(void) __cold;
>  void printk_trigger_flush(void);
> +void dump_printk_buffer(void);
>  #else
>  static inline __printf(1, 0)
>  int vprintk(const char *s, va_list args)
> @@ -271,6 +272,9 @@ static inline void dump_stack(void)
>  static inline void printk_trigger_flush(void)
>  {
>  }
> +static inline void dump_printk_buffer(void)
> +{
> +}
>  #endif
>  
>  #ifdef CONFIG_SMP
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index f2444b581e16..5b11fb377f8f 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -4259,6 +4259,39 @@ void kmsg_dump_rewind(struct kmsg_dump_iter *iter)
>  }
>  EXPORT_SYMBOL_GPL(kmsg_dump_rewind);
>  
> +/**
> + * Dump the printk ring buffer directly to consoles
> + */
> +void dump_printk_buffer(void)
> +{
> +	struct kmsg_dump_iter iter;
> +	struct console *con;
> +	char *buf;
> +	size_t len;
> +	int cookie;
> +
> +	buf = kmalloc(PRINTK_MESSAGE_MAX, GFP_KERNEL);
> +	if (!buf)
> +		return;
> +
> +	kmsg_dump_rewind(&iter);
> +	while (kmsg_dump_get_line(&iter, 1, buf, PRINTK_MESSAGE_MAX, &len)) {

Although using the kmsg_dump interface will provide you the messages,
they will not necessarily be in the correct format. Consoles can be set
to use extended format.

We probably should respect that console setting.

> +		/*
> +		 * Since using printk() or pr_*() will append the message to the
> +		 * printk ring buffer, they cannot be used to display the retrieved
> +		 * message. Hence console_write() of serial drivers is used.
> +		 */
> +		console_lock();
> +		cookie = console_srcu_read_lock();
> +		for_each_console_srcu(con) {
> +			if ((console_srcu_read_flags(con) & CON_ENABLED) && con->write)

console_is_usable() should be used instead. It makes the correct checks.

> +				con->write(con, buf, len);
> +		}
> +		console_srcu_read_unlock(cookie);
> +		console_unlock();
> +	}
> +	kfree(buf);
> +}

We could do something like this:

void dump_printk_buffer(void)
{
	console_lock();
	console_flush_on_panic(CONSOLE_REPLAY_ALL);
	console_unlock();
}

This version respects all the console features (formatting, handovers),
but console_flush_on_panic() does not to allow cond_resched(), which we
would want in this case.

We could take the console sequence-resetting code out into its own
helper function. Then it would look like this (comments removed to keep
things short):

static void console_rewind_all(void)
{
	struct console *c;
	short flags;
	int cookie;
	u64 seq;

	seq = prb_first_valid_seq(prb);

	cookie = console_srcu_read_lock();
	for_each_console_srcu(c) {
		flags = console_srcu_read_flags(c);

		if (flags & CON_NBCON)
			nbcon_seq_force(c, seq);
		else
			c->seq = seq;
	}
	console_srcu_read_unlock(cookie);
}

void console_flush_on_panic(enum con_flush_mode mode)
{
	bool handover;
	u64 next_seq;

	console_may_schedule = 0;

	if (mode == CONSOLE_REPLAY_ALL)
		console_rewind_all();

	console_flush_all(false, &next_seq, &handover);
}

void dump_printk_buffer(void)
{
	bool handover;
	u64 next_seq;

	console_lock();
	console_rewind_all();
	console_flush_all(true, &next_seq, &handover);
	console_unlock();
}

Any thoughts?

John

Re: [PATCH v3 1/2] printk: Add function to dump printk buffer directly to consoles

[John Ogness]

Oops, for the current mainline code it is actually even simpler because
the console_unlock() will perform the flushing:

void dump_printk_buffer(void)
{
 	console_lock();
 	console_rewind_all();
 	console_unlock();
}

John

Re: [PATCH v3 1/2] printk: Add function to dump printk buffer directly to consoles

[Sreenath Vijayan]

On Thu, Jan 18, 2024 at 10:55:20AM +0106, John Ogness wrote:
> On 2024-01-17, Sreenath Vijayan <sreenath.vijayan@sony.com> wrote:
> > It is useful to be able to dump the printk buffer directly to
> > consoles in some situations so as to not flood the buffer.
> > This needs access to private items of printk like PRINTK_MESSAGE_MAX.
> > Add function in printk.c to accomplish this.
> >
> > Suggested-by: John Ogness <john.ogness@linutronix.de>
> > Signed-off-by: Sreenath Vijayan <sreenath.vijayan@sony.com>
> > Signed-off-by: Shimoyashiki Taichi <taichi.shimoyashiki@sony.com>
> > ---
> >  include/linux/printk.h |  4 ++++
> >  kernel/printk/printk.c | 33 +++++++++++++++++++++++++++++++++
> >  2 files changed, 37 insertions(+)
> >
> > diff --git a/include/linux/printk.h b/include/linux/printk.h
> > index 8ef499ab3c1e..0896745f31e2 100644
> > --- a/include/linux/printk.h
> > +++ b/include/linux/printk.h
> > @@ -192,6 +192,7 @@ void show_regs_print_info(const char *log_lvl);
> >  extern asmlinkage void dump_stack_lvl(const char *log_lvl) __cold;
> >  extern asmlinkage void dump_stack(void) __cold;
> >  void printk_trigger_flush(void);
> > +void dump_printk_buffer(void);
> >  #else
> >  static inline __printf(1, 0)
> >  int vprintk(const char *s, va_list args)
> > @@ -271,6 +272,9 @@ static inline void dump_stack(void)
> >  static inline void printk_trigger_flush(void)
> >  {
> >  }
> > +static inline void dump_printk_buffer(void)
> > +{
> > +}
> >  #endif
> >  
> >  #ifdef CONFIG_SMP
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index f2444b581e16..5b11fb377f8f 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -4259,6 +4259,39 @@ void kmsg_dump_rewind(struct kmsg_dump_iter *iter)
> >  }
> >  EXPORT_SYMBOL_GPL(kmsg_dump_rewind);
> >  
> > +/**
> > + * Dump the printk ring buffer directly to consoles
> > + */
> > +void dump_printk_buffer(void)
> > +{
> > +	struct kmsg_dump_iter iter;
> > +	struct console *con;
> > +	char *buf;
> > +	size_t len;
> > +	int cookie;
> > +
> > +	buf = kmalloc(PRINTK_MESSAGE_MAX, GFP_KERNEL);
> > +	if (!buf)
> > +		return;
> > +
> > +	kmsg_dump_rewind(&iter);
> > +	while (kmsg_dump_get_line(&iter, 1, buf, PRINTK_MESSAGE_MAX, &len)) {
> 
> Although using the kmsg_dump interface will provide you the messages,
> they will not necessarily be in the correct format. Consoles can be set
> to use extended format.
> 
> We probably should respect that console setting.

Thank you for reviewing the patch and pointing out the limitations
of ksmg_dump interface.

> 
> > +		/*
> > +		 * Since using printk() or pr_*() will append the message to the
> > +		 * printk ring buffer, they cannot be used to display the retrieved
> > +		 * message. Hence console_write() of serial drivers is used.
> > +		 */
> > +		console_lock();
> > +		cookie = console_srcu_read_lock();
> > +		for_each_console_srcu(con) {
> > +			if ((console_srcu_read_flags(con) & CON_ENABLED) && con->write)
> 
> console_is_usable() should be used instead. It makes the correct checks.
>

Ok, noted.
 
> > +				con->write(con, buf, len);
> > +		}
> > +		console_srcu_read_unlock(cookie);
> > +		console_unlock();
> > +	}
> > +	kfree(buf);
> > +}
> 
> We could do something like this:
> 
> void dump_printk_buffer(void)
> {
> 	console_lock();
> 	console_flush_on_panic(CONSOLE_REPLAY_ALL);
> 	console_unlock();
> }
> 
> This version respects all the console features (formatting, handovers),
> but console_flush_on_panic() does not to allow cond_resched(), which we
> would want in this case.
> 
> We could take the console sequence-resetting code out into its own
> helper function. Then it would look like this (comments removed to keep
> things short):
> 
> static void console_rewind_all(void)
> {
> 	struct console *c;
> 	short flags;
> 	int cookie;
> 	u64 seq;
> 
> 	seq = prb_first_valid_seq(prb);
> 
> 	cookie = console_srcu_read_lock();
> 	for_each_console_srcu(c) {
> 		flags = console_srcu_read_flags(c);
> 
> 		if (flags & CON_NBCON)
> 			nbcon_seq_force(c, seq);
> 		else
> 			c->seq = seq;
> 	}
> 	console_srcu_read_unlock(cookie);
> }
> 
> void console_flush_on_panic(enum con_flush_mode mode)
> {
> 	bool handover;
> 	u64 next_seq;
> 
> 	console_may_schedule = 0;
> 
> 	if (mode == CONSOLE_REPLAY_ALL)
> 		console_rewind_all();
> 
> 	console_flush_all(false, &next_seq, &handover);
> }
> 
> void dump_printk_buffer(void)
> {
> 	bool handover;
> 	u64 next_seq;
> 
> 	console_lock();
> 	console_rewind_all();
> 	console_flush_all(true, &next_seq, &handover);
> 	console_unlock();
> }
> 
> Any thoughts?
> 
> John

Thank you for suggesting this new method. From initial tests,
this change looks ok. I will do more testing and send out the
next version.

Sreenath

[PATCH v3 2/2] tty/sysrq: Dump printk ring buffer messages via sysrq

[Sreenath Vijayan]

When terminal is unresponsive, one cannot use dmesg to view printk
ring buffer messages. Also, syslog services may be disabled,
to check the messages after a reboot, especially on embedded systems.
In this scenario, dump the printk ring buffer messages via sysrq
by pressing sysrq+D.

Signed-off-by: Sreenath Vijayan <sreenath.vijayan@sony.com>
Signed-off-by: Shimoyashiki Taichi <taichi.shimoyashiki@sony.com>
---
 Documentation/admin-guide/sysrq.rst |  2 ++
 drivers/tty/sysrq.c                 | 20 +++++++++++++++++++-
 2 files changed, 21 insertions(+), 1 deletion(-)

diff --git a/Documentation/admin-guide/sysrq.rst b/Documentation/admin-guide/sysrq.rst
index 51906e47327b..246a7b61a0eb 100644
--- a/Documentation/admin-guide/sysrq.rst
+++ b/Documentation/admin-guide/sysrq.rst
@@ -152,6 +152,8 @@ Command	    Function
             will be printed to your console. (``0``, for example would make
             it so that only emergency messages like PANICs or OOPSes would
             make it to your console.)
+
+``D``	    Dump the printk ring buffer
 =========== ===================================================================
 
 Okay, so what can I use them for?
diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c
index 6b4a28bcf2f5..1976412706a4 100644
--- a/drivers/tty/sysrq.c
+++ b/drivers/tty/sysrq.c
@@ -450,6 +450,24 @@ static const struct sysrq_key_op sysrq_unrt_op = {
 	.enable_mask	= SYSRQ_ENABLE_RTNICE,
 };
 
+static void dmesg_dump_callback(struct work_struct *work)
+{
+	dump_printk_buffer();
+}
+
+static DECLARE_WORK(sysrq_dmesg_work, dmesg_dump_callback);
+
+static void sysrq_handle_dmesg_dump(u8 key)
+{
+	queue_work(system_unbound_wq, &sysrq_dmesg_work);
+}
+static struct sysrq_key_op sysrq_dmesg_dump_op = {
+	.handler        = sysrq_handle_dmesg_dump,
+	.help_msg       = "dump-dmesg(D)",
+	.action_msg     = "Dump dmesg",
+	.enable_mask    = SYSRQ_ENABLE_DUMP,
+};
+
 /* Key Operations table and lock */
 static DEFINE_SPINLOCK(sysrq_key_table_lock);
 
@@ -505,7 +523,7 @@ static const struct sysrq_key_op *sysrq_key_table[62] = {
 	NULL,				/* A */
 	NULL,				/* B */
 	NULL,				/* C */
-	NULL,				/* D */
+	&sysrq_dmesg_dump_op,		/* D */
 	NULL,				/* E */
 	NULL,				/* F */
 	NULL,				/* G */
-- 
2.43.0

[PATCH v3 2/2] tty/sysrq: Dump printk ring buffer messages via sysrq

[Sreenath Vijayan]

When terminal is unresponsive, one cannot use dmesg to view printk
ring buffer messages. Also, syslog services may be disabled,
to check the messages after a reboot, especially on embedded systems.
In this scenario, dump the printk ring buffer messages via sysrq
by pressing sysrq+D.

Signed-off-by: Sreenath Vijayan <sreenath.vijayan@sony.com>
Signed-off-by: Shimoyashiki Taichi <taichi.shimoyashiki@sony.com>
---
 Documentation/admin-guide/sysrq.rst |  2 ++
 drivers/tty/sysrq.c                 | 20 +++++++++++++++++++-
 2 files changed, 21 insertions(+), 1 deletion(-)

diff --git a/Documentation/admin-guide/sysrq.rst b/Documentation/admin-guide/sysrq.rst
index 51906e47327b..246a7b61a0eb 100644
--- a/Documentation/admin-guide/sysrq.rst
+++ b/Documentation/admin-guide/sysrq.rst
@@ -152,6 +152,8 @@ Command	    Function
             will be printed to your console. (``0``, for example would make
             it so that only emergency messages like PANICs or OOPSes would
             make it to your console.)
+
+``D``	    Dump the printk ring buffer
 =========== ===================================================================
 
 Okay, so what can I use them for?
diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c
index 6b4a28bcf2f5..1976412706a4 100644
--- a/drivers/tty/sysrq.c
+++ b/drivers/tty/sysrq.c
@@ -450,6 +450,24 @@ static const struct sysrq_key_op sysrq_unrt_op = {
 	.enable_mask	= SYSRQ_ENABLE_RTNICE,
 };
 
+static void dmesg_dump_callback(struct work_struct *work)
+{
+	dump_printk_buffer();
+}
+
+static DECLARE_WORK(sysrq_dmesg_work, dmesg_dump_callback);
+
+static void sysrq_handle_dmesg_dump(u8 key)
+{
+	queue_work(system_unbound_wq, &sysrq_dmesg_work);
+}
+static struct sysrq_key_op sysrq_dmesg_dump_op = {
+	.handler        = sysrq_handle_dmesg_dump,
+	.help_msg       = "dump-dmesg(D)",
+	.action_msg     = "Dump dmesg",
+	.enable_mask    = SYSRQ_ENABLE_DUMP,
+};
+
 /* Key Operations table and lock */
 static DEFINE_SPINLOCK(sysrq_key_table_lock);
 
@@ -505,7 +523,7 @@ static const struct sysrq_key_op *sysrq_key_table[62] = {
 	NULL,				/* A */
 	NULL,				/* B */
 	NULL,				/* C */
-	NULL,				/* D */
+	&sysrq_dmesg_dump_op,		/* D */
 	NULL,				/* E */
 	NULL,				/* F */
 	NULL,				/* G */
-- 
2.43.0

Re: [PATCH v3 2/2] tty/sysrq: Dump printk ring buffer messages via sysrq

[John Ogness]

On 2024-01-17, Sreenath Vijayan <sreenath.vijayan@sony.com> wrote:
> When terminal is unresponsive, one cannot use dmesg to view printk
> ring buffer messages. Also, syslog services may be disabled,
> to check the messages after a reboot, especially on embedded systems.
> In this scenario, dump the printk ring buffer messages via sysrq
> by pressing sysrq+D.

Note that using sysrq+g with kgdb or kdb it is already possible to dump
the printk ringbuffer messages. However using this new sysrq+D is much
more comfortable, less intrusive, and generally safer.

I have no problems with this change. But I guess the tty maintainers
will need to speak up about extending the sysrq list.

John

RE: [PATCH v3 2/2] tty/sysrq: Dump printk ring buffer messages via sysrq

[David Laight]

From: Sreenath Vijayan
> Sent: 17 January 2024 11:14
....
>  /* Key Operations table and lock */
>  static DEFINE_SPINLOCK(sysrq_key_table_lock);
> 
> @@ -505,7 +523,7 @@ static const struct sysrq_key_op *sysrq_key_table[62] = {
>  	NULL,				/* A */
>  	NULL,				/* B */
>  	NULL,				/* C */
> -	NULL,				/* D */
> +	&sysrq_dmesg_dump_op,		/* D */
>  	NULL,				/* E */
>  	NULL,				/* F */
>  	NULL,				/* G */

That looks like it ought to use C99 initialisers:
	['D' - 'A'] = &sysrq_dmesg_dump_op,

Possible with a #define to hide the offset.

	David

-
Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
Registration No: 1397386 (Wales)

Re: [PATCH v3 2/2] tty/sysrq: Dump printk ring buffer messages via sysrq

[gregkh]

On Thu, Jan 18, 2024 at 10:56:59PM +0000, David Laight wrote:
> From: Sreenath Vijayan
> > Sent: 17 January 2024 11:14
> ....
> >  /* Key Operations table and lock */
> >  static DEFINE_SPINLOCK(sysrq_key_table_lock);
> > 
> > @@ -505,7 +523,7 @@ static const struct sysrq_key_op *sysrq_key_table[62] = {
> >  	NULL,				/* A */
> >  	NULL,				/* B */
> >  	NULL,				/* C */
> > -	NULL,				/* D */
> > +	&sysrq_dmesg_dump_op,		/* D */
> >  	NULL,				/* E */
> >  	NULL,				/* F */
> >  	NULL,				/* G */
> 
> That looks like it ought to use C99 initialisers:
> 	['D' - 'A'] = &sysrq_dmesg_dump_op,
> 
> Possible with a #define to hide the offset.

Maybe in the future, but for now, let's leave it as-is please.

thanks,

greg k-h