From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753287AbdHQPaK (ORCPT ); Thu, 17 Aug 2017 11:30:10 -0400 Received: from mail-pg0-f41.google.com ([74.125.83.41]:35697 "EHLO mail-pg0-f41.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753018AbdHQPaI (ORCPT ); Thu, 17 Aug 2017 11:30:08 -0400 Subject: Re: [PATCH 2/2 v7] printk: Add monotonic, boottime, and realtime timestamps To: Prarit Bhargava , linux-kernel@vger.kernel.org Cc: Jonathan Corbet , Petr Mladek , Sergey Senozhatsky , Steven Rostedt , John Stultz , Thomas Gleixner , Stephen Boyd , Andrew Morton , Greg Kroah-Hartman , "Paul E. McKenney" , Christoffer Dall , Deepa Dinamani , Ingo Molnar , Joel Fernandes , Kees Cook , Peter Zijlstra , Geert Uytterhoeven , "Luis R. Rodriguez" , Nicholas Piggin , "Jason A. Donenfeld" , Olof Johansson , Josh Poimboeuf , linux-doc@vger.kernel.org References: <1502975739-21328-1-git-send-email-prarit@redhat.com> <1502975739-21328-3-git-send-email-prarit@redhat.com> From: Mark Salyzyn Message-ID: <6b265b2b-130a-c19b-1f68-b12895e1c17e@android.com> Date: Thu, 17 Aug 2017 08:30:05 -0700 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Thunderbird/52.1.1 MIME-Version: 1.0 In-Reply-To: <1502975739-21328-3-git-send-email-prarit@redhat.com> Content-Type: text/plain; charset=utf-8; format=flowed Content-Transfer-Encoding: 7bit Content-Language: en-US Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org 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) 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 ). 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? . . . diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 8817ed5ee6a3..2e3321f6604b 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -1273,7 +1273,7 @@ static int printk_time_set(const char *val, const struct kernel_param *kp) if (printk_time_source == PRINTK_TIME_UNDEFINED) printk_time_source = _printk_time; -#ifndef PRINTK_TIME_DEBUG +#ifndef CONFIG_PRINTK_TIME_DEBUG else if ((printk_time_source != _printk_time) && (_printk_time != PRINTK_TIME_DISABLE)) { /* @@ -1288,7 +1288,9 @@ static int printk_time_set(const char *val, const struct kernel_param *kp) #endif printk_time = _printk_time; +#ifndef CONFIG_PRINTK_TIME_DEBUG if (printk_time_source > PRINTK_TIME_DISABLE) +#endif printk_set_timestamp(); pr_info("printk: timestamp set to %s\n", > + > +config PRINTK_TIME_TYPE > + int > + depends on PRINTK > + range 1 5 > + default 1 if !PRINTK_TIME > + default 2 if PRINTK_TIME_LOCAL > + default 3 if PRINTK_TIME_BOOT > + default 4 if PRINTK_TIME_MONO > + default 5 if PRINTK_TIME_REAL > + > diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug index 1fb23d851ca2..2517ed69d7f8 100644 --- a/lib/Kconfig.debug +++ b/lib/Kconfig.debug @@ -60,6 +60,22 @@ config PRINTK_TIME_TYPE default 4 if PRINTK_TIME_MONO default 5 if PRINTK_TIME_REAL +config PRINTK_TIME_DEBUG + bool "Allow runtime reselection of any timebase on printks" + depends on PRINTK + help + Selecting this option causes time stamps of the printk() + messages to be changed freely at runtime on the output of + the syslog() system call and at the console. Without this + option, one can only enable or disable the configuration + selected timebase. + + Runtime adjustment can be set via + /sys/module/printk/paramters/time as follows with a string: + 0/N/n/disable, 1/Y/y/local, b/boot, m/monotonic, r/realtime. + eg: echo local >/sys/module/printk/parameters/time + echo realtime >/sys/module/printk/parameters/time + config MESSAGE_LOGLEVEL_DEFAULT int "Default message log level (1-15)" range 1 15 The last bit should probably be adjusted to eliminate details, maybe keep the example as it will stand the test of time, and merely reference the Documentation tree w.r.t. printk.time=