From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S966256AbdGUAVI (ORCPT ); Thu, 20 Jul 2017 20:21:08 -0400 Received: from mail-pf0-f195.google.com ([209.85.192.195]:38007 "EHLO mail-pf0-f195.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S965855AbdGUAVE (ORCPT ); Thu, 20 Jul 2017 20:21:04 -0400 Date: Fri, 21 Jul 2017 09:21:13 +0900 From: Sergey Senozhatsky To: Mark Salyzyn Cc: linux-kernel@vger.kernel.org, pavel@ucw.cz, andriy.shevchenko@linux.intel.com, joe@perches.com, prarit@redhat.com, rjw@rjwysocki.net, tglx@linutronix.de, Petr Mladek , Sergey Senozhatsky , Steven Rostedt , Kees Cook , Anton Vorontsov , Colin Cross , Tony Luck , Andrew Morton , "Paul E. McKenney" , Ingo Molnar , Peter Zijlstra , Geert Uytterhoeven , Mark Salyzyn , "Luis R. Rodriguez" , Nicholas Piggin , Olof Johansson , "Jason A. Donenfeld" , Josh Poimboeuf Subject: Re: [PATCH v5] printk: Add pr_info_show_time Message-ID: <20170721002112.GA3678@jagdpanzerIV.localdomain> References: <20170720182505.9357-1-salyzyn@android.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20170720182505.9357-1-salyzyn@android.com> User-Agent: Mutt/1.8.3 (2017-05-23) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On (07/20/17 11:24), Mark Salyzyn wrote: > Primary purpose of pr_info_show_time() is to provide a marker used for > post-mortem Battery and Power analysis. These markers are to be > placed at major discontinuities of time and power level. so shouldn't that just be under CONFIG_PM_DEBUG or even CONFIG_PM_ADVANCED_DEBUG and, hence, be implemented somewhere in PM? I just don't see why this needs to be in printk. without the users or (at least) examples that would demonstrate why this is more useful than local_clock(), which we already append to every message, it's rather hard for me to judge. [..] > +/* > + * pr_info_show_time() prefixes an alternate time prefix as selected by > + * CONFIG_PR_INFO_SHOW_TIME_. The time is prefixed on the message > + * as "[.] ". in the config selection > + * can be one of the following: > + * > + * MONOTONIC - (default) print no alternate time, monotonic is part of dmesg. > + * BOOTTIME - Adds a message prefix with getboottime64() values. > + * REALTIME - Adds a message prefix with getnstimeofday64() values. > + */ > +#if defined(CONFIG_PR_INFO_SHOW_TIME_BOOTTIME) > +#define pr_info_show_time(fmt, ...) ({ \ > + struct timespec64 ts; \ > + \ > + getboottime64(&ts); \ > + pr_info("[%5lu.%09luB] " fmt, ts.tv_sec, ts.tv_nsec, ##__VA_ARGS__); }) > +#include > +#elif defined(CONFIG_PR_INFO_SHOW_TIME_REALTIME) > +#define pr_info_show_time(fmt, ...) ({ \ > + struct timespec64 ts; \ > + \ > + getnstimeofday64(&ts); \ > + pr_info("[%lu.%09luU] " fmt, ts.tv_sec, ts.tv_nsec, ##__VA_ARGS__); }) > +#include > +#else > +#define pr_info_show_time(fmt, ...) \ > + pr_info(fmt, ##__VA_ARGS__) > +#endif so why just pr_info()? what about pr_err(), pr_crit() and so on? > /* > * Like KERN_CONT, pr_cont() should only be used when continuing > * a line with no newline ('\n') enclosed. Otherwise it defaults > diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug > index 98fe715522e8..0d63c3fb4e24 100644 > --- a/lib/Kconfig.debug > +++ b/lib/Kconfig.debug > @@ -30,6 +30,58 @@ config CONSOLE_LOGLEVEL_DEFAULT > usage in the kernel. That is controlled by the MESSAGE_LOGLEVEL_DEFAULT > option. > > +# set if time is being printed in pr_info_show_time() > +config PR_INFO_SHOW_TIME > + bool we all love Kconfig, don't we? ;) > +choice > + prompt "pr_info_show_time() alternate time message prefix" > + help > + Activate alternate time prefix in pr_info_show_time > + > + The primary use of the instrumentation is to aid field > + analysis of Battery and Power usage. The instrumentation > + may also help triage and synchronize kernel logs and user > + space activity logs at key displacements. > + config PR_INFO_SHOW_TIME_MONOTONIC > + bool "monotonic" > + help > + Deactivate alternate time prefix in pr_info_show_time. > + Doing so because monotonic time is part of the normal > + printk time logging. > + > + Print only the supplied message in pr_info_show_time, > + indistinguishable from pr_info. I think this should not exist. a new Kconfig option to enable something that is already there? > + config PR_INFO_SHOW_TIME_REALTIME > + bool "realtime" > + select PR_INFO_SHOW_TIME > + help > + Activate alternate time prefix in pr_info_show_time > + > + The primary use of the instrumentation is to aid field > + analysis of Battery and Power usage. The instrumentation > + may also help triage and synchronize kernel logs and user > + space activity logs at key displacements. For instance > + CLOCK_MONOTONIC stops while suspended, while CLOCK_REALTIME > + continues, and the timestamps help re-orient post-analysis. > + > + Prefix realtime [.U] timestamp in pr_info_show_time > + config PR_INFO_SHOW_TIME_BOOTTIME > + bool "boottime" > + select PR_INFO_SHOW_TIME > + help > + Activate alternate time prefix in pr_info_show_time > + > + The primary use of the instrumentation is to aid field > + analysis of Battery and Power usage. The instrumentation > + may also help triage and synchronize kernel logs and user > + space activity logs at key displacements. For instance > + CLOCK_MONOTONIC stops while suspended, while CLOCK_BOOTTIME > + continues, and the timestamps help re-orient post-analysis. > + > + Prefix boottime [.B] timestamp in pr_info_show_time > +endchoice dunno, I'm still not sure I see why this "add a special prefix to some messages" needs to be part of generic printk(). sorry. -ss