Re: [PATCH 2/2] printk: make sure to print log on console.

[Petr Mladek]

On Thu 2018-05-31 15:49:11, Maninder Singh wrote:
> This patch make sure printing of log if loglevel at time of storing
> log is greater than current console loglevel.
> 
> @why
> In case of async printk, printk thread can miss logs because it checks
> current log level at time of console_unlock.
> 
> func()
> {
> ....
> ....
> 	console_verbose();  // user wants to have all the logs on console.
> 	pr_alert();
> 	pr_info();
> 	dump_backtrace(); // prints with default loglevel.
> 	pr_info();
> 	pr_emerg();
> 	pr_info();
> 	...
> 	...
> 	...
> 	pr_info();
> 	console_silent(); // stop all logs from printing on console.
> }
> 
> Now if printk thread is scheduled after setting console loglevel
> to silent, then user's requirement will be in waste, because it will not
> print logs on console at time of printk thread scheduling.

A better text would be something like:

Now if console_lock was owned by another process, the messages might
be handled after the consoles were silenced.

> @how
> use one bit of flags field to store whether its console print
> or not(console_print) by checking current console loglevel with 
> message's level at time of log.
> At time of print check this flag for printing message on console.
> 
> Signed-off-by: Vaneet Narang <v.narang@xxxxxxxxxxx>
> Signed-off-by: Maninder Singh <maninder1.s@xxxxxxxxxxx>
> ---
>  kernel/printk/printk.c | 33 +++++++++++++++++++++++----------
>  1 file changed, 23 insertions(+), 10 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index ab15903..4e0be66e 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -360,8 +360,16 @@ struct printk_log {
>  	u16 text_len;		/* length of text buffer */
>  	u16 dict_len;		/* length of dictionary buffer */
>  	u8 facility;		/* syslog facility */
> -	u8 flags:5;		/* internal record flags */
> +	u8 flags:4;		/* internal record flags */
>  	u8 level:3;		/* syslog level */
> +	/*
> +	 * whether to print this msg on console or not?
> +	 * due to async printk, printk thread can miss
> +	 * prints at the time of console_flush because of
> +	 * change in print level afterwards.
> +	 */
> +	u8 console_print:1;

We should be careful with changing the structure. It is accessed
by external tools, like "crash".

IMHO, it is perfectly fine to handle this by a flag, e.g.
add LOG_CON_SUPPRESS.

> +
>  }
>  #ifdef CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS
>  __packed __aligned(4)
> @@ -623,7 +631,12 @@ static int log_store(int facility, int level,
>  	msg->dict_len = dict_len;
>  	msg->facility = facility;
>  	msg->level = level & 7;
> -	msg->flags = flags & 0x1f;
> +	if (msg->level >= console_loglevel)
> +		msg->console_print = 0;
> +	else
> +		msg->console_print = 1;

We are going to decide about the visibility when the message is
stored. Let's handle it completely and make it easier later.

We could keep suppress_message_printing() as is and do the following
in vprintk_emit():

	if (suppress_message_printing(level)
		lflags |= LOG_CON_SUPPRESS;

> @@ -2354,7 +2367,7 @@ void console_unlock(void)
>  			break;
>  
>  		msg = log_from_idx(console_idx);
> -		if (suppress_message_printing(msg->level)) {
> +		if (suppress_message_printing(msg->console_print)) {

Then it is enough to do

-		if (suppress_message_printing(msg->level)) {
+		if (msg->flags & LOG_CON_SUPRESSED) {

Best Regards,
Petr

  			/*
>  			 * Skip record we have buffered and already printed
>  			 * directly to the console when we received it, and
> -- 
> 1.9.1
>