Re: [PATCH] printk: don't unconditionally shortcut print_time()

[Petr Mladek]

On Sat 2018-11-24 19:50:13, Tetsuo Handa wrote:
> Since /sys/module/printk/parameters/time can change from N to Y between
> "msg_print_text() called print_prefix() with buf == NULL" and
> "msg_print_text() again calls print_prefix() with buf != NULL", it is not
> safe for print_time() to unconditionally return 0 if printk_time == false.
>
> Signed-off-by: Tetsuo Handa <penguin-kernel@xxxxxxxxxxxxxxxxxxx>
> ---
>  kernel/printk/printk.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 5c2079d..df7ced0 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1230,7 +1230,7 @@ static size_t print_time(u64 ts, char *buf)
>  {
>  	unsigned long rem_nsec;
>  
> -	if (!printk_time)
> +	if (!printk_time && buf)

This fixes a real problem. It might even avoid a crash.

See syslog_print_all() and kmsg_dump_get_buffer(). They
start with calling msg_print_text() many times to calculate
how many messages fit into the given buffer. Then they
blindly copy the messages into the buffer.

Now, the buffer might overflow if the size is calculated
with printk_time disabled and the messages are copied with
printk_time enabled.


Well, the time stamps are 22% of the printed characters on
my test systems:

$> dmesg | wc -l
524
$> dmesg | wc -c
33013
>$ bc -l
524 * 14 / 33013
.22221549086723411989

It seems worth supporting the disabled printk_time() properly.
I am not sure who is disabling the timestamps. But people might
worry if we waste 22% of the given buffer.

IMHO, passing it as parameter to msg_print_text(), print_prefix(),
and print_time() looks acceptable.

Best Regards,
Petr