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

[xiang xiao]

On Wed, Feb 13, 2019 at 3:46 AM Steven Rostedt <rostedt@xxxxxxxxxxx> wrote:
>
> On Wed, 13 Feb 2019 02:11:05 +0800
> Xiang Xiao <xiaoxiang781216@xxxxxxxxx> 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
4.Kernel call printk to dump the received buffer
So I want that printk skip the timestamp here.

> If anything, I would probably prefer that we export whether
> time is being printed, and have the caller not print time if printk is
> doing it already, than to add the complexity into printk itself.

Actually, the timestamp of our initial implementation like your
suggestion come from printk,
but we found that timestamp from kernel isn't accurate as from RTOS
due the buffer and IPC.

>
> -- Steve
>
> >
> > Signed-off-by: Xiang Xiao <xiaoxiang@xxxxxxxxxx>
> > ---
> >  include/linux/kern_levels.h | 2 ++
> >  include/linux/printk.h      | 1 +
> >  kernel/printk/printk.c      | 7 ++++++-
> >  3 files changed, 9 insertions(+), 1 deletion(-)
> >
> > diff --git a/include/linux/kern_levels.h b/include/linux/kern_levels.h
> > index d237fe8..ed2aec6 100644
> > --- a/include/linux/kern_levels.h
> > +++ b/include/linux/kern_levels.h
> > @@ -23,6 +23,8 @@
> >   */
> >  #define KERN_CONT    KERN_SOH "c"
> >
> > +#define KERN_NOTIME  KERN_SOH "t"    /* don't print the timestamp */
> > +
> >  /* integer equivalents of KERN_<LEVEL> */
> >  #define LOGLEVEL_SCHED               -2      /* Deferred messages from sched code
> >                                        * are set to this special level */
> > diff --git a/include/linux/printk.h b/include/linux/printk.h
> > index 77740a5..be12ac4 100644
> > --- a/include/linux/printk.h
> > +++ b/include/linux/printk.h
> > @@ -20,6 +20,7 @@ static inline int printk_get_level(const char *buffer)
> >               case '0' ... '7':
> >               case 'd':       /* KERN_DEFAULT */
> >               case 'c':       /* KERN_CONT */
> > +             case 't':       /* KERN_NOTIME */
> >                       return buffer[1];
> >               }
> >       }
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index d3d1703..0688cf2 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -346,6 +346,7 @@ enum log_flags {
> >       LOG_NEWLINE     = 2,    /* text ended with a newline */
> >       LOG_PREFIX      = 4,    /* text started with a prefix */
> >       LOG_CONT        = 8,    /* text is a fragment of a continuation line */
> > +     LOG_NOTIME      = 16,   /* don't print the timestamp */
> >  };
> >
> >  struct printk_log {
> > @@ -1247,7 +1248,7 @@ static size_t print_prefix(const struct printk_log *msg, bool syslog,
> >
> >       if (syslog)
> >               len = print_syslog((msg->facility << 3) | msg->level, buf);
> > -     if (time)
> > +     if (time && !(msg->flags & LOG_NOTIME))
> >               len += print_time(msg->ts_nsec, buf + len);
> >       return len;
> >  }
> > @@ -1873,6 +1874,10 @@ int vprintk_store(int facility, int level,
> >                               break;
> >                       case 'c':       /* KERN_CONT */
> >                               lflags |= LOG_CONT;
> > +                             break;
> > +                     case 't':       /* KERN_NOTIME */
> > +                             lflags |= LOG_NOTIME;
> > +                             break;
> >                       }
> >
> >                       text_len -= 2;
>