* [PATCHv2] printk: add console_msg_format command line option
@ 2017-12-19 8:42 Sergey Senozhatsky
2017-12-19 15:17 ` Steven Rostedt
2017-12-21 5:41 ` [PATCHv3] " Sergey Senozhatsky
0 siblings, 2 replies; 5+ messages in thread
From: Sergey Senozhatsky @ 2017-12-19 8:42 UTC (permalink / raw)
To: Petr Mladek, Steven Rostedt
Cc: Linus Torvalds, Fengguang Wu, Kevin Hilman, Mark Brown,
Greg Kroah-Hartman, Andrew Morton, LKML, Sergey Senozhatsky,
Sergey Senozhatsky
0day and kernelCI automatically parse kernel log - basically some sort
of grepping using the pre-defined text patterns - in order to detect
and report regressions/errors. There are several sources they get the
kernel logs from:
a) dmesg or /proc/ksmg
This is the preferred way. Because `dmesg --raw' (see later Note)
and /proc/kmsg output contains facility and log level, which greatly
simplifies grepping for EMERG/ALERT/CRIT/ERR messages.
b) serial consoles
This option is harder to maintain, because serial console messages
don't contain facility and log level.
This patch introduces a `console_msg_format=' command line option,
to switch between different message formatting on serial consoles.
For the time being we have just two options - default and syslog.
The "default" option just keeps the existing format. While the
"syslog" option makes serial console messages to appear in syslog
format [syslog() syscall], matching the `dmesg -S --raw' and
`cat /proc/kmsg' output formats:
- facility and log level
- time stamp (depends on printk_time/PRINTK_TIME)
- message
<%u>[time stamp] text\n
NOTE: while Kevin and Fengguang talk about "dmesg --raw", it's actually
"dmesg -S --raw" that always prints messages in syslog format [per
Petr Mladek]. Running "dmesg --raw" may produce output in non-syslog
format sometimes. console_msg_format=syslog enables syslog format,
thus in documentation we mention "dmesg -S --raw", not "dmesg --raw".
Per Kevin Hilman:
: Right now we can get this info from a "dmesg --raw" after bootup,
: but it would be really nice in certain automation frameworks to
: have a kernel command-line option to enable printing of loglevels
: in default boot log.
:
: This is especially useful when ingesting kernel logs into advanced
: search/analytics frameworks (I'm playing with and ELK stack: Elastic
: Search, Logstash, Kibana).
:
: The other important reason for having this on the command line is that
: for testing linux-next (and other bleeding edge developer branches),
: it's common that we never make it to userspace, so can't even run
: "dmesg --raw" (or equivalent.) So we really want this on the primary
: boot (serial) console.
Per Fengguang Wu, 0day scripts should quickly benefit from that
feature, because they will be able to switch to a more reliable
parsing, based on messages' facility and log levels [1]:
`#{grep} -a -E -e '^<[0123]>' -e '^kern :(err |crit |alert |emerg )'
instead of doing text pattern matching
`#{grep} -a -F -f /lkp/printk-error-messages #{kmsg_file} |
grep -a -v -E -f #{LKP_SRC}/etc/oops-pattern |
grep -a -v -F -f #{LKP_SRC}/etc/kmsg-blacklist`
[1] https://github.com/fengguang/lkp-tests/blob/master/lib/dmesg.rb
Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Reviewed-by: Fengguang Wu <fengguang.wu@intel.com>
Reviewed-by: Kevin Hilman <khilman@baylibre.com>
Tested-by: Kevin Hilman <khilman@baylibre.com>
---
v2: addressed comments made by Petr Mladek
Documentation/admin-guide/kernel-parameters.txt | 14 ++++++++++++++
kernel/printk/printk.c | 23 ++++++++++++++++++++++-
2 files changed, 36 insertions(+), 1 deletion(-)
diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
index 8a61d1eda677..543de386e01e 100644
--- a/Documentation/admin-guide/kernel-parameters.txt
+++ b/Documentation/admin-guide/kernel-parameters.txt
@@ -642,6 +642,20 @@
console=brl,ttyS0
For now, only VisioBraille is supported.
+ console_msg_format=
+ [KNL] Change console messages format
+ default
+ By default we print messages on consoles in
+ "[time stamp] text\n" format (time stamp may not be
+ printed, depending on CONFIG_PRINTK_TIME or
+ `printk_time' param).
+ syslog
+ Switch to syslog format: "<%u>[time stamp] text\n"
+ IOW, each message will have a facility and loglevel
+ prefix. The format is similar to one used by syslog()
+ syscall, or to executing "dmesg -S --raw" or to reading
+ from /proc/kmsg.
+
consoleblank= [KNL] The console blank (screen saver) timeout in
seconds. A value of 0 disables the blank timer.
Defaults to 0.
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c2e713f6ae2e..16dd91260273 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -277,6 +277,13 @@ EXPORT_SYMBOL(console_set_on_cmdline);
/* Flag: console code may call schedule() */
static int console_may_schedule;
+enum con_msg_format {
+ MSG_FORMAT_DEFAULT = 0,
+ MSG_FORMAT_SYSLOG = (1 << 0),
+};
+
+static int console_msg_format = MSG_FORMAT_DEFAULT;
+
/*
* The printk log buffer consists of a chain of concatenated variable
* length records. Every record starts with a record header, containing
@@ -1913,6 +1920,17 @@ static int __add_preferred_console(char *name, int idx, char *options,
c->index = idx;
return 0;
}
+
+static int __init console_msg_format_setup(char *str)
+{
+ if (!strncmp(str, "syslog", 6))
+ console_msg_format = MSG_FORMAT_SYSLOG;
+ if (!strncmp(str, "default", 7))
+ console_msg_format = MSG_FORMAT_DEFAULT;
+ return 1;
+}
+__setup("console_msg_format=", console_msg_format_setup);
+
/*
* Set up a console. Called via do_early_param() in init/main.c
* for each "console=" parameter in the boot command line.
@@ -2215,7 +2233,10 @@ void console_unlock(void)
goto skip;
}
- len += msg_print_text(msg, false, text + len, sizeof(text) - len);
+ len += msg_print_text(msg,
+ console_msg_format & MSG_FORMAT_SYSLOG,
+ text + len,
+ sizeof(text) - len);
if (nr_ext_console_drivers) {
ext_len = msg_print_ext_header(ext_text,
sizeof(ext_text),
--
2.15.1
^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PATCHv2] printk: add console_msg_format command line option
2017-12-19 8:42 [PATCHv2] printk: add console_msg_format command line option Sergey Senozhatsky
@ 2017-12-19 15:17 ` Steven Rostedt
2017-12-19 15:32 ` Sergey Senozhatsky
2017-12-21 5:41 ` [PATCHv3] " Sergey Senozhatsky
1 sibling, 1 reply; 5+ messages in thread
From: Steven Rostedt @ 2017-12-19 15:17 UTC (permalink / raw)
To: Sergey Senozhatsky
Cc: Petr Mladek, Linus Torvalds, Fengguang Wu, Kevin Hilman,
Mark Brown, Greg Kroah-Hartman, Andrew Morton, LKML,
Sergey Senozhatsky
On Tue, 19 Dec 2017 17:42:43 +0900
Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> wrote:
> diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
> index 8a61d1eda677..543de386e01e 100644
> --- a/Documentation/admin-guide/kernel-parameters.txt
> +++ b/Documentation/admin-guide/kernel-parameters.txt
> @@ -642,6 +642,20 @@
> console=brl,ttyS0
> For now, only VisioBraille is supported.
>
> + console_msg_format=
> + [KNL] Change console messages format
> + default
> + By default we print messages on consoles in
> + "[time stamp] text\n" format (time stamp may not be
> + printed, depending on CONFIG_PRINTK_TIME or
> + `printk_time' param).
> + syslog
> + Switch to syslog format: "<%u>[time stamp] text\n"
> + IOW, each message will have a facility and loglevel
> + prefix. The format is similar to one used by syslog()
> + syscall, or to executing "dmesg -S --raw" or to reading
> + from /proc/kmsg.
Just to clarify. This affects all consoles, not just serial?
> +
> consoleblank= [KNL] The console blank (screen saver) timeout in
> seconds. A value of 0 disables the blank timer.
> Defaults to 0.
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index c2e713f6ae2e..16dd91260273 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -277,6 +277,13 @@ EXPORT_SYMBOL(console_set_on_cmdline);
> /* Flag: console code may call schedule() */
> static int console_may_schedule;
>
> +enum con_msg_format {
> + MSG_FORMAT_DEFAULT = 0,
> + MSG_FORMAT_SYSLOG = (1 << 0),
> +};
So the con_msg_format will be a flag (as denoted with the (1<<0)).
Should we call it "con_msg_format_flags" to make it more obvious that
these are treated as flags and not a simple number.
> +
> +static int console_msg_format = MSG_FORMAT_DEFAULT;
> +
> /*
> * The printk log buffer consists of a chain of concatenated variable
> * length records. Every record starts with a record header, containing
> @@ -1913,6 +1920,17 @@ static int __add_preferred_console(char *name, int idx, char *options,
> c->index = idx;
> return 0;
> }
> +
> +static int __init console_msg_format_setup(char *str)
> +{
> + if (!strncmp(str, "syslog", 6))
> + console_msg_format = MSG_FORMAT_SYSLOG;
> + if (!strncmp(str, "default", 7))
You can use strcmp() instead of strncmp(), the init code will nul
terminate the string for you before calling this function. Otherwise if
we add "syslog_special" or "default_extra" they will be confused with
the above.
-- Steve
> + console_msg_format = MSG_FORMAT_DEFAULT;
> + return 1;
> +}
> +__setup("console_msg_format=", console_msg_format_setup);
> +
> /*
> * Set up a console. Called via do_early_param() in init/main.c
> * for each "console=" parameter in the boot command line.
> @@ -2215,7 +2233,10 @@ void console_unlock(void)
> goto skip;
> }
>
> - len += msg_print_text(msg, false, text + len, sizeof(text) - len);
> + len += msg_print_text(msg,
> + console_msg_format & MSG_FORMAT_SYSLOG,
> + text + len,
> + sizeof(text) - len);
> if (nr_ext_console_drivers) {
> ext_len = msg_print_ext_header(ext_text,
> sizeof(ext_text),
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCHv2] printk: add console_msg_format command line option
2017-12-19 15:17 ` Steven Rostedt
@ 2017-12-19 15:32 ` Sergey Senozhatsky
0 siblings, 0 replies; 5+ messages in thread
From: Sergey Senozhatsky @ 2017-12-19 15:32 UTC (permalink / raw)
To: Steven Rostedt
Cc: Sergey Senozhatsky, Petr Mladek, Linus Torvalds, Fengguang Wu,
Kevin Hilman, Mark Brown, Greg Kroah-Hartman, Andrew Morton,
LKML, Sergey Senozhatsky
Hi,
On (12/19/17 10:17), Steven Rostedt wrote:
[..]
> > + console_msg_format=
> > + [KNL] Change console messages format
> > + default
> > + By default we print messages on consoles in
> > + "[time stamp] text\n" format (time stamp may not be
> > + printed, depending on CONFIG_PRINTK_TIME or
> > + `printk_time' param).
> > + syslog
> > + Switch to syslog format: "<%u>[time stamp] text\n"
> > + IOW, each message will have a facility and loglevel
> > + prefix. The format is similar to one used by syslog()
> > + syscall, or to executing "dmesg -S --raw" or to reading
> > + from /proc/kmsg.
>
> Just to clarify. This affects all consoles, not just serial?
yes.
just like printk_time param/config option affects all the consoles,
console_msg_format affects all of them. we msg_print_text() once, that
makes messages look the same on every console. so I kept the existing
behaviour.
[..]
> > +enum con_msg_format {
> > + MSG_FORMAT_DEFAULT = 0,
> > + MSG_FORMAT_SYSLOG = (1 << 0),
> > +};
>
> So the con_msg_format will be a flag (as denoted with the (1<<0)).
> Should we call it "con_msg_format_flags" to make it more obvious that
> these are treated as flags and not a simple number.
ok, can do.
[..]
> > +static int __init console_msg_format_setup(char *str)
> > +{
> > + if (!strncmp(str, "syslog", 6))
> > + console_msg_format = MSG_FORMAT_SYSLOG;
> > + if (!strncmp(str, "default", 7))
>
> You can use strcmp() instead of strncmp(), the init code will nul
> terminate the string for you before calling this function. Otherwise if
> we add "syslog_special" or "default_extra" they will be confused with
> the above.
ok, that's a minor thing, but can change.
-ss
^ permalink raw reply [flat|nested] 5+ messages in thread
* [PATCHv3] printk: add console_msg_format command line option
2017-12-19 8:42 [PATCHv2] printk: add console_msg_format command line option Sergey Senozhatsky
2017-12-19 15:17 ` Steven Rostedt
@ 2017-12-21 5:41 ` Sergey Senozhatsky
2017-12-22 14:30 ` Petr Mladek
1 sibling, 1 reply; 5+ messages in thread
From: Sergey Senozhatsky @ 2017-12-21 5:41 UTC (permalink / raw)
To: Petr Mladek, Steven Rostedt
Cc: Linus Torvalds, Fengguang Wu, Kevin Hilman, Mark Brown,
Greg Kroah-Hartman, Andrew Morton, LKML, Sergey Senozhatsky,
Sergey Senozhatsky
0day and kernelCI automatically parse kernel log - basically some sort
of grepping using the pre-defined text patterns - in order to detect
and report regressions/errors. There are several sources they get the
kernel logs from:
a) dmesg or /proc/ksmg
This is the preferred way. Because `dmesg --raw' (see later Note)
and /proc/kmsg output contains facility and log level, which greatly
simplifies grepping for EMERG/ALERT/CRIT/ERR messages.
b) serial consoles
This option is harder to maintain, because serial console messages
don't contain facility and log level.
This patch introduces a `console_msg_format=' command line option,
to switch between different message formatting on serial consoles.
For the time being we have just two options - default and syslog.
The "default" option just keeps the existing format. While the
"syslog" option makes serial console messages to appear in syslog
format [syslog() syscall], matching the `dmesg -S --raw' and
`cat /proc/kmsg' output formats:
- facility and log level
- time stamp (depends on printk_time/PRINTK_TIME)
- message
<%u>[time stamp] text\n
NOTE: while Kevin and Fengguang talk about "dmesg --raw", it's actually
"dmesg -S --raw" that always prints messages in syslog format [per
Petr Mladek]. Running "dmesg --raw" may produce output in non-syslog
format sometimes. console_msg_format=syslog enables syslog format,
thus in documentation we mention "dmesg -S --raw", not "dmesg --raw".
Per Kevin Hilman:
: Right now we can get this info from a "dmesg --raw" after bootup,
: but it would be really nice in certain automation frameworks to
: have a kernel command-line option to enable printing of loglevels
: in default boot log.
:
: This is especially useful when ingesting kernel logs into advanced
: search/analytics frameworks (I'm playing with and ELK stack: Elastic
: Search, Logstash, Kibana).
:
: The other important reason for having this on the command line is that
: for testing linux-next (and other bleeding edge developer branches),
: it's common that we never make it to userspace, so can't even run
: "dmesg --raw" (or equivalent.) So we really want this on the primary
: boot (serial) console.
Per Fengguang Wu, 0day scripts should quickly benefit from that
feature, because they will be able to switch to a more reliable
parsing, based on messages' facility and log levels [1]:
`#{grep} -a -E -e '^<[0123]>' -e '^kern :(err |crit |alert |emerg )'
instead of doing text pattern matching
`#{grep} -a -F -f /lkp/printk-error-messages #{kmsg_file} |
grep -a -v -E -f #{LKP_SRC}/etc/oops-pattern |
grep -a -v -F -f #{LKP_SRC}/etc/kmsg-blacklist`
[1] https://github.com/fengguang/lkp-tests/blob/master/lib/dmesg.rb
Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Reviewed-by: Fengguang Wu <fengguang.wu@intel.com>
Reviewed-by: Kevin Hilman <khilman@baylibre.com>
Tested-by: Kevin Hilman <khilman@baylibre.com>
---
v3: addressed comments made by Steven Rostedt
v2: addressed comments made by Petr Mladek
Documentation/admin-guide/kernel-parameters.txt | 14 ++++++++++++++
kernel/printk/printk.c | 23 ++++++++++++++++++++++-
2 files changed, 36 insertions(+), 1 deletion(-)
diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
index 8a61d1eda677..543de386e01e 100644
--- a/Documentation/admin-guide/kernel-parameters.txt
+++ b/Documentation/admin-guide/kernel-parameters.txt
@@ -642,6 +642,20 @@
console=brl,ttyS0
For now, only VisioBraille is supported.
+ console_msg_format=
+ [KNL] Change console messages format
+ default
+ By default we print messages on consoles in
+ "[time stamp] text\n" format (time stamp may not be
+ printed, depending on CONFIG_PRINTK_TIME or
+ `printk_time' param).
+ syslog
+ Switch to syslog format: "<%u>[time stamp] text\n"
+ IOW, each message will have a facility and loglevel
+ prefix. The format is similar to one used by syslog()
+ syscall, or to executing "dmesg -S --raw" or to reading
+ from /proc/kmsg.
+
consoleblank= [KNL] The console blank (screen saver) timeout in
seconds. A value of 0 disables the blank timer.
Defaults to 0.
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c2e713f6ae2e..a214759b0fc1 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -277,6 +277,13 @@ EXPORT_SYMBOL(console_set_on_cmdline);
/* Flag: console code may call schedule() */
static int console_may_schedule;
+enum con_msg_format_flags {
+ MSG_FORMAT_DEFAULT = 0,
+ MSG_FORMAT_SYSLOG = (1 << 0),
+};
+
+static int console_msg_format = MSG_FORMAT_DEFAULT;
+
/*
* The printk log buffer consists of a chain of concatenated variable
* length records. Every record starts with a record header, containing
@@ -1913,6 +1920,17 @@ static int __add_preferred_console(char *name, int idx, char *options,
c->index = idx;
return 0;
}
+
+static int __init console_msg_format_setup(char *str)
+{
+ if (!strcmp(str, "syslog"))
+ console_msg_format = MSG_FORMAT_SYSLOG;
+ if (!strcmp(str, "default"))
+ console_msg_format = MSG_FORMAT_DEFAULT;
+ return 1;
+}
+__setup("console_msg_format=", console_msg_format_setup);
+
/*
* Set up a console. Called via do_early_param() in init/main.c
* for each "console=" parameter in the boot command line.
@@ -2215,7 +2233,10 @@ void console_unlock(void)
goto skip;
}
- len += msg_print_text(msg, false, text + len, sizeof(text) - len);
+ len += msg_print_text(msg,
+ console_msg_format & MSG_FORMAT_SYSLOG,
+ text + len,
+ sizeof(text) - len);
if (nr_ext_console_drivers) {
ext_len = msg_print_ext_header(ext_text,
sizeof(ext_text),
--
2.15.1
^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PATCHv3] printk: add console_msg_format command line option
2017-12-21 5:41 ` [PATCHv3] " Sergey Senozhatsky
@ 2017-12-22 14:30 ` Petr Mladek
0 siblings, 0 replies; 5+ messages in thread
From: Petr Mladek @ 2017-12-22 14:30 UTC (permalink / raw)
To: Sergey Senozhatsky
Cc: Steven Rostedt, Linus Torvalds, Fengguang Wu, Kevin Hilman,
Mark Brown, Greg Kroah-Hartman, Andrew Morton, LKML,
Sergey Senozhatsky
On Thu 2017-12-21 14:41:49, Sergey Senozhatsky wrote:
> This patch introduces a `console_msg_format=' command line option,
> to switch between different message formatting on serial consoles.
> For the time being we have just two options - default and syslog.
> The "default" option just keeps the existing format. While the
> "syslog" option makes serial console messages to appear in syslog
> format [syslog() syscall], matching the `dmesg -S --raw' and
> `cat /proc/kmsg' output formats:
>
> - facility and log level
> - time stamp (depends on printk_time/PRINTK_TIME)
> - message
>
> <%u>[time stamp] text\n
>
> Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
> Reviewed-by: Fengguang Wu <fengguang.wu@intel.com>
> Reviewed-by: Kevin Hilman <khilman@baylibre.com>
> Tested-by: Kevin Hilman <khilman@baylibre.com>
The patch looks and works good for me.
Reviewed-by: Petr Mladek <pmladek@suse.com>
I am going to add it into for-4.16 branch when I am back in January.
The patch is basically innocent. But I do not want to eventually
screw up printk.git with a last minute commit.
Best Regards,
Petr
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2017-12-22 14:30 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-12-19 8:42 [PATCHv2] printk: add console_msg_format command line option Sergey Senozhatsky
2017-12-19 15:17 ` Steven Rostedt
2017-12-19 15:32 ` Sergey Senozhatsky
2017-12-21 5:41 ` [PATCHv3] " Sergey Senozhatsky
2017-12-22 14:30 ` Petr Mladek
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).