Re: [PATCH v4] printk: Add monotonic, boottime, and realtime timestamps

From: Prarit Bhargava
Date: Mon Aug 07 2017 - 14:04:50 EST

Next message: Prarit Bhargava: "Re: [PATCH v4] printk: Add monotonic, boottime, and realtime timestamps"
Previous message: Christopher Lameter: "Re: [RFC][PATCH] mm/slub.c: Allow poisoning to use the fast path"
In reply to: Peter Zijlstra: "Re: [PATCH v4] printk: Add monotonic, boottime, and realtime timestamps"
Next in thread: John Stultz: "Re: [PATCH v4] printk: Add monotonic, boottime, and realtime timestamps"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On 08/07/2017 12:52 PM, John Stultz wrote:
> On Mon, Aug 7, 2017 at 8:52 AM, Prarit Bhargava <prarit@xxxxxxxxxx> 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 timestampes 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
>> offset is read without the protection of a sequence lock in the call to
>> ktime_get_log_ts() in printk_get_ts().
>>
>> 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.
>>
>> Signed-off-by: Prarit Bhargava <prarit@xxxxxxxxxx>
>> Cc: Mark Salyzyn <salyzyn@xxxxxxxxxxx>
>> Cc: Jonathan Corbet <corbet@xxxxxxx>
>> Cc: Petr Mladek <pmladek@xxxxxxxx>
>> Cc: Sergey Senozhatsky <sergey.senozhatsky@xxxxxxxxx>
>> Cc: Steven Rostedt <rostedt@xxxxxxxxxxx>
>> Cc: John Stultz <john.stultz@xxxxxxxxxx>
>> Cc: Thomas Gleixner <tglx@xxxxxxxxxxxxx>
>> Cc: Stephen Boyd <sboyd@xxxxxxxxxxxxxx>
>> Cc: Andrew Morton <akpm@xxxxxxxxxxxxxxxxxxxx>
>> Cc: Greg Kroah-Hartman <gregkh@xxxxxxxxxxxxxxxxxxx>
>> Cc: "Paul E. McKenney" <paulmck@xxxxxxxxxxxxxxxxxx>
>> Cc: Christoffer Dall <cdall@xxxxxxxxxx>
>> Cc: Deepa Dinamani <deepa.kernel@xxxxxxxxx>
>> Cc: Ingo Molnar <mingo@xxxxxxxxxx>
>> Cc: Joel Fernandes <joelaf@xxxxxxxxxx>
>> Cc: Prarit Bhargava <prarit@xxxxxxxxxx>
>> Cc: Kees Cook <keescook@xxxxxxxxxxxx>
>> Cc: Peter Zijlstra <peterz@xxxxxxxxxxxxx>
>> Cc: Geert Uytterhoeven <geert+renesas@xxxxxxxxx>
>> Cc: "Luis R. Rodriguez" <mcgrof@xxxxxxxxxx>
>> Cc: Nicholas Piggin <npiggin@xxxxxxxxx>
>> Cc: "Jason A. Donenfeld" <Jason@xxxxxxxxx>
>> Cc: Olof Johansson <olof@xxxxxxxxx>
>> Cc: Josh Poimboeuf <jpoimboe@xxxxxxxxxx>
>> Cc: linux-doc@xxxxxxxxxxxxxxx
>> ---
>> Documentation/admin-guide/kernel-parameters.txt | 6 +-
>> arch/arm/configs/aspeed_g4_defconfig | 2 +-
>> arch/arm/configs/aspeed_g5_defconfig | 2 +-
>> arch/arm/configs/axm55xx_defconfig | 2 +-
>> arch/arm/configs/bcm2835_defconfig | 2 +-
>> arch/arm/configs/colibri_pxa270_defconfig | 2 +-
>> arch/arm/configs/colibri_pxa300_defconfig | 2 +-
>> arch/arm/configs/dove_defconfig | 2 +-
>> arch/arm/configs/efm32_defconfig | 2 +-
>> arch/arm/configs/exynos_defconfig | 2 +-
>> arch/arm/configs/ezx_defconfig | 2 +-
>> arch/arm/configs/h5000_defconfig | 2 +-
>> arch/arm/configs/hisi_defconfig | 2 +-
>> arch/arm/configs/imote2_defconfig | 2 +-
>> arch/arm/configs/imx_v6_v7_defconfig | 2 +-
>> arch/arm/configs/keystone_defconfig | 2 +-
>> arch/arm/configs/lpc18xx_defconfig | 2 +-
>> arch/arm/configs/magician_defconfig | 2 +-
>> arch/arm/configs/mmp2_defconfig | 2 +-
>> arch/arm/configs/moxart_defconfig | 2 +-
>> arch/arm/configs/mps2_defconfig | 2 +-
>> arch/arm/configs/multi_v7_defconfig | 2 +-
>> arch/arm/configs/mvebu_v7_defconfig | 2 +-
>> arch/arm/configs/mxs_defconfig | 2 +-
>> arch/arm/configs/omap2plus_defconfig | 2 +-
>> arch/arm/configs/pxa168_defconfig | 2 +-
>> arch/arm/configs/pxa3xx_defconfig | 2 +-
>> arch/arm/configs/pxa910_defconfig | 2 +-
>> arch/arm/configs/pxa_defconfig | 2 +-
>> arch/arm/configs/qcom_defconfig | 2 +-
>> arch/arm/configs/raumfeld_defconfig | 2 +-
>> arch/arm/configs/shmobile_defconfig | 2 +-
>> arch/arm/configs/socfpga_defconfig | 2 +-
>> arch/arm/configs/stm32_defconfig | 2 +-
>> arch/arm/configs/sunxi_defconfig | 2 +-
>> arch/arm/configs/tango4_defconfig | 2 +-
>> arch/arm/configs/tegra_defconfig | 2 +-
>> arch/arm/configs/u300_defconfig | 2 +-
>> arch/arm/configs/u8500_defconfig | 2 +-
>> arch/arm/configs/vt8500_v6_v7_defconfig | 2 +-
>> arch/arm/configs/xcep_defconfig | 2 +-
>> arch/arm/configs/zx_defconfig | 2 +-
>> arch/arm64/configs/defconfig | 2 +-
>> arch/m68k/configs/amcore_defconfig | 2 +-
>> arch/mips/configs/ath25_defconfig | 2 +-
>> arch/mips/configs/bcm47xx_defconfig | 2 +-
>> arch/mips/configs/bmips_be_defconfig | 2 +-
>> arch/mips/configs/bmips_stb_defconfig | 2 +-
>> arch/mips/configs/ci20_defconfig | 2 +-
>> arch/mips/configs/generic_defconfig | 2 +-
>> arch/mips/configs/lemote2f_defconfig | 2 +-
>> arch/mips/configs/loongson3_defconfig | 2 +-
>> arch/mips/configs/nlm_xlp_defconfig | 2 +-
>> arch/mips/configs/nlm_xlr_defconfig | 2 +-
>> arch/mips/configs/pistachio_defconfig | 2 +-
>> arch/mips/configs/qi_lb60_defconfig | 2 +-
>> arch/mips/configs/rt305x_defconfig | 2 +-
>> arch/mips/configs/xway_defconfig | 2 +-
>> arch/parisc/configs/generic-64bit_defconfig | 2 +-
>> arch/powerpc/configs/40x/virtex_defconfig | 2 +-
>> arch/powerpc/configs/44x/fsp2_defconfig | 2 +-
>> arch/powerpc/configs/44x/virtex5_defconfig | 2 +-
>> arch/powerpc/configs/44x/warp_defconfig | 2 +-
>> arch/powerpc/configs/52xx/cm5200_defconfig | 2 +-
>> arch/powerpc/configs/52xx/lite5200b_defconfig | 2 +-
>> arch/powerpc/configs/52xx/motionpro_defconfig | 2 +-
>> arch/powerpc/configs/52xx/tqm5200_defconfig | 2 +-
>> arch/powerpc/configs/gamecube_defconfig | 2 +-
>> arch/powerpc/configs/mpc5200_defconfig | 2 +-
>> arch/powerpc/configs/pasemi_defconfig | 2 +-
>> arch/powerpc/configs/wii_defconfig | 2 +-
>> arch/s390/configs/default_defconfig | 2 +-
>> arch/s390/configs/gcov_defconfig | 2 +-
>> arch/s390/configs/performance_defconfig | 2 +-
>> arch/s390/configs/zfcpdump_defconfig | 2 +-
>> arch/sh/configs/edosk7760_defconfig | 2 +-
>> arch/sh/configs/sdk7786_defconfig | 2 +-
>> arch/sh/configs/se7722_defconfig | 2 +-
>> arch/sh/configs/sh7785lcr_32bit_defconfig | 2 +-
>> arch/sh/configs/urquell_defconfig | 2 +-
>> arch/sparc/configs/sparc64_defconfig | 2 +-
>> arch/x86/configs/i386_defconfig | 2 +-
>> arch/x86/configs/x86_64_defconfig | 2 +-
>> arch/xtensa/configs/audio_kc705_defconfig | 2 +-
>> arch/xtensa/configs/cadence_csp_defconfig | 2 +-
>> arch/xtensa/configs/generic_kc705_defconfig | 2 +-
>> arch/xtensa/configs/nommu_kc705_defconfig | 2 +-
>> arch/xtensa/configs/smp_lx200_defconfig | 2 +-
>
> Still not quite following why you're updating all the defconfigs. I'd
> make sure the Kconfig default settings are right, and leave updating
> the defconfig to arch/device maintainers. It adds a lot of noise to
> the patch.

Hmm ... I thought it was up to the patch submitter to make sure that
'make defconfig' still worked? Are you sure I can leave that broken?

/me *really* doesn't want to get yelled at by every arch maintainer.

>
>
>> +u64 ktime_get_real_log_ts(u64 *offset_real)
>> +{
>> + *offset_real = ktime_to_ns(tk_core.timekeeper.offs_real);
>> +
>> + if (timekeeping_active)
>> + return ktime_get_mono_fast_ns();
>> + else
>> + return local_clock();
>> +}
>> +
>> +u64 ktime_get_boot_log_ts(void)
>> +{
>> + if (timekeeping_active)
>> + return ktime_get_boot_fast_ns();
>> + else
>> + return local_clock();
>> +}
>
> This feels a little tacked on and duplicative. I'd suggest having one
> function that returns the offset_real and offset_boot or have a
> separate get_mono_log_ts() so its at least consistent.

I have a better suggestion that I was toying with -- exporting
timekeeping_active and using the existing ktime_get_mono|boot|real|_fast_ns()
functions with a function pointer would simplify this code.

> Additionally,
> in the commit message, you call out the lack of locking between
> grabing the offs_real and calling get_mono_fast_ns(), but I worry it
> may be particularly problematic on 32bit systems, and you don't have
> any notes in the actual code about it (it looks like an oversight).
>

I was told to move that comment to the kdoc description by Luis R. Rodriguez.

> Also, when timekeeping_active flips over, and we change from local
> clock to the specified clock, do we see a discontinuity in the log? I
> know folks use to gripe about that back in the day.
>

I have tested this across many systems and haven't seen a discontinunity
yet. I've done both large and small cpu footprint systems and haven't seen
anything like that.

P.

> thanks
> -john
>

Next message: Prarit Bhargava: "Re: [PATCH v4] printk: Add monotonic, boottime, and realtime timestamps"
Previous message: Christopher Lameter: "Re: [RFC][PATCH] mm/slub.c: Allow poisoning to use the fast path"
In reply to: Peter Zijlstra: "Re: [PATCH v4] printk: Add monotonic, boottime, and realtime timestamps"
Next in thread: John Stultz: "Re: [PATCH v4] printk: Add monotonic, boottime, and realtime timestamps"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]