[PATCH v2 0/2] printk: Add force_con printk flag to not suppress sysrq header msgs

[PATCH v2 0/2] printk: Add force_con printk flag to not suppress sysrq header msgs

[Marcos Paulo de Souza]

Hello,

This is the second version of the patchset. It now addresses comments
from John and Petr, while also mentioning that the current work solves
one issue on handle_sysrq when the printk messages are deferred.

The original cover-letter in is the v1.

Please review!

Signed-off-by: Marcos Paulo de Souza <mpdesouza@suse.com>
---
Changes in v2:
- Mentioned that it fixes a bug related to loglevel= dance (suggested by John)
- Changed to loud_con to FORCE_CON (John, Petr)
- Don't skip printk delay if FORCE_CON is specified (John)
- Set FORCE_CON when LOG_CONT is handled (John)
- Changed force_con from a per-CPU variable to a global variable because
  we can't disable migration on the callsites. (John, Petr)
- Used is_printk_force_console() on boot_delay_msec(), since it's used
  when the message is stored, instead of setting is as an argument.
- Link to v1: https://lore.kernel.org/r/20241016-printk-loud-con-v1-0-065e4dad6632@suse.com

---
Marcos Paulo de Souza (2):
      printk: Introduce FORCE_CON flag
      tty: sysrq: Use printk_force_console context on __handle_sysrq

 drivers/tty/sysrq.c         | 18 ++++++++----------
 include/linux/printk.h      |  3 +++
 kernel/printk/internal.h    |  3 +++
 kernel/printk/printk.c      | 21 ++++++++++++++++-----
 kernel/printk/printk_safe.c | 18 ++++++++++++++++++
 5 files changed, 48 insertions(+), 15 deletions(-)
---
base-commit: d9f4b813ae5c9bcdc9fcbaa1f4c9829bdc272532
change-id: 20241016-printk-loud-con-03b393d5f6fb

Best regards,
-- 
Marcos Paulo de Souza <mpdesouza@suse.com>

[PATCH v2 1/2] printk: Introduce FORCE_CON flag

[Marcos Paulo de Souza]

Introduce FORCE_CON flag to printk. The new flag will make it possible to
create a context where printk messages will never be suppressed.

This mechanism will be used in the next patch to create a force_con
context on sysrq handling, removing an existing workaround on the
loglevel global variable. The workaround existed to make sure that sysrq
header messages were sent to all consoles, but this doesn't work with
deferred messages because the loglevel might be restored to its original
value before a console flushes the messages.

Signed-off-by: Marcos Paulo de Souza <mpdesouza@suse.com>
---
 include/linux/printk.h      |  3 +++
 kernel/printk/internal.h    |  3 +++
 kernel/printk/printk.c      | 21 ++++++++++++++++-----
 kernel/printk/printk_safe.c | 18 ++++++++++++++++++
 4 files changed, 40 insertions(+), 5 deletions(-)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index eca9bb2ee637..232e5fd06701 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -166,6 +166,9 @@ __printf(1, 2) __cold int _printk_deferred(const char *fmt, ...);
 extern void __printk_deferred_enter(void);
 extern void __printk_deferred_exit(void);
 
+extern void printk_force_console_enter(void);
+extern void printk_force_console_exit(void);
+
 /*
  * The printk_deferred_enter/exit macros are available only as a hack for
  * some code paths that need to defer all printk console printing. Interrupts
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 3fcb48502adb..c6bb47666aef 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -53,6 +53,8 @@ int devkmsg_sysctl_set_loglvl(const struct ctl_table *table, int write,
 
 /* Flags for a single printk record. */
 enum printk_info_flags {
+	/* always show on console, ignore console_loglevel */
+	LOG_FORCE_CON	= 1,
 	LOG_NEWLINE	= 2,	/* text ended with a newline */
 	LOG_CONT	= 8,	/* text is a fragment of a continuation line */
 };
@@ -90,6 +92,7 @@ bool printk_percpu_data_ready(void);
 
 void defer_console_output(void);
 bool is_printk_legacy_deferred(void);
+bool is_printk_force_console(void);
 
 u16 printk_parse_prefix(const char *text, int *level,
 			enum printk_info_flags *flags);
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index beb808f4c367..911f2a32f1cb 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1319,11 +1319,11 @@ static void boot_delay_msec(int level)
 {
 	unsigned long long k;
 	unsigned long timeout;
+	bool suppress = !is_printk_force_console() &&
+			suppress_message_printing(level);
 
-	if ((boot_delay == 0 || system_state >= SYSTEM_RUNNING)
-		|| suppress_message_printing(level)) {
+	if ((boot_delay == 0 || system_state >= SYSTEM_RUNNING) || suppress)
 		return;
-	}
 
 	k = (unsigned long long)loops_per_msec * boot_delay;
 
@@ -2273,6 +2273,9 @@ int vprintk_store(int facility, int level,
 	if (dev_info)
 		flags |= LOG_NEWLINE;
 
+	if (is_printk_force_console())
+		flags |= LOG_FORCE_CON;
+
 	if (flags & LOG_CONT) {
 		prb_rec_init_wr(&r, reserve_size);
 		if (prb_reserve_in_last(&e, prb, &r, caller_id, PRINTKRB_RECORD_MAX)) {
@@ -2280,6 +2283,9 @@ int vprintk_store(int facility, int level,
 						 facility, &flags, fmt, args);
 			r.info->text_len += text_len;
 
+			if (flags & LOG_FORCE_CON)
+				r.info->flags |= LOG_FORCE_CON;
+
 			if (flags & LOG_NEWLINE) {
 				r.info->flags |= LOG_NEWLINE;
 				prb_final_commit(&e);
@@ -2947,6 +2953,7 @@ bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
 	struct printk_info info;
 	struct printk_record r;
 	size_t len = 0;
+	bool force_con;
 
 	/*
 	 * Formatting extended messages requires a separate buffer, so use the
@@ -2965,9 +2972,13 @@ bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
 
 	pmsg->seq = r.info->seq;
 	pmsg->dropped = r.info->seq - seq;
+	force_con = r.info->flags & LOG_FORCE_CON;
 
-	/* Skip record that has level above the console loglevel. */
-	if (may_suppress && suppress_message_printing(r.info->level))
+	/*
+	 * Skip records that are not forced to be printed on consoles and that
+	 * has level above the console loglevel.
+	 */
+	if (!force_con && may_suppress && suppress_message_printing(r.info->level))
 		goto out;
 
 	if (is_extended) {
diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c
index 2b35a9d3919d..6f94418d53ff 100644
--- a/kernel/printk/printk_safe.c
+++ b/kernel/printk/printk_safe.c
@@ -12,6 +12,24 @@
 
 #include "internal.h"
 
+/* Context where printk messages are never suppressed */
+static atomic_t force_con;
+
+void printk_force_console_enter(void)
+{
+	atomic_inc(&force_con);
+}
+
+void printk_force_console_exit(void)
+{
+	atomic_dec(&force_con);
+}
+
+bool is_printk_force_console(void)
+{
+	return atomic_read(&force_con);
+}
+
 static DEFINE_PER_CPU(int, printk_context);
 
 /* Can be preempted by NMI. */

-- 
2.47.0

Re: [PATCH v2 1/2] printk: Introduce FORCE_CON flag

[John Ogness]

On 2024-11-05, Marcos Paulo de Souza <mpdesouza@suse.com> wrote:
> @@ -2947,6 +2953,7 @@ bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
>  	struct printk_info info;
>  	struct printk_record r;
>  	size_t len = 0;
> +	bool force_con;
>  
>  	/*
>  	 * Formatting extended messages requires a separate buffer, so use the
> @@ -2965,9 +2972,13 @@ bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
>  
>  	pmsg->seq = r.info->seq;
>  	pmsg->dropped = r.info->seq - seq;
> +	force_con = r.info->flags & LOG_FORCE_CON;
>  
> -	/* Skip record that has level above the console loglevel. */
> -	if (may_suppress && suppress_message_printing(r.info->level))
> +	/*
> +	 * Skip records that are not forced to be printed on consoles and that
> +	 * has level above the console loglevel.
> +	 */
> +	if (!force_con && may_suppress && suppress_message_printing(r.info->level))
>  		goto out;

Rather than adding a new local variable, setting it, and expanding the
condition, it might be cleaner to just update @may_suppress before the
condition check?

	/* Records forced to be printed on consoles must not be skipped. */
	may_suppress &= !(r.info->flags & LOG_FORCE_CON);

Feel free to ignore this suggestion if you think having an extra
variable is easier to follow.

With or without suggested change:

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

Re: [PATCH v2 1/2] printk: Introduce FORCE_CON flag

[Marcos Paulo de Souza]

On Tue, 2024-11-05 at 22:40 +0106, John Ogness wrote:
> On 2024-11-05, Marcos Paulo de Souza <mpdesouza@suse.com> wrote:
> > @@ -2947,6 +2953,7 @@ bool printk_get_next_message(struct
> > printk_message *pmsg, u64 seq,
> >  	struct printk_info info;
> >  	struct printk_record r;
> >  	size_t len = 0;
> > +	bool force_con;
> >  
> >  	/*
> >  	 * Formatting extended messages requires a separate
> > buffer, so use the
> > @@ -2965,9 +2972,13 @@ bool printk_get_next_message(struct
> > printk_message *pmsg, u64 seq,
> >  
> >  	pmsg->seq = r.info->seq;
> >  	pmsg->dropped = r.info->seq - seq;
> > +	force_con = r.info->flags & LOG_FORCE_CON;
> >  
> > -	/* Skip record that has level above the console loglevel.
> > */
> > -	if (may_suppress && suppress_message_printing(r.info-
> > >level))
> > +	/*
> > +	 * Skip records that are not forced to be printed on
> > consoles and that
> > +	 * has level above the console loglevel.
> > +	 */
> > +	if (!force_con && may_suppress &&
> > suppress_message_printing(r.info->level))
> >  		goto out;
> 
> Rather than adding a new local variable, setting it, and expanding
> the
> condition, it might be cleaner to just update @may_suppress before
> the
> condition check?
> 
> 	/* Records forced to be printed on consoles must not be
> skipped. */
> 	may_suppress &= !(r.info->flags & LOG_FORCE_CON);

Well, your suggestion seems clever than what I did :)

IHMO, I would prefer the new variable as it's easier to read (for me at
least), but I can change if you think it's better..

> 
> Feel free to ignore this suggestion if you think having an extra
> variable is easier to follow.
> 
> With or without suggested change:
> 
> Reviewed-by: John Ogness <john.ogness@linutronix.de>

Thanks John!

Re: [PATCH v2 1/2] printk: Introduce FORCE_CON flag

[Petr Mladek]

On Tue 2024-11-05 16:45:08, Marcos Paulo de Souza wrote:
> Introduce FORCE_CON flag to printk. The new flag will make it possible to
> create a context where printk messages will never be suppressed.
> 
> This mechanism will be used in the next patch to create a force_con
> context on sysrq handling, removing an existing workaround on the
> loglevel global variable. The workaround existed to make sure that sysrq
> header messages were sent to all consoles, but this doesn't work with
> deferred messages because the loglevel might be restored to its original
> value before a console flushes the messages.
> 
> Signed-off-by: Marcos Paulo de Souza <mpdesouza@suse.com>

Looks good:

Reviewed-by: Petr Mladek <pmladek@suse.com>

Just a nit below.

> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1319,11 +1319,11 @@ static void boot_delay_msec(int level)
>  {
>  	unsigned long long k;
>  	unsigned long timeout;
> +	bool suppress = !is_printk_force_console() &&
> +			suppress_message_printing(level);
>  
> -	if ((boot_delay == 0 || system_state >= SYSTEM_RUNNING)
> -		|| suppress_message_printing(level)) {
> +	if ((boot_delay == 0 || system_state >= SYSTEM_RUNNING) || suppress)
>  		return;

These spaghetti conditions are hard to follow. I would personally
prefer:

	if ((boot_delay == 0)
		return;

	if (system_state >= SYSTEM_RUNNING)
		return;

	if (suppress_message_printing(level) &&	!is_printk_force_console())
		return;

But I do not resist on it.


Best Regards,
Petr

[PATCH v2 2/2] tty: sysrq: Use printk_force_console context on __handle_sysrq

[Marcos Paulo de Souza]

By using the printk_force_console the loglevel workaround can be removed.
The workaround existed to always send the sysrq header message to all
consoles not matter what was the current loglevel, but it won't work for
deferred messages, since the loglevel can be restore before the message
is printed, suppressing the message that wasn't supposed to be
suppressed by the workaround.

Signed-off-by: Marcos Paulo de Souza <mpdesouza@suse.com>
---
 drivers/tty/sysrq.c | 18 ++++++++----------
 1 file changed, 8 insertions(+), 10 deletions(-)

diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c
index 930b04e3d148..f85ce02e4725 100644
--- a/drivers/tty/sysrq.c
+++ b/drivers/tty/sysrq.c
@@ -583,7 +583,6 @@ static void __sysrq_put_key_op(u8 key, const struct sysrq_key_op *op_p)
 void __handle_sysrq(u8 key, bool check_mask)
 {
 	const struct sysrq_key_op *op_p;
-	int orig_log_level;
 	int orig_suppress_printk;
 	int i;
 
@@ -593,13 +592,12 @@ void __handle_sysrq(u8 key, bool check_mask)
 	rcu_sysrq_start();
 	rcu_read_lock();
 	/*
-	 * Raise the apparent loglevel to maximum so that the sysrq header
-	 * is shown to provide the user with positive feedback.  We do not
-	 * simply emit this at KERN_EMERG as that would change message
-	 * routing in the consumers of /proc/kmsg.
+	 * Enter in the force_console context so that sysrq header is shown to
+	 * provide the user with positive feedback.  We do not simply emit this
+	 * at KERN_EMERG as that would change message routing in the consumers
+	 * of /proc/kmsg.
 	 */
-	orig_log_level = console_loglevel;
-	console_loglevel = CONSOLE_LOGLEVEL_DEFAULT;
+	printk_force_console_enter();
 
 	op_p = __sysrq_get_key_op(key);
 	if (op_p) {
@@ -609,11 +607,11 @@ void __handle_sysrq(u8 key, bool check_mask)
 		 */
 		if (!check_mask || sysrq_on_mask(op_p->enable_mask)) {
 			pr_info("%s\n", op_p->action_msg);
-			console_loglevel = orig_log_level;
+			printk_force_console_exit();
 			op_p->handler(key);
 		} else {
 			pr_info("This sysrq operation is disabled.\n");
-			console_loglevel = orig_log_level;
+			printk_force_console_exit();
 		}
 	} else {
 		pr_info("HELP : ");
@@ -631,7 +629,7 @@ void __handle_sysrq(u8 key, bool check_mask)
 			}
 		}
 		pr_cont("\n");
-		console_loglevel = orig_log_level;
+		printk_force_console_exit();
 	}
 	rcu_read_unlock();
 	rcu_sysrq_end();

-- 
2.47.0

Re: [PATCH v2 2/2] tty: sysrq: Use printk_force_console context on __handle_sysrq

[John Ogness]

On 2024-11-05, Marcos Paulo de Souza <mpdesouza@suse.com> wrote:
> By using the printk_force_console the loglevel workaround can be removed.
> The workaround existed to always send the sysrq header message to all
> consoles not matter what was the current loglevel, but it won't work for
> deferred messages, since the loglevel can be restore before the message
> is printed, suppressing the message that wasn't supposed to be
> suppressed by the workaround.
>
> Signed-off-by: Marcos Paulo de Souza <mpdesouza@suse.com>

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

Re: [PATCH v2 2/2] tty: sysrq: Use printk_force_console context on __handle_sysrq

[Petr Mladek]

On Tue 2024-11-05 16:45:09, Marcos Paulo de Souza wrote:
> By using the printk_force_console the loglevel workaround can be removed.
> The workaround existed to always send the sysrq header message to all
> consoles not matter what was the current loglevel, but it won't work for
> deferred messages, since the loglevel can be restore before the message
> is printed, suppressing the message that wasn't supposed to be
> suppressed by the workaround.
> 
> Signed-off-by: Marcos Paulo de Souza <mpdesouza@suse.com>

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

Re: [PATCH v2 0/2] printk: Add force_con printk flag to not suppress sysrq header msgs

[Petr Mladek]

On Tue 2024-11-05 16:45:07, Marcos Paulo de Souza wrote:
> Hello,
> 
> This is the second version of the patchset. It now addresses comments
> from John and Petr, while also mentioning that the current work solves
> one issue on handle_sysrq when the printk messages are deferred.
> 
> The original cover-letter in is the v1.
> 
> Please review!
> 
> Signed-off-by: Marcos Paulo de Souza <mpdesouza@suse.com>
> ---
> Changes in v2:
> - Mentioned that it fixes a bug related to loglevel= dance (suggested by John)
> - Changed to loud_con to FORCE_CON (John, Petr)
> - Don't skip printk delay if FORCE_CON is specified (John)
> - Set FORCE_CON when LOG_CONT is handled (John)
> - Changed force_con from a per-CPU variable to a global variable because
>   we can't disable migration on the callsites. (John, Petr)
> - Used is_printk_force_console() on boot_delay_msec(), since it's used
>   when the message is stored, instead of setting is as an argument.
> - Link to v1: https://lore.kernel.org/r/20241016-printk-loud-con-v1-0-065e4dad6632@suse.com
> ---
> Marcos Paulo de Souza (2):
>       printk: Introduce FORCE_CON flag
>       tty: sysrq: Use printk_force_console context on __handle_sysrq

The patchset looks ready for linux-next from my POV. I am going to
push it there tomorrow or on Monday unless anyone complains.

There was some bike-shedding about the code style in the reviews.
But the proposals did not look like a big win. I think that it
is not worth a respin.

Best Regards,
Petr

Re: [PATCH v2 0/2] printk: Add force_con printk flag to not suppress sysrq header msgs

[Greg Kroah-Hartman]

On Thu, Nov 07, 2024 at 04:57:36PM +0100, Petr Mladek wrote:
> On Tue 2024-11-05 16:45:07, Marcos Paulo de Souza wrote:
> > Hello,
> > 
> > This is the second version of the patchset. It now addresses comments
> > from John and Petr, while also mentioning that the current work solves
> > one issue on handle_sysrq when the printk messages are deferred.
> > 
> > The original cover-letter in is the v1.
> > 
> > Please review!
> > 
> > Signed-off-by: Marcos Paulo de Souza <mpdesouza@suse.com>
> > ---
> > Changes in v2:
> > - Mentioned that it fixes a bug related to loglevel= dance (suggested by John)
> > - Changed to loud_con to FORCE_CON (John, Petr)
> > - Don't skip printk delay if FORCE_CON is specified (John)
> > - Set FORCE_CON when LOG_CONT is handled (John)
> > - Changed force_con from a per-CPU variable to a global variable because
> >   we can't disable migration on the callsites. (John, Petr)
> > - Used is_printk_force_console() on boot_delay_msec(), since it's used
> >   when the message is stored, instead of setting is as an argument.
> > - Link to v1: https://lore.kernel.org/r/20241016-printk-loud-con-v1-0-065e4dad6632@suse.com
> > ---
> > Marcos Paulo de Souza (2):
> >       printk: Introduce FORCE_CON flag
> >       tty: sysrq: Use printk_force_console context on __handle_sysrq
> 
> The patchset looks ready for linux-next from my POV. I am going to
> push it there tomorrow or on Monday unless anyone complains.
> 
> There was some bike-shedding about the code style in the reviews.
> But the proposals did not look like a big win. I think that it
> is not worth a respin.

No objection from me!

Acked-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

Re: [PATCH v2 0/2] printk: Add force_con printk flag to not suppress sysrq header msgs

[Petr Mladek]

On Thu 2024-11-07 16:57:40, Petr Mladek wrote:
> On Tue 2024-11-05 16:45:07, Marcos Paulo de Souza wrote:
> > Hello,
> > 
> > This is the second version of the patchset. It now addresses comments
> > from John and Petr, while also mentioning that the current work solves
> > one issue on handle_sysrq when the printk messages are deferred.
> > 
> > The original cover-letter in is the v1.
> > 
> > Please review!
> > 
> > Signed-off-by: Marcos Paulo de Souza <mpdesouza@suse.com>
> > ---
> > Changes in v2:
> > - Mentioned that it fixes a bug related to loglevel= dance (suggested by John)
> > - Changed to loud_con to FORCE_CON (John, Petr)
> > - Don't skip printk delay if FORCE_CON is specified (John)
> > - Set FORCE_CON when LOG_CONT is handled (John)
> > - Changed force_con from a per-CPU variable to a global variable because
> >   we can't disable migration on the callsites. (John, Petr)
> > - Used is_printk_force_console() on boot_delay_msec(), since it's used
> >   when the message is stored, instead of setting is as an argument.
> > - Link to v1: https://lore.kernel.org/r/20241016-printk-loud-con-v1-0-065e4dad6632@suse.com
> > ---
> > Marcos Paulo de Souza (2):
> >       printk: Introduce FORCE_CON flag
> >       tty: sysrq: Use printk_force_console context on __handle_sysrq
> 
> The patchset looks ready for linux-next from my POV. I am going to
> push it there tomorrow or on Monday unless anyone complains.
> 
> There was some bike-shedding about the code style in the reviews.
> But the proposals did not look like a big win. I think that it
> is not worth a respin.

JFYI, the patchset has been committed into printk/linux.git,
branch for-6.13-force-console.

Best Regards,
Petr