Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1741877 > unrolled thread

[PATCH 1/3] printk: Introduce per-console loglevel setting

Back to article view | Back to linux.kernel

Contents

  [PATCH 1/3] printk: Introduce per-console loglevel setting Calvin Owens <calvinowens@fb.com> - 2017-09-29 02:50 +0200
    [PATCH 3/3] printk: Add ability to set loglevel via "console=" cmdline Calvin Owens <calvinowens@fb.com> - 2017-09-29 02:50 +0200
    [PATCH 2/3] printk: Add /sys/consoles/ interface Calvin Owens <calvinowens@fb.com> - 2017-09-29 02:50 +0200

#1741877 — [PATCH 1/3] printk: Introduce per-console loglevel setting

Not all consoles are created equal: depending on the actual hardware,
the latency of a printk() call can vary dramatically. The worst examples
are serial consoles, where it can spin for tens of milliseconds banging
the UART to emit a message, which can cause application-level problems
when the kernel spews onto the console.

At Facebook we use netconsole to monitor our fleet, but we still have
serial consoles attached on each host for live debugging, and the latter
has caused problems. An obvious solution is to disable the kernel
console output to ttyS0, but this makes live debugging frustrating,
since crashes become silent and opaque to the ttyS0 user. Enabling it on
the fly when needed isn't feasible, since boxes you need to debug via
serial are likely to be borked in ways that make this impossible.

That puts us between a rock and a hard place: we'd love to set
kernel.printk to KERN_INFO and get all the logs. But while netconsole is
fast enough to permit that without perturbing userspace, ttyS0 is not,
and we're forced to limit console logging to KERN_WARNING and higher.

This patch introduces a new per-console loglevel setting, and changes
console_unlock() to use max(global_level, per_console_level) when
deciding whether or not to emit a given log message.

This lets us have our cake and eat it too: instead of being forced to
limit all consoles verbosity based on the speed of the slowest one, we
can "promote" the faster console while still using a conservative system
loglevel setting to avoid disturbing applications.

Cc: Petr Mladek <pmladek@suse.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Signed-off-by: Calvin Owens <calvinowens@fb.com>
---
(V1: https://lkml.org/lkml/2017/4/4/783)

Changes in V2:
	* Honor the ignore_loglevel setting in all cases
	* Change semantics to use max(global, console) as the loglevel
	  for a console, instead of the previous patch where we treated
	  the per-console one as a filter downstream of the global one.

 include/linux/console.h |  1 +
 kernel/printk/printk.c  | 38 +++++++++++++++++++-------------------
 2 files changed, 20 insertions(+), 19 deletions(-)

diff --git a/include/linux/console.h b/include/linux/console.h
index b8920a0..a5b5d79 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -147,6 +147,7 @@ struct console {
 	int	cflag;
 	void	*data;
 	struct	 console *next;
+	int	level;
 };
 
 /*
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 512f7c2..3f1675e 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1141,9 +1141,14 @@ 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 int effective_loglevel(struct console *con)
 {
-	return (level >= console_loglevel && !ignore_loglevel);
+	return max(console_loglevel, con ? con->level : LOGLEVEL_EMERG);
+}
+
+static bool suppress_message_printing(int level, struct console *con)
+{
+	return (level >= effective_loglevel(con) && !ignore_loglevel);
 }
 
 #ifdef CONFIG_BOOT_PRINTK_DELAY
@@ -1175,7 +1180,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, NULL)) {
 		return;
 	}
 
@@ -1549,7 +1554,7 @@ SYSCALL_DEFINE3(syslog, int, type, char __user *, buf, int, len)
  * The console_lock must be held.
  */
 static void call_console_drivers(const char *ext_text, size_t ext_len,
-				 const char *text, size_t len)
+				 const char *text, size_t len, int level)
 {
 	struct console *con;
 
@@ -1568,6 +1573,8 @@ static void call_console_drivers(const char *ext_text, size_t ext_len,
 		if (!cpu_online(smp_processor_id()) &&
 		    !(con->flags & CON_ANYTIME))
 			continue;
+		if (suppress_message_printing(level, con))
+			continue;
 		if (con->flags & CON_EXTENDED)
 			con->write(con, ext_text, ext_len);
 		else
@@ -1856,10 +1863,9 @@ static ssize_t msg_print_ext_body(char *buf, size_t size,
 				  char *dict, size_t dict_len,
 				  char *text, size_t text_len) { return 0; }
 static void call_console_drivers(const char *ext_text, size_t ext_len,
-				 const char *text, size_t len) {}
+				 const char *text, size_t len, int level) {}
 static size_t msg_print_text(const struct printk_log *msg,
 			     bool syslog, char *buf, size_t size) { return 0; }
-static bool suppress_message_printing(int level) { return false; }
 
 #endif /* CONFIG_PRINTK */
 
@@ -2199,22 +2205,11 @@ void console_unlock(void)
 		} else {
 			len = 0;
 		}
-skip:
+
 		if (console_seq == log_next_seq)
 			break;
 
 		msg = log_from_idx(console_idx);
-		if (suppress_message_printing(msg->level)) {
-			/*
-			 * Skip record we have buffered and already printed
-			 * directly to the console when we received it, and
-			 * record that has level above the console loglevel.
-			 */
-			console_idx = log_next(console_idx);
-			console_seq++;
-			goto skip;
-		}
-
 		len += msg_print_text(msg, false, text + len, sizeof(text) - len);
 		if (nr_ext_console_drivers) {
 			ext_len = msg_print_ext_header(ext_text,
@@ -2230,7 +2225,7 @@ void console_unlock(void)
 		raw_spin_unlock(&logbuf_lock);
 
 		stop_critical_timings();	/* don't trace print latency */
-		call_console_drivers(ext_text, ext_len, text, len);
+		call_console_drivers(ext_text, ext_len, text, len, msg->level);
 		start_critical_timings();
 		printk_safe_exit_irqrestore(flags);
 
@@ -2497,6 +2492,11 @@ void register_console(struct console *newcon)
 		newcon->flags &= ~CON_PRINTBUFFER;
 
 	/*
+	 * By default, the per-console minimum forces no messages through.
+	 */
+	newcon->level = LOGLEVEL_EMERG;
+
+	/*
 	 *	Put this console in the list - keep the
 	 *	preferred driver at the head of the list.
 	 */
-- 
2.9.5

[toc] | [next] | [standalone]

#1741878 — [PATCH 3/3] printk: Add ability to set loglevel via "console=" cmdline

This extends the "console=" interface to allow setting the per-console
loglevel by adding "/N" to the string, where N is the desired loglevel
expressed as a base 10 integer. Invalid values are silently ignored.

Cc: Petr Mladek <pmladek@suse.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Signed-off-by: Calvin Owens <calvinowens@fb.com>
---
 Documentation/admin-guide/kernel-parameters.txt |  6 ++---
 kernel/printk/console_cmdline.h                 |  1 +
 kernel/printk/printk.c                          | 30 ++++++++++++++++++++-----
 3 files changed, 28 insertions(+), 9 deletions(-)

diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
index 0549662..f22b992 100644
--- a/Documentation/admin-guide/kernel-parameters.txt
+++ b/Documentation/admin-guide/kernel-parameters.txt
@@ -607,10 +607,10 @@
 		ttyS<n>[,options]
 		ttyUSB0[,options]
 			Use the specified serial port.  The options are of
-			the form "bbbbpnf", where "bbbb" is the baud rate,
+			the form "bbbbpnf/l", where "bbbb" is the baud rate,
 			"p" is parity ("n", "o", or "e"), "n" is number of
-			bits, and "f" is flow control ("r" for RTS or
-			omit it).  Default is "9600n8".
+			bits, "f" is flow control ("r" for RTS or omit it),
+			and "l" is the loglevel on [0,7]. Default is "9600n8".
 
 			See Documentation/admin-guide/serial-console.rst for more
 			information.  See
diff --git a/kernel/printk/console_cmdline.h b/kernel/printk/console_cmdline.h
index 2ca4a8b..269e666 100644
--- a/kernel/printk/console_cmdline.h
+++ b/kernel/printk/console_cmdline.h
@@ -5,6 +5,7 @@ struct console_cmdline
 {
 	char	name[16];			/* Name of the driver	    */
 	int	index;				/* Minor dev. to use	    */
+	int	loglevel;			/* Loglevel to use */
 	char	*options;			/* Options for the driver   */
 #ifdef CONFIG_A11Y_BRAILLE_CONSOLE
 	char	*brl_options;			/* Options for braille driver */
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 488bda3..4c14cf2 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1892,7 +1892,7 @@ asmlinkage __visible void early_printk(const char *fmt, ...)
 #endif
 
 static int __add_preferred_console(char *name, int idx, char *options,
-				   char *brl_options)
+				   int loglevel, char *brl_options)
 {
 	struct console_cmdline *c;
 	int i;
@@ -1918,6 +1918,7 @@ static int __add_preferred_console(char *name, int idx, char *options,
 	c->options = options;
 	braille_set_options(c, brl_options);
 
+	c->loglevel = loglevel;
 	c->index = idx;
 	return 0;
 }
@@ -1928,8 +1929,8 @@ static int __add_preferred_console(char *name, int idx, char *options,
 static int __init console_setup(char *str)
 {
 	char buf[sizeof(console_cmdline[0].name) + 4]; /* 4 for "ttyS" */
-	char *s, *options, *brl_options = NULL;
-	int idx;
+	char *s, *options, *llevel, *brl_options = NULL;
+	int idx, loglevel = LOGLEVEL_EMERG;
 
 	if (_braille_console_setup(&str, &brl_options))
 		return 1;
@@ -1947,6 +1948,14 @@ static int __init console_setup(char *str)
 	options = strchr(str, ',');
 	if (options)
 		*(options++) = 0;
+
+	llevel = strchr(str, '/');
+	if (llevel) {
+		*(llevel++) = 0;
+		if (kstrtoint(llevel, 10, &loglevel))
+			loglevel = LOGLEVEL_EMERG;
+	}
+
 #ifdef __sparc__
 	if (!strcmp(str, "ttya"))
 		strcpy(buf, "ttyS0");
@@ -1959,7 +1968,7 @@ static int __init console_setup(char *str)
 	idx = simple_strtoul(s, NULL, 10);
 	*s = 0;
 
-	__add_preferred_console(buf, idx, options, brl_options);
+	__add_preferred_console(buf, idx, options, loglevel, brl_options);
 	console_set_on_cmdline = 1;
 	return 1;
 }
@@ -1980,7 +1989,8 @@ __setup("console=", console_setup);
  */
 int add_preferred_console(char *name, int idx, char *options)
 {
-	return __add_preferred_console(name, idx, options, NULL);
+	return __add_preferred_console(name, idx, options, LOGLEVEL_EMERG,
+				       NULL);
 }
 
 bool console_suspend_enabled = true;
@@ -2475,6 +2485,7 @@ void register_console(struct console *newcon)
 	struct console *bcon = NULL;
 	struct console_cmdline *c;
 	static bool has_preferred;
+	bool extant = false;
 
 	if (console_drivers)
 		for_each_console(bcon)
@@ -2541,6 +2552,12 @@ void register_console(struct console *newcon)
 			if (newcon->index < 0)
 				newcon->index = c->index;
 
+			/*
+			 * Carry over the loglevel from the cmdline
+			 */
+			newcon->level = c->loglevel;
+			extant = true;
+
 			if (_braille_register_console(newcon, c))
 				return;
 
@@ -2572,8 +2589,9 @@ void register_console(struct console *newcon)
 	/*
 	 * By default, the per-console minimum forces no messages through.
 	 */
-	newcon->level = LOGLEVEL_EMERG;
 	newcon->kobj = NULL;
+	if (!extant)
+		newcon->level = LOGLEVEL_EMERG;
 
 	/*
 	 *	Put this console in the list - keep the
-- 
2.9.5

[toc] | [prev] | [next] | [standalone]

#1741879 — [PATCH 2/3] printk: Add /sys/consoles/ interface

This adds a new sysfs interface that contains a directory for each
console registered on the system. Each directory contains a single
"loglevel" file for reading and setting the per-console loglevel.

We can let kobject destruction race with console removal: if it does,
loglevel_{show,store}() will safely fail with -ENODEV. This is a little
weird, but avoids embedding the kobject and therefore needing to totally
refactor the way we handle console struct lifetime.

Cc: Petr Mladek <pmladek@suse.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Signed-off-by: Calvin Owens <calvinowens@fb.com>
---
(V1: https://lkml.org/lkml/2017/4/4/784)

Changes in V2:
	* Honor minimum_console_loglevel when setting loglevels
	* Added entry in Documentation/ABI/testing

 Documentation/ABI/testing/sysfs-consoles | 13 +++++
 include/linux/console.h                  |  1 +
 kernel/printk/printk.c                   | 88 ++++++++++++++++++++++++++++++++
 3 files changed, 102 insertions(+)
 create mode 100644 Documentation/ABI/testing/sysfs-consoles

diff --git a/Documentation/ABI/testing/sysfs-consoles b/Documentation/ABI/testing/sysfs-consoles
new file mode 100644
index 0000000..6a1593e
--- /dev/null
+++ b/Documentation/ABI/testing/sysfs-consoles
@@ -0,0 +1,13 @@
+What:		/sys/consoles/
+Date:		September 2017
+KernelVersion:	4.15
+Contact:	Calvin Owens <calvinowens@fb.com>
+Description:	The /sys/consoles tree contains a directory for each console
+		configured on the system. These directories contain the
+		following attributes:
+
+		* "loglevel"	Set the per-console loglevel: the kernel uses
+				max(system_loglevel, perconsole_loglevel) when
+				deciding whether to emit a given message. The
+				default is 0, which means max() always yields
+				the system setting in the kernel.printk sysctl.
diff --git a/include/linux/console.h b/include/linux/console.h
index a5b5d79..76840be 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -148,6 +148,7 @@ struct console {
 	void	*data;
 	struct	 console *next;
 	int	level;
+	struct kobject *kobj;
 };
 
 /*
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 3f1675e..488bda3 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -105,6 +105,8 @@ enum devkmsg_log_masks {
 
 static unsigned int __read_mostly devkmsg_log = DEVKMSG_LOG_MASK_DEFAULT;
 
+static struct kobject *consoles_dir_kobj;
+
 static int __control_devkmsg(char *str)
 {
 	if (!str)
@@ -2371,6 +2373,82 @@ static int __init keep_bootcon_setup(char *str)
 
 early_param("keep_bootcon", keep_bootcon_setup);
 
+static ssize_t loglevel_show(struct kobject *kobj, struct kobj_attribute *attr,
+			     char *buf)
+{
+	struct console *con;
+	ssize_t ret = -ENODEV;
+
+	console_lock();
+	for_each_console(con) {
+		if (con->kobj == kobj) {
+			ret = sprintf(buf, "%d\n", con->level);
+			break;
+		}
+	}
+	console_unlock();
+
+	return ret;
+}
+
+static ssize_t loglevel_store(struct kobject *kobj, struct kobj_attribute *attr,
+			      const char *buf, size_t count)
+{
+	struct console *con;
+	ssize_t ret;
+	int tmp;
+
+	ret = kstrtoint(buf, 10, &tmp);
+	if (ret < 0)
+		return ret;
+
+	if (tmp < LOGLEVEL_EMERG)
+		return -ERANGE;
+
+	/*
+	 * Mimic the behavior of /dev/kmsg with respect to minimum_loglevel
+	 */
+	if (tmp < minimum_console_loglevel)
+		tmp = minimum_console_loglevel;
+
+	ret = -ENODEV;
+	console_lock();
+	for_each_console(con) {
+		if (con->kobj == kobj) {
+			con->level = tmp;
+			ret = count;
+			break;
+		}
+	}
+	console_unlock();
+
+	return ret;
+}
+
+static const struct kobj_attribute console_loglevel_attr =
+	__ATTR(loglevel, 0644, loglevel_show, loglevel_store);
+
+static void console_register_sysfs(struct console *newcon)
+{
+	/*
+	 * We might be called very early from register_console(): in that case,
+	 * printk_late_init() will take care of this later.
+	 */
+	if (!consoles_dir_kobj)
+		return;
+
+	newcon->kobj = kobject_create_and_add(newcon->name, consoles_dir_kobj);
+	if (WARN_ON(!newcon->kobj))
+		return;
+
+	WARN_ON(sysfs_create_file(newcon->kobj, &console_loglevel_attr.attr));
+}
+
+static void console_unregister_sysfs(struct console *oldcon)
+{
+	kobject_put(oldcon->kobj);
+}
+
 /*
  * The console driver calls this routine during kernel initialization
  * to register the console printing procedure with printk() and to
@@ -2495,6 +2573,7 @@ void register_console(struct console *newcon)
 	 * By default, the per-console minimum forces no messages through.
 	 */
 	newcon->level = LOGLEVEL_EMERG;
+	newcon->kobj = NULL;
 
 	/*
 	 *	Put this console in the list - keep the
@@ -2531,6 +2610,7 @@ void register_console(struct console *newcon)
 		 */
 		exclusive_console = newcon;
 	}
+	console_register_sysfs(newcon);
 	console_unlock();
 	console_sysfs_notify();
 
@@ -2597,6 +2677,7 @@ int unregister_console(struct console *console)
 		console_drivers->flags |= CON_CONSDEV;
 
 	console->flags &= ~CON_ENABLED;
+	console_unregister_sysfs(console);
 	console_unlock();
 	console_sysfs_notify();
 	return res;
@@ -2672,6 +2753,13 @@ static int __init printk_late_init(void)
 	ret = cpuhp_setup_state_nocalls(CPUHP_AP_ONLINE_DYN, "printk:online",
 					console_cpu_notify, NULL);
 	WARN_ON(ret < 0);
+
+	consoles_dir_kobj = kobject_create_and_add("consoles", NULL);
+	WARN_ON(!consoles_dir_kobj);
+
+	for_each_console(con)
+		console_register_sysfs(con);
+
 	return 0;
 }
 late_initcall(printk_late_init);
-- 
2.9.5

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web