Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18;
Date:   Wed, 5 Aug 2020 16:04:30 +0200
From:   Petr Mladek <pmladek@suse.com>
To:     Prarit Bhargava <prarit@redhat.com>
Cc:     corbet@lwn.net, rostedt@goodmis.org, sergey.senozhatsky@gmail.com,
        chunyan.zhang@unisoc.com, linux-doc@vger.kernel.org,
        linux-kernel@vger.kernel.org, orsonzhai@gmail.com,
        zhang.lyra@gmail.com
Subject: Re: [PATCH V13] printk: Add monotonic, boottime, and realtime
 timestamps
Message-ID: <20200805140430.GI24529@alley>
References: <20200729114423.30606-1-zhang.lyra@gmail.com>
 <20200729122236.17418-1-prarit@redhat.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <20200729122236.17418-1-prarit@redhat.com>
User-Agent: Mutt/1.10.1 (2018-07-13)
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On Wed 2020-07-29 08:22:36, Prarit Bhargava wrote:
>   Chunyan Zhang <zhang.lyra@gmail.com> wrote:
> > From: Prarit Bhargava <prarit@redhat.com>
> > 
> > printk.time=1/CONFIG_PRINTK_TIME=1 adds a unmodified local hardware clock
> > timestamp to printk messages.  The local hardware clock loses time each
> > day making it difficult to determine exactly when an issue has occurred in
> > the kernel log, and making it difficult to determine how kernel and
> > hardware issues relate to each other in real time.
> > 
> > Make printk output different timestamps by adding options for no
> > timestamp, the local hardware clock, the monotonic clock, the boottime
> > clock, and the real clock.  Allow a user to pick one of the clocks by
> > using the printk.time kernel parameter.  Output the type of clock in
> > /sys/module/printk/parameters/time so userspace programs can interpret the
> > timestamp.
> > 
> ISTR the reason that this was dropped was because of the a problem with
> the way systemd read the kernel's timestamps.  It got the attention of
> Linus, and it was then pulled from the tree.
> 
> I need to go back and review the entire thread as it's been several years
> since we had the discussion although ISTR someone mentioning that doing two
> timestamps would not be a problem for systemd.

I guess that you talk about this thread
https://lore.kernel.org/lkml/CA+55aFwUfA__6MgMgjENnx+_RYY2ZOOLiSx2ea1AvYhSZN+78A@mail.gmail.com/

> For example,
> 
> [48551.015086]
> 
> would be
> 
> [48551.015086] m[xxxx.xxxx]
> 
> for the monotonic clock timestamp, and
> 
> [48551.015086] b[xxxx.xxxx]
> 
> for the boottime clock, etc.

This approach has several drawbacks:

  + Too long prefix might make it hard to see the real messages
    because of shrunken/wrapped lines.

  + Too long lines are problem with slow consoles.

  + More space will be necessary to store all the time stamps.

  + Userspace tools would need/want to parse the format. We would
    need to maintain it forever.


Linus had an interesting idea to print all timestamps regularly.
The frequency might be configurable. It might print, for example,
the following line every 10 minutes or once a day:

  [48551.015086] System alive: b[xxxx.xxxx] m[xxxx.xxxx]

It might be useful in general to see when the system was still alive
before it froze.

Would it be enough to sort messages printed with different clock
sources?

Best Regards,
Petr