Re: [PATCH 1/3] printk: Introduce per-console loglevel setting
On 10/20/2017 01:05 AM, Petr Mladek wrote: On Thu 2017-10-19 16:40:45, Calvin Owens wrote: On 09/28/2017 05:43 PM, Calvin Owens wrote: 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. Any thoughts on this series? Happy to resend again, but if there are no objections I'd love to see it merged sooner rather than later :) Happy to resend too, just let me know. There is no need to resend the patch. It is on my radar and I am going to look at it. Please, be patient, you hit conference, illness, after vacation season. We do not want to unnecessarily delay it but it is not a trivial change that might be accepted within minutes. No worries, just wanted to make sure it hadn't been missed :) Thanks, Calvin Best Regards, Petr -- To unsubscribe from this list: send the line "unsubscribe linux-doc" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH 1/3] printk: Introduce per-console loglevel setting
On 09/28/2017 05:43 PM, Calvin Owens wrote:
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.
Any thoughts on this series? Happy to resend again, but if there are no
objections I'd love to see it merged sooner rather than later :)
Happy to resend too, just let me know.
Thanks,
Calvin
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 <pmla...@suse.com>
Cc: Steven Rostedt <rost...@goodmis.org>
Cc: Sergey Senozhatsky <sergey.senozhat...@gmail.com>
Signed-off-by: Calvin Owens <calvinow...@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_
[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 <pmla...@suse.com>
Cc: Steven Rostedt <rost...@goodmis.org>
Cc: Sergey Senozhatsky <sergey.senozhat...@gmail.com>
Signed-off-by: Calvin Owens <calvinow...@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_te
[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 <pmla...@suse.com>
Cc: Steven Rostedt <rost...@goodmis.org>
Cc: Sergey Senozhatsky <sergey.senozhat...@gmail.com>
Signed-off-by: Calvin Owens <calvinow...@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 000..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 <calvinow...@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, );
+ 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, _loglevel_attr.attr));
+}
+
+static void console_unregister_sysfs(struct console *oldcon)
+{
+ kob
[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 <pmla...@suse.com>
Cc: Steven Rostedt <rost...@goodmis.org>
Cc: Sergey Senozhatsky <sergey.senozhat...@gmail.com>
Signed-off-by: Calvin Owens <calvinow...@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[,options]
ttyUSB0[,options]
Use the specified serial port. The options are of
- the form "pnf", where "" is the baud rate,
+ the form "pnf/l", where "" 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
{
charname[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(, _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_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)
stru
