From patchwork Wed Jul 19 19:44:41 2017 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Mark Salyzyn X-Patchwork-Id: 9853153 Return-Path: Received: from mail.wl.linuxfoundation.org (pdx-wl-mail.web.codeaurora.org [172.30.200.125]) by pdx-korg-patchwork.web.codeaurora.org (Postfix) with ESMTP id 99FD460388 for ; Wed, 19 Jul 2017 19:45:25 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 99B75286E1 for ; Wed, 19 Jul 2017 19:45:25 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id 8DE0428655; Wed, 19 Jul 2017 19:45:25 +0000 (UTC) X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on pdx-wl-mail.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-6.5 required=2.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID, DKIM_VALID_AU, RCVD_IN_DNSWL_HI, RCVD_IN_SORBS_SPAM autolearn=ham version=3.3.1 Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id A5CBE285F0 for ; Wed, 19 Jul 2017 19:45:24 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S934131AbdGSTpX (ORCPT ); Wed, 19 Jul 2017 15:45:23 -0400 Received: from mail-pg0-f46.google.com ([74.125.83.46]:38464 "EHLO mail-pg0-f46.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S934008AbdGSTpU (ORCPT ); Wed, 19 Jul 2017 15:45:20 -0400 Received: by mail-pg0-f46.google.com with SMTP id s4so4388981pgr.5 for ; Wed, 19 Jul 2017 12:45:20 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=android.com; s=20161025; h=from:to:cc:subject:date:message-id; bh=bzcXFkKIODBUrCIUrGChg7jHwqHon4LCvyrJvoY2+WE=; b=HBdO8s5DfKYzwRFvk1r0HgQzF7zQeVY5Wn48N9vBmjnp7MCMnWc68lC8W/tZL/XPmb ts+rE/tsRe4e0a5P+vndg+hlCrykhhpYI8GcP9ETP+DABXy0UrOg1sO93egpIaAmEvUu AdzfWAMAC609mL5/nmKGDlVCak47VQBMOOsCfz59DYNBviXucTGvAVymbp92NINlLB2y zcoNYui8VzDFAs4UqJ6gz/R41yxvT8L1sDA5ysqt9d6g9YofDREVZ7SSM8D/X+ty7FOw kEObShhZ3j23tdTpWAxWAxfGib1mQ9/U2/mQs+icEcjSatLENPcTa+JhnULfvPR4Vr/Z LoyQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:from:to:cc:subject:date:message-id; bh=bzcXFkKIODBUrCIUrGChg7jHwqHon4LCvyrJvoY2+WE=; b=EvpCt8Q6lmJPBGV4vFOD/9CCCMgKZmO9MdWXePrFJu9jtrSPTD+uVxI3je1B6iHo6B OvefqEyx5onHUfdkyYFXI6BTj5lYm0fCidmVkPLu/t54SZJ+H7yeT4PoNe3Pvc5xitke lEiGGRqvtAITKoDCqlBVAADUW9oN4+3zjC80/RfRuVadaaLKExT3N6Bo/bZNfFSbK+Xj uCDVrFnGHy/E7Bdsw5xe2sveLoGOy4EW57ukjLRTsVDbrDrMSwvaqcpLko3xsWd6oQSh urojchdA16oADTQzRvEXPlHnPnumiWYdBq8ai9H+by8jJ1qOMANen6b4IcbnneY9dZC4 xIuQ== X-Gm-Message-State: AIVw110gB5HOQ1Gy0++La0bT8j8IUnWFxNqarQ0fgU4sim3jOvt9bceE G6YCD+9IG25aJrYk X-Received: by 10.99.169.17 with SMTP id u17mr1243900pge.292.1500493520227; Wed, 19 Jul 2017 12:45:20 -0700 (PDT) Received: from nebulus.mtv.corp.google.com ([100.98.120.17]) by smtp.gmail.com with ESMTPSA id 28sm1064008pfq.125.2017.07.19.12.45.18 (version=TLS1_2 cipher=ECDHE-RSA-AES128-SHA bits=128/128); Wed, 19 Jul 2017 12:45:19 -0700 (PDT) From: Mark Salyzyn To: linux-kernel@vger.kernel.org Cc: rjw@rjwysocki.net, len.brown@intel.com, pavel@ucw.cz, linux-pm@vger.kernel.org, a.zummo@towertech.it, alexandre.belloni@free-electrons.com, linux-rtc@vger.kernel.org, Mark Salyzyn , Kees Cook , Anton Vorontsov , Colin Cross , Tony Luck , "Paul E. McKenney" , Thomas Gleixner , John Stultz , Nicolas Pitre , Richard Cochran Subject: [PATCH v4 1/4] time: rtc-lib: Add rtc_show_time(const char *prefix_msg) Date: Wed, 19 Jul 2017 12:44:41 -0700 Message-Id: <20170719194511.28899-1-salyzyn@android.com> X-Mailer: git-send-email 2.14.0.rc0.284.gd933b75aa4-goog Sender: linux-pm-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-pm@vger.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP Primary purpose of rtc_show_time is to provide a marker used for post-mortem Battery and Power analysis. These markers occur at major discontinuities of time, and thus optionally add a timestamp to aid the analysis. This function is to be called at a higher level, and were added because of a lack of current kernel logging data. The persistent clock that is used to report Suspended for message is not present on all platforms, and is currently standardized for millisecond precision. An added value to the time report is the ability in post-mortem triage analysis to synchronize kernel activities in MONOTONIC time with user space activities in REALTIME. Feature activated by CONFIG_RTC_SHOW_TIME_, where is None (default, disabled), realtime, boottime or monotonic. Since this is for post mortem field analysis, there is no debugfs or trace facility that can generally be leveraged. analyze_suspend.py for example requires a debug configured kernel, on the other hand these prints can remain in a field product. The purpose for rtc_show_time is not for development debugging. Data collected may be recorded by klogd with a longer logspan than the built-in dmesg buffer, or land in pstore console driver to be collected after a reboot. Signed-off-by: Mark Salyzyn v2: - move implementation to kernel timekeeping from rtc_lib files - use rtc_time64_to_tm() instead of rtc_time_to_tm() - use inline in include/linux/rtc.h for !CONFIG_RTC_SHOW_TIME v3: - _correctly_ use rtc_time64_to_tm v4: - introduce CONFIG_RTC_SHOW_TIME_ and split off rtc time format printing to a separate patch. --- include/linux/rtc.h | 5 +++ kernel/time/Kconfig | 77 +++++++++++++++++++++++++++++++++++++++++++++ kernel/time/Makefile | 1 + kernel/time/rtc_show_time.c | 29 +++++++++++++++++ 4 files changed, 112 insertions(+) create mode 100644 kernel/time/rtc_show_time.c diff --git a/include/linux/rtc.h b/include/linux/rtc.h index 0a0f0d14a5fb..779401c937d5 100644 --- a/include/linux/rtc.h +++ b/include/linux/rtc.h @@ -22,6 +22,11 @@ extern int rtc_year_days(unsigned int day, unsigned int month, unsigned int year extern int rtc_valid_tm(struct rtc_time *tm); extern time64_t rtc_tm_to_time64(struct rtc_time *tm); extern void rtc_time64_to_tm(time64_t time, struct rtc_time *tm); +#ifdef CONFIG_RTC_SHOW_TIME +extern void rtc_show_time(const char *prefix_msg); +#else +static inline void rtc_show_time(const char *prefix_msg) { } +#endif ktime_t rtc_tm_to_ktime(struct rtc_time tm); struct rtc_time rtc_ktime_to_tm(ktime_t kt); diff --git a/kernel/time/Kconfig b/kernel/time/Kconfig index ac09bc29eb08..2dc891056635 100644 --- a/kernel/time/Kconfig +++ b/kernel/time/Kconfig @@ -145,3 +145,80 @@ config HIGH_RES_TIMERS endmenu endif + +config RTC_SHOW_TIME + bool + help + Activate optional rtc_show_time(const char *msg) wall clock + time instrumentation. + + 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. + + Select the appropriate RTC_SHOW_TIME_ + +choice + prompt "choose a clock for rtc_show_time" + config RTC_SHOW_TIME_NONE + bool "not activated" + help + Turn off all printing associated with rtc_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. + + This is the default behavior. + config RTC_SHOW_TIME_REALTIME + bool "realtime" + select RTC_SHOW_TIME + help + Activate optional rtc_show_time(const char *msg) wall clock + time instrumentation. + + 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. + + Print realtime . timestamp in rtc_show_time + config RTC_SHOW_TIME_MONOTONIC + bool "monotonic" + select RTC_SHOW_TIME + help + Activate optional rtc_show_time(const char *msg) wall clock + time instrumentation. + + 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. + + Print only the supplied message in rtc_show_time + config RTC_SHOW_TIME_BOOTTIME + bool "boottime" + select RTC_SHOW_TIME + help + Activate optional rtc_show_time(const char *msg) wall clock + time instrumentation. + + 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. + + Print boottime . timestamp in rtc_show_time +endchoice diff --git a/kernel/time/Makefile b/kernel/time/Makefile index 938dbf33ef49..66f17e641052 100644 --- a/kernel/time/Makefile +++ b/kernel/time/Makefile @@ -17,3 +17,4 @@ obj-$(CONFIG_GENERIC_SCHED_CLOCK) += sched_clock.o obj-$(CONFIG_TICK_ONESHOT) += tick-oneshot.o tick-sched.o obj-$(CONFIG_DEBUG_FS) += timekeeping_debug.o obj-$(CONFIG_TEST_UDELAY) += test_udelay.o +obj-$(CONFIG_RTC_SHOW_TIME) += rtc_show_time.o diff --git a/kernel/time/rtc_show_time.c b/kernel/time/rtc_show_time.c new file mode 100644 index 000000000000..19a8a0cc94f0 --- /dev/null +++ b/kernel/time/rtc_show_time.c @@ -0,0 +1,29 @@ +/* + * rtc time printing utility functions + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License version 2 as + * published by the Free Software Foundation. + */ + +#include + +void rtc_show_time(const char *prefix_msg) +{ +#if defined(CONFIG_RTC_SHOW_TIME_MONOTONIC) /* dmesg is in monotonic */ + pr_info("%s\n", prefix_msg ? prefix_msg : "Time:"); +#elif defined(CONFIG_RTC_SHOW_TIME_BOOTTIME) + struct timespec64 ts; + + getboottime64(&ts); + pr_info("%s %lu.%09lu B\n", + prefix_msg ? prefix_msg : "Time:", ts.tv_sec, ts.tv_nsec); +#else /* realtime */ + struct timespec64 ts; + + getnstimeofday64(&ts); + pr_info("%s %lu.%09lu UTC\n", + prefix_msg ? prefix_msg : "Time:", ts.tv_sec, ts.tv_nsec); +#endif +} +EXPORT_SYMBOL(rtc_show_time);