* [PATCH 0/2 v8] printk: Add new timestamps @ 2017-08-24 13:42 Prarit Bhargava 2017-08-24 13:42 ` [PATCH 1/2 v8] time: Make fast functions return 0 before timekeeping is initialized Prarit Bhargava 2017-08-24 13:42 ` [PATCH 2/2 v8] printk: Add monotonic, boottime, and realtime timestamps Prarit Bhargava 0 siblings, 2 replies; 7+ messages in thread From: Prarit Bhargava @ 2017-08-24 13:42 UTC (permalink / raw) To: linux-kernel Cc: Prarit Bhargava, Mark Salyzyn, 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 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. Add monotonic, boottime, and real clock timestamps in addition to the existing local hardware clock timestamp. Signed-off-by: Prarit Bhargava <prarit@redhat.com> Cc: Mark Salyzyn <salyzyn@android.com> Cc: Jonathan Corbet <corbet@lwn.net> Cc: Petr Mladek <pmladek@suse.com> Cc: Sergey Senozhatsky <sergey.senozhatsky@gmail.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: John Stultz <john.stultz@linaro.org> Cc: Thomas Gleixner <tglx@linutronix.de> Cc: Stephen Boyd <sboyd@codeaurora.org> Cc: Andrew Morton <akpm@linux-foundation.org> Cc: Greg Kroah-Hartman <gregkh@linuxfoundation.org> Cc: "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> Cc: Christoffer Dall <cdall@linaro.org> Cc: Deepa Dinamani <deepa.kernel@gmail.com> Cc: Ingo Molnar <mingo@kernel.org> Cc: Joel Fernandes <joelaf@google.com> Cc: Prarit Bhargava <prarit@redhat.com> Cc: Kees Cook <keescook@chromium.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Geert Uytterhoeven <geert+renesas@glider.be> Cc: "Luis R. Rodriguez" <mcgrof@kernel.org> Cc: Nicholas Piggin <npiggin@gmail.com> Cc: "Jason A. Donenfeld" <Jason@zx2c4.com> Cc: Olof Johansson <olof@lixom.net> Cc: Josh Poimboeuf <jpoimboe@redhat.com> Cc: linux-doc@vger.kernel.org [jstultz: reworked Kconfig settings to avoid defconfig noise] Signed-off-by: John Stultz <john.stultz@linaro.org> Prarit Bhargava (2): time: Make fast functions return 0 before timekeeping is initialized printk: Add monotonic, boottime, and realtime timestamps Documentation/admin-guide/kernel-parameters.txt | 6 +- include/linux/timekeeping.h | 1 + kernel/printk/printk.c | 154 +++++++++++++++++++++++- kernel/time/timekeeping.c | 46 +++++-- lib/Kconfig.debug | 65 +++++++++- 5 files changed, 253 insertions(+), 19 deletions(-) -- 1.8.5.5 ^ permalink raw reply [flat|nested] 7+ messages in thread
* [PATCH 1/2 v8] time: Make fast functions return 0 before timekeeping is initialized 2017-08-24 13:42 [PATCH 0/2 v8] printk: Add new timestamps Prarit Bhargava @ 2017-08-24 13:42 ` Prarit Bhargava 2017-08-24 13:42 ` [PATCH 2/2 v8] printk: Add monotonic, boottime, and realtime timestamps Prarit Bhargava 1 sibling, 0 replies; 7+ messages in thread From: Prarit Bhargava @ 2017-08-24 13:42 UTC (permalink / raw) To: linux-kernel; +Cc: Prarit Bhargava, John Stultz, Thomas Gleixner, Stephen Boyd printk timestamps will be extended to include mono and boot time by using the fast timekeeping functions ktime_get_mono|boot_fast_ns() functions. The functions can return garbage before timekeeping is initialized resulting in garbage timestamps. The fast time functions must return 0 before timekeeping is initialized. Signed-off-by: Prarit Bhargava <prarit@redhat.com> Suggested-by: Peter Zijlstra <peterz@infradead.org> Cc: John Stultz <john.stultz@linaro.org> Cc: Thomas Gleixner <tglx@linutronix.de> Cc: Stephen Boyd <sboyd@codeaurora.org> --- kernel/time/timekeeping.c | 47 +++++++++++++++++++++++++++++++++-------------- 1 file changed, 33 insertions(+), 14 deletions(-) diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c index cedafa008de5..d111039e0245 100644 --- a/kernel/time/timekeeping.c +++ b/kernel/time/timekeeping.c @@ -60,8 +60,39 @@ struct tk_fast { struct tk_read_base base[2]; }; -static struct tk_fast tk_fast_mono ____cacheline_aligned; -static struct tk_fast tk_fast_raw ____cacheline_aligned; +/* Suspend-time cycles value for halted fast timekeeper. */ +static u64 cycles_at_suspend; + +static u64 dummy_clock_read(struct clocksource *cs) +{ + return cycles_at_suspend; +} + +static struct clocksource dummy_clock = { + .read = dummy_clock_read, +}; + +static struct tk_fast tk_fast_mono ____cacheline_aligned = { + .base = { + (struct tk_read_base){ + .clock = &dummy_clock, + }, + (struct tk_read_base){ + .clock = &dummy_clock, + }, + }, +}; + +static struct tk_fast tk_fast_raw ____cacheline_aligned = { + .base = { + (struct tk_read_base){ + .clock = &dummy_clock, + }, + (struct tk_read_base){ + .clock = &dummy_clock, + }, + }, +}; /* flag for if timekeeping is suspended */ int __read_mostly timekeeping_suspended; @@ -477,18 +508,6 @@ u64 notrace ktime_get_boot_fast_ns(void) } EXPORT_SYMBOL_GPL(ktime_get_boot_fast_ns); -/* Suspend-time cycles value for halted fast timekeeper. */ -static u64 cycles_at_suspend; - -static u64 dummy_clock_read(struct clocksource *cs) -{ - return cycles_at_suspend; -} - -static struct clocksource dummy_clock = { - .read = dummy_clock_read, -}; - /** * halt_fast_timekeeper - Prevent fast timekeeper from accessing clocksource. * @tk: Timekeeper to snapshot. -- 1.8.5.5 ^ permalink raw reply related [flat|nested] 7+ messages in thread
* [PATCH 2/2 v8] printk: Add monotonic, boottime, and realtime timestamps 2017-08-24 13:42 [PATCH 0/2 v8] printk: Add new timestamps Prarit Bhargava 2017-08-24 13:42 ` [PATCH 1/2 v8] time: Make fast functions return 0 before timekeeping is initialized Prarit Bhargava @ 2017-08-24 13:42 ` Prarit Bhargava 2017-08-24 18:50 ` John Stultz 2017-08-25 4:52 ` Sergey Senozhatsky 1 sibling, 2 replies; 7+ messages in thread From: Prarit Bhargava @ 2017-08-24 13:42 UTC (permalink / raw) To: linux-kernel Cc: Prarit Bhargava, Mark Salyzyn, 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 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. Make printk output different timestamps by adding options for no timestamp, the local hardware clock, the monotonic clock, the boottime clock, and the real clock. Allow a user to pick one of the clocks by using the printk.time kernel parameter. Output the type of clock in /sys/module/printk/parameters/time so userspace programs can interpret the timestamp. Real clock & 32-bit systems: Selecting the real clock printk timestamp may lead to unlikely situations where a timestamp is wrong because the real time without the protection of a sequence lock when printk_get_ts() is set printk_get_real_ns(). v2: Use peterz's suggested Kconfig options. Merge patchset together. Fix i386 !CONFIG_PRINTK builds. v3: Fixed x86_64_defconfig. Added printk_time_type enum and printk_time_str for better output. Added BOOTTIME clock functionality. v4: Fix messages, add additional printk.time options, and fix configs. v5: Renaming of structures, and allow printk_time_set() to evaluate substrings of entries (eg: allow 'r', 'real', 'realtime'). From peterz, make fast functions return 0 until timekeeping is initialized (removes timekeeping_active & ktime_get_boot|real_log_ts() suggested by tglx and adds ktime_get_real_offset()). Switch to a function pointer for printk_get_ts() and reference fast functions. Make timestamp_sources enum match choice options for CONFIG_PRINTK_TIME (adds PRINTK_TIME_UNDEFINED). v6: Define PRINTK_TIME_UNDEFINED for !CONFIG_PRINTK builds. Separate timekeeping changes into separate patch. Minor include file cleanup. v7: Add default case to printk_set_timestamp() and add PRINTK_TIME_DEBUG for users that want to set timestamp to different values during runtime. Add jstultz' Kconfig to avoid defconfig churn. v8: Add CONFIG_PRINTK_TIME_DEBUG to allow timestamp runtime switching. Rename PRINTK_TIME_DISABLE to PRINTK_TIME_DISABLED. Rename printk_set_timestamp() to printk_set_ts_func(). Separate printk_set_ts_func() and printk_get_first_ts() portions. Rename param functions. Adjust configs, enum, and timestamp_sources_str to be 0-4. Add mention realtime clock is UTC in Documentation. Signed-off-by: Prarit Bhargava <prarit@redhat.com> Cc: Mark Salyzyn <salyzyn@android.com> Cc: Jonathan Corbet <corbet@lwn.net> Cc: Petr Mladek <pmladek@suse.com> Cc: Sergey Senozhatsky <sergey.senozhatsky@gmail.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: John Stultz <john.stultz@linaro.org> Cc: Thomas Gleixner <tglx@linutronix.de> Cc: Stephen Boyd <sboyd@codeaurora.org> Cc: Andrew Morton <akpm@linux-foundation.org> Cc: Greg Kroah-Hartman <gregkh@linuxfoundation.org> Cc: "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> Cc: Christoffer Dall <cdall@linaro.org> Cc: Deepa Dinamani <deepa.kernel@gmail.com> Cc: Ingo Molnar <mingo@kernel.org> Cc: Joel Fernandes <joelaf@google.com> Cc: Prarit Bhargava <prarit@redhat.com> Cc: Kees Cook <keescook@chromium.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Geert Uytterhoeven <geert+renesas@glider.be> Cc: "Luis R. Rodriguez" <mcgrof@kernel.org> Cc: Nicholas Piggin <npiggin@gmail.com> Cc: "Jason A. Donenfeld" <Jason@zx2c4.com> Cc: Olof Johansson <olof@lixom.net> Cc: Josh Poimboeuf <jpoimboe@redhat.com> Cc: linux-doc@vger.kernel.org [jstultz: reworked Kconfig settings to avoid defconfig noise] Signed-off-by: John Stultz <john.stultz@linaro.org> --- Documentation/admin-guide/kernel-parameters.txt | 6 +- include/linux/timekeeping.h | 1 + kernel/printk/printk.c | 154 +++++++++++++++++++++++- kernel/time/timekeeping.c | 5 + lib/Kconfig.debug | 65 +++++++++- 5 files changed, 223 insertions(+), 8 deletions(-) diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt index d9c171ce4190..8d6b194533af 100644 --- a/Documentation/admin-guide/kernel-parameters.txt +++ b/Documentation/admin-guide/kernel-parameters.txt @@ -3188,8 +3188,10 @@ ratelimit - ratelimit the logging Default: ratelimit - printk.time= Show timing data prefixed to each printk message line - Format: <bool> (1/Y/y=enable, 0/N/n=disable) + printk.time= Show timestamp prefixed to each printk message line + Format: <string> + (0/N/n/disable, 1/Y/y/local, + b/boot, m/monotonic, r/realtime (in UTC)) processor.max_cstate= [HW,ACPI] Limit processor to maximum C-state diff --git a/include/linux/timekeeping.h b/include/linux/timekeeping.h index ddc229ff6d1e..80ca2fa22b6a 100644 --- a/include/linux/timekeeping.h +++ b/include/linux/timekeeping.h @@ -239,6 +239,7 @@ static inline u64 ktime_get_raw_ns(void) extern u64 ktime_get_mono_fast_ns(void); extern u64 ktime_get_raw_fast_ns(void); extern u64 ktime_get_boot_fast_ns(void); +extern u64 ktime_get_real_offset(void); /* * Timespec interfaces utilizing the ktime based ones diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index fc47863f629c..dd972bc5c88b 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -576,6 +576,9 @@ static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len, return msg_used_size(*text_len + *trunc_msg_len, 0, pad_len); } +static u64 printk_get_first_ts(void); +static u64 (*printk_get_ts)(void) = printk_get_first_ts; + /* insert record into the buffer, discard old ones, update heads */ static int log_store(int facility, int level, enum log_flags flags, u64 ts_nsec, @@ -624,7 +627,7 @@ static int log_store(int facility, int level, if (ts_nsec > 0) msg->ts_nsec = ts_nsec; else - msg->ts_nsec = local_clock(); + msg->ts_nsec = printk_get_ts(); memset(log_dict(msg) + dict_len, 0, pad_len); msg->len = size; @@ -1202,14 +1205,148 @@ static inline void boot_delay_msec(int level) } #endif -static bool printk_time = IS_ENABLED(CONFIG_PRINTK_TIME); -module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR); +/** + * enum timestamp_sources - Timestamp sources for printk() messages. + * @PRINTK_TIME_UNDEFINED: Timestamp undefined. This option is not selectable + * from the configs, and is used as a reference in the code. + * @PRINTK_TIME_DISABLED: No time stamp. + * @PRINTK_TIME_LOCAL: Local hardware clock timestamp. + * @PRINTK_TIME_BOOT: Boottime clock timestamp. + * @PRINTK_TIME_MONO: Monotonic clock timestamp. + * @PRINTK_TIME_REAL: Realtime clock timestamp. On 32-bit + * systems selecting the real clock printk timestamp may lead to unlikely + * situations where a timestamp is wrong because the real time offset is read + * without the protection of a sequence lock when printk_get_ts() is set to + * printk_get_real_ns(). + */ +enum timestamp_sources { + PRINTK_TIME_UNDEFINED = -1, + PRINTK_TIME_DISABLED = 0, + PRINTK_TIME_LOCAL = 1, + PRINTK_TIME_BOOT = 2, + PRINTK_TIME_MONO = 3, + PRINTK_TIME_REAL = 4, +}; + +static const char * const timestamp_sources_str[5] = { + "disabled", + "local", + "boottime", + "monotonic", + "realtime", +}; + +static int printk_time = CONFIG_PRINTK_TIME_TYPE; +static int printk_time_source = PRINTK_TIME_UNDEFINED; + +/** + * printk_get_real_ns: - Return a realtime timestamp for printk messages + * On 32-bit systems selecting the real clock printk timestamp may lead to + * unlikely situations where a timestamp is wrong because the real time offset + * is read without the protection of a sequence lock. + */ +static u64 printk_get_real_ns(void) +{ + return ktime_get_mono_fast_ns() + ktime_get_real_offset(); +} + +static void printk_set_ts_func(void) +{ + switch (printk_time) { + case PRINTK_TIME_LOCAL: + case PRINTK_TIME_DISABLED: + default: + printk_get_ts = local_clock; + break; + case PRINTK_TIME_BOOT: + printk_get_ts = ktime_get_boot_fast_ns; + break; + case PRINTK_TIME_MONO: + printk_get_ts = ktime_get_mono_fast_ns; + break; + case PRINTK_TIME_REAL: + printk_get_ts = printk_get_real_ns; + break; + } +} + +static u64 printk_get_first_ts(void) +{ + printk_set_ts_func(); + return printk_get_ts(); +} + +static int param_set_time(const char *val, const struct kernel_param *kp) +{ + char *param = strstrip((char *)val); + int _printk_time = PRINTK_TIME_UNDEFINED; + int ts; + + if (strlen(param) == 1) { + /* Preserve legacy boolean settings */ + if ((param[0] == '0') || (param[0] == 'n') || + (param[0] == 'N')) + _printk_time = PRINTK_TIME_DISABLED; + if ((param[0] == '1') || (param[0] == 'y') || + (param[0] == 'Y')) + _printk_time = PRINTK_TIME_LOCAL; + } + if (_printk_time == PRINTK_TIME_UNDEFINED) { + for (ts = 0; ts < ARRAY_SIZE(timestamp_sources_str); ts++) { + if (!strncmp(timestamp_sources_str[ts], param, + strlen(param))) { + _printk_time = ts; + break; + } + } + } + if (_printk_time == PRINTK_TIME_UNDEFINED) { + pr_warn("printk: invalid timestamp option %s\n", param); + return -EINVAL; + } + + if (printk_time_source == PRINTK_TIME_UNDEFINED) + printk_time_source = _printk_time; +#ifndef CONFIG_PRINTK_TIME_DEBUG + else if ((printk_time_source != _printk_time) && + (_printk_time != PRINTK_TIME_DISABLED)) { + /* + * Only allow enabling and disabling of the current printk_time + * setting. Changing it from one setting to another confuses + * userspace. + */ + pr_warn("printk: timestamp can only be set to 0, disabled, or %s\n", + timestamp_sources_str[printk_time_source]); + return -EINVAL; + } +#endif + + printk_time = _printk_time; + if (printk_time_source > PRINTK_TIME_DISABLED) + printk_set_ts_func(); + + pr_info("printk: timestamp set to %s\n", + timestamp_sources_str[printk_time]); + return 0; +} + +static int param_get_time(char *buffer, const struct kernel_param *kp) +{ + return scnprintf(buffer, PAGE_SIZE, "%s", + timestamp_sources_str[printk_time]); +} + +static struct kernel_param_ops printk_time_ops = { + .set = param_set_time, + .get = param_get_time, +}; +module_param_cb(time, &printk_time_ops, NULL, 0644); static size_t print_time(u64 ts, char *buf) { unsigned long rem_nsec; - if (!printk_time) + if (printk_time == PRINTK_TIME_DISABLED) return 0; rem_nsec = do_div(ts, 1000000000); @@ -1643,7 +1780,7 @@ static bool cont_add(int facility, int level, enum log_flags flags, const char * cont.facility = facility; cont.level = level; cont.owner = current; - cont.ts_nsec = local_clock(); + cont.ts_nsec = printk_get_ts(); cont.flags = flags; } @@ -1873,6 +2010,9 @@ static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *buf, size_t size) { return 0; } static bool suppress_message_printing(int level) { return false; } +#define PRINTK_TIME_UNDEFINED -1 +static int printk_time; +static int printk_time_source; #endif /* CONFIG_PRINTK */ #ifdef CONFIG_EARLY_PRINTK @@ -2659,6 +2799,10 @@ static int __init printk_late_init(void) struct console *con; int ret; + /* initialize printk_time settings */ + if (printk_time_source == PRINTK_TIME_UNDEFINED) + printk_time_source = printk_time; + for_each_console(con) { if (!keep_bootcon && con->flags & CON_BOOT) { /* diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c index d111039e0245..de07bb5ffef5 100644 --- a/kernel/time/timekeeping.c +++ b/kernel/time/timekeeping.c @@ -508,6 +508,11 @@ u64 notrace ktime_get_boot_fast_ns(void) } EXPORT_SYMBOL_GPL(ktime_get_boot_fast_ns); +u64 ktime_get_real_offset(void) +{ + return ktime_to_ns(tk_core.timekeeper.offs_real); +} + /** * halt_fast_timekeeper - Prevent fast timekeeper from accessing clocksource. * @tk: Timekeeper to snapshot. diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug index c617b9d1d6cb..144fd4681637 100644 --- a/lib/Kconfig.debug +++ b/lib/Kconfig.debug @@ -8,12 +8,58 @@ config PRINTK_TIME messages to be added to the output of the syslog() system call and at the console. +choice + prompt "printk default clock timestamp" if PRINTK_TIME + default PRINTK_TIME_LOCAL if PRINTK_TIME + help + This option is selected by setting one of + PRINTK_TIME_[DISABLE|LOCAL|BOOT|MONO|REAL] and causes time stamps of + the printk() messages to be added to the output of the syslog() + system call and at the console. + The timestamp is always recorded internally, and exported to /dev/kmsg. This flag just specifies if the timestamp should be included, not that the timestamp is recorded. The behavior is also controlled by the kernel command line - parameter printk.time=1. See Documentation/admin-guide/kernel-parameters.rst + parameter printk.time. See + Documentation/admin-guide/kernel-parameters.rst + +config PRINTK_TIME_LOCAL + bool "Local Clock" + help + Selecting this option causes the time stamps of printk() to be + stamped with the unadjusted hardware clock. + +config PRINTK_TIME_BOOT + bool "CLOCK_BOOTTIME" + help + Selecting this option causes the time stamps of printk() to be + stamped with the adjusted boottime clock. + +config PRINTK_TIME_MONO + bool "CLOCK_MONOTONIC" + help + Selecting this option causes the time stamps of printk() to be + stamped with the adjusted monotonic clock. + +config PRINTK_TIME_REAL + bool "CLOCK_REALTIME" + help + Selecting this option causes the time stamps of printk() to be + stamped with the adjusted realtime clock (UTC). +endchoice + +config PRINTK_TIME_TYPE + int + depends on PRINTK + range 0 4 + default 0 if !PRINTK_TIME + default 1 if PRINTK_TIME_LOCAL + default 2 if PRINTK_TIME_BOOT + default 3 if PRINTK_TIME_MONO + default 4 if PRINTK_TIME_REAL + config CONSOLE_LOGLEVEL_DEFAULT int "Default console loglevel (1-15)" @@ -30,6 +76,23 @@ config CONSOLE_LOGLEVEL_DEFAULT usage in the kernel. That is controlled by the MESSAGE_LOGLEVEL_DEFAULT option. +config PRINTK_TIME_DEBUG + bool "Allow runtime reselection of any timebase on printks" + depends on PRINTK + default N + 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-7)" range 1 7 -- 1.8.5.5 ^ permalink raw reply related [flat|nested] 7+ messages in thread
* Re: [PATCH 2/2 v8] printk: Add monotonic, boottime, and realtime timestamps 2017-08-24 13:42 ` [PATCH 2/2 v8] printk: Add monotonic, boottime, and realtime timestamps Prarit Bhargava @ 2017-08-24 18:50 ` John Stultz 2017-08-25 14:46 ` Prarit Bhargava 2017-08-25 4:52 ` Sergey Senozhatsky 1 sibling, 1 reply; 7+ messages in thread From: John Stultz @ 2017-08-24 18:50 UTC (permalink / raw) To: Prarit Bhargava Cc: lkml, Mark Salyzyn, Jonathan Corbet, Petr Mladek, Sergey Senozhatsky, Steven Rostedt, 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 On Thu, Aug 24, 2017 at 6:42 AM, Prarit Bhargava <prarit@redhat.com> wrote: > --- a/include/linux/timekeeping.h > +++ b/include/linux/timekeeping.h > @@ -239,6 +239,7 @@ static inline u64 ktime_get_raw_ns(void) > extern u64 ktime_get_mono_fast_ns(void); > extern u64 ktime_get_raw_fast_ns(void); > extern u64 ktime_get_boot_fast_ns(void); > +extern u64 ktime_get_real_offset(void); > > /* > * Timespec interfaces utilizing the ktime based ones > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c > index fc47863f629c..dd972bc5c88b 100644 > --- a/kernel/printk/printk.c > +++ b/kernel/printk/printk.c ... > + * printk_get_real_ns: - Return a realtime timestamp for printk messages > + * On 32-bit systems selecting the real clock printk timestamp may lead to > + * unlikely situations where a timestamp is wrong because the real time offset > + * is read without the protection of a sequence lock. > + */ > +static u64 printk_get_real_ns(void) > +{ > + return ktime_get_mono_fast_ns() + ktime_get_real_offset(); > +} > + ... > diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c > index d111039e0245..de07bb5ffef5 100644 > --- a/kernel/time/timekeeping.c > +++ b/kernel/time/timekeeping.c > @@ -508,6 +508,11 @@ u64 notrace ktime_get_boot_fast_ns(void) > } > EXPORT_SYMBOL_GPL(ktime_get_boot_fast_ns); > > +u64 ktime_get_real_offset(void) > +{ > + return ktime_to_ns(tk_core.timekeeper.offs_real); > +} > + Apologies! One last nit here. So if we're going to export ktime_get_real_offset(), folks are going to use it, and there is no documentation about its very sketchy behavioral limits as an interface, except elsewhere in the printk code. Instead of doing that, could you export a __ktime_get_real_fast_ns_unsafe() function, which has its limits (calculating the realtime w/o locks, thus may return completely bad values occasionally) clearly documented in the timekeeping code? You can then use that directly in your printk code, and others who find it and think "Hey this would be great for my life-safety-critical-system driver" will be clearly warned. thanks -john ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [PATCH 2/2 v8] printk: Add monotonic, boottime, and realtime timestamps 2017-08-24 18:50 ` John Stultz @ 2017-08-25 14:46 ` Prarit Bhargava 2017-08-25 14:58 ` Steven Rostedt 0 siblings, 1 reply; 7+ messages in thread From: Prarit Bhargava @ 2017-08-25 14:46 UTC (permalink / raw) To: John Stultz, Joel Fernandes Cc: lkml, Mark Salyzyn, Jonathan Corbet, Petr Mladek, Sergey Senozhatsky, Steven Rostedt, 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 On 08/24/2017 02:50 PM, John Stultz wrote: > On Thu, Aug 24, 2017 at 6:42 AM, Prarit Bhargava <prarit@redhat.com> wrote: >> --- a/include/linux/timekeeping.h >> +++ b/include/linux/timekeeping.h >> @@ -239,6 +239,7 @@ static inline u64 ktime_get_raw_ns(void) >> extern u64 ktime_get_mono_fast_ns(void); >> extern u64 ktime_get_raw_fast_ns(void); >> extern u64 ktime_get_boot_fast_ns(void); >> +extern u64 ktime_get_real_offset(void); >> >> /* >> * Timespec interfaces utilizing the ktime based ones >> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c >> index fc47863f629c..dd972bc5c88b 100644 >> --- a/kernel/printk/printk.c >> +++ b/kernel/printk/printk.c > ... >> + * printk_get_real_ns: - Return a realtime timestamp for printk messages >> + * On 32-bit systems selecting the real clock printk timestamp may lead to >> + * unlikely situations where a timestamp is wrong because the real time offset >> + * is read without the protection of a sequence lock. >> + */ >> +static u64 printk_get_real_ns(void) >> +{ >> + return ktime_get_mono_fast_ns() + ktime_get_real_offset(); >> +} >> + > ... >> diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c >> index d111039e0245..de07bb5ffef5 100644 >> --- a/kernel/time/timekeeping.c >> +++ b/kernel/time/timekeeping.c >> @@ -508,6 +508,11 @@ u64 notrace ktime_get_boot_fast_ns(void) >> } >> EXPORT_SYMBOL_GPL(ktime_get_boot_fast_ns); >> >> +u64 ktime_get_real_offset(void) >> +{ >> + return ktime_to_ns(tk_core.timekeeper.offs_real); >> +} >> + > > Apologies! One last nit here. So if we're going to export > ktime_get_real_offset(), folks are going to use it, and there is no > documentation about its very sketchy behavioral limits as an > interface, except elsewhere in the printk code. > > Instead of doing that, could you export a > __ktime_get_real_fast_ns_unsafe() function, which has its limits > (calculating the realtime w/o locks, thus may return completely bad > values occasionally) clearly documented in the timekeeping code? np. I'm going to copy the code for u64 notrace ktime_get_boot_fast_ns(void) but I'm unsure why the function is marked "notrace", and if __ktime_get_real_fast_ns_unsafe() must be as well? I don't see anything in the git log that indicates why the function is notrace. I've added Joel to this thread ... P. ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [PATCH 2/2 v8] printk: Add monotonic, boottime, and realtime timestamps 2017-08-25 14:46 ` Prarit Bhargava @ 2017-08-25 14:58 ` Steven Rostedt 0 siblings, 0 replies; 7+ messages in thread From: Steven Rostedt @ 2017-08-25 14:58 UTC (permalink / raw) To: Prarit Bhargava Cc: John Stultz, Joel Fernandes, lkml, Mark Salyzyn, Jonathan Corbet, Petr Mladek, Sergey Senozhatsky, Thomas Gleixner, Stephen Boyd, Andrew Morton, Greg Kroah-Hartman, Paul E. McKenney, Christoffer Dall, Deepa Dinamani, Ingo Molnar, Kees Cook, Peter Zijlstra, Geert Uytterhoeven, Luis R. Rodriguez, Nicholas Piggin, Jason A. Donenfeld, Olof Johansson, Josh Poimboeuf, linux-doc On Fri, 25 Aug 2017 10:46:21 -0400 Prarit Bhargava <prarit@redhat.com> wrote: > np. I'm going to copy the code for > > u64 notrace ktime_get_boot_fast_ns(void) > > but I'm unsure why the function is marked "notrace", and if > __ktime_get_real_fast_ns_unsafe() must be as well? I don't see anything in the > git log that indicates why the function is notrace. > > I've added Joel to this thread ... The "notrace" is added because it is one of the trace clocks: kernel/trace/trace.c: { ktime_get_boot_fast_ns, "boot", 1 }, And function tracer can use it. We don't want to be tracing the clock that the function tracer is using (otherwise it will get double traced). It use to bug, but I believe I finally got the recursion protection working to prevent that. -- Steve ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [PATCH 2/2 v8] printk: Add monotonic, boottime, and realtime timestamps 2017-08-24 13:42 ` [PATCH 2/2 v8] printk: Add monotonic, boottime, and realtime timestamps Prarit Bhargava 2017-08-24 18:50 ` John Stultz @ 2017-08-25 4:52 ` Sergey Senozhatsky 1 sibling, 0 replies; 7+ messages in thread From: Sergey Senozhatsky @ 2017-08-25 4:52 UTC (permalink / raw) To: Prarit Bhargava Cc: linux-kernel, Mark Salyzyn, 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 On (08/24/17 09:42), Prarit Bhargava wrote: [..] > +config PRINTK_TIME_DEBUG > + bool "Allow runtime reselection of any timebase on printks" > + depends on PRINTK > + default N > + 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: s/paramters/parameters/ > + 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 -ss ^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2017-08-25 14:58 UTC | newest] Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2017-08-24 13:42 [PATCH 0/2 v8] printk: Add new timestamps Prarit Bhargava 2017-08-24 13:42 ` [PATCH 1/2 v8] time: Make fast functions return 0 before timekeeping is initialized Prarit Bhargava 2017-08-24 13:42 ` [PATCH 2/2 v8] printk: Add monotonic, boottime, and realtime timestamps Prarit Bhargava 2017-08-24 18:50 ` John Stultz 2017-08-25 14:46 ` Prarit Bhargava 2017-08-25 14:58 ` Steven Rostedt 2017-08-25 4:52 ` Sergey Senozhatsky
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).