linux-kernel - Re: [PATCH] printk: add KERN_NOTIME to skip the timestamp

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <CAH2Cfb-5-ZxQPBTx_Gxt9kK3DqwTOS1Z6RVJ-ewMSB2-U0eTRg@mail.gmail.com>
Date:   Wed, 13 Feb 2019 21:49:30 +0800
From:   xiang xiao <xiaoxiang781216@...il.com>
To:     Petr Mladek <pmladek@...e.com>
Cc:     Steven Rostedt <rostedt@...dmis.org>,
        Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
        linux-kernel@...r.kernel.org, Xiang Xiao <xiaoxiang@...omi.com>
Subject: Re: [PATCH] printk: add KERN_NOTIME to skip the timestamp

On Wed, Feb 13, 2019 at 9:19 PM Petr Mladek <pmladek@...e.com> wrote:
>
> On Wed 2019-02-13 14:19:01, xiang xiao wrote:
> > On Wed, Feb 13, 2019 at 3:46 AM Steven Rostedt <rostedt@...dmis.org> wrote:
> > >
> > > On Wed, 13 Feb 2019 02:11:05 +0800
> > > Xiang Xiao <xiaoxiang781216@...il.com> wrote:
> > >
> > > > Because log may already add the timestamp sometime
> > >
> > > Can you be a bit more detailed on this. When and where does this
> > > happen?
> >
> > Here is my case:
> > 1.A small MCU(Cortex M4) in SoC run RTOS
> > 2.RTOS append timestamp to log for the accurate timing
> > 3.RTOS send log to Linux kernel when buffer exceed the threshold
>
> What do you exactly mean by the threshold, please?

The current algorithm is:
1.the free space is less than 25% or
2.the idle time is large than 100ms

> Does it mean
> that you use the kernel buffer when there are too many messages
> and they do not fit into the MCU local buffer?

The buffering just happen in MCU side, kernel don't do any buffering
except waiting for '\n' before printk.

>
> How exactly the kernel gets the messages, please?
> Via a kernel driver or from userspace (via /dev/kmsg)?
>

It's a kernel rpmsg driver:
https://github.com/thesofproject/linux/pull/177/commits/a0b7009fede5552dc98733f2996a8140bff62455

>
> > 4.Kernel call printk to dump the received buffer
> > So I want that printk skip the timestamp here.
>
> If the messages are printed by a kernel driver then
> a better solution would be to create a printk() API
> where you could pass the time stamp as a parameter.

Yes, this is a better approach and could fix all issues you list below.

>
> The aim is to store the precise time stamp in ts_nsec, struct
> printk_log. Then it will get handled correctly by any
> output, e.g. consoles, syslog, /dev/kmsg.
>
>
> There are several problems with your approach:
>
> 1. The time stamp is still duplicated in the output via /dev/kmsg,
>    see msg_print_ext_header(). We could not change this
>    because the time stamp is part of the format.
>    Any change could break userspace (systemd).
>
>
> 2. The time stamp stays part of the message:
>
>      + It might have different format than the normal
>        time stamp. Therefore it might be hard to filter
>
>      + dmesg might be unable to parse it and show in
>        the other formats.
>
>      + Kernel-5.1 will allow to print information
>        about the caller. It is supposed to be between
>        the time stamp and the message text, see
>        http://lkml.kernel.org/r/93f19e57-5051-c67d-9af4-b17624062d44@i-love.sakura.ne.jp
>
>
> Best Regards,
> Petr