On Wed 2020-07-29 08:22:36, Prarit Bhargava wrote:

  Chunyan Zhang [off-list ref] wrote:

quoted

From: Prarit Bhargava <redacted>

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/ (local)

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