Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
MIME-Version: 1.0
References: <1549995065-27597-1-git-send-email-xiaoxiang@xiaomi.com>
 <20190212144606.4b7cf0f8@gandalf.local.home> <CAH2Cfb-Zd9TKgs52ROVGYg6F_hiN2ieWKwYPkxpVV8St+zwa2A@mail.gmail.com>
 <20190213084741.5512307a@gandalf.local.home> <CAH2Cfb9YTAf4j7tv4Q5dWM_jQCzsWBo6ufoT=BXYx5qpgcMCNQ@mail.gmail.com>
 <20190213093154.7af84743@gandalf.local.home>
In-Reply-To: <20190213093154.7af84743@gandalf.local.home>
From:   xiang xiao <xiaoxiang781216@gmail.com>
Date:   Thu, 14 Feb 2019 00:25:56 +0800
Message-ID: <CAH2Cfb-1n8-KwoAJqjoH-M701T+s6Dfp+j_YB=kMc-cnWAY=Pg@mail.gmail.com>
Subject: Re: [PATCH] printk: add KERN_NOTIME to skip the timestamp
To:     Steven Rostedt <rostedt@goodmis.org>
Cc:     Petr Mladek <pmladek@suse.com>,
        Sergey Senozhatsky <sergey.senozhatsky@gmail.com>,
        linux-kernel@vger.kernel.org, Xiang Xiao <xiaoxiang@xiaomi.com>
Content-Type: text/plain; charset="UTF-8"
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On Wed, Feb 13, 2019 at 10:31 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Wed, 13 Feb 2019 22:00:04 +0800
> xiang xiao <xiaoxiang781216@gmail.com> wrote:
>
> > On Wed, Feb 13, 2019 at 9:47 PM Steven Rostedt <rostedt@goodmis.org> wrote:
> > >
> > > On Wed, 13 Feb 2019 14:19:01 +0800
> > > xiang xiao <xiaoxiang781216@gmail.com> wrote:
> > >
> > > > On Wed, Feb 13, 2019 at 3:46 AM Steven Rostedt <rostedt@goodmis.org> wrote:
> > > > >
> > > > > On Wed, 13 Feb 2019 02:11:05 +0800
> > > > > Xiang Xiao <xiaoxiang781216@gmail.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
> > > > 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.
> > > >
> > >
> > > If the timestamps are different, then you don't want to remove the
> > > printk one. Otherwise you are going to have a confusion between your
> > > added timestamp mixed in with the kernel's inaccurate timestamps.
> > >
> >
> > Here is a sample output with this patch:
> > [   10.991426] virtio_rpmsg_bus virtio1: rpmsg host is online
> > [   10.991443] remoteproc remoteproc1: registered virtio1 (type 7)
> > [   10.991450] remoteproc remoteproc1: remote processor
> > f9210000.toppwr:sen-rproc is now up
> > [   10.993715] virtio_rpmsg_bus virtio1: creating channel
> > rpmsg-ttySENSOR addr 0x1
> > [   10.994606] virtio_rpmsg_bus virtio1: creating channel rpmsg-ttyGPS addr 0x2
> > [   10.995236] virtio_rpmsg_bus virtio1: creating channel rpmsg-clk addr 0x3
> > [   10.995702] virtio_rpmsg_bus virtio1: creating channel rpmsg-syslog addr 0x4
> > [   10.996197] virtio_rpmsg_bus virtio1: creating channel rpmsg-rtc addr 0x5
> > [   10.997297] virtio_rpmsg_bus virtio1: creating channel rpmsg-hostfs addr 0x6
> > [   10.999842] virtio_rpmsg_bus virtio1: creating channel rpmsg-usrsock addr 0x7
> > [     0.007680] sensor: NuttX sensor 7.28 e3c2ecb Feb 12 2019 16:53:49
> > arm song/banks
> > ^^^^^^^^^^^^^
> > [   11.918177] random: crng init done
> > [   12.567362] e2fsck: e2fsck 1.42.9 (28-Dec-2013)
> >
> > Without this patch:
> > [   10.991426] virtio_rpmsg_bus virtio1: rpmsg host is online
> > [   10.991443] remoteproc remoteproc1: registered virtio1 (type 7)
> > [   10.991450] remoteproc remoteproc1: remote processor
> > f9210000.toppwr:sen-rproc is now up
> > [   10.993715] virtio_rpmsg_bus virtio1: creating channel
> > rpmsg-ttySENSOR addr 0x1
> > [   10.994606] virtio_rpmsg_bus virtio1: creating channel rpmsg-ttyGPS addr 0x2
> > [   10.995236] virtio_rpmsg_bus virtio1: creating channel rpmsg-clk addr 0x3
> > [   10.995702] virtio_rpmsg_bus virtio1: creating channel rpmsg-syslog addr 0x4
> > [   10.996197] virtio_rpmsg_bus virtio1: creating channel rpmsg-rtc addr 0x5
> > [   10.997297] virtio_rpmsg_bus virtio1: creating channel rpmsg-hostfs addr 0x6
> > [   10.999842] virtio_rpmsg_bus virtio1: creating channel rpmsg-usrsock addr 0x7
> > [   11.105345][     0.007680] sensor: NuttX sensor 7.28 e3c2ecb Feb 12
> > 2019 16:53:49 arm song/banks
> > ^^^^^^^^^^^^^^^^^^^^^^^^^^
> > [   11.918177] random: crng init done
> > [   12.567362] e2fsck: e2fsck 1.42.9 (28-Dec-2013)
> >
> > Which one do you think better?
>
> Honestly, the one without the patch.
>
> Seriously, it also makes it easy to see where that message happened
> with respect to the other printks. With your patch, we would have no
> idea, and if I was a normal user, unaware of this patch, I would
> probably submit a bug report claiming that something is wrong with the
> timestamps.
>

Ok, I will remove KERN_NOTIME from rpmsg-syslog driver.

> -- Steve