Re: [PATCH v4] printk: Add monotonic, boottime, and realtime timestamps
From: John Stultz
Date: Mon Aug 07 2017 - 12:52:18 EST
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.
> +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. 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).
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.
thanks
-john