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

[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:
> >  *   "<level>,<sequnum>,<timestamp>,<contflag>[,additional_values, ... ];<message text>\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.000000] 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.000000] 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.000000] 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