Re: [RFC][PATCH] printk: add console_msg_format command line option

2017-12-07 Thread Sergey Senozhatsky
On (12/07/17 16:45), Petr Mladek wrote:
[.,]
> > hmm... `dmesg -S --raw' doesn't show anything on my system. `dmesg --raw'
> > matches the console_msg_format=syslog.
> 
> Huh, I am confused now. I thought that I saw the extended, /dev/kmsg - like,
> output with "dmesg --raw" but I do not see it now.
> 
> Anyway, I can see a difference related to
> /sys/module/printk/parameters/time. The command "dmesg --raw" always
> shows the timestamp help because it reads the messages via /dev/kmsg.
> But "dmesg -S --raw" shows the timestamp only when the "time"
> parameter is enabled:

aha, I see your point. -S forces dmesg to use syslog() syscall. so it
doesn't access the kmsg. otherwise it attempts to read from kmsg first.
you are right.

> $> echo 0 >/sys/module/printk/parameters/time
> $> dmesg -S --raw | head -n 3
> <5>Linux version 4.15.0-rc2-5-default+ (pmladek@pathway) (gcc version 4.8.5 
> (SUSE Linux)) #4180 SMP Thu Dec 7 16:06:42 CET 2017
> <6>Command line: BOOT_IMAGE=/boot/vmlinuz-4.15.0-rc2-5-default+ 
> root=UUID=9ba368bb-c323-4131-ad94-c29cf3add76f resume=/dev/sda2 
> earlyprintk=ttyS0,115200 console=tty0 console=ttyS0,115200 
> console_msg_format=syslog ignore_loglevel nosplash showopts 
> crashkernel=256M,high crashkernel=128M,low
> <6>x86/fpu: x87 FPU will use FXSAVE
> $> echo 1 >/sys/module/printk/parameters/time
> $> dmesg -S --raw | head -n 3
> <5>[0.00] Linux version 4.15.0-rc2-5-default+ (pmladek@pathway) (gcc 
> version 4.8.5 (SUSE Linux)) #4180 SMP Thu Dec 7 16:06:42 CET 2017
> <6>[0.00] Command line: 
> BOOT_IMAGE=/boot/vmlinuz-4.15.0-rc2-5-default+ 
> root=UUID=9ba368bb-c323-4131-ad94-c29cf3add76f resume=/dev/sda2 
> earlyprintk=ttyS0,115200 console=tty0 console=ttyS0,115200 
> console_msg_format=syslog ignore_loglevel nosplash showopts 
> crashkernel=256M,high crashkernel=128M,low
> <6>[0.00] x86/fpu: x87 FPU will use FXSAVE

I see.

> To be honest, I am somehow confused by the terminology.
> We should make it clear that the "syslog" console format
> is the same as the format used by the syslog syscall.

yeah. that was exactly my point. syslog format means that

 : we do what reading from /proc/kmsg does -- do_syslog(). which "is"
 : the same for some dmesg modes.

I thought that `dmesg --raw' always uses do_syslog(), apparently this
is not the case, and that "is" was not correct.

-ss


Re: [RFC][PATCH] printk: add console_msg_format command line option

2017-12-07 Thread Sergey Senozhatsky
On (12/07/17 16:45), Petr Mladek wrote:
[.,]
> > hmm... `dmesg -S --raw' doesn't show anything on my system. `dmesg --raw'
> > matches the console_msg_format=syslog.
> 
> Huh, I am confused now. I thought that I saw the extended, /dev/kmsg - like,
> output with "dmesg --raw" but I do not see it now.
> 
> Anyway, I can see a difference related to
> /sys/module/printk/parameters/time. The command "dmesg --raw" always
> shows the timestamp help because it reads the messages via /dev/kmsg.
> But "dmesg -S --raw" shows the timestamp only when the "time"
> parameter is enabled:

aha, I see your point. -S forces dmesg to use syslog() syscall. so it
doesn't access the kmsg. otherwise it attempts to read from kmsg first.
you are right.

> $> echo 0 >/sys/module/printk/parameters/time
> $> dmesg -S --raw | head -n 3
> <5>Linux version 4.15.0-rc2-5-default+ (pmladek@pathway) (gcc version 4.8.5 
> (SUSE Linux)) #4180 SMP Thu Dec 7 16:06:42 CET 2017
> <6>Command line: BOOT_IMAGE=/boot/vmlinuz-4.15.0-rc2-5-default+ 
> root=UUID=9ba368bb-c323-4131-ad94-c29cf3add76f resume=/dev/sda2 
> earlyprintk=ttyS0,115200 console=tty0 console=ttyS0,115200 
> console_msg_format=syslog ignore_loglevel nosplash showopts 
> crashkernel=256M,high crashkernel=128M,low
> <6>x86/fpu: x87 FPU will use FXSAVE
> $> echo 1 >/sys/module/printk/parameters/time
> $> dmesg -S --raw | head -n 3
> <5>[0.00] Linux version 4.15.0-rc2-5-default+ (pmladek@pathway) (gcc 
> version 4.8.5 (SUSE Linux)) #4180 SMP Thu Dec 7 16:06:42 CET 2017
> <6>[0.00] Command line: 
> BOOT_IMAGE=/boot/vmlinuz-4.15.0-rc2-5-default+ 
> root=UUID=9ba368bb-c323-4131-ad94-c29cf3add76f resume=/dev/sda2 
> earlyprintk=ttyS0,115200 console=tty0 console=ttyS0,115200 
> console_msg_format=syslog ignore_loglevel nosplash showopts 
> crashkernel=256M,high crashkernel=128M,low
> <6>[0.00] x86/fpu: x87 FPU will use FXSAVE

I see.

> To be honest, I am somehow confused by the terminology.
> We should make it clear that the "syslog" console format
> is the same as the format used by the syslog syscall.

yeah. that was exactly my point. syslog format means that

 : we do what reading from /proc/kmsg does -- do_syslog(). which "is"
 : the same for some dmesg modes.

I thought that `dmesg --raw' always uses do_syslog(), apparently this
is not the case, and that "is" was not correct.

-ss


Re: [RFC][PATCH] printk: add console_msg_format command line option

2017-12-07 Thread Petr Mladek
On Thu 2017-12-07 23:01:04, Sergey Senozhatsky wrote:
> Hi,
> 
> On (12/07/17 14:48), Petr Mladek 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 one option - syslog. This option
> > > makes serial console messages to appear in syslog format, matching
> > > the `dmesg --raw' and `cat /proc/kmsg' output formats:
> > 
> > I have realized that 'cat /proc/kmsg' did not work. It can be done using:
> 
> hm, it does work on my system. what do you mean by 'did not work'?
> 
> 
> > Also the format is more comlicated here, see printk.c:
> > 
> >  * /dev/kmsg exports the structured data in the following line format:
> >  *   ",,,[,additional_values, ... 
> > ];\n"
> 
> that's /dev/kmsg. /dev/kmsg != /proc/kmsg. I never mentioned /dev/kmsg
> in my commit. /dev/kmsg prints the extended stuff, /proc/kmsg does not.

Ah, I have messed /dev/kmsg and /proc/kmsg.

> 
> > > diff --git a/Documentation/admin-guide/kernel-parameters.txt 
> > > b/Documentation/admin-guide/kernel-parameters.txt
> > > index 28467638488d..2dd91c5073f9 100644
> > > --- a/Documentation/admin-guide/kernel-parameters.txt
> > > +++ b/Documentation/admin-guide/kernel-parameters.txt
> > > @@ -643,6 +643,16 @@
> > >   console=brl,ttyS0
> > >   For now, only VisioBraille is supported.
> > >  
> > > + console_msg_format=
> > > + [KNL] Control message format
> > > + By default we print messages 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 (similar to "dmesg --raw" or
> > > + reading from /proc/kmsg): "<%u>[time stamp] text\n"
> > 
> > To be precise, it exactly the same as "dmesg -S --raw". Also it is the
> > format used by SYSLOG_ACTION_READ* actions of the syslog syscall.
> 
> hmm... `dmesg -S --raw' doesn't show anything on my system. `dmesg --raw'
> matches the console_msg_format=syslog.

Huh, I am confused now. I thought that I saw the extended, /dev/kmsg - like,
output with "dmesg --raw" but I do not see it now.

Anyway, I can see a difference related to
/sys/module/printk/parameters/time. The command "dmesg --raw" always
shows the timestamp help because it reads the messages via /dev/kmsg.
But "dmesg -S --raw" shows the timestamp only when the "time"
parameter is enabled:

$> echo 0 >/sys/module/printk/parameters/time
$> dmesg -S --raw | head -n 3
<5>Linux version 4.15.0-rc2-5-default+ (pmladek@pathway) (gcc version 4.8.5 
(SUSE Linux)) #4180 SMP Thu Dec 7 16:06:42 CET 2017
<6>Command line: BOOT_IMAGE=/boot/vmlinuz-4.15.0-rc2-5-default+ 
root=UUID=9ba368bb-c323-4131-ad94-c29cf3add76f resume=/dev/sda2 
earlyprintk=ttyS0,115200 console=tty0 console=ttyS0,115200 
console_msg_format=syslog ignore_loglevel nosplash showopts 
crashkernel=256M,high crashkernel=128M,low
<6>x86/fpu: x87 FPU will use FXSAVE
$> echo 1 >/sys/module/printk/parameters/time
$> dmesg -S --raw | head -n 3
<5>[0.00] Linux version 4.15.0-rc2-5-default+ (pmladek@pathway) (gcc 
version 4.8.5 (SUSE Linux)) #4180 SMP Thu Dec 7 16:06:42 CET 2017
<6>[0.00] Command line: BOOT_IMAGE=/boot/vmlinuz-4.15.0-rc2-5-default+ 
root=UUID=9ba368bb-c323-4131-ad94-c29cf3add76f resume=/dev/sda2 
earlyprintk=ttyS0,115200 console=tty0 console=ttyS0,115200 
console_msg_format=syslog ignore_loglevel nosplash showopts 
crashkernel=256M,high crashkernel=128M,low
<6>[0.00] x86/fpu: x87 FPU will use FXSAVE

Note that the -S option has been added in util-linux, v2.22
by the commit
https://git.kernel.org/pub/scm/utils/util-linux/util-linux.git/commit/?id=ed61acc2542ebb0d9b8f5600c38fbe0d77933345

I guess that dmesg fallbacks to the classic syslog mode
when /dev/kmsg is not available.


To be honest, I am somehow confused by the terminology.
We should make it clear that the "syslog" console format
is the same as the format used by the syslog syscall.

dmesg --raw might show something different when it gets the data
from /dev/kmsg as shown above.

Best Regards,
Petr


Re: [RFC][PATCH] printk: add console_msg_format command line option

2017-12-07 Thread Petr Mladek
On Thu 2017-12-07 23:01:04, Sergey Senozhatsky wrote:
> Hi,
> 
> On (12/07/17 14:48), Petr Mladek 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 one option - syslog. This option
> > > makes serial console messages to appear in syslog format, matching
> > > the `dmesg --raw' and `cat /proc/kmsg' output formats:
> > 
> > I have realized that 'cat /proc/kmsg' did not work. It can be done using:
> 
> hm, it does work on my system. what do you mean by 'did not work'?
> 
> 
> > Also the format is more comlicated here, see printk.c:
> > 
> >  * /dev/kmsg exports the structured data in the following line format:
> >  *   ",,,[,additional_values, ... 
> > ];\n"
> 
> that's /dev/kmsg. /dev/kmsg != /proc/kmsg. I never mentioned /dev/kmsg
> in my commit. /dev/kmsg prints the extended stuff, /proc/kmsg does not.

Ah, I have messed /dev/kmsg and /proc/kmsg.

> 
> > > diff --git a/Documentation/admin-guide/kernel-parameters.txt 
> > > b/Documentation/admin-guide/kernel-parameters.txt
> > > index 28467638488d..2dd91c5073f9 100644
> > > --- a/Documentation/admin-guide/kernel-parameters.txt
> > > +++ b/Documentation/admin-guide/kernel-parameters.txt
> > > @@ -643,6 +643,16 @@
> > >   console=brl,ttyS0
> > >   For now, only VisioBraille is supported.
> > >  
> > > + console_msg_format=
> > > + [KNL] Control message format
> > > + By default we print messages 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 (similar to "dmesg --raw" or
> > > + reading from /proc/kmsg): "<%u>[time stamp] text\n"
> > 
> > To be precise, it exactly the same as "dmesg -S --raw". Also it is the
> > format used by SYSLOG_ACTION_READ* actions of the syslog syscall.
> 
> hmm... `dmesg -S --raw' doesn't show anything on my system. `dmesg --raw'
> matches the console_msg_format=syslog.

Huh, I am confused now. I thought that I saw the extended, /dev/kmsg - like,
output with "dmesg --raw" but I do not see it now.

Anyway, I can see a difference related to
/sys/module/printk/parameters/time. The command "dmesg --raw" always
shows the timestamp help because it reads the messages via /dev/kmsg.
But "dmesg -S --raw" shows the timestamp only when the "time"
parameter is enabled:

$> echo 0 >/sys/module/printk/parameters/time
$> dmesg -S --raw | head -n 3
<5>Linux version 4.15.0-rc2-5-default+ (pmladek@pathway) (gcc version 4.8.5 
(SUSE Linux)) #4180 SMP Thu Dec 7 16:06:42 CET 2017
<6>Command line: BOOT_IMAGE=/boot/vmlinuz-4.15.0-rc2-5-default+ 
root=UUID=9ba368bb-c323-4131-ad94-c29cf3add76f resume=/dev/sda2 
earlyprintk=ttyS0,115200 console=tty0 console=ttyS0,115200 
console_msg_format=syslog ignore_loglevel nosplash showopts 
crashkernel=256M,high crashkernel=128M,low
<6>x86/fpu: x87 FPU will use FXSAVE
$> echo 1 >/sys/module/printk/parameters/time
$> dmesg -S --raw | head -n 3
<5>[0.00] Linux version 4.15.0-rc2-5-default+ (pmladek@pathway) (gcc 
version 4.8.5 (SUSE Linux)) #4180 SMP Thu Dec 7 16:06:42 CET 2017
<6>[0.00] Command line: BOOT_IMAGE=/boot/vmlinuz-4.15.0-rc2-5-default+ 
root=UUID=9ba368bb-c323-4131-ad94-c29cf3add76f resume=/dev/sda2 
earlyprintk=ttyS0,115200 console=tty0 console=ttyS0,115200 
console_msg_format=syslog ignore_loglevel nosplash showopts 
crashkernel=256M,high crashkernel=128M,low
<6>[0.00] x86/fpu: x87 FPU will use FXSAVE

Note that the -S option has been added in util-linux, v2.22
by the commit
https://git.kernel.org/pub/scm/utils/util-linux/util-linux.git/commit/?id=ed61acc2542ebb0d9b8f5600c38fbe0d77933345

I guess that dmesg fallbacks to the classic syslog mode
when /dev/kmsg is not available.


To be honest, I am somehow confused by the terminology.
We should make it clear that the "syslog" console format
is the same as the format used by the syslog syscall.

dmesg --raw might show something different when it gets the data
from /dev/kmsg as shown above.

Best Regards,
Petr


Re: [RFC][PATCH] printk: add console_msg_format command line option

2017-12-07 Thread Sergey Senozhatsky
Hi,

On (12/07/17 14:48), Petr Mladek 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 one option - syslog. This option
> > makes serial console messages to appear in syslog format, matching
> > the `dmesg --raw' and `cat /proc/kmsg' output formats:
> 
> I have realized that 'cat /proc/kmsg' did not work. It can be done using:

hm, it does work on my system. what do you mean by 'did not work'?


> Also the format is more comlicated here, see printk.c:
> 
>  * /dev/kmsg exports the structured data in the following line format:
>  *   ",,,[,additional_values, ... 
> ];\n"

that's /dev/kmsg. /dev/kmsg != /proc/kmsg. I never mentioned /dev/kmsg
in my commit. /dev/kmsg prints the extended stuff, /proc/kmsg does not.


> > diff --git a/Documentation/admin-guide/kernel-parameters.txt 
> > b/Documentation/admin-guide/kernel-parameters.txt
> > index 28467638488d..2dd91c5073f9 100644
> > --- a/Documentation/admin-guide/kernel-parameters.txt
> > +++ b/Documentation/admin-guide/kernel-parameters.txt
> > @@ -643,6 +643,16 @@
> > console=brl,ttyS0
> > For now, only VisioBraille is supported.
> >  
> > +   console_msg_format=
> > +   [KNL] Control message format
> > +   By default we print messages 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 (similar to "dmesg --raw" or
> > +   reading from /proc/kmsg): "<%u>[time stamp] text\n"
> 
> To be precise, it exactly the same as "dmesg -S --raw". Also it is the
> format used by SYSLOG_ACTION_READ* actions of the syslog syscall.

hmm... `dmesg -S --raw' doesn't show anything on my system. `dmesg --raw'
matches the console_msg_format=syslog.


> > +static int __init console_msg_format_setup(char *str)
> > +{
> > +   if (!strncmp(str, "syslog", 6))
> > +   console_msg_format = MSG_FORMAT_SYSLOG;
> 
> It might make sense to accept also the "default" format.
> 
> > +   return 1;
> > +}
> > +__setup("console_msg_format=", console_msg_format_setup);
> 
> I would use early_param() so that it takes effect as soon as possible.

ok. can take a look.

-ss


Re: [RFC][PATCH] printk: add console_msg_format command line option

2017-12-07 Thread Sergey Senozhatsky
Hi,

On (12/07/17 14:48), Petr Mladek 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 one option - syslog. This option
> > makes serial console messages to appear in syslog format, matching
> > the `dmesg --raw' and `cat /proc/kmsg' output formats:
> 
> I have realized that 'cat /proc/kmsg' did not work. It can be done using:

hm, it does work on my system. what do you mean by 'did not work'?


> Also the format is more comlicated here, see printk.c:
> 
>  * /dev/kmsg exports the structured data in the following line format:
>  *   ",,,[,additional_values, ... 
> ];\n"

that's /dev/kmsg. /dev/kmsg != /proc/kmsg. I never mentioned /dev/kmsg
in my commit. /dev/kmsg prints the extended stuff, /proc/kmsg does not.


> > diff --git a/Documentation/admin-guide/kernel-parameters.txt 
> > b/Documentation/admin-guide/kernel-parameters.txt
> > index 28467638488d..2dd91c5073f9 100644
> > --- a/Documentation/admin-guide/kernel-parameters.txt
> > +++ b/Documentation/admin-guide/kernel-parameters.txt
> > @@ -643,6 +643,16 @@
> > console=brl,ttyS0
> > For now, only VisioBraille is supported.
> >  
> > +   console_msg_format=
> > +   [KNL] Control message format
> > +   By default we print messages 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 (similar to "dmesg --raw" or
> > +   reading from /proc/kmsg): "<%u>[time stamp] text\n"
> 
> To be precise, it exactly the same as "dmesg -S --raw". Also it is the
> format used by SYSLOG_ACTION_READ* actions of the syslog syscall.

hmm... `dmesg -S --raw' doesn't show anything on my system. `dmesg --raw'
matches the console_msg_format=syslog.


> > +static int __init console_msg_format_setup(char *str)
> > +{
> > +   if (!strncmp(str, "syslog", 6))
> > +   console_msg_format = MSG_FORMAT_SYSLOG;
> 
> It might make sense to accept also the "default" format.
> 
> > +   return 1;
> > +}
> > +__setup("console_msg_format=", console_msg_format_setup);
> 
> I would use early_param() so that it takes effect as soon as possible.

ok. can take a look.

-ss


Re: [RFC][PATCH] printk: add console_msg_format command line option

2017-12-07 Thread Petr Mladek
On Fri 2017-12-01 19:44:04, Sergey Senozhatsky wrote:
> 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' 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 one option - syslog. This option
> makes serial console messages to appear in syslog format, matching
> the `dmesg --raw' and `cat /proc/kmsg' output formats:

I have realized that 'cat /proc/kmsg' did not work. It can be done using:

dd if=/dev/kmsg iflag=nonblock

Also the format is more comlicated here, see printk.c:

 * /dev/kmsg exports the structured data in the following line format:
 *   ",,,[,additional_values, ... 
];\n"

> diff --git a/Documentation/admin-guide/kernel-parameters.txt 
> b/Documentation/admin-guide/kernel-parameters.txt
> index 28467638488d..2dd91c5073f9 100644
> --- a/Documentation/admin-guide/kernel-parameters.txt
> +++ b/Documentation/admin-guide/kernel-parameters.txt
> @@ -643,6 +643,16 @@
>   console=brl,ttyS0
>   For now, only VisioBraille is supported.
>  
> + console_msg_format=
> + [KNL] Control message format
> + By default we print messages 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 (similar to "dmesg --raw" or
> + reading from /proc/kmsg): "<%u>[time stamp] text\n"

To be precise, it exactly the same as "dmesg -S --raw". Also it is the
format used by SYSLOG_ACTION_READ* actions of the syslog syscall.

Note that it is affected by CONFIG_PRINTK_TIME or "printk_time" command-line
option the same way as the default format.

> + IOW, each message has a facility and loglevel prefix.
> +
>   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 5d81206a572d..012a6b4991a6 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,15 @@ 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;

It might make sense to accept also the "default" format.

> + return 1;
> +}
> +__setup("console_msg_format=", console_msg_format_setup);

I would use early_param() so that it takes effect as soon as possible.

Otherwise, it looks fine. The patch is nicely minimalistic.

Best Regards,
Petr


Re: [RFC][PATCH] printk: add console_msg_format command line option

2017-12-07 Thread Petr Mladek
On Fri 2017-12-01 19:44:04, Sergey Senozhatsky wrote:
> 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' 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 one option - syslog. This option
> makes serial console messages to appear in syslog format, matching
> the `dmesg --raw' and `cat /proc/kmsg' output formats:

I have realized that 'cat /proc/kmsg' did not work. It can be done using:

dd if=/dev/kmsg iflag=nonblock

Also the format is more comlicated here, see printk.c:

 * /dev/kmsg exports the structured data in the following line format:
 *   ",,,[,additional_values, ... 
];\n"

> diff --git a/Documentation/admin-guide/kernel-parameters.txt 
> b/Documentation/admin-guide/kernel-parameters.txt
> index 28467638488d..2dd91c5073f9 100644
> --- a/Documentation/admin-guide/kernel-parameters.txt
> +++ b/Documentation/admin-guide/kernel-parameters.txt
> @@ -643,6 +643,16 @@
>   console=brl,ttyS0
>   For now, only VisioBraille is supported.
>  
> + console_msg_format=
> + [KNL] Control message format
> + By default we print messages 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 (similar to "dmesg --raw" or
> + reading from /proc/kmsg): "<%u>[time stamp] text\n"

To be precise, it exactly the same as "dmesg -S --raw". Also it is the
format used by SYSLOG_ACTION_READ* actions of the syslog syscall.

Note that it is affected by CONFIG_PRINTK_TIME or "printk_time" command-line
option the same way as the default format.

> + IOW, each message has a facility and loglevel prefix.
> +
>   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 5d81206a572d..012a6b4991a6 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,15 @@ 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;

It might make sense to accept also the "default" format.

> + return 1;
> +}
> +__setup("console_msg_format=", console_msg_format_setup);

I would use early_param() so that it takes effect as soon as possible.

Otherwise, it looks fine. The patch is nicely minimalistic.

Best Regards,
Petr