printk: Add monotonic, boottime, and realtime timestamps

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 <[email protected]>

Cc Mark Salyzyn <[email protected]>

Cc Jonathan Corbet <[email protected]>

Cc Petr Mladek <[email protected]>

Cc Sergey Senozhatsky <[email protected]>

Cc Steven Rostedt <[email protected]>

Cc John Stultz <[email protected]>

Cc Thomas Gleixner <[email protected]>

Cc Stephen Boyd <[email protected]>

Cc Andrew Morton <[email protected]>

Cc Greg Kroah-Hartman <[email protected]>

Cc "Paul E. McKenney" <[email protected]>

Cc Christoffer Dall <[email protected]>

Cc Deepa Dinamani <[email protected]>

Cc Ingo Molnar <[email protected]>

Cc Joel Fernandes <[email protected]>

Cc Prarit Bhargava <[email protected]>

Cc Kees Cook <[email protected]>

Cc Peter Zijlstra <[email protected]>

Cc Geert Uytterhoeven <[email protected]>

Cc "Luis R. Rodriguez" <[email protected]>

Cc Nicholas Piggin <[email protected]>

Cc "Jason A. Donenfeld" <[email protected]>

Cc Olof Johansson <[email protected]>

Cc Josh Poimboeuf <[email protected]>

Cc [email protected]

---
 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 +-

kernel/time/timekeeping.c +7 -0

+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

Quoted 7 lines · Prarit Bhargava

(quoted diff) +7 -0

+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

Review

Quoted 10 lines

(quoted diff) +10 -0

+               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.

Quoted 133 lines · Prarit Bhargava

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 <[email protected]>

Cc Mark Salyzyn <[email protected]>

Cc Jonathan Corbet <[email protected]>

Cc Petr Mladek <[email protected]>

Cc Sergey Senozhatsky <[email protected]>

Cc Steven Rostedt <[email protected]>

Cc John Stultz <[email protected]>

Cc Thomas Gleixner <[email protected]>

Cc Stephen Boyd <[email protected]>

Cc Andrew Morton <[email protected]>

Cc Greg Kroah-Hartman <[email protected]>

Cc "Paul E. McKenney" <[email protected]>

Cc Christoffer Dall <[email protected]>

Cc Deepa Dinamani <[email protected]>

Cc Ingo Molnar <[email protected]>

Cc Joel Fernandes <[email protected]>

Cc Prarit Bhargava <[email protected]>

Cc Kees Cook <[email protected]>

Cc Peter Zijlstra <[email protected]>

Cc Geert Uytterhoeven <[email protected]>

Cc "Luis R. Rodriguez" <[email protected]>

Cc Nicholas Piggin <[email protected]>

Cc "Jason A. Donenfeld" <[email protected]>

Cc Olof Johansson <[email protected]>

Cc Josh Poimboeuf <[email protected]>

Cc [email protected]

---
 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 +-

Quoted 8 lines

 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.

Quoted 15 lines

kernel/time/timekeeping.c +13 -0

+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)

kernel/time/timekeeping.c u64 notrace ktime_get_boot_fast_ns(void) · line 498

Quoted 4 lines

kernel/time/timekeeping.c +4 -0

+               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

Quoted 4 lines · John Stultz

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.

Quoted 13 lines

Quoted 13 lines

kernel/time/timekeeping.c +13 -0

+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)

Quoted 8 lines

kernel/time/timekeeping.c u64 notrace ktime_get_boot_fast_ns(void) · line 498

Quoted 4 lines

kernel/time/timekeeping.c +4 -0

+               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.

Quoted 6 lines

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.

Quoted 4 lines

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.

Quoted 10 lines · Prarit Bhargava

Quoted 4 lines · John Stultz

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.

No. Don't break systems, but at the same time, can't you use the default value in Kconfig to set it properly so the old defconfig settings don't really matter?

Apologies if I've not followed the issue properly, but it is odd, as I'm not sure I can think of a patch I've seen before that had so much defconfig noise in it. Again, I've not looked into it closely, so it may just be my own ignorance, but it makes me suspect there is a better way.

Quoted 16 lines · John Stultz

Quoted 10 lines · Prarit Bhargava

Quoted 4 lines · John Stultz

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.

No. Don't break systems, but at the same time, can't you use the default value in Kconfig to set it properly so the old defconfig settings don't really matter?

Quoted 6 lines

Apologies if I've not followed the issue properly, but it is odd, as I'm not sure I can think of a patch I've seen before that had so much defconfig noise in it. Again, I've not looked into it closely, so it may just be my own ignorance, but it makes me suspect there is a better way.

peterz? Want to offer a suggestion? The issue is that I'm changing a bool config option to an int and that impacts all the arch's defconfigs. John points out that this is a lot of churn and we're both wondering if there's a better way to do the configs.

Quoted 4 lines · Prarit Bhargava

peterz? Want to offer a suggestion? The issue is that I'm changing a bool config option to an int and that impacts all the arch's defconfigs. John points out that this is a lot of churn and we're both wondering if there's a better way to do the configs.

The usual approach is to keep the old bool Kconfig option, and add another int Kconfig option that depends on the original one. The tests for the int value get a bit more complex, but one way to handle this is to define a cpp macro something like the following:

#ifdef CONFIG_OLD_OPTION
#define CPP_NEW_OPTION 0
#else
#define CPP_NEW_OPTION CONFIG_NEW_OPTION
#endif

Then use CPP_NEW_OPTION, where zero means disabled and other numbers select the available options.

Adjust to suit depending on what values mean what.

Another approach is to make the range of the new Kconfig option depend on the old option:

config NEW_OPTION
int "your description here"
range 1 5 if OLD_OPTION
range 0 0 if !OLD_OPTION
default 0
help
your help here

Again, adjust to suit depending on what values mean what.

lib/Kconfig.debug +24 -0

@@ -1,8 +1,46 @@
 menu "printk and dmesg options"
 
+choice
+       prompt "printk default clock"
+       config PRINTK_TIME_DISABLE
+       bool "Disabled"
+       help
+        Selecting this option disables the time stamps of printk().
+
+       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.

Quoted 34 lines · Paul E. McKenney

Quoted 4 lines · Prarit Bhargava

peterz? Want to offer a suggestion? The issue is that I'm changing a bool config option to an int and that impacts all the arch's defconfigs. John points out that this is a lot of churn and we're both wondering if there's a better way to do the configs.

The usual approach is to keep the old bool Kconfig option, and add another int Kconfig option that depends on the original one. The tests for the int value get a bit more complex, but one way to handle this is to define a cpp macro something like the following:

#ifdef CONFIG_OLD_OPTION
#define CPP_NEW_OPTION 0
#else
#define CPP_NEW_OPTION CONFIG_NEW_OPTION
#endif

Then use CPP_NEW_OPTION, where zero means disabled and other numbers select the available options.

Adjust to suit depending on what values mean what.

Another approach is to make the range of the new Kconfig option depend on the old option:

config NEW_OPTION
int "your description here"
range 1 5 if OLD_OPTION
range 0 0 if !OLD_OPTION
default 0
help
your help here

Quoted 1 line

Again, adjust to suit depending on what values mean what.

Right this. Except I don't see the !OLD_OPTION working as expected. A 'new' config will not include the old one, so the !OLD_OPTION thing will 'always' be true.

So your:

Quoted 27 lines

(quoted diff) +24 -0

@@ -1,8 +1,46 @@
 menu "printk and dmesg options"
 
+choice
+       prompt "printk default clock"
+       config PRINTK_TIME_DISABLE
+       bool "Disabled"
+       help
+        Selecting this option disables the time stamps of printk().
+
+       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.

Review line 36

Quoted 10 lines

(quoted diff) +9 -0

+
+       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.
+
+endchoice
+
 config PRINTK_TIME

Change that into something like:

config PRINTK_CLOCK

Review line 40

Quoted 5 lines

(quoted diff) +3 -1

-       bool "Show timing information on printks"
+       int "Show time stamp information on printks"
        depends on PRINTK
+       default 0 if PRINTK_TIME_DISABLE
+       default 1 if PRINTK_TIME_LOCAL

And that into:

	default 1 if PRINTK_TIME_LOCAL || PRINTK_TIME

Review line 45

Quoted 5 lines

(quoted diff) +3 -0

+       default 2 if PRINTK_TIME_BOOT
+       default 3 if PRINTK_TIME_MONO
+       default 4 if PRINTK_TIME_REAL
 	  help
 	    Selecting this option causes time stamps of the printk()

Then the old PRINTK_TIME symbol will auto-convert into the new equivalent.

Quoted 96 lines · Peter Zijlstra

Quoted 34 lines · Paul E. McKenney

Quoted 4 lines · Prarit Bhargava

peterz? Want to offer a suggestion? The issue is that I'm changing a bool config option to an int and that impacts all the arch's defconfigs. John points out that this is a lot of churn and we're both wondering if there's a better way to do the configs.

The usual approach is to keep the old bool Kconfig option, and add another int Kconfig option that depends on the original one. The tests for the int value get a bit more complex, but one way to handle this is to define a cpp macro something like the following:

#ifdef CONFIG_OLD_OPTION
#define CPP_NEW_OPTION 0
#else
#define CPP_NEW_OPTION CONFIG_NEW_OPTION
#endif

Then use CPP_NEW_OPTION, where zero means disabled and other numbers select the available options.

Adjust to suit depending on what values mean what.

Another approach is to make the range of the new Kconfig option depend on the old option:

config NEW_OPTION
int "your description here"
range 1 5 if OLD_OPTION
range 0 0 if !OLD_OPTION
default 0
help
your help here

Quoted 1 line

Again, adjust to suit depending on what values mean what.

Right this. Except I don't see the !OLD_OPTION working as expected. A 'new' config will not include the old one, so the !OLD_OPTION thing will 'always' be true.

So your:

Quoted 27 lines

(quoted diff) +24 -0

@@ -1,8 +1,46 @@
 menu "printk and dmesg options"
 
+choice
+       prompt "printk default clock"
+       config PRINTK_TIME_DISABLE
+       bool "Disabled"
+       help
+        Selecting this option disables the time stamps of printk().
+
+       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.

Review line 36

Quoted 10 lines

(quoted diff) +9 -0

+
+       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.
+
+endchoice
+
 config PRINTK_TIME

Change that into something like:

config PRINTK_CLOCK

Review line 40

Quoted 5 lines

(quoted diff) +3 -1

-       bool "Show timing information on printks"
+       int "Show time stamp information on printks"
        depends on PRINTK
+       default 0 if PRINTK_TIME_DISABLE
+       default 1 if PRINTK_TIME_LOCAL

And that into:

	default 1 if PRINTK_TIME_LOCAL || PRINTK_TIME

Quoted 9 lines

Review line 45

Quoted 5 lines

(quoted diff) +3 -0

+       default 2 if PRINTK_TIME_BOOT
+       default 3 if PRINTK_TIME_MONO
+       default 4 if PRINTK_TIME_REAL
 	  help
 	    Selecting this option causes time stamps of the printk()

Then the old PRINTK_TIME symbol will auto-convert into the new equivalent.

I don't think there's an easy code way around this. Essentially this Kconfig code boils down to properly evaluating

config PRINTK_CLOCK
default 1 if PRINTK_TIME
default 0

where there is no Kconfig entry for PRINTK_TIME.

If undefined CONFIG_PRINTK_TIME is used in a config, it is immediately scrubbed by the kconfig script so it doesn't "exist" when CONFIG_PRINTK_CLOCK is evaluated. The result of that is CONFIG_PRINT_CLOCK=0.

I tried

config PRINTK_TIME
bool "old config option"

then I end up with both a CONFIG_PRINTK_CLOCK=1 and a CONFIG_PRINTK_TIME=y in the resulting config which is confusing.

I've debated using the other suggestion that Paul made but TBH (sorry Paul) it seems like I'm avoiding the real but noisy solution of

	s/PRINTK_TIME=y/PRINTK_TIME=1/g

I'm obviously open to other suggestions...

Quoted 6 lines · Prarit Bhargava

arch/arm/configs/aspeed_g4_defconfig +0 -0

index cfc2465e8b77..5f3c50914e92 100644

arch/arm/configs/aspeed_g4_defconfig CONFIG_JFFS2_FS_XATTR=y · line 168

Quoted 8 lines

arch/arm/configs/aspeed_g4_defconfig +1 -1

@@ -162,7 +162,7 @@ CONFIG_JFFS2_FS_XATTR=y
  CONFIG_UBIFS_FS=y
  CONFIG_SQUASHFS=y
  CONFIG_SQUASHFS_XZ=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME_LOCAL=y
  CONFIG_DYNAMIC_DEBUG=y
  CONFIG_STRIP_ASM_SYMS=y
  CONFIG_DEBUG_FS=y

Many have had misgivings, let me try another pass at this.

We (royal we) should really look into adjusting configuration parsing to allow an easy transition from boolean to selection ... I am sure this is not the first time bistate/tristate was moved to a number.

An idea? Maybe look into a way to deal with this to use something _other_ than CONFIG_PRINTK_TIME to hold the selection, and keep a (hidden/legacy?) CONFIG_PRINTK_TIME that when selected sets CONFIG_PRINTK_TIME_LOCAL, and switch to _not_ CONFIG_PRINTK_TIME_DISABLE as the internal mechanical replacement for it. I do not know how disruptive this will be, but is worth it if the codebase supports it, and legacy config retained?

arch/arm/configs/aspeed_g4_defconfig

Quoted 10 lines

arch/arm/configs/aspeed_g4_defconfig +10 -0

+
+static int printk_time_set(const char *val, const struct kernel_param *kp)
+{
+    char *param = strstrip((char *)val);
+    int _printk_time = -1;
+    int stamp;
+
+    if (strlen(param) == 1) {
+        /* Preserve legacy boolean settings */
+        if (!strcmp("0", param) || !strcmp("n", param) ||

if strlen(param) == 1, then param[0] == '0' etc works fine and is KISS.

arch/arm/configs/aspeed_g4_defconfig

Quoted 13 lines

arch/arm/configs/aspeed_g4_defconfig +13 -0

+    /*
+     * Only allow enabling and disabling of the current printk_time
+     * setting.  Changing it from one setting to another confuses
+     * userspace.
+     */
+    if (printk_time_setting == PRINTK_TIME_DISABLE) {
+        printk_time_setting = _printk_time;
+    } else if ((printk_time_setting != _printk_time) &&
+           (_printk_time != 0)) {
+        pr_warn("printk: timestamp can only be set to 0(disabled) or %s\n",
+            printk_time_str[printk_time_setting]);
+        return -EINVAL;
+    }

I agree with the restriction in the general case. However (as hinted at before() #ifdef CONFIG_PRINTK_TIME_RESTRICT (default y, or #ifndef CONFIG_PRINTK_TIME_DEBUG default n) around this will allow us users to choose if we are confused or not. I can see being able to change it on the fly as an option. Especially since we have /sys/module/printk/parameters/time.

-- Mark

kernel/printk/printk.c +17 -0

+static u64 printk_get_ts(void)
+{
+	u64 mono, offset_real;
+
+	if (printk_time <= PRINTK_TIME_LOCAL)
+		return local_clock();
+
+	if (printk_time == PRINTK_TIME_BOOT)
+		return ktime_get_boot_log_ts();
+
+	mono = ktime_get_real_log_ts(&offset_real);
+
+	if (printk_time == PRINTK_TIME_MONO)
+		return mono;
+
+	return mono + offset_real;
+}
 
 static size_t print_time(u64 ts, char *buf)
 {

kernel/printk/printk.c +9 -0

+/**
+ * enum printk_time_type - Timestamp types for printk() messages.
+ * @PRINTK_TIME_DISABLE: 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

kernel/printk/printk.c +8 -0

+	if (strlen(param) == 1) {
+		/* Preserve legacy boolean settings */
+		if (!strcmp("0", param) || !strcmp("n", param) ||
+		    !strcmp("N", param))
+			_printk_time = PRINTK_TIME_DISABLE;
+		if (!strcmp("1", param) || !strcmp("y", param) ||
+		    !strcmp("Y", param))
+			_printk_time = PRINTK_TIME_LOCAL;

kernel/printk/printk.c +7 -0

+static u64 printk_get_ts(void)
+{
+	u64 mono, offset_real;
+
+	if (printk_time <= PRINTK_TIME_LOCAL)
+		return local_clock();
+

On (08/07/17 11:52), Prarit Bhargava wrote:
[..]

Quoted 13 lines

kernel/printk/printk.c +13 -0

+/**
+ * enum printk_time_type - Timestamp types for printk() messages.
+ * @PRINTK_TIME_DISABLE: 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 in the call to ktime_get_log_ts()
+ * in printk_get_ts() below.
+ */
+enum printk_time_type {

kernel/printk/printk.c static inline void boot_delay_msec(int level) · line 1228

Quoted 6 lines

kernel/printk/printk.c +6 -0

+	PRINTK_TIME_DISABLE = 0,
+	PRINTK_TIME_LOCAL = 1,
+	PRINTK_TIME_BOOT = 2,
+	PRINTK_TIME_MONO = 3,
+	PRINTK_TIME_REAL = 4,
+};

may be call the entire thing 'timestamp surces' or something?

[..]

Quoted 8 lines

kernel/printk/printk.c +8 -0

+	if (strlen(param) == 1) {
+		/* Preserve legacy boolean settings */
+		if (!strcmp("0", param) || !strcmp("n", param) ||
+		    !strcmp("N", param))
+			_printk_time = PRINTK_TIME_DISABLE;
+		if (!strcmp("1", param) || !strcmp("y", param) ||
+		    !strcmp("Y", param))
+			_printk_time = PRINTK_TIME_LOCAL;

kernel/printk/printk.c static inline void boot_delay_msec(int level) · line 1261

Quoted 10 lines

kernel/printk/printk.c +10 -0

+	}
+	if (_printk_time == -1) {
+		for (stamp = 0; stamp <= 4; stamp++) {
+			if (!strncmp(printk_time_str[stamp], param,
+				     strlen(param))) {
+				_printk_time = stamp;
+				break;
+			}
+		}
+	}

you can use match_string() here.

kernel/printk/printk.c static inline void boot_delay_msec(int level) · line 1265

Quoted 4 lines

kernel/printk/printk.c +4 -0

+	if (_printk_time == -1) {
+		pr_warn("printk: invalid timestamp value %s\n", param);
+		return -EINVAL;
+	}

`invalid timestamp value' is confusing.

kernel/printk/printk.c static inline void boot_delay_msec(int level) · line 1277

Quoted 6 lines

kernel/printk/printk.c +4 -0

+	} else if ((printk_time_setting != _printk_time) &&
+		   (_printk_time != 0)) {
+		pr_warn("printk: timestamp can only be set to 0(disabled) or %s\n",
+			printk_time_str[printk_time_setting]);

ditto.

kernel/printk/printk.c static inline void boot_delay_msec(int level) · line 1282

Quoted 7 lines

kernel/printk/printk.c +5 -0

+		return -EINVAL;
+	}
+
+	printk_time = _printk_time;
+	pr_info("printk: timestamp set to %s\n", printk_time_str[printk_time]);

ditto.

[..]

Quoted 11 lines

kernel/printk/printk.c +11 -0

+static u64 printk_get_ts(void)
+{
+	u64 mono, offset_real;
+
+	if (printk_time <= PRINTK_TIME_LOCAL)
+		return local_clock();
+
+	if (printk_time == PRINTK_TIME_BOOT)
+		return ktime_get_boot_log_ts();
+
+	mono = ktime_get_real_log_ts(&offset_real);

kernel/printk/printk.c static inline void boot_delay_msec(int level) · line 1313

Quoted 6 lines

kernel/printk/printk.c +6 -0

+
+	if (printk_time == PRINTK_TIME_MONO)
+		return mono;
+
+	return mono + offset_real;
+}

this looks hard...

kernel/printk/printk.c static size_t msg_print_text(const struct printk_log *msg, · line 1984

Quoted 3 lines

kernel/printk/printk.c +2 -0

+static int printk_time;
+static int printk_time_setting;

how about s/printk_time_setting/printk_time_source/? or something similar?

	-ss

On (08/07/17 11:52), Prarit Bhargava wrote:

[..]

Quoted 12 lines

kernel/printk/printk.c +12 -0

+	if (strlen(param) == 1) {
+		/* Preserve legacy boolean settings */
+		if (!strcmp("0", param) || !strcmp("n", param) ||
+		    !strcmp("N", param))
+			_printk_time = PRINTK_TIME_DISABLE;
+		if (!strcmp("1", param) || !strcmp("y", param) ||
+		    !strcmp("Y", param))
+			_printk_time = PRINTK_TIME_LOCAL;
+	}
+	if (_printk_time == -1) {
+		for (stamp = 0; stamp <= 4; stamp++) {
+			if (!strncmp(printk_time_str[stamp], param,

kernel/printk/printk.c static inline void boot_delay_msec(int level) · line 1261

Quoted 6 lines

kernel/printk/printk.c +6 -0

+				     strlen(param))) {
+				_printk_time = stamp;
+				break;
+			}
+		}
+	}

you can use match_string() here.