[PATCH v5 0/2] Add support to replay kernel log on console via sysrq

[PATCH v5 0/2] Add support to replay kernel log on console via sysrq

[Sreenath Vijayan]

Hi,

This patch series enables one to replay the kernel log messages
in printk ring buffer on consoles via sysrq. This is useful to
view the kernel messages when terminal is unresponsive to enter
commands like dmesg and syslog services are also disabled,
especially on embedded targets. Although debug features like
kdb/kgdb already allow this, these debug configs should be
enabled which is often not the case.

In the first commit, a generic function console_replay_all()
is added that replays the kernel log messages on consoles.
To do this, code under CONSOLE_REPLAY_ALL mode in
console_flush_on_panic() is taken out to a helper function
__console_rewind_all() to set the console sequence number to
oldest record in the printk buffer. This function can be called
safely under console_lock(). console_replay_all() tries to get
console subsystem lock using console_trylock() and if successful,
calls __console_rewind_all() to reset the sequence number.
Finally it calls console_unlock() which flushes out the contents
of printk buffer to consoles. The console loglevel will determine
which all kernel log messages are displayed.

In the second commit, code is added to call console_replay_all()
from the sysrq key handler when sysrq+R is pressed. Document is
also updated describing the use case and limitations.

Limitations:
- User may have to press the key combination multiple times if
console lock is not obtained at the time of key press.
- If console lock owner is stuck, console_trylock() will fail
continuously and messages won't be displayed.

These limitations can be overcome once atomic consoles are
available. Currently, it is best effort.

Links to previous discussion:
- https://lore.kernel.org/all/ZcyWU0V6Kmq0Txqr@sony.com/T/#t
- https://lore.kernel.org/all/cover.1705331453.git.sreenath.vijayan@sony.com/T/#t
- https://lore.kernel.org/linux-serial/20231221133953.1507021-1-sreenath.vijayan@sony.com/

Changelog:
V4 -> V5:
- renamed console_rewind_all() to __console_rewind_all()
- modified comments for __console_rewind_all()
- renamed dump_printk_buffer() to console_replay_all()
- used sysrq+R instead of sysrq+D
- removed workqueue based implementation and used console_trylock()

V3 -> V4:
- refactor code in console_flush_on_panic() under CONSOLE_REPLAY_ALL mode
- add new function console_rewind_all()
- use console_rewind_all() instead of ksmg_dump*() in dump_printk_buffer()

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 replay kernel log on consoles
  tty/sysrq: Replay kernel log messages on consoles via sysrq

 Documentation/admin-guide/sysrq.rst |  8 +++
 drivers/tty/sysrq.c                 | 13 ++++-
 include/linux/printk.h              |  4 ++
 kernel/printk/printk.c              | 77 ++++++++++++++++++++---------
 4 files changed, 77 insertions(+), 25 deletions(-)

-- 
2.25.1

[PATCH v5 1/2] printk: Add function to replay kernel log on consoles

[Sreenath Vijayan]

Add a generic function console_replay_all() for replaying
the kernel log on consoles, in any context. It would allow
viewing the logs on an unresponsive terminal via sysrq.

Reuse the existing code from console_flush_on_panic() for
resetting the sequence numbers, by introducing a new helper
function __console_rewind_all(). It is safe to be called
under console_lock().

Try to acquire lock on the console subsystem without waiting.
If successful, reset the sequence number to oldest available
record on all consoles and call console_unlock() which will
automatically flush the messages to the consoles.

Suggested-by: John Ogness <john.ogness@linutronix.de>
Suggested-by: Petr Mladek <pmladek@suse.com>
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 | 77 +++++++++++++++++++++++++++++-------------
 2 files changed, 57 insertions(+), 24 deletions(-)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index 8ef499ab3c1e..8df2ac6c0e1f 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 console_replay_all(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 console_replay_all(void)
+{
+}
 #endif
 
 #ifdef CONFIG_SMP
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index f2444b581e16..9e38cf0c1002 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3134,6 +3134,40 @@ void console_unblank(void)
 		pr_flush(1000, true);
 }
 
+/*
+ * Rewind all consoles to the oldest available record.
+ *
+ * IMPORTANT: The function is safe only when called under
+ *            console_lock(). It is not enforced because
+ *            it is used as a best effort in panic().
+ */
+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 {
+			/*
+			 * This assignment is safe only when called under
+			 * console_lock(). On panic, legacy consoles are
+			 * only best effort.
+			 */
+			c->seq = seq;
+		}
+	}
+	console_srcu_read_unlock(cookie);
+}
+
 /**
  * console_flush_on_panic - flush console content on panic
  * @mode: flush all messages in buffer or just the pending ones
@@ -3162,30 +3196,8 @@ void console_flush_on_panic(enum con_flush_mode mode)
 	 */
 	console_may_schedule = 0;
 
-	if (mode == CONSOLE_REPLAY_ALL) {
-		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 {
-				/*
-				 * This is an unsynchronized assignment. On
-				 * panic legacy consoles are only best effort.
-				 */
-				c->seq = seq;
-			}
-		}
-		console_srcu_read_unlock(cookie);
-	}
+	if (mode == CONSOLE_REPLAY_ALL)
+		__console_rewind_all();
 
 	console_flush_all(false, &next_seq, &handover);
 }
@@ -4259,6 +4271,23 @@ void kmsg_dump_rewind(struct kmsg_dump_iter *iter)
 }
 EXPORT_SYMBOL_GPL(kmsg_dump_rewind);
 
+/**
+ * console_replay_all - replay kernel log on consoles
+ *
+ * Try to obtain lock on console subsystem and replay all
+ * available records in printk buffer on the consoles.
+ * Does nothing if lock is not obtained.
+ *
+ * Context: Any context.
+ */
+void console_replay_all(void)
+{
+	if (console_trylock()) {
+		__console_rewind_all();
+		/* Consoles are flushed as part of console_unlock(). */
+		console_unlock();
+	}
+}
 #endif
 
 #ifdef CONFIG_SMP
-- 
2.25.1

Re: [PATCH v5 1/2] printk: Add function to replay kernel log on consoles

[John Ogness]

On 2024-03-07, Sreenath Vijayan <sreenath.vijayan@sony.com> wrote:
> Add a generic function console_replay_all() for replaying
> the kernel log on consoles, in any context. It would allow
> viewing the logs on an unresponsive terminal via sysrq.
>
> Reuse the existing code from console_flush_on_panic() for
> resetting the sequence numbers, by introducing a new helper
> function __console_rewind_all(). It is safe to be called
> under console_lock().
>
> Try to acquire lock on the console subsystem without waiting.
> If successful, reset the sequence number to oldest available
> record on all consoles and call console_unlock() which will
> automatically flush the messages to the consoles.
>
> Suggested-by: John Ogness <john.ogness@linutronix.de>
> Suggested-by: Petr Mladek <pmladek@suse.com>
> Signed-off-by: Sreenath Vijayan <sreenath.vijayan@sony.com>
> Signed-off-by: Shimoyashiki Taichi <taichi.shimoyashiki@sony.com>

Reviewed-by: John Ogness <john.ogness@linutronix.de>

[PATCH v5 2/2] tty/sysrq: Replay kernel log messages on consoles via sysrq

[Sreenath Vijayan]

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

The console loglevel will determine which all kernel log messages
are displayed. The messages will be displayed only when
console_trylock() succeeds. Users could repeat the sysrq key when
it fails. If the owner of console subsystem lock is stuck,
repeating the key won't work.

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

diff --git a/Documentation/admin-guide/sysrq.rst b/Documentation/admin-guide/sysrq.rst
index 2f2e5bd440f9..8098a1b4908d 100644
--- a/Documentation/admin-guide/sysrq.rst
+++ b/Documentation/admin-guide/sysrq.rst
@@ -161,6 +161,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.)
+
+``R``	    Replay the kernel log messages on consoles.
 =========== ===================================================================
 
 Okay, so what can I use them for?
@@ -211,6 +213,12 @@ processes.
 "just thaw ``it(j)``" is useful if your system becomes unresponsive due to a
 frozen (probably root) filesystem via the FIFREEZE ioctl.
 
+``Replay logs(R)`` is useful to view the kernel log messages when system is hung
+or you are not able to use dmesg command to view the messages in printk buffer.
+User may have to press the key combination multiple times if console system is
+busy. If it is completely locked up, then messages won't be printed. Output
+messages depend on current console loglevel.
+
 Sometimes SysRq seems to get 'stuck' after using it, what can I do?
 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
 
diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c
index 02217e3c916b..c4deea41a8b5 100644
--- a/drivers/tty/sysrq.c
+++ b/drivers/tty/sysrq.c
@@ -450,6 +450,17 @@ static const struct sysrq_key_op sysrq_unrt_op = {
 	.enable_mask	= SYSRQ_ENABLE_RTNICE,
 };
 
+static void sysrq_handle_replay_logs(u8 key)
+{
+	console_replay_all();
+}
+static struct sysrq_key_op sysrq_replay_logs_op = {
+	.handler        = sysrq_handle_replay_logs,
+	.help_msg       = "replay-kernel-logs(R)",
+	.action_msg     = "replay kernel logs on consoles",
+	.enable_mask    = SYSRQ_ENABLE_DUMP,
+};
+
 /* Key Operations table and lock */
 static DEFINE_SPINLOCK(sysrq_key_table_lock);
 
@@ -519,7 +530,7 @@ static const struct sysrq_key_op *sysrq_key_table[62] = {
 	NULL,				/* O */
 	NULL,				/* P */
 	NULL,				/* Q */
-	NULL,				/* R */
+	&sysrq_replay_logs_op,		/* R */
 	NULL,				/* S */
 	NULL,				/* T */
 	NULL,				/* U */
-- 
2.25.1

Re: [PATCH v5 2/2] tty/sysrq: Replay kernel log messages on consoles via sysrq

[John Ogness]

On 2024-03-07, Sreenath Vijayan <sreenath.vijayan@sony.com> wrote:
> diff --git a/Documentation/admin-guide/sysrq.rst b/Documentation/admin-guide/sysrq.rst
> index 2f2e5bd440f9..8098a1b4908d 100644
> --- a/Documentation/admin-guide/sysrq.rst
> +++ b/Documentation/admin-guide/sysrq.rst
> @@ -161,6 +161,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.)
> +
> +``R``	    Replay the kernel log messages on consoles.
>  =========== ===================================================================
>  
>  Okay, so what can I use them for?
> @@ -211,6 +213,12 @@ processes.
>  "just thaw ``it(j)``" is useful if your system becomes unresponsive due to a
>  frozen (probably root) filesystem via the FIFREEZE ioctl.
>  
> +``Replay logs(R)`` is useful to view the kernel log messages when system is hung
> +or you are not able to use dmesg command to view the messages in printk buffer.
> +User may have to press the key combination multiple times if console system is
> +busy. If it is completely locked up, then messages won't be printed. Output
> +messages depend on current console loglevel.
> +

I recommend including a reference to SysRq [0-9] about changing the
loglevel.

>  Sometimes SysRq seems to get 'stuck' after using it, what can I do?
>  ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
>  
> diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c
> index 02217e3c916b..c4deea41a8b5 100644
> --- a/drivers/tty/sysrq.c
> +++ b/drivers/tty/sysrq.c
> @@ -450,6 +450,17 @@ static const struct sysrq_key_op sysrq_unrt_op = {
>  	.enable_mask	= SYSRQ_ENABLE_RTNICE,
>  };
>  
> +static void sysrq_handle_replay_logs(u8 key)
> +{
> +	console_replay_all();
> +}
> +static struct sysrq_key_op sysrq_replay_logs_op = {
> +	.handler        = sysrq_handle_replay_logs,
> +	.help_msg       = "replay-kernel-logs(R)",
> +	.action_msg     = "replay kernel logs on consoles",

If I do:

$ grep '\.action_msg' drivers/tty/sysrq.c

This is the only action message that begins lowercase. Please start with
a capital letter for consistency.

With the change to the action message:

Reviewed-by: John Ogness <john.ogness@linutronix.de>