* [PATCH 0/3 v11] printk: Add new timestamps @ 2017-09-05 12:06 Prarit Bhargava 2017-09-05 12:06 ` [PATCH 1/3 v11] time: Make fast functions return 0 before timekeeping is initialized Prarit Bhargava ` (2 more replies) 0 siblings, 3 replies; 12+ messages in thread From: Prarit Bhargava @ 2017-09-05 12:06 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 Thomas Gleixner (1): timekeeping: Provide NMI safe access to clock realtime Documentation/admin-guide/kernel-parameters.txt | 6 +- include/linux/timekeeper_internal.h | 6 +- include/linux/timekeeping.h | 1 + kernel/printk/printk.c | 113 ++++++++++++++++++++++-- kernel/time/timekeeping.c | 72 +++++++++++++-- lib/Kconfig.debug | 48 +++++++++- 6 files changed, 228 insertions(+), 18 deletions(-) -- 1.8.5.5 ^ permalink raw reply [flat|nested] 12+ messages in thread
* [PATCH 1/3 v11] time: Make fast functions return 0 before timekeeping is initialized 2017-09-05 12:06 [PATCH 0/3 v11] printk: Add new timestamps Prarit Bhargava @ 2017-09-05 12:06 ` Prarit Bhargava 2017-09-05 12:15 ` Thomas Gleixner 2017-09-05 12:06 ` [PATCH 2/3 v11] timekeeping: Provide NMI safe access to clock realtime Prarit Bhargava 2017-09-05 12:06 ` [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps Prarit Bhargava 2 siblings, 1 reply; 12+ messages in thread From: Prarit Bhargava @ 2017-09-05 12:06 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 7e7e61c00d61..1f8596ef7408 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] 12+ messages in thread
* Re: [PATCH 1/3 v11] time: Make fast functions return 0 before timekeeping is initialized 2017-09-05 12:06 ` [PATCH 1/3 v11] time: Make fast functions return 0 before timekeeping is initialized Prarit Bhargava @ 2017-09-05 12:15 ` Thomas Gleixner 2017-09-15 13:42 ` Prarit Bhargava 0 siblings, 1 reply; 12+ messages in thread From: Thomas Gleixner @ 2017-09-05 12:15 UTC (permalink / raw) To: Prarit Bhargava; +Cc: linux-kernel, John Stultz, Stephen Boyd On Tue, 5 Sep 2017, Prarit Bhargava wrote: > +static struct tk_fast tk_fast_mono ____cacheline_aligned = { > + .base = { > + (struct tk_read_base){ > + .clock = &dummy_clock, > + }, > + (struct tk_read_base){ > + .clock = &dummy_clock, > + }, > + }, > +}; http://lkml.kernel.org/r/alpine.DEB.2.20.1708281658370.1867@nanos Sigh tglx ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH 1/3 v11] time: Make fast functions return 0 before timekeeping is initialized 2017-09-05 12:15 ` Thomas Gleixner @ 2017-09-15 13:42 ` Prarit Bhargava 0 siblings, 0 replies; 12+ messages in thread From: Prarit Bhargava @ 2017-09-15 13:42 UTC (permalink / raw) To: Thomas Gleixner; +Cc: linux-kernel, John Stultz, Stephen Boyd On 09/05/2017 08:15 AM, Thomas Gleixner wrote: > On Tue, 5 Sep 2017, Prarit Bhargava wrote: >> +static struct tk_fast tk_fast_mono ____cacheline_aligned = { >> + .base = { >> + (struct tk_read_base){ >> + .clock = &dummy_clock, >> + }, >> + (struct tk_read_base){ >> + .clock = &dummy_clock, >> + }, >> + }, >> +}; > > http://lkml.kernel.org/r/alpine.DEB.2.20.1708281658370.1867@nanos > > Sigh Oof ... sorry tglx. I missed that email :( My apologies. I'll fix that, retest, and resend. P. > > tglx > ^ permalink raw reply [flat|nested] 12+ messages in thread
* [PATCH 2/3 v11] timekeeping: Provide NMI safe access to clock realtime 2017-09-05 12:06 [PATCH 0/3 v11] printk: Add new timestamps Prarit Bhargava 2017-09-05 12:06 ` [PATCH 1/3 v11] time: Make fast functions return 0 before timekeeping is initialized Prarit Bhargava @ 2017-09-05 12:06 ` Prarit Bhargava 2017-09-05 12:06 ` [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps Prarit Bhargava 2 siblings, 0 replies; 12+ messages in thread From: Prarit Bhargava @ 2017-09-05 12:06 UTC (permalink / raw) To: linux-kernel; +Cc: Thomas Gleixner From: Thomas Gleixner <tglx@linutronix.de> The configurable printk timestamping wants access to clock realtime. Right now there is no ktime_get_real_fast_ns() accessor because reading the monotonic base and the realtime offset cannot be done atomically. Contrary to boot time this offset can change during runtime and cause half updated readouts. struct tk_read_base was fully packed when the fast timekeeper access was implemented. commit ceea5e3771ed ("time: Fix clock->read(clock) race around clocksource changes") removed the 'read' function pointer from the structure, but of course left the comment stale. So now the structure can fit a new 64bit member w/o violating the cache line constraints. Add real_base to tk_read_base and update it in the fast timekeeper update sequence. Implement an accessor which follows the same scheme as the accessor to clock monotonic, but uses the new real_base to access clock real time. The runtime overhead for updating real_base is minimal as it just adds two cache hot values and stores into the same an already dirtied cache line. Signed-off-by: Thomas Gleixner <tglx@linutronix.de> --- include/linux/timekeeper_internal.h | 6 +++++- include/linux/timekeeping.h | 1 + kernel/time/timekeeping.c | 35 +++++++++++++++++++++++++++++++++++ 3 files changed, 41 insertions(+), 1 deletion(-) diff --git a/include/linux/timekeeper_internal.h b/include/linux/timekeeper_internal.h index 0a0a53daf2a2..98f645ee8409 100644 --- a/include/linux/timekeeper_internal.h +++ b/include/linux/timekeeper_internal.h @@ -13,19 +13,22 @@ /** * struct tk_read_base - base structure for timekeeping readout * @clock: Current clocksource used for timekeeping. - * @read: Read function of @clock * @mask: Bitmask for two's complement subtraction of non 64bit clocks * @cycle_last: @clock cycle value at last update * @mult: (NTP adjusted) multiplier for scaled math conversion * @shift: Shift value for scaled math conversion * @xtime_nsec: Shifted (fractional) nano seconds offset for readout * @base: ktime_t (nanoseconds) base time for readout + * @base_real: Nanoseconds base value for clock REALTIME readout * * This struct has size 56 byte on 64 bit. Together with a seqcount it * occupies a single 64byte cache line. * * The struct is separate from struct timekeeper as it is also used * for a fast NMI safe accessors. + * + * @base_real is for the fast NMI safe accessor to allow reading clock + * realtime from any context. */ struct tk_read_base { struct clocksource *clock; @@ -35,6 +38,7 @@ struct tk_read_base { u32 shift; u64 xtime_nsec; ktime_t base; + u64 base_real; }; /** diff --git a/include/linux/timekeeping.h b/include/linux/timekeeping.h index ddc229ff6d1e..eb98cbdbb323 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_fast_ns(void); /* * Timespec interfaces utilizing the ktime based ones diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c index 1f8596ef7408..8b14f35d44fa 100644 --- a/kernel/time/timekeeping.c +++ b/kernel/time/timekeeping.c @@ -508,6 +508,39 @@ u64 notrace ktime_get_boot_fast_ns(void) } EXPORT_SYMBOL_GPL(ktime_get_boot_fast_ns); + +/* + * See comment for __ktime_get_fast_ns() vs. timestamp ordering + */ +static __always_inline u64 __ktime_get_real_fast_ns(struct tk_fast *tkf) +{ + struct tk_read_base *tkr; + unsigned int seq; + u64 now; + + do { + seq = raw_read_seqcount_latch(&tkf->seq); + tkr = tkf->base + (seq & 0x01); + now = ktime_to_ns(tkr->base_real); + + now += timekeeping_delta_to_ns(tkr, + clocksource_delta( + tk_clock_read(tkr), + tkr->cycle_last, + tkr->mask)); + } while (read_seqcount_retry(&tkf->seq, seq)); + + return now; +} + +/** + * ktime_get_real_fast_ns: - NMI safe and fast access to clock realtime. + */ +u64 ktime_get_real_fast_ns(void) +{ + return __ktime_get_real_fast_ns(&tk_fast_mono); +} + /** * halt_fast_timekeeper - Prevent fast timekeeper from accessing clocksource. * @tk: Timekeeper to snapshot. @@ -526,6 +559,7 @@ static void halt_fast_timekeeper(struct timekeeper *tk) memcpy(&tkr_dummy, tkr, sizeof(tkr_dummy)); cycles_at_suspend = tk_clock_read(tkr); tkr_dummy.clock = &dummy_clock; + tkr_dummy.base_real = tkr->base + tk->offs_real; update_fast_timekeeper(&tkr_dummy, &tk_fast_mono); tkr = &tk->tkr_raw; @@ -673,6 +707,7 @@ static void timekeeping_update(struct timekeeper *tk, unsigned int action) update_vsyscall(tk); update_pvclock_gtod(tk, action & TK_CLOCK_WAS_SET); + tk->tkr_mono.base_real = tk->tkr_mono.base + tk->offs_real; update_fast_timekeeper(&tk->tkr_mono, &tk_fast_mono); update_fast_timekeeper(&tk->tkr_raw, &tk_fast_raw); -- 1.8.5.5 ^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps 2017-09-05 12:06 [PATCH 0/3 v11] printk: Add new timestamps Prarit Bhargava 2017-09-05 12:06 ` [PATCH 1/3 v11] time: Make fast functions return 0 before timekeeping is initialized Prarit Bhargava 2017-09-05 12:06 ` [PATCH 2/3 v11] timekeeping: Provide NMI safe access to clock realtime Prarit Bhargava @ 2017-09-05 12:06 ` Prarit Bhargava 2017-09-13 18:30 ` Mark Salyzyn 2017-09-15 13:28 ` Petr Mladek 2 siblings, 2 replies; 12+ messages in thread From: Prarit Bhargava @ 2017-09-05 12:06 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. 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. v9: Fix typo. Add __ktime_get_real_fast_ns_unsafe(). v10: Remove time parameter restrictions. 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 +- kernel/printk/printk.c | 113 ++++++++++++++++++++++-- lib/Kconfig.debug | 48 +++++++++- 3 files changed, 159 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/kernel/printk/printk.c b/kernel/printk/printk.c index fc47863f629c..5aaeb1ebd26c 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,113 @@ 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_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. + */ +enum timestamp_sources { + 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 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 = ktime_get_real_fast_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 = -1; + 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 == -1) { + 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 == -1) { + pr_warn("printk: invalid timestamp option %s\n", param); + return -EINVAL; + } + + printk_time = _printk_time; + if (printk_time > 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 +1745,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 +1975,7 @@ 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; } +static int printk_time; #endif /* CONFIG_PRINTK */ #ifdef CONFIG_EARLY_PRINTK diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug index c617b9d1d6cb..e9e1798415fa 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)" -- 1.8.5.5 ^ permalink raw reply related [flat|nested] 12+ messages in thread
* Re: [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps 2017-09-05 12:06 ` [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps Prarit Bhargava @ 2017-09-13 18:30 ` Mark Salyzyn 2017-09-15 13:28 ` Petr Mladek 1 sibling, 0 replies; 12+ messages in thread From: Mark Salyzyn @ 2017-09-13 18:30 UTC (permalink / raw) To: Prarit Bhargava, linux-kernel 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 On 09/05/2017 05:06 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. > > 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. > > 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. > > v9: Fix typo. Add __ktime_get_real_fast_ns_unsafe(). > > v10: Remove time parameter restrictions. > Ack and unit tested on Backport to 4.9. (you are missing the v11 respin comment, NBD) -- Mark ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps 2017-09-05 12:06 ` [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps Prarit Bhargava 2017-09-13 18:30 ` Mark Salyzyn @ 2017-09-15 13:28 ` Petr Mladek 2017-09-15 14:29 ` Mark Salyzyn 2017-09-15 14:40 ` Prarit Bhargava 1 sibling, 2 replies; 12+ messages in thread From: Petr Mladek @ 2017-09-15 13:28 UTC (permalink / raw) To: Prarit Bhargava Cc: linux-kernel, Mark Salyzyn, Jonathan Corbet, 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 Tue 2017-09-05 08:06:41, 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. > > 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. > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c > index fc47863f629c..5aaeb1ebd26c 100644 > --- a/kernel/printk/printk.c > +++ b/kernel/printk/printk.c > @@ -1202,14 +1205,113 @@ 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_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. > + */ > +enum timestamp_sources { > + 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 void printk_set_ts_func(void) > +{ > + switch (printk_time) { > + case PRINTK_TIME_LOCAL: > + case PRINTK_TIME_DISABLED: > + default: > + printk_get_ts = local_clock; > + break; This is slightly confusing. One would expect that local_clock() will be used when "disabled" is written into /sys/module/printk/parameters/time. But it is not true because this function is not called in that case. I know that you do this to avoid recursion in printk_get_first_ts(), I know because I read the discussion about an older version of the patch. But this is less obvious from the code. > + 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 = ktime_get_real_fast_ns; > + break; > + } > +} I think that it would be cleaner the following way: static int printk_set_ts_source(enum timestamp_sources ts_source) { int err = 0; switch (ts_source) { case PRINTK_TIME_LOCAL: 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 = ktime_get_real_fast_ns; break; case PRINTK_TIME_DISABLED: /* * The timestamp is always stored into the log buffer. * Keep the current one. */ break; default: err = -EINVAL; break; } if (!err) printk_time = ts_source; return err; } Then we could avoid the recursion directly in printk_get_first_ts(). > + > +static u64 printk_get_first_ts(void) > +{ > + printk_set_ts_func(); printk_set_ts_source(printk_time); /* Fallback for invalid or disabled timestamp source */ if (printk_get_ts == printk_get_first_ts) printk_get_ts = local_clock; > + 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 = -1; > + int ts; int err; > + > + 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 == -1) { > + 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 == -1) { > + pr_warn("printk: invalid timestamp option %s\n", param); > + return -EINVAL; > + } > + > + printk_time = _printk_time; > + if (printk_time > PRINTK_TIME_DISABLED) > + printk_set_ts_func(); Finally, we could replace the above two sections by: err = printk_set_ts_source(_printk_time); if (err) { pr_warn("printk: invalid timestamp option %s\n", param); return err; } Also I would rename the variable "_pritnk_time" to "time_source" in this function. > + 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); > diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug > index c617b9d1d6cb..e9e1798415fa 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" s/CLOCK_BOOTTIME/Boot time clock/ It will make it easier to read and consistent with the local clock option. > + 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" same here > + 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" and here > + 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 > + I am still slightly nervous that external tools would need updating. Also they might have troubles to interpret the time stamps especially when the source is changed at runtime via /sys/module/printk/parameters/time. On the other hand, we do not change the default behavior. You sent me a patch against dmesg. It was trivial and worked well. Also we got positive (constructive) feedback from several people. Therefore I am getting open for this change. Best Regards, Petr PS: Please, do not forget to handle the complains from Thomas Gleixner in the first patch. ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps 2017-09-15 13:28 ` Petr Mladek @ 2017-09-15 14:29 ` Mark Salyzyn 2017-09-17 10:46 ` Sergey Senozhatsky 2017-09-15 14:40 ` Prarit Bhargava 1 sibling, 1 reply; 12+ messages in thread From: Mark Salyzyn @ 2017-09-15 14:29 UTC (permalink / raw) To: Petr Mladek, Prarit Bhargava Cc: linux-kernel, Jonathan Corbet, 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 09/15/2017 06:28 AM, Petr Mladek wrote: > I am still slightly nervous that external tools would need updating. > Also they might have troubles to interpret the time stamps especially > when the source is changed at runtime via > /sys/module/printk/parameters/time. My comment below is a rehash/summary: In the discussion, it appears that DAC protection is enough to prevent flippant changes. The use cases I can imagine for runtime alteration fall in two groups, late boot changes after all disks are mounted and the application layers have started; or as an aid to debugging where the deliberate nature can be accounted for. Change it, erase the logs is the KISS solution, so the tools do not have to 'sniff' the stream for dynamic changes, likely getting the 'leader' wrong, checking /sys/module/printk/parameters/time for the current/last timebase. To mitigate the 'leader' issue, or post-mortem/off-machine interpretation, really for the debugging corner case IMHO, I had proposed that local, and perhaps monotonic, time print as-is as they are almost(?) imperceptibly different, but that realtime add a U suffix (to denote time is UTC), and that boottime add a B suffix (well, because) so that tools can discern. Monotonic could have a M suffix if it is really a stickler. This proposal would require more disruptive tool modifications and should be scoped as a separate effort. I do expect a debate regarding upper and lower case ... I have a patch waiting in the wings here where disruptive time changes (suspend/resume/hibernate/restore; maybe date(1), ntpd(8) or embedded systems LTE hardware time updates) will report dual timestamps so that resynchronization and tracking can happen in post-mortem on the stream, I expect to use the above proposal for the 'second' occasional timestamp. -- Mark ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps 2017-09-15 14:29 ` Mark Salyzyn @ 2017-09-17 10:46 ` Sergey Senozhatsky 2017-09-19 11:52 ` Prarit Bhargava 0 siblings, 1 reply; 12+ messages in thread From: Sergey Senozhatsky @ 2017-09-17 10:46 UTC (permalink / raw) To: Mark Salyzyn, Petr Mladek, Prarit Bhargava Cc: linux-kernel, Jonathan Corbet, 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 (09/15/17 07:29), Mark Salyzyn wrote: > On 09/15/2017 06:28 AM, Petr Mladek wrote: > > I am still slightly nervous that external tools would need updating. > > Also they might have troubles to interpret the time stamps especially > > when the source is changed at runtime via > > /sys/module/printk/parameters/time. > My comment below is a rehash/summary: > > In the discussion, it appears that DAC protection is enough to prevent > flippant changes. The use cases I can imagine for runtime alteration fall in > two groups, late boot changes after all disks are mounted and the > application layers have started; or as an aid to debugging where the > deliberate nature can be accounted for. Change it, erase the logs is the > KISS solution, so the tools do not have to 'sniff' the stream for dynamic > changes, likely getting the 'leader' wrong, checking > /sys/module/printk/parameters/time for the current/last timebase. > > To mitigate the 'leader' issue, or post-mortem/off-machine interpretation, > really for the debugging corner case IMHO, I had proposed that local, and > perhaps monotonic, time print as-is as they are almost(?) imperceptibly > different, but that realtime add a U suffix (to denote time is UTC), and > that boottime add a B suffix (well, because) so that tools can discern. > Monotonic could have a M suffix if it is really a stickler. This proposal > would require more disruptive tool modifications and should be scoped as a > separate effort. I do expect a debate regarding upper and lower case ... > > I have a patch waiting in the wings here where disruptive time changes > (suspend/resume/hibernate/restore; maybe date(1), ntpd(8) or embedded > systems LTE hardware time updates) will report dual timestamps so that > resynchronization and tracking can happen in post-mortem on the stream, I > expect to use the above proposal for the 'second' occasional timestamp. I'm a bit uncomfortable with the "breaks user space" part. since this is a strictly debugging option, would it be sufficient to store those extended timestamps as prefixes of every message? see (sorry for "self-quoting"): lkml.kernel.org/r/20170917062608.GA512@tigerII.localdomain each message, thus, will be in the following format [current header: loglevel, timestamp, etc] [extended printk data] message text extended printk data can contain your monotonic/etc timestamps, and anything else. and then it's up to you how do you grep the messages and process the extended data. but the point is - user space tools (journald, dmesg, etc.) stays intact. which is kinda nice. so we can avoid that chicken and egg problem: we break user space by merging the patchset but user space people don't want to talk about any fixes until we break those tools. -ss ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps 2017-09-17 10:46 ` Sergey Senozhatsky @ 2017-09-19 11:52 ` Prarit Bhargava 0 siblings, 0 replies; 12+ messages in thread From: Prarit Bhargava @ 2017-09-19 11:52 UTC (permalink / raw) To: Sergey Senozhatsky, Mark Salyzyn, Petr Mladek Cc: linux-kernel, Jonathan Corbet, 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 09/17/2017 06:46 AM, Sergey Senozhatsky wrote: > I'm a bit uncomfortable with the "breaks user space" part. since this > is a strictly debugging option, would it be sufficient to store those > extended timestamps as prefixes of every message? > see (sorry for "self-quoting"): > lkml.kernel.org/r/20170917062608.GA512@tigerII.localdomain > Sergey, I haven't forgotten about the above. It's something I'm going to look at after this initial patchset is done. P. > each message, thus, will be in the following format > > [current header: loglevel, timestamp, etc] [extended printk data] message text > > extended printk data can contain your monotonic/etc timestamps, and > anything else. > > and then it's up to you how do you grep the messages and process the > extended data. but the point is - user space tools (journald, dmesg, > etc.) stays intact. which is kinda nice. > > so we can avoid that chicken and egg problem: we break user space > by merging the patchset but user space people don't want to talk > about any fixes until we break those tools. > > -ss > ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps 2017-09-15 13:28 ` Petr Mladek 2017-09-15 14:29 ` Mark Salyzyn @ 2017-09-15 14:40 ` Prarit Bhargava 1 sibling, 0 replies; 12+ messages in thread From: Prarit Bhargava @ 2017-09-15 14:40 UTC (permalink / raw) To: Petr Mladek Cc: linux-kernel, Mark Salyzyn, Jonathan Corbet, 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 09/15/2017 09:28 AM, Petr Mladek wrote: > > I am still slightly nervous that external tools would need updating. > Also they might have troubles to interpret the time stamps especially > when the source is changed at runtime via > /sys/module/printk/parameters/time. In earlier versions I had logic to prevent switching during runtime. tglx requested that it be removed and I removed it. Personally I fall into the "I'm going to set it once and never change it" however, as Mark will offer there are cases where it might be advantageous to change the timestamp. I think he has a patch that will append a b/r/etc. to the timestamp so that userspace can interpret the different timestamps. P. ^ permalink raw reply [flat|nested] 12+ messages in thread
end of thread, other threads:[~2017-09-19 11:52 UTC | newest] Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2017-09-05 12:06 [PATCH 0/3 v11] printk: Add new timestamps Prarit Bhargava 2017-09-05 12:06 ` [PATCH 1/3 v11] time: Make fast functions return 0 before timekeeping is initialized Prarit Bhargava 2017-09-05 12:15 ` Thomas Gleixner 2017-09-15 13:42 ` Prarit Bhargava 2017-09-05 12:06 ` [PATCH 2/3 v11] timekeeping: Provide NMI safe access to clock realtime Prarit Bhargava 2017-09-05 12:06 ` [PATCH 3/3 v11] printk: Add monotonic, boottime, and realtime timestamps Prarit Bhargava 2017-09-13 18:30 ` Mark Salyzyn 2017-09-15 13:28 ` Petr Mladek 2017-09-15 14:29 ` Mark Salyzyn 2017-09-17 10:46 ` Sergey Senozhatsky 2017-09-19 11:52 ` Prarit Bhargava 2017-09-15 14:40 ` Prarit Bhargava
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.