From mboxrd@z Thu Jan  1 00:00:00 1970
Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S932977AbdHVOJs (ORCPT <rfc822;w@1wt.eu>);
        Tue, 22 Aug 2017 10:09:48 -0400
Received: from mx1.redhat.com ([209.132.183.28]:47802 "EHLO mx1.redhat.com"
        rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP
        id S932510AbdHVOJq (ORCPT <rfc822;linux-kernel@vger.kernel.org>);
        Tue, 22 Aug 2017 10:09:46 -0400
DMARC-Filter: OpenDMARC Filter v1.3.2 mx1.redhat.com 5EF127EA9A
Authentication-Results: ext-mx04.extmail.prod.ext.phx2.redhat.com; dmarc=none (p=none dis=none) header.from=redhat.com
Authentication-Results: ext-mx04.extmail.prod.ext.phx2.redhat.com; spf=fail smtp.mailfrom=prarit@redhat.com
Subject: Re: [PATCH 2/2 v7] printk: Add monotonic, boottime, and realtime
 timestamps
To: Mark Salyzyn <salyzyn@android.com>, linux-kernel@vger.kernel.org
References: <1502975739-21328-1-git-send-email-prarit@redhat.com>
 <1502975739-21328-3-git-send-email-prarit@redhat.com>
 <6b265b2b-130a-c19b-1f68-b12895e1c17e@android.com>
Cc: Jonathan Corbet <corbet@lwn.net>, Petr Mladek <pmladek@suse.com>,
        Sergey Senozhatsky <sergey.senozhatsky@gmail.com>,
        Steven Rostedt <rostedt@goodmis.org>,
        John Stultz <john.stultz@linaro.org>,
        Thomas Gleixner <tglx@linutronix.de>,
        Stephen Boyd <sboyd@codeaurora.org>,
        Andrew Morton <akpm@linux-foundation.org>,
        Greg Kroah-Hartman <gregkh@linuxfoundation.org>,
        "Paul E. McKenney" <paulmck@linux.vnet.ibm.com>,
        Christoffer Dall <cdall@linaro.org>,
        Deepa Dinamani <deepa.kernel@gmail.com>,
        Ingo Molnar <mingo@kernel.org>, Joel Fernandes <joelaf@google.com>,
        Kees Cook <keescook@chromium.org>,
        Peter Zijlstra <peterz@infradead.org>,
        Geert Uytterhoeven <geert+renesas@glider.be>,
        "Luis R. Rodriguez" <mcgrof@kernel.org>,
        Nicholas Piggin <npiggin@gmail.com>,
        "Jason A. Donenfeld" <Jason@zx2c4.com>,
        Olof Johansson <olof@lixom.net>, Josh Poimboeuf <jpoimboe@redhat.com>,
        linux-doc@vger.kernel.org
From: Prarit Bhargava <prarit@redhat.com>
Message-ID: <8eb770a9-1068-c239-6131-97b64c2944dc@redhat.com>
Date: Tue, 22 Aug 2017 10:09:40 -0400
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:45.0) Gecko/20100101
 Thunderbird/45.7.0
MIME-Version: 1.0
In-Reply-To: <6b265b2b-130a-c19b-1f68-b12895e1c17e@android.com>
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit
X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.28]); Tue, 22 Aug 2017 14:09:46 +0000 (UTC)
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org



On 08/17/2017 11:30 AM, Mark Salyzyn wrote:
> On 08/17/2017 06:15 AM, Prarit Bhargava wrote:
>> 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.
> Congrats, greatly eases merges into older kernels, and has eliminated the churn
> this could place on all the configured systems out there.
> 
> Sadly, one of my suggestions did not quite go the way I expected ;-} easy to
> correct, and fix (I missed a spot in my original suggestion, as code changed
> underfoot over the set ;-/). (see bottom)

Added.  I will send out v8 shortly.

> 
> <discussion type="maybe out of the scope for this patch">
> 
> I am not convinced that user space is entirely at a disadvantage with this
> 'feature' enabled. Before interpreting it can read
> /sys/module/printk/parameters/time, then sniff for the flowing content for time
> breaks (watch for printk: timestamp set to <string>). Of course, the value in
> 'time' is current, so it would be _wrong_ during flow of previous content until
> the first time break shows up if it really was being switched that often.
> 
> (echo local ; echo disabled ; echo boottime ; echo monotonic ; echo realtime ;
> echo local ) > /sys/module/printk/parameters/time
> 
> [  473.589169] printk: timestamp set to local
> printk: timestamp set to disabled
> [  473.545384] printk: timestamp set to boottime
> [  473.549924] printk: timestamp set to monotonic
> [1502957708.055265] printk: timestamp set to realtime
> [  473.612024] printk: timestamp set to local
> 
> A 'fix' would be to add a letter after the timestamp if not local. For example:
> 
> [  473.589169] printk: timestamp set to local
> printk: timestamp set to disabled
> [  473.545384b] printk: timestamp set to boottime
> [  473.549924m] printk: timestamp set to monotonic
> [1502957708.055265U] printk: timestamp set to realtime
> [  473.612024] printk: timestamp set to local
> 
> (I used U instead of r, because it is actually UTC, and did not add 'l' because
> it is a long standing default)
> 
> But there would be concern over a change in time format API, so maybe it should
> be relegated to a CONFIG_PRINTK_TIME_DEBUG 'feature' only to add the timebase
> letters?

... then you wouldn't be able to use dmesg, etc., to get proper timestamp
conversions. :(  I'm not going to code dmesg for that because, as you point out
it is outside of the scope of this patch.  Maybe we can do something in future
for this?

P.