[RFC] printk/sysrq: Don't play with console_loglevel

From: Dmitry Safonov
Date: Mon May 27 2019 - 20:31:17 EST


While handling sysrq the console_loglevel is bumped to default to print
sysrq headers. It's done to print sysrq messages with WARNING level for
consumers of /proc/kmsg, though it sucks by the following reasons:
- changing console_loglevel may produce tons of messages (especially on
bloated with debug/info prints systems)
- it doesn't guarantee that the message will be printed as printk may
deffer the actual console output from buffer (see the comment near
printk() in kernel/printk/printk.c)

Provide KERN_UNSUPPRESSED printk() annotation for such legacy places.
Make sysrq print the headers unsuppressed instead of changing
console_loglevel.

Cc: Greg Kroah-Hartman <gregkh@xxxxxxxxxxxxxxxxxxx>
Cc: Jiri Slaby <jslaby@xxxxxxxx>
Cc: Petr Mladek <pmladek@xxxxxxxx>
Cc: Sergey Senozhatsky <sergey.senozhatsky@xxxxxxxxx>
Cc: Steven Rostedt <rostedt@xxxxxxxxxxx>
Cc: Tetsuo Handa <penguin-kernel@xxxxxxxxxxxxxxxxxxx>
Signed-off-by: Dmitry Safonov <dima@xxxxxxxxxx>
---
(I'm not fond at all of this patch - sending as RFC just to touch
how you all feel about this..)

drivers/tty/sysrq.c | 34 ++++++++++++++++++----------------
include/linux/kern_levels.h | 6 ++++++
include/linux/printk.h | 1 +
kernel/printk/printk.c | 17 ++++++++++++-----
4 files changed, 37 insertions(+), 21 deletions(-)

diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c
index 59e82e6d776d..ea37e3aa84b3 100644
--- a/drivers/tty/sysrq.c
+++ b/drivers/tty/sysrq.c
@@ -523,23 +523,28 @@ static void __sysrq_put_key_op(int key, struct sysrq_key_op *op_p)
sysrq_key_table[i] = op_p;
}

+#if (CONSOLE_LOGLEVEL_DEFAULT > LOGLEVEL_INFO)
+#define KERN_SYSRQ KERN_UNSUPPRESSED
+#else
+#define KERN_SYSRQ
+#endif
+#define sysrq_info(fmt, ...) \
+ printk(KERN_SYSRQ KERN_INFO pr_fmt(fmt), ##__VA_ARGS__)
+#define sysrq_cont(fmt, ...) \
+ printk(KERN_SYSRQ KERN_CONT pr_fmt(fmt), ##__VA_ARGS__)
+
void __handle_sysrq(int key, bool check_mask)
{
struct sysrq_key_op *op_p;
- int orig_log_level;
int i;

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.
+ * 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;
-
op_p = __sysrq_get_key_op(key);
if (op_p) {
/*
@@ -547,15 +552,13 @@ void __handle_sysrq(int key, bool check_mask)
* should not) and is the invoked operation enabled?
*/
if (!check_mask || sysrq_on_mask(op_p->enable_mask)) {
- pr_info("%s\n", op_p->action_msg);
- console_loglevel = orig_log_level;
+ sysrq_info("%s\n", op_p->action_msg);
op_p->handler(key);
} else {
- pr_info("This sysrq operation is disabled.\n");
- console_loglevel = orig_log_level;
+ sysrq_info("This sysrq operation is disabled.\n");
}
} else {
- pr_info("HELP : ");
+ sysrq_info("HELP : ");
/* Only print the help msg once per handler */
for (i = 0; i < ARRAY_SIZE(sysrq_key_table); i++) {
if (sysrq_key_table[i]) {
@@ -566,11 +569,10 @@ void __handle_sysrq(int key, bool check_mask)
;
if (j != i)
continue;
- pr_cont("%s ", sysrq_key_table[i]->help_msg);
+ sysrq_cont("%s ", sysrq_key_table[i]->help_msg);
}
}
- pr_cont("\n");
- console_loglevel = orig_log_level;
+ sysrq_cont("\n");
}
rcu_read_unlock();
rcu_sysrq_end();
diff --git a/include/linux/kern_levels.h b/include/linux/kern_levels.h
index bf2389c26ae3..2f40d6ace60d 100644
--- a/include/linux/kern_levels.h
+++ b/include/linux/kern_levels.h
@@ -23,6 +23,12 @@
*/
#define KERN_CONT KERN_SOH "c"

+/*
+ * Annotation for a message that will be printed regardless current
+ * console_loglevel. _DO_NOT_USE_IT! Exists for legacy code.
+ */
+#define KERN_UNSUPPRESSED KERN_SOH "u"
+
/* integer equivalents of KERN_<LEVEL> */
#define LOGLEVEL_SCHED -2 /* Deferred messages from sched code
* are set to this special level */
diff --git a/include/linux/printk.h b/include/linux/printk.h
index 84ea4d094af3..60a5cfde1488 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -19,6 +19,7 @@ static inline int printk_get_level(const char *buffer)
switch (buffer[1]) {
case '0' ... '7':
case 'c': /* KERN_CONT */
+ case 'u': /* KERN_UNSUPPRESSED */
return buffer[1];
}
}
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 02ca827b8fac..c6dd82c37382 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -345,6 +345,7 @@ static int console_msg_format = MSG_FORMAT_DEFAULT;

enum log_flags {
LOG_NEWLINE = 2, /* text ended with a newline */
+ LOG_DONT_SUPPRESS = 4, /* ignore current console_loglevel */
LOG_CONT = 8, /* text is a fragment of a continuation line */
};

@@ -1179,9 +1180,12 @@ module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
MODULE_PARM_DESC(ignore_loglevel,
"ignore loglevel setting (prints all kernel messages to the console)");

-static bool suppress_message_printing(int level)
+static bool suppress_message_printing(int level, u8 lflags)
{
- return (level >= console_loglevel && !ignore_loglevel);
+ if (ignore_loglevel || (lflags & LOG_DONT_SUPPRESS))
+ return false;
+
+ return level >= console_loglevel;
}

#ifdef CONFIG_BOOT_PRINTK_DELAY
@@ -1213,7 +1217,7 @@ static void boot_delay_msec(int level)
unsigned long timeout;

if ((boot_delay == 0 || system_state >= SYSTEM_RUNNING)
- || suppress_message_printing(level)) {
+ || suppress_message_printing(level, 0)) {
return;
}

@@ -1917,6 +1921,9 @@ int vprintk_store(int facility, int level,
break;
case 'c': /* KERN_CONT */
lflags |= LOG_CONT;
+ break;
+ case 'u': /* KERN_UNSUPPRESSED */
+ lflags |= LOG_DONT_SUPPRESS;
}

text_len -= 2;
@@ -2069,7 +2076,7 @@ static void call_console_drivers(const char *ext_text, size_t ext_len,
const char *text, size_t len) {}
static size_t msg_print_text(const struct printk_log *msg, bool syslog,
bool time, char *buf, size_t size) { return 0; }
-static bool suppress_message_printing(int level) { return false; }
+static bool suppress_message_printing(int level, u8 lflags) { return false; }

#endif /* CONFIG_PRINTK */

@@ -2407,7 +2414,7 @@ void console_unlock(void)
break;

msg = log_from_idx(console_idx);
- if (suppress_message_printing(msg->level)) {
+ if (suppress_message_printing(msg->level, msg->flags)) {
/*
* Skip record we have buffered and already printed
* directly to the console when we received it, and
--
2.21.0