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

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