Re: [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps

[Sergey Senozhatsky]

On (09/15/17 07:29), Mark Salyzyn wrote:
> On 09/15/2017 06:28 AM, Petr Mladek wrote:
> > I am still slightly nervous that external tools would need updating.
> > Also they might have troubles to interpret the time stamps especially
> > when the source is changed at runtime via
> > /sys/module/printk/parameters/time.
> My comment below is a rehash/summary:
> 
> In the discussion, it appears that DAC protection is enough to prevent
> flippant changes. The use cases I can imagine for runtime alteration fall in
> two groups, late boot changes after all disks are mounted and the
> application layers have started; or as an aid to debugging where the
> deliberate nature can be accounted for. Change it, erase the logs is the
> KISS solution, so the tools do not have to 'sniff' the stream for dynamic
> changes, likely getting the 'leader' wrong, checking
> /sys/module/printk/parameters/time for the current/last timebase.
> 
> To mitigate the 'leader' issue, or post-mortem/off-machine interpretation,
> really for the debugging corner case IMHO, I had proposed that local, and
> perhaps monotonic, time print as-is as they are almost(?) imperceptibly
> different, but that realtime add a U suffix (to denote time is UTC), and
> that boottime add a B suffix (well, because) so that tools can discern.
> Monotonic could have a M suffix if it is really a stickler. This proposal
> would require more disruptive tool modifications and should be scoped as a
> separate effort. I do expect a debate regarding upper and lower case ...
> 
> I have a patch waiting in the wings here where disruptive time changes
> (suspend/resume/hibernate/restore; maybe date(1), ntpd(8) or embedded
> systems LTE hardware time updates) will report dual timestamps so that
> resynchronization and tracking can happen in post-mortem on the stream, I
> expect to use the above proposal for the 'second' occasional timestamp.

I'm a bit uncomfortable with the "breaks user space" part. since this
is a strictly debugging option, would it be sufficient to store those
extended timestamps as prefixes of every message?
see (sorry for "self-quoting"):
	lkml.kernel.org/r/20170917062608.GA512@xxxxxxxxxxxxxxxxxxx

each message, thus, will be in the following format

[current header: loglevel, timestamp, etc] [extended printk data] message text

extended printk data can contain your monotonic/etc timestamps, and
anything else.

and then it's up to you how do you grep the messages and process the
extended data. but the point is - user space tools (journald, dmesg,
etc.) stays intact. which is kinda nice.

so we can avoid that chicken and egg problem: we break user space
by merging the patchset but user space people don't want to talk
about any fixes until we break those tools.

	-ss