Re: [GIT pull] printk updates for 4.15

From: Mark Salyzyn <salyzyn@android.com>
To: Petr Mladek <pmladek@suse.com>,
	Linus Torvalds <torvalds@linux-foundation.org>
Cc: Thomas Gleixner <tglx@linutronix.de>,
	LKML <linux-kernel@vger.kernel.org>,
	Ingo Molnar <mingo@kernel.org>, "H. Peter Anvin" <hpa@zytor.com>,
	Peter Zijlstra <peterz@infradead.org>,
	Andrew Morton <akpm@linux-foundation.org>,
	Prarit Bhargava <prarit@redhat.com>,
	Sergey Senozhatsky <sergey.senozhatsky@gmail.com>,
	Steven Rostedt <rostedt@goodmis.org>
Subject: Re: [GIT pull] printk updates for 4.15
Date: Tue, 14 Nov 2017 07:56:52 -0800	[thread overview]
Message-ID: <b609e8ed-7317-81fe-876c-7687f7e5044c@android.com> (raw)
In-Reply-To: <20171114100336.uil744pxmbsawq63@pathway.suse.cz>

On 11/14/2017 02:03 AM, Petr Mladek wrote:
> On Mon 2017-11-13 17:18:33, Linus Torvalds wrote:
>> On Mon, Nov 13, 2017 at 1:36 AM, Thomas Gleixner <tglx@linutronix.de> wrote:
>> Honestly, this just seems bogus to me, particularly since it's a single choice.
>>
>> The *sane* model would be to
>>
>>   (a) continue to use the existing time that we always have
>> (local_clock()) in the printk timestamps, and don't confuse people
>> with the semantics of that field changing.
>>
>>   (b) just emit a "synchronization printk" every once in a while, which
>> is obviously also using the same standard time source, but the line
>> actually _says_ what the other time sources are.
> This was actually the original approach by Mark Salyzyn, see
> https://lkml.kernel.org/r/20170720182505.9357-1-salyzyn@android.com

Thanks for the vote of confidence :-) but we were holding back re 
spinning that set until the ability to switch the primary timestamp got 
accepted. (we were to use U suffix for realtime, B for boottime etc to 
designate them).

Printing the other timebases during major disruptions 
(suspend/resume/etc) was needed for our battery monitoring analysis 
tools, and we only used them as synchronization markers as a secondary 
effect.

But we _also_ had Android partners asking if it was possible to switch 
the primary (dmesg) timestamp to one of boottime or realtime to aid in 
triaging temporal issues. Doing so in the tool was sometimes too 
inaccurate (~+/-20ms) even with help sniffing the periodic 
synchronization/disruption prints. Switching the timebase for dmesg gave 
us roughly 1000 times more comparative time precision which helps 
immensely when trying to correlate and order the sequence of events in 
user space and kernel activities.

-- Mark