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;
Subject: Re: [PATCH V13] printk: Add monotonic, boottime, and realtime
 timestamps
To:     Petr Mladek <pmladek@suse.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
References: <20200729114423.30606-1-zhang.lyra@gmail.com>
 <20200729122236.17418-1-prarit@redhat.com> <20200805140430.GI24529@alley>
From:   Prarit Bhargava <prarit@redhat.com>
Message-ID: <77c37735-e258-4933-f568-8450253a38ff@redhat.com>
Date:   Wed, 5 Aug 2020 10:11:32 -0400
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101
 Thunderbird/60.6.1
MIME-Version: 1.0
In-Reply-To: <20200805140430.GI24529@alley>
Content-Type: text/plain; charset=utf-8
Content-Language: en-US
Content-Transfer-Encoding: 7bit
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk


On 8/5/20 10:04 AM, Petr Mladek wrote:
> 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?

Hey Petr,

After reviewing the thread (it has been three years after all), I have asked
Orson and Lyra to look at the suggested changes by tglx and Linus and submit
those instead of "this" patch.

I should have updated this thread with that info.  Sorry 'bout that.

P.