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

From: Vaneet Narang
Date: Fri Jun 01 2018 - 04:42:46 EST


Hi Sergey,

>> but the problem is real.
>
>Yep, could be. But not exactly the way it is described in the commit
>messages and the patch does not fully address the problem.
>
>The patch assumes that all those events happen sequentially. While
>in reality they can happen in parallel on different CPUs.
>
>Example:
>
> CPU0 CPU1
>
> set console verbose
>
> dump_backtrace()
> {
> // for (;;) print frames
> printk("%pS\n", frame0);
> printk("%pS\n", frame1);
> printk("%pS\n", frame2);
> printk("%pS\n", frame3);
> ... console_loglevel = CONSOLE_LOGLEVEL_SILENT;
> printk("%pS\n", frame12);
> printk("%pS\n", frame13);
> }
>

This is not printk issue, its printk usage issue. User need to handle this part using some protection.

What we highlighted is issue related to printk, Where usage is correct
but still printk can miss some logs due to printk design of asynchronous printing.


>Part of backtrace or the entire backtrace will be missed, because
>we read the global console_loglevel. The problem is still there.
>
>> The console handling is asynchronous even without the kthread.
>> The current console_lock owner is responsible for handling messages
>> also from other CPUs.
>
>A nitpick: that's another thing to improve in the commit message, because
> I don't see that console_silent() race in the upstream kernel. We even
> don't have any users of console_silent() function. The only thing that
> ever sets console_loglevel to CONSOLE_LOGLEVEL_SILENT is
> kernel/debug/kdb/kdb_io.c
>

Issue is not related to console_silent() user, Issue is with dynamic console log level handling.
Which can be done using dmesg as well.
For example:
dmesg -n 7
"Run some scenario to capture all the kernel logs"
dmesg -n 1

I may end up not getting all the logs if my console flush is slow &
dmesg -n 1 got excuted before flush .


Thanks & Regards,
Vaneet Narang