From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1161167AbcBDRDd (ORCPT ); Thu, 4 Feb 2016 12:03:33 -0500 Received: from mx1.redhat.com ([209.132.183.28]:38178 "EHLO mx1.redhat.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S933903AbcBDRD3 (ORCPT ); Thu, 4 Feb 2016 12:03:29 -0500 Message-ID: <56B3845F.8050203@redhat.com> Date: Thu, 04 Feb 2016 12:03:27 -0500 From: Prarit Bhargava User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Thunderbird/31.7.0 MIME-Version: 1.0 To: Petr Mladek CC: linux-kernel@vger.kernel.org, John Stultz , Xunlei Pang , Thomas Gleixner , Baolin Wang , Andrew Morton , Greg Kroah-Hartman , Tejun Heo , Peter Hurley , Vasily Averin , Joe Perches Subject: Re: [PATCH] printk, allow different timestamps for printk.time [v2] References: <1453985029-25912-1-git-send-email-prarit@redhat.com> <20160204164824.GB3305@pathway.suse.cz> In-Reply-To: <20160204164824.GB3305@pathway.suse.cz> Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On 02/04/2016 11:48 AM, Petr Mladek wrote: > On Thu 2016-01-28 07:43:49, Prarit Bhargava wrote: >> +static u64 printk_get_ts(void) >> +{ >> + u64 mono, offset_real; >> + >> + if (printk_time == 0) >> + return 0; >> + >> + if (printk_time == 1) >> + return local_clock(); >> + >> + mono = ktime_get_log_ts(&offset_real); >> + >> + if (printk_time == 2) >> + return mono; >> + >> + return mono + offset_real; > > At least dmesg is not capable to read the absolute size of the > real time. It expects offset against the start of the timekeeping > stuff or so. I get this: > > $> dmesg | tail -n 5 > [ 7.128924] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready > [ 0.000000] printk: timestamp set to 0. ^^^ Hmm ... I'll have to think about that. > [ 179.983704] printk: timestamp set to 1. > [ 181.895655] printk: timestamp set to 2. > [1454602412.026424] printk: timestamp set to 3. > > $dmesg -T -S | tail -n 5 > [Thu Feb 4 17:10:34 2016] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready > [Thu Feb 4 17:10:27 2016] printk: timestamp set to 0. > [Thu Feb 4 17:13:26 2016] printk: timestamp set to 1. > [Thu Feb 4 17:13:28 2016] printk: timestamp set to 2. > [Fri Mar 10 09:23:59 2062] printk: timestamp set to 3. Yes, this is a known issue that someone else previously brought to my attention on LKML. I will have to modify dmesg once this code is stabilized. > > Please, note that the last entry points to the year 2062. > > >> --- a/lib/Kconfig.debug >> +++ b/lib/Kconfig.debug >> @@ -13,7 +13,7 @@ config PRINTK_TIME >> be included, not that the timestamp is recorded. >> >> The behavior is also controlled by the kernel command line >> - parameter printk.time=1. See Documentation/kernel-parameters.txt >> + parameter printk.time=[0-3]. See Documentation/kernel-parameters.txt > > Please, mention there the mention of the numbers. The cross reference > is annoying if you look at the help when configuring kernel build. I can certainly make that change and provide better documentation. > > Also there is a mismatch between the values and the type of > CONFIG_PRINTK_TIME. You should change it to > > int "Show timing information on printks" > range 0 3 I don't think that's what CONFIG_PRINTK_TIME does. All CONFIG_PRINTK_TIME does is turn the timestamping on or off. IOW, CONFIG_PRINTK_TIME=n results in IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready and CONFIG_PRINTK_TIME=y results in [ 7.128924] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready I explicitly did NOT want to change the behavior of CONFIG_PRINTK_TIME. P.