Skip to contentSkip to conversation

printk, Add monotonic and real printk timestamps

PATCH Superseded Prarit Bhargava 3 participants 12 messages Feb 23, 2016 – Apr 26, 2016

Subsystems (29)
Documentation Arm (32-bit) x86 Arm Qualcomm mailing list +25 more subsystems

v6 of 7 Superseded Latest is v7 →

lore
Share & tools
lore

Prarit Bhargava

author
#0 lore raw

v6 cover printk, Add monotonic and real printk timestamps

This patchset adds monotonic and real printk timestamps. The first patch changes CONFIG_PRINT_TIME from a bool to an int to allow for the additional timestamps that are added in patch 2.

Changes from v6: Petr Mladek pointed out that the current patch fails to indicate to userspace programs which timestamp is being used. Additionally he pointed out that no other config option uses a mix of bool and integers the way CONFIG_PRINTK_TIME would have done after my patch. This results in a patch to modify CONFIG_PRINTK_TIME to switch to int (which includes modifications to config files) and a second patch to implement the new timestamps.

Additionally, while testing the dmesg utility I noticed a difference in behaviour between the old CONFIG_PRINTK_TIME=n and CONFIG_PRINTK_TIME=0 (both of which disabled timestamp on the console). In the new case the dmesg output always included 0.000000 timestamp instead of the actual time. I have fixed this by recording (but not writing to the console) the timestamp for 0 and 1 in printk_get_ts() so that dmesg behaves as before.

Cc Petr Mladek <[email protected]>
Cc John Stultz <[email protected]>
Cc Xunlei Pang <[email protected]>
Cc Thomas Gleixner <[email protected]>
Cc Baolin Wang <[email protected]>
Cc Andrew Morton <[email protected]>
Cc Greg Kroah-Hartman <[email protected]>
Cc Petr Mladek <[email protected]>
Cc Tejun Heo <[email protected]>
Cc Peter Hurley <[email protected]>
Cc Vasily Averin <[email protected]>
Cc Joe Perches <[email protected]>
Signed-off-by Prarit Bhargava <[email protected]>

Prarit Bhargava (2):
lib, switch CONFIG_PRINTK_TIME to int printk, allow different timestamps for printk.time

 Documentation/kernel-parameters.txt                |  6 +-
 arch/arm/configs/axm55xx_defconfig                 |  2 +-
 arch/arm/configs/bcm2835_defconfig                 |  2 +-
 arch/arm/configs/bcm_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/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/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/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/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/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/generic_kc705_defconfig        |  2 +-
 arch/xtensa/configs/nommu_kc705_defconfig          |  2 +-
 arch/xtensa/configs/smp_lx200_defconfig            |  2 +-
 include/linux/timekeeping.h                        |  1 +
 kernel/printk/printk.c                             | 76 ++++++++++++++++++++--
 kernel/time/timekeeping.c                          | 13 ++++
 lib/Kconfig.debug                                  |  8 ++-
 .../selftests/rcutorture/configs/lock/CFcommon     |  2 +-
 .../selftests/rcutorture/configs/rcu/CFcommon      |  2 +-
 86 files changed, 177 insertions(+), 89 deletions(-)
Signature · 1 line
1.8.3.1
author
#1 lore raw

PATCH v6 1/2 lib, switch CONFIG_PRINTK_TIME to int

CONFIG_PRINTK_TIME is a bool and in order to add timestamp options for the monotonic and real time clock it must be expanded to an int.

Cc Petr Mladek <[email protected]>
Cc John Stultz <[email protected]>
Cc Xunlei Pang <[email protected]>
Cc Thomas Gleixner <[email protected]>
Cc Baolin Wang <[email protected]>
Cc Andrew Morton <[email protected]>
Cc Greg Kroah-Hartman <[email protected]>
Cc Petr Mladek <[email protected]>
Cc Tejun Heo <[email protected]>
Cc Peter Hurley <[email protected]>
Cc Vasily Averin <[email protected]>
Cc Joe Perches <[email protected]>
Signed-off-by Prarit Bhargava <[email protected]>
---
 Documentation/kernel-parameters.txt                |  2 +-
 arch/arm/configs/axm55xx_defconfig                 |  2 +-
 arch/arm/configs/bcm2835_defconfig                 |  2 +-
 arch/arm/configs/bcm_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/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/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/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/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/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/generic_kc705_defconfig        |  2 +-
 arch/xtensa/configs/nommu_kc705_defconfig          |  2 +-
 arch/xtensa/configs/smp_lx200_defconfig            |  2 +-
 kernel/printk/printk.c                             | 41 ++++++++++++++++++++--
 lib/Kconfig.debug                                  |  7 ++--
 .../selftests/rcutorture/configs/lock/CFcommon     |  2 +-
 .../selftests/rcutorture/configs/rcu/CFcommon      |  2 +-
 84 files changed, 126 insertions(+), 86 deletions(-)
Documentation/kernel-parameters.txt +1 -1
index 9a53c92..a86642c 100644
@@ -3066,7 +3066,7 @@ bytes respectively. Such letter suffixes can also be entirely omitted.
 			default: disabled
 
 	printk.time=	Show timing data prefixed to each printk message line
-			Format: <bool>  (1/Y/y=enable, 0/N/n=disable)
+			Format: <string>  (1/Y/y=enable, 0/N/n=disable)
 
 	processor.max_cstate=	[HW,ACPI]
 			Limit processor to maximum C-state
arch/arm/configs/axm55xx_defconfig +1 -1
index d3260d7..55eba35 100644
@@ -232,7 +232,7 @@ CONFIG_NFS_FSCACHE=y
 CONFIG_SUNRPC_DEBUG=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_FS=y
 CONFIG_MAGIC_SYSRQ=y
arch/arm/configs/bcm2835_defconfig +1 -1
index 72def20..6b7e08f 100644
@@ -126,7 +126,7 @@ CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ASCII=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_BOOT_PRINTK_DELAY=y
 CONFIG_DYNAMIC_DEBUG=y
 CONFIG_DEBUG_INFO=y
arch/arm/configs/bcm_defconfig +1 -1
index 7117662..19710f4 100644
@@ -121,7 +121,7 @@ CONFIG_CONFIGFS_FS=y
 # CONFIG_MISC_FILESYSTEMS is not set
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_FS=y
 CONFIG_MAGIC_SYSRQ=y
arch/arm/configs/colibri_pxa270_defconfig +1 -1
index 18c311a..ddbba8e 100644
@@ -156,7 +156,7 @@ CONFIG_NLS_ASCII=y
 CONFIG_NLS_ISO8859_1=m
 CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_UTF8=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_FS=y
 CONFIG_DEBUG_KERNEL=y
arch/arm/configs/colibri_pxa300_defconfig +1 -1
index be02fe2..3a0b92b 100644
@@ -58,7 +58,7 @@ CONFIG_INOTIFY=y
 CONFIG_NFS_FS=y
 CONFIG_NFS_V3=y
 CONFIG_ROOT_NFS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_KERNEL=y
 CONFIG_DEBUG_INFO=y
 # CONFIG_RCU_CPU_STALL_DETECTOR is not set
arch/arm/configs/dove_defconfig +1 -1
index 701677f..d952d3d 100644
@@ -119,7 +119,7 @@ CONFIG_NLS_CODEPAGE_850=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_ISO8859_2=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_FS=y
 # CONFIG_SCHED_DEBUG is not set
arch/arm/configs/efm32_defconfig +1 -1
index c0dac0f0f..306d156 100644
@@ -93,7 +93,7 @@ CONFIG_EXT2_FS=y
 CONFIG_ROMFS_FS=y
 CONFIG_ROMFS_BACKED_BY_MTD=y
 # CONFIG_NETWORK_FILESYSTEMS is not set
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 # CONFIG_ENABLE_MUST_CHECK is not set
arch/arm/configs/exynos_defconfig +1 -1
index 24dcd2b..59b91c0 100644
@@ -228,7 +228,7 @@ CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ASCII=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_FS=y
 CONFIG_MAGIC_SYSRQ=y
arch/arm/configs/ezx_defconfig +1 -1
index ea316c4..c4bdecd 100644
@@ -379,7 +379,7 @@ CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_KOI8_R=m
 CONFIG_NLS_KOI8_U=m
 CONFIG_NLS_UTF8=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_FS=y
 CONFIG_DEBUG_KERNEL=y
 # CONFIG_SCHED_DEBUG is not set
arch/arm/configs/h5000_defconfig +1 -1
index 37903e3..e3507cb 100644
@@ -66,7 +66,7 @@ CONFIG_TMPFS=y
 CONFIG_JFFS2_FS=y
 CONFIG_JFFS2_COMPRESSION_OPTIONS=y
 # CONFIG_NETWORK_FILESYSTEMS is not set
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_KERNEL=y
 # CONFIG_SCHED_DEBUG is not set
 # CONFIG_DEBUG_BUGVERBOSE is not set
arch/arm/configs/hisi_defconfig +1 -1
index b2e340b..4dc0a4a 100644
@@ -82,7 +82,7 @@ CONFIG_NFS_FS=y
 CONFIG_NFS_V3_ACL=y
 CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_FS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
arch/arm/configs/imote2_defconfig +1 -1
index 18e59fe..672010d 100644
@@ -350,7 +350,7 @@ CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_KOI8_R=m
 CONFIG_NLS_KOI8_U=m
 CONFIG_NLS_UTF8=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_FS=y
 CONFIG_DEBUG_KERNEL=y
 # CONFIG_SCHED_DEBUG is not set
arch/arm/configs/imx_v6_v7_defconfig +1 -1
index 2d5253d..65b8d66 100644
@@ -354,7 +354,7 @@ CONFIG_NLS_ASCII=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_FS=y
 CONFIG_MAGIC_SYSRQ=y
 # CONFIG_SCHED_DEBUG is not set
arch/arm/configs/keystone_defconfig +1 -1
index 5bcc9cf..d402c59 100644
@@ -195,7 +195,7 @@ CONFIG_NFSD_V3=y
 CONFIG_NFSD_V3_ACL=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_SHIRQ=y
 CONFIG_DEBUG_USER=y
arch/arm/configs/lpc18xx_defconfig +1 -1
index 2ae00b0..c25ff23 100644
@@ -159,7 +159,7 @@ CONFIG_EXT2_FS=y
 # CONFIG_INOTIFY_USER is not set
 CONFIG_JFFS2_FS=y
 # CONFIG_NETWORK_FILESYSTEMS is not set
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 # CONFIG_ENABLE_MUST_CHECK is not set
arch/arm/configs/magician_defconfig +1 -1
index a5b4920..accbf10 100644
@@ -167,7 +167,7 @@ CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_CODEPAGE_1251=m
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_KERNEL=y
 # CONFIG_SCHED_DEBUG is not set
 CONFIG_TIMER_STATS=y
arch/arm/configs/mmp2_defconfig +1 -1
index f1cb95e..0385e4a 100644
@@ -81,7 +81,7 @@ CONFIG_NFS_V3=y
 CONFIG_NFS_V3_ACL=y
 CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_FS=y
 CONFIG_DEBUG_KERNEL=y
arch/arm/configs/moxart_defconfig +1 -1
index a3cb76c..32fab5a 100644
@@ -124,7 +124,7 @@ CONFIG_EXT3_FS=y
 CONFIG_TMPFS=y
 CONFIG_CONFIGFS_FS=y
 CONFIG_JFFS2_FS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 # CONFIG_ENABLE_MUST_CHECK is not set
arch/arm/configs/multi_v7_defconfig +1 -1
index 8e8b2ac..238f730 100644
@@ -798,7 +798,7 @@ CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_FS=y
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_LOCKUP_DETECTOR=y
arch/arm/configs/mvebu_v7_defconfig +1 -1
index c6729bf..19465c3 100644
@@ -145,7 +145,7 @@ CONFIG_NLS_CODEPAGE_850=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_ISO8859_2=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_FS=y
 CONFIG_MAGIC_SYSRQ=y
arch/arm/configs/mxs_defconfig +1 -1
index b47e7c6..21738c9 100644
@@ -166,7 +166,7 @@ CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_CODEPAGE_850=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_ISO8859_15=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_FRAME_WARN=2048
 CONFIG_UNUSED_SYMBOLS=y
arch/arm/configs/omap2plus_defconfig +1 -1
index d18d6b4..fa7c950 100644
@@ -454,7 +454,7 @@ CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_INFO_SPLIT=y
 CONFIG_DEBUG_INFO_DWARF4=y
arch/arm/configs/pxa168_defconfig +1 -1
index 74d7e01..5824b89 100644
@@ -57,7 +57,7 @@ CONFIG_NFS_V3=y
 CONFIG_NFS_V3_ACL=y
 CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_KERNEL=y
 # CONFIG_DEBUG_PREEMPT is not set
arch/arm/configs/pxa3xx_defconfig +1 -1
index 5f337d7..e60d656 100644
@@ -117,7 +117,7 @@ CONFIG_NFS_V3_ACL=y
 CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
 CONFIG_NLS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_KERNEL=y
 CONFIG_DEBUG_SHIRQ=y
arch/arm/configs/pxa910_defconfig +1 -1
index 3bb7771..a2f6f08 100644
@@ -65,7 +65,7 @@ CONFIG_NFS_V3=y
 CONFIG_NFS_V3_ACL=y
 CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_KERNEL=y
 # CONFIG_DEBUG_PREEMPT is not set
arch/arm/configs/pxa_defconfig +1 -1
index 0cb724b..2ff6cb2 100644
@@ -733,7 +733,7 @@ CONFIG_NLS_ASCII=m
 CONFIG_NLS_ISO8859_1=m
 CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_UTF8=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DYNAMIC_DEBUG=y
 CONFIG_DEBUG_INFO=y
 CONFIG_FRAME_WARN=0
arch/arm/configs/qcom_defconfig +1 -1
index 7bff7bf..5dfac70 100644
@@ -181,7 +181,7 @@ CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ASCII=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DYNAMIC_DEBUG=y
 CONFIG_DEBUG_INFO=y
 CONFIG_MAGIC_SYSRQ=y
arch/arm/configs/raumfeld_defconfig +1 -1
index 3d833ae..b836f8f 100644
@@ -196,7 +196,7 @@ CONFIG_NLS_ISO8859_15=y
 CONFIG_NLS_KOI8_R=y
 CONFIG_NLS_KOI8_U=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_KERNEL=y
 CONFIG_DEBUG_INFO=y
 # CONFIG_RCU_CPU_STALL_DETECTOR is not set
arch/arm/configs/shmobile_defconfig +1 -1
index 9697383..5acb1a9 100644
@@ -206,7 +206,7 @@ CONFIG_NFS_V4_1=y
 CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 # CONFIG_ENABLE_MUST_CHECK is not set
 # CONFIG_ARM_UNWIND is not set
arch/arm/configs/socfpga_defconfig +1 -1
index f7f4e2e..1d42a0b 100644
@@ -100,7 +100,7 @@ CONFIG_NFS_FS=y
 CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DETECT_HUNG_TASK=y
arch/arm/configs/stm32_defconfig +1 -1
index ec52505..b78037d 100644
@@ -60,7 +60,7 @@ CONFIG_STM32_DMA=y
 # CONFIG_DNOTIFY is not set
 # CONFIG_INOTIFY_USER is not set
 CONFIG_NLS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 # CONFIG_ENABLE_MUST_CHECK is not set
arch/arm/configs/sunxi_defconfig +1 -1
index a9a81a7..4ac923b 100644
@@ -133,6 +133,6 @@ CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_FS=y
 CONFIG_CRYPTO_DEV_SUN4I_SS=y
arch/arm/configs/tegra_defconfig +1 -1
index 3a36244..95eaa46 100644
@@ -285,7 +285,7 @@ CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_FS=y
 CONFIG_MAGIC_SYSRQ=y
arch/arm/configs/u300_defconfig +1 -1
index aaa95ab..7746006 100644
@@ -63,7 +63,7 @@ CONFIG_VFAT_FS=y
 CONFIG_TMPFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_FS=y
 # CONFIG_SCHED_DEBUG is not set
arch/arm/configs/u8500_defconfig +1 -1
index 07055ea..0c1952f 100644
@@ -126,7 +126,7 @@ CONFIG_NFS_FS=y
 CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_FS=y
 CONFIG_MAGIC_SYSRQ=y
arch/arm/configs/vt8500_v6_v7_defconfig +1 -1
index 1bfaa7b..d5a2cc8 100644
@@ -84,6 +84,6 @@ CONFIG_NFS_FS=y
 CONFIG_NFS_V3_ACL=y
 CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_KERNEL=y
 CONFIG_LOCKUP_DETECTOR=y
arch/arm/configs/xcep_defconfig +1 -1
index 721832f..5c8435d 100644
@@ -85,7 +85,7 @@ CONFIG_NFS_V3=y
 CONFIG_NLS=m
 CONFIG_NLS_DEFAULT="utf8"
 CONFIG_NLS_UTF8=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_STRIP_ASM_SYMS=y
 CONFIG_DEBUG_KERNEL=y
 # CONFIG_SCHED_DEBUG is not set
arch/arm/configs/zx_defconfig +1 -1
index ab683fb..e955730 100644
@@ -98,7 +98,7 @@ CONFIG_TMPFS_POSIX_ACL=y
 CONFIG_NLS_CODEPAGE_936=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_KERNEL=y
 CONFIG_DEBUG_INFO=y
arch/arm64/configs/defconfig +1 -1
index 86581f7..ae624bb 100644
@@ -235,7 +235,7 @@ CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_VIRTUALIZATION=y
 CONFIG_KVM=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_FS=y
 CONFIG_MAGIC_SYSRQ=y
arch/mips/configs/bcm47xx_defconfig +1 -1
index 0db4eb3..f19fb76 100644
@@ -75,7 +75,7 @@ CONFIG_USB_HCD_BCMA=y
 CONFIG_USB_HCD_SSB=y
 CONFIG_LEDS_TRIGGER_TIMER=y
 CONFIG_LEDS_TRIGGER_DEFAULT_ON=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_INFO_REDUCED=y
 CONFIG_STRIP_ASM_SYMS=y
arch/mips/configs/bmips_be_defconfig +1 -1
index 24dcb90..d065143 100644
@@ -33,7 +33,7 @@ CONFIG_DEVTMPFS=y
 CONFIG_DEVTMPFS_MOUNT=y
 # CONFIG_STANDALONE is not set
 # CONFIG_PREVENT_FIRMWARE_BUILD is not set
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_BRCMSTB_GISB_ARB=y
 CONFIG_MTD=y
 CONFIG_MTD_CFI=y
arch/mips/configs/bmips_stb_defconfig +1 -1
index 4eb5d6e..0800662 100644
@@ -34,7 +34,7 @@ CONFIG_DEVTMPFS=y
 CONFIG_DEVTMPFS_MOUNT=y
 # CONFIG_STANDALONE is not set
 # CONFIG_PREVENT_FIRMWARE_BUILD is not set
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_BRCMSTB_GISB_ARB=y
 CONFIG_MTD=y
 CONFIG_MTD_CFI=y
arch/mips/configs/ci20_defconfig +1 -1
index 4e36b6e..cd161f1 100644
@@ -144,7 +144,7 @@ CONFIG_NLS_ISO8859_15=y
 CONFIG_NLS_KOI8_R=y
 CONFIG_NLS_KOI8_U=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_STRIP_ASM_SYMS=y
 CONFIG_DEBUG_FS=y
arch/mips/configs/lemote2f_defconfig +1 -1
index 004cf52..2a76426 100644
@@ -405,7 +405,7 @@ CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_KOI8_R=m
 CONFIG_NLS_KOI8_U=m
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_FRAME_WARN=1024
 CONFIG_STRIP_ASM_SYMS=y
 CONFIG_DEBUG_FS=y
arch/mips/configs/loongson3_defconfig +1 -1
index f8bf915c..e66df9f 100644
@@ -330,7 +330,7 @@ CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_CODEPAGE_936=y
 CONFIG_NLS_ASCII=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_FRAME_WARN=1024
 CONFIG_STRIP_ASM_SYMS=y
 CONFIG_MAGIC_SYSRQ=y
arch/mips/configs/nlm_xlp_defconfig +1 -1
index b3d1d37..efd6877 100644
@@ -554,7 +554,7 @@ CONFIG_NLS_ISO8859_14=m
 CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_KOI8_R=m
 CONFIG_NLS_KOI8_U=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 # CONFIG_ENABLE_MUST_CHECK is not set
 CONFIG_FRAME_WARN=1024
arch/mips/configs/nlm_xlr_defconfig +1 -1
index 3d8016d..c913c70 100644
@@ -514,7 +514,7 @@ CONFIG_NLS_ISO8859_14=m
 CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_KOI8_R=m
 CONFIG_NLS_KOI8_U=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 # CONFIG_ENABLE_MUST_CHECK is not set
 CONFIG_UNUSED_SYMBOLS=y
arch/mips/configs/pistachio_defconfig +1 -1
index 8b74291..022907e 100644
@@ -299,7 +299,7 @@ CONFIG_NLS_DEFAULT="utf8"
 CONFIG_NLS_CODEPAGE_437=m
 CONFIG_NLS_ASCII=m
 CONFIG_NLS_ISO8859_1=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_MAGIC_SYSRQ_DEFAULT_ENABLE=0
arch/mips/configs/qi_lb60_defconfig +1 -1
index d7bb8cc..e9dd20a 100644
@@ -172,7 +172,7 @@ CONFIG_NLS_ISO8859_15=y
 CONFIG_NLS_KOI8_R=y
 CONFIG_NLS_KOI8_U=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_STRIP_ASM_SYMS=y
 CONFIG_READABLE_ASM=y
arch/mips/configs/rt305x_defconfig +1 -1
index d14ae2f..005754c 100644
@@ -145,7 +145,7 @@ CONFIG_JFFS2_COMPRESSION_OPTIONS=y
 CONFIG_SQUASHFS=y
 # CONFIG_SQUASHFS_ZLIB is not set
 CONFIG_SQUASHFS_XZ=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_MUST_CHECK is not set
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_STRIP_ASM_SYMS=y
arch/mips/configs/xway_defconfig +1 -1
index 8987846..c293c78 100644
@@ -143,7 +143,7 @@ CONFIG_JFFS2_COMPRESSION_OPTIONS=y
 CONFIG_SQUASHFS=y
 # CONFIG_SQUASHFS_ZLIB is not set
 CONFIG_SQUASHFS_XZ=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_MUST_CHECK is not set
 CONFIG_STRIP_ASM_SYMS=y
 CONFIG_DEBUG_FS=y
arch/parisc/configs/generic-64bit_defconfig +1 -1
index e945c08..df76193 100644
@@ -279,7 +279,7 @@ CONFIG_NLS_ASCII=m
 CONFIG_NLS_ISO8859_1=m
 CONFIG_NLS_ISO8859_2=m
 CONFIG_NLS_UTF8=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_STRIP_ASM_SYMS=y
 CONFIG_UNUSED_SYMBOLS=y
 CONFIG_DEBUG_FS=y
arch/powerpc/configs/40x/virtex_defconfig +1 -1
index bcb0c4d..bb076ef 100644
@@ -72,7 +72,7 @@ CONFIG_CRC_CCITT=y
 CONFIG_FONTS=y
 CONFIG_FONT_8x8=y
 CONFIG_FONT_8x16=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_KERNEL=y
 # CONFIG_CRYPTO_ANSI_CPRNG is not set
arch/powerpc/configs/44x/virtex5_defconfig +1 -1
index 53d0300..f5cf657 100644
@@ -71,7 +71,7 @@ CONFIG_CRC_CCITT=y
 CONFIG_FONTS=y
 CONFIG_FONT_8x8=y
 CONFIG_FONT_8x16=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_KERNEL=y
 # CONFIG_CRYPTO_ANSI_CPRNG is not set
arch/powerpc/configs/44x/warp_defconfig +1 -1
index ee43437..e925959 100644
@@ -93,7 +93,7 @@ CONFIG_NLS_ISO8859_15=y
 CONFIG_NLS_UTF8=y
 CONFIG_CRC_CCITT=y
 CONFIG_CRC_T10DIF=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_FS=y
 CONFIG_MAGIC_SYSRQ=y
arch/powerpc/configs/52xx/cm5200_defconfig +1 -1
index 19fad0e..3cc0a427 100644
@@ -74,7 +74,7 @@ CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DETECT_HUNG_TASK=y
 # CONFIG_DEBUG_BUGVERBOSE is not set
 CONFIG_CRYPTO_ECB=y
arch/powerpc/configs/52xx/lite5200b_defconfig +1 -1
index 5f40ba9..5a24f60 100644
@@ -60,7 +60,7 @@ CONFIG_TMPFS=y
 CONFIG_NFS_FS=y
 CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DETECT_HUNG_TASK=y
 # CONFIG_DEBUG_BUGVERBOSE is not set
arch/powerpc/configs/52xx/motionpro_defconfig +1 -1
index 909e185..e7ef6c8 100644
@@ -86,7 +86,7 @@ CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DETECT_HUNG_TASK=y
 # CONFIG_DEBUG_BUGVERBOSE is not set
arch/powerpc/configs/52xx/tqm5200_defconfig +1 -1
index efab838..5a91b50 100644
@@ -88,7 +88,7 @@ CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DETECT_HUNG_TASK=y
 # CONFIG_DEBUG_BUGVERBOSE is not set
arch/powerpc/configs/gamecube_defconfig +1 -1
index 6c6c60f..d4dbe36 100644
@@ -92,7 +92,7 @@ CONFIG_CIFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_CRC_CCITT=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_SPINLOCK=y
 CONFIG_DEBUG_MUTEXES=y
 CONFIG_LATENCYTOP=y
arch/powerpc/configs/mpc5200_defconfig +1 -1
index 9fd041b..4b7dc33 100644
@@ -128,7 +128,7 @@ CONFIG_NFS_V4=y
 CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_KERNEL=y
 CONFIG_DETECT_HUNG_TASK=y
arch/powerpc/configs/pasemi_defconfig +1 -1
index 8f94782..b025444 100644
@@ -171,7 +171,7 @@ CONFIG_NFSD_V4=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_CRC_CCITT=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_FS=y
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_KERNEL=y
arch/powerpc/configs/wii_defconfig +1 -1
index 34eaf52..2d9ee18 100644
@@ -113,7 +113,7 @@ CONFIG_CIFS=m
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_CRC_CCITT=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_SPINLOCK=y
 CONFIG_DEBUG_MUTEXES=y
arch/s390/configs/default_defconfig +1 -1
index 0ac42cc..5e3e73e 100644
@@ -534,7 +534,7 @@ CONFIG_NLS_ISO8859_1=m
 CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_UTF8=m
 CONFIG_DLM=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DYNAMIC_DEBUG=y
 CONFIG_DEBUG_INFO=y
 CONFIG_FRAME_WARN=1024
arch/s390/configs/gcov_defconfig +1 -1
index a31dcd5..aedc828 100644
@@ -528,7 +528,7 @@ CONFIG_NLS_ISO8859_1=m
 CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_UTF8=m
 CONFIG_DLM=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 # CONFIG_ENABLE_MUST_CHECK is not set
 CONFIG_FRAME_WARN=1024
arch/s390/configs/performance_defconfig +1 -1
index 7b73bf3..b5e9dc1 100644
@@ -528,7 +528,7 @@ CONFIG_NLS_ISO8859_1=m
 CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_UTF8=m
 CONFIG_DLM=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 # CONFIG_ENABLE_MUST_CHECK is not set
 CONFIG_FRAME_WARN=1024
arch/s390/configs/zfcpdump_defconfig +1 -1
index 1719843..ef2a9b6 100644
@@ -56,7 +56,7 @@ CONFIG_RAW_DRIVER=y
 # CONFIG_INOTIFY_USER is not set
 CONFIG_CONFIGFS_FS=y
 # CONFIG_MISC_FILESYSTEMS is not set
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DEBUG_INFO=y
 CONFIG_DEBUG_FS=y
 CONFIG_DEBUG_KERNEL=y
arch/sh/configs/edosk7760_defconfig +1 -1
index e1077a0..e588da2 100644
@@ -109,7 +109,7 @@ CONFIG_NLS_ASCII=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_ISO8859_15=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_MUST_CHECK is not set
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_UNUSED_SYMBOLS=y
arch/sh/configs/sdk7786_defconfig +1 -1
index e7e56a4..2e12997 100644
@@ -216,7 +216,7 @@ CONFIG_NLS_ASCII=m
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_ISO8859_15=m
 CONFIG_NLS_UTF8=m
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 # CONFIG_ENABLE_MUST_CHECK is not set
 CONFIG_MAGIC_SYSRQ=y
arch/sh/configs/se7722_defconfig +1 -1
index ae998c7..09aac57 100644
@@ -53,7 +53,7 @@ CONFIG_EXT3_FS=y
 CONFIG_PROC_KCORE=y
 CONFIG_TMPFS=y
 CONFIG_HUGETLBFS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_MUST_CHECK is not set
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_FS=y
arch/sh/configs/sh7785lcr_32bit_defconfig +1 -1
index 9bdcf72..bdb7783 100644
@@ -144,7 +144,7 @@ CONFIG_NFSD_V3=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_CODEPAGE_932=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_MUST_CHECK is not set
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_KERNEL=y
arch/sh/configs/urquell_defconfig +1 -1
index 1e843db..795afb5 100644
@@ -143,7 +143,7 @@ CONFIG_ROOT_NFS=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_CODEPAGE_932=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 # CONFIG_ENABLE_MUST_CHECK is not set
 CONFIG_DEBUG_FS=y
arch/sparc/configs/sparc64_defconfig +1 -1
index 6b68f12..0ef3f30 100644
@@ -202,7 +202,7 @@ CONFIG_EXT3_FS_SECURITY=y
 CONFIG_PROC_KCORE=y
 CONFIG_TMPFS=y
 CONFIG_HUGETLBFS=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 CONFIG_MAGIC_SYSRQ=y
 CONFIG_DEBUG_KERNEL=y
arch/x86/configs/i386_defconfig +1 -1
index 028be48..f6ba6ca 100644
@@ -286,7 +286,7 @@ CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ASCII=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 CONFIG_FRAME_WARN=2048
 CONFIG_MAGIC_SYSRQ=y
arch/x86/configs/x86_64_defconfig +1 -1
index cb5b3ab..9f40186 100644
@@ -284,7 +284,7 @@ CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ASCII=y
 CONFIG_NLS_ISO8859_1=y
 CONFIG_NLS_UTF8=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 # CONFIG_ENABLE_WARN_DEPRECATED is not set
 CONFIG_MAGIC_SYSRQ=y
 # CONFIG_UNUSED_SYMBOLS is not set
arch/xtensa/configs/audio_kc705_defconfig +1 -1
index c4904db..bc0e69f 100644
@@ -123,7 +123,7 @@ CONFIG_ROOT_NFS=y
 CONFIG_SUNRPC_DEBUG=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DYNAMIC_DEBUG=y
 CONFIG_DEBUG_INFO=y
 CONFIG_MAGIC_SYSRQ=y
arch/xtensa/configs/generic_kc705_defconfig +1 -1
index f4b7b38..6adabfa 100644
@@ -111,7 +111,7 @@ CONFIG_ROOT_NFS=y
 CONFIG_SUNRPC_DEBUG=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DYNAMIC_DEBUG=y
 CONFIG_DEBUG_INFO=y
 CONFIG_MAGIC_SYSRQ=y
arch/xtensa/configs/nommu_kc705_defconfig +1 -1
index 337d5ba..0727336 100644
@@ -107,7 +107,7 @@ CONFIG_ROOT_NFS=y
 CONFIG_SUNRPC_DEBUG=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DYNAMIC_DEBUG=y
 CONFIG_DEBUG_INFO=y
 # CONFIG_FRAME_POINTER is not set
arch/xtensa/configs/smp_lx200_defconfig +1 -1
index 22eeacb..fb09f54 100644
@@ -115,7 +115,7 @@ CONFIG_ROOT_NFS=y
 CONFIG_SUNRPC_DEBUG=y
 CONFIG_NLS_CODEPAGE_437=y
 CONFIG_NLS_ISO8859_1=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_DYNAMIC_DEBUG=y
 CONFIG_DEBUG_INFO=y
 CONFIG_MAGIC_SYSRQ=y
kernel/printk/printk.c +39 -2

47 lines not on this page · raw message

lib/Kconfig.debug +5 -2
index 8bfd1ac..d0caf14 100644
@@ -1,7 +1,9 @@
 menu "printk and dmesg options"
 
 config PRINTK_TIME
-	bool "Show timing information on printks"
+	int "Show timing information on printks (0-1)"
+	range 0 1
+	default "0"
 	depends on PRINTK
 	help
 	  Selecting this option causes time stamps of the printk()

@@ -10,7 +12,8 @@ config PRINTK_TIME
 
 	  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.
+	  be included, not that the timestamp is recorded. 0 disables the
+	  timestamp and 1 uses the local clock.
 
 	  The behavior is also controlled by the kernel command line
 	  parameter printk.time=1. See Documentation/kernel-parameters.txt
tools/testing/selftests/rcutorture/configs/lock/CFcommon +1 -1
index e372dc2..779f984 100644
@@ -1,2 +1,2 @@
 CONFIG_LOCK_TORTURE_TEST=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
tools/testing/selftests/rcutorture/configs/rcu/CFcommon +1 -1
index f824b4c..7461db3 100644
@@ -1,5 +1,5 @@
 CONFIG_RCU_TORTURE_TEST=y
-CONFIG_PRINTK_TIME=y
+CONFIG_PRINTK_TIME=1
 CONFIG_RCU_TORTURE_TEST_SLOW_CLEANUP=y
 CONFIG_RCU_TORTURE_TEST_SLOW_INIT=y
 CONFIG_RCU_TORTURE_TEST_SLOW_PREINIT=y
Signature · 1 line
1.8.3.1
author
#2 lore raw

PATCH v6 2/2 printk, allow different timestamps for printk.time

In reply to Prarit Bhargava

Over the past years I've seen many reports of bugs that include time-stamped kernel logs (enabled when CONFIG_PRINTK_TIME=y or print.time=1 is specified as a kernel parameter) that do not align with either external time stamped logs or /var/log/messages. This also makes determining the time of a failure difficult in cases where /var/log/messages is unavailable.

For example,

[root@intel-wildcatpass-06 ~]# date; echo "Hello!" > /dev/kmsg ; date Thu Dec 17 13:58:31 EST 2015
Thu Dec 17 13:58:31 EST 2015

which displays

[83973.768912] Hello!

on the serial console.

Running a script to convert this to the stamped time,

[root@intel-wildcatpass-06 ~]# ./human.sh | tail -1

[Thu Dec 17 13:59:57 2015] Hello!

which is already off by 1 minute and 26 seconds off after ~24 hours of uptime.

This occurs because the time stamp is obtained from a call to local_clock() which (on x86) is a direct call to the hardware. These hardware clock reads are not modified by the standard ntp or ptp protocol, while the other timestamps are, and that results in situations external time sources are further and further offset from the kernel log timestamps.

This patch introduces printk.time=[0-3] allowing a user to specify an adjusted clock to use with printk timestamps. The hardware clock, or the existing functionality, is preserved by default.

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 NMI safe timekeeping access functions
[v3]: use tglx's ktime_get_log_ts() suggestion to get monotonic & real clocks [v4]: Fix kernel parameters
[v5]: Modify configs to accept [0-3]
[v6]: Implement Kconfig changes from Petr Mladek, fix CONFIG_PRINTK_TIME=0 and dmesg bug

Cc Cc: Petr Mladek <[email protected]>
Cc John Stultz <[email protected]>
Cc Xunlei Pang <[email protected]>
Cc Thomas Gleixner <[email protected]>
Cc Baolin Wang <[email protected]>
Cc Andrew Morton <[email protected]>
Cc Greg Kroah-Hartman <[email protected]>
Cc Petr Mladek <[email protected]>
Cc Tejun Heo <[email protected]>
Cc Peter Hurley <[email protected]>
Cc Vasily Averin <[email protected]>
Cc Joe Perches <[email protected]>
Signed-off-by Prarit Bhargava <[email protected]>
---
 Documentation/kernel-parameters.txt |  6 ++++--
 include/linux/timekeeping.h         |  1 +
 kernel/printk/printk.c              | 35 +++++++++++++++++++++++++++++++++--
 kernel/time/timekeeping.c           | 13 +++++++++++++
 lib/Kconfig.debug                   |  7 ++++---
 5 files changed, 55 insertions(+), 7 deletions(-)
Documentation/kernel-parameters.txt +4 -2
index a86642c..92e9076 100644
@@ -3065,8 +3065,10 @@ bytes respectively. Such letter suffixes can also be entirely omitted.
 			Format: <bool>  (1/Y/y=enable, 0/N/n=disable)
 			default: disabled
 
-	printk.time=	Show timing data prefixed to each printk message line
-			Format: <string>  (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 clock,
+				2 = monotonic clock, 3 = real clock)
 
 	processor.max_cstate=	[HW,ACPI]
 			Limit processor to maximum C-state
include/linux/timekeeping.h +1 -0
index ec89d84..0b99a84 100644
@@ -233,6 +233,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_log_ts(u64 *offset_real);
 
 /*
  * Timespec interfaces utilizing the ktime based ones
kernel/printk/printk.c +33 -2
index 1f4a29b..dfe9ab0 100644
@@ -420,6 +420,8 @@ 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_ts(void);
+
 /* 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,

@@ -468,7 +470,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;
 

@@ -1037,6 +1039,12 @@ static inline void boot_delay_msec(int level)
 
 static int printk_time = CONFIG_PRINTK_TIME;
 
+/*
+ * 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() below.
+ */
 static int printk_time_param_set(const char *val,
 				 const struct kernel_param *kp)
 {

@@ -1058,6 +1066,14 @@ static int printk_time_param_set(const char *val,
 	case 'y':
 		printk_time = 1;
 		break;
+	/* 2 = monotonic clock */
+	case '2':
+		printk_time = 2;
+		break;
+	/* 3 = real clock */
+	case '3':
+		printk_time = 3;
+		break;
 	default:
 		pr_warn("printk: invalid timestamp value\n");
 		return -EINVAL;

@@ -1075,6 +1091,21 @@ static struct kernel_param_ops printk_time_param_ops = {
 
 module_param_cb(time, &printk_time_param_ops, &printk_time, S_IRUGO | S_IWUSR);
 
+static u64 printk_get_ts(void)
+{
+	u64 mono, offset_real;
+
+	if (printk_time <= 1)
+		return local_clock();
+
+	mono = ktime_get_log_ts(&offset_real);
+
+	if (printk_time == 2)
+		return mono;
+
+	return mono + offset_real;
+}
+
 static size_t print_time(u64 ts, char *buf)
 {
 	unsigned long rem_nsec;

@@ -1651,7 +1682,7 @@ static bool cont_add(int facility, int level, const char *text, size_t len)
 		cont.facility = facility;
 		cont.level = level;
 		cont.owner = current;
-		cont.ts_nsec = local_clock();
+		cont.ts_nsec = printk_get_ts();
 		cont.flags = 0;
 		cont.cons = 0;
 		cont.flushed = false;
kernel/time/timekeeping.c +13 -0
index 34b4ced..698e1a2 100644
@@ -43,6 +43,7 @@ static struct {
 
 static DEFINE_RAW_SPINLOCK(timekeeper_lock);
 static struct timekeeper shadow_timekeeper;
+static int timekeeping_active;
 
 /**
  * struct tk_fast - NMI safe timekeeper

@@ -401,6 +402,16 @@ u64 ktime_get_raw_fast_ns(void)
 }
 EXPORT_SYMBOL_GPL(ktime_get_raw_fast_ns);
 
+u64 ktime_get_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();
+}
+
 /* Suspend-time cycles value for halted fast timekeeper. */
 static cycle_t cycles_at_suspend;
 

@@ -1267,6 +1278,8 @@ void __init timekeeping_init(void)
 
 	write_seqcount_end(&tk_core.seq);
 	raw_spin_unlock_irqrestore(&timekeeper_lock, flags);
+
+	timekeeping_active = 1;
 }
 
 /* time in seconds when suspend began for persistent clock */
lib/Kconfig.debug +4 -3
index d0caf14..cb2598f 100644
@@ -1,8 +1,8 @@
 menu "printk and dmesg options"
 
 config PRINTK_TIME
-	int "Show timing information on printks (0-1)"
-	range 0 1
+	int "Show timing information on printks (0-3)"
+	range 0 3
 	default "0"
 	depends on PRINTK
 	help

@@ -13,7 +13,8 @@ config PRINTK_TIME
 	  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. 0 disables the
-	  timestamp and 1 uses the local clock.
+	  timestamp and 1 uses the local clock, 2 uses the monotonic clock, and
+	  3 uses real clock.
 
 	  The behavior is also controlled by the kernel command line
 	  parameter printk.time=1. See Documentation/kernel-parameters.txt
Signature · 1 line
1.8.3.1
#3 lore raw
In reply to Prarit Bhargava
Quoted 6 lines · Prarit Bhargava

This patchset adds monotonic and real printk timestamps. The first patch changes CONFIG_PRINT_TIME from a bool to an int to allow for the additional timestamps that are added in patch 2.

Changes from v6: Petr Mladek pointed out that the current patch fails to indicate to userspace programs which timestamp is being used.

How is that solved?

Thanks,

tglx

author
#4 lore raw
Quoted 10 lines · Thomas Gleixner
Quoted 6 lines · Prarit Bhargava

This patchset adds monotonic and real printk timestamps. The first patch changes CONFIG_PRINT_TIME from a bool to an int to allow for the additional timestamps that are added in patch 2.

Changes from v6: Petr Mladek pointed out that the current patch fails to indicate to userspace programs which timestamp is being used.

How is that solved?

Hi Thomas,

Userspace programs can now look at /sys/modules/printk/parameters/time which will contain [0-3] for the timestamp clock.

The file is globally readable so it shouldn't cause any problems for userspace programs:

[root@intel-wildcatpass-06 dummy-module]# ls -l /sys/module/printk/parameters/time -rw-r--r--. 1 root root 4096 Mar 8 06:01 /sys/module/printk/parameters/time

P.

Quoted 5 lines

Thanks,

tglx

maintainer
#5 lore raw
Quoted 12 lines · Prarit Bhargava
Quoted 9 lines · Thomas Gleixner
Quoted 6 lines · Prarit Bhargava

This patchset adds monotonic and real printk timestamps. The first patch changes CONFIG_PRINT_TIME from a bool to an int to allow for the additional timestamps that are added in patch 2.

Changes from v6: Petr Mladek pointed out that the current patch fails to indicate to userspace programs which timestamp is being used.

Quoted 6 lines
Quoted 1 line

How is that solved?

Hi Thomas,

Userspace programs can now look at /sys/modules/printk/parameters/time which will contain [0-3] for the timestamp clock.

But it includes only the current setting that is valid only for messages printed with this setting. The ring buffer might include different messages produced with different setting.

I suggest to look how dmesg handles the time stamp. I wonder how it converts the relative time into an absolute one. I wonder if you could convert all timestamps to the relative format, so that you do not need to change all userspace tools at all.

Best regards,
Petr

#6 lore raw
Quoted 20 lines · Petr Mladek
Quoted 12 lines · Prarit Bhargava
Quoted 9 lines · Thomas Gleixner
Quoted 6 lines · Prarit Bhargava

This patchset adds monotonic and real printk timestamps. The first patch changes CONFIG_PRINT_TIME from a bool to an int to allow for the additional timestamps that are added in patch 2.

Changes from v6: Petr Mladek pointed out that the current patch fails to indicate to userspace programs which timestamp is being used.

Quoted 6 lines
Quoted 1 line

How is that solved?

Hi Thomas,

Userspace programs can now look at /sys/modules/printk/parameters/time which will contain [0-3] for the timestamp clock.

Quoted 8 lines

But it includes only the current setting that is valid only for messages printed with this setting. The ring buffer might include different messages produced with different setting.

I suggest to look how dmesg handles the time stamp. I wonder how it converts the relative time into an absolute one. I wonder if you could convert all timestamps to the relative format, so that you do not need to change all userspace tools at all.

ctime = system_boot_time + dmesg_stamp

The reason why you see wrong values here is that dmesg_stamp is not based on clock monotonic. So if printk uses clock monotonic, dmesg does not have to be changed.

Though you have to know, that the above is a linearized history because system_boot_time is

clock_monotonic_now() + boot_offset

So you can't observe stuff like leap seconds, settimeofday or other things which result in a non linear behaviour of clock realtime.

Thanks,

tglx

author
#7 lore raw
In reply to Petr Mladek
Quoted 20 lines · Petr Mladek
Quoted 12 lines · Prarit Bhargava
Quoted 9 lines · Thomas Gleixner
Quoted 6 lines · Prarit Bhargava

This patchset adds monotonic and real printk timestamps. The first patch changes CONFIG_PRINT_TIME from a bool to an int to allow for the additional timestamps that are added in patch 2.

Changes from v6: Petr Mladek pointed out that the current patch fails to indicate to userspace programs which timestamp is being used.

Quoted 6 lines
Quoted 1 line

How is that solved?

Hi Thomas,

Userspace programs can now look at /sys/modules/printk/parameters/time which will contain [0-3] for the timestamp clock.

Quoted 8 lines

But it includes only the current setting that is valid only for messages printed with this setting. The ring buffer might include different messages produced with different setting.

I suggest to look how dmesg handles the time stamp. I wonder how it converts the relative time into an absolute one. I wonder if you could convert all timestamps to the relative format, so that you do not need to change all userspace tools at all.

I looked into this and the only thing I can come up with is that I modify the patchset to allow users to set the timestamp type at boot but not runtime. Having to set it at runtime would require additional timestamp information be added to the output of /dev/kmsg.

Petr -- the dmesg code can be found in the utils-linux package, sys-utils/dmesg.c. The timestamping displaying code is this function:

static struct tm *record_localtime(struct dmesg_control *ctl,
struct dmesg_record *rec, struct tm *tm)

{
        time_t t = ctl->boot_time + rec->tv.tv_sec;
        return localtime_r(&t, tm);
}

If you have any suggestion on how to modify it, I'm more than willing to do it.
If not, then I suggest I change the code to make the timestamp RO during runtime.

P.

Quoted 4 lines

Best regards,
Petr

maintainer
#8 lore raw
Quoted 43 lines · Prarit Bhargava
Quoted 20 lines · Petr Mladek
Quoted 12 lines · Prarit Bhargava
Quoted 9 lines · Thomas Gleixner
Quoted 6 lines · Prarit Bhargava

This patchset adds monotonic and real printk timestamps. The first patch changes CONFIG_PRINT_TIME from a bool to an int to allow for the additional timestamps that are added in patch 2.

Changes from v6: Petr Mladek pointed out that the current patch fails to indicate to userspace programs which timestamp is being used.

Quoted 6 lines
Quoted 1 line

How is that solved?

Hi Thomas,

Userspace programs can now look at /sys/modules/printk/parameters/time which will contain [0-3] for the timestamp clock.

Quoted 8 lines

But it includes only the current setting that is valid only for messages printed with this setting. The ring buffer might include different messages produced with different setting.

I suggest to look how dmesg handles the time stamp. I wonder how it converts the relative time into an absolute one. I wonder if you could convert all timestamps to the relative format, so that you do not need to change all userspace tools at all.

I looked into this and the only thing I can come up with is that I modify the patchset to allow users to set the timestamp type at boot but not runtime. Having to set it at runtime would require additional timestamp information be added to the output of /dev/kmsg.

Petr -- the dmesg code can be found in the utils-linux package, sys-utils/dmesg.c. The timestamping displaying code is this function:

static struct tm *record_localtime(struct dmesg_control *ctl,
struct dmesg_record *rec, struct tm *tm)

Quoted 7 lines
{
        time_t t = ctl->boot_time + rec->tv.tv_sec;
        return localtime_r(&t, tm);
}

If you have any suggestion on how to modify it, I'm more than willing to do it.
If not, then I suggest I change the code to make the timestamp RO during runtime.

Hmm, If you allow to change the timestamp format only at boot time, it will make things easier. I just wonder if it would work correctly for early messages. For example, are there any messages printed before the real time clock is initialized? Which timestamp will they use?

Also note that you still need to modify the dmesg code. It must not add boot_time when real time timestamp is used.

And you need to modify also the other tools, e.g. crash.

Best Regards,
Petr

author
#9 lore raw
Quoted 49 lines · Petr Mladek
Quoted 48 lines · Prarit Bhargava
Quoted 20 lines · Petr Mladek
Quoted 12 lines · Prarit Bhargava
Quoted 9 lines · Thomas Gleixner
Quoted 6 lines · Prarit Bhargava

This patchset adds monotonic and real printk timestamps. The first patch changes CONFIG_PRINT_TIME from a bool to an int to allow for the additional timestamps that are added in patch 2.

Changes from v6: Petr Mladek pointed out that the current patch fails to indicate to userspace programs which timestamp is being used.

Quoted 6 lines
Quoted 1 line

How is that solved?

Hi Thomas,

Userspace programs can now look at /sys/modules/printk/parameters/time which will contain [0-3] for the timestamp clock.

Quoted 8 lines

But it includes only the current setting that is valid only for messages printed with this setting. The ring buffer might include different messages produced with different setting.

I suggest to look how dmesg handles the time stamp. I wonder how it converts the relative time into an absolute one. I wonder if you could convert all timestamps to the relative format, so that you do not need to change all userspace tools at all.

I looked into this and the only thing I can come up with is that I modify the patchset to allow users to set the timestamp type at boot but not runtime. Having to set it at runtime would require additional timestamp information be added to the output of /dev/kmsg.

Petr -- the dmesg code can be found in the utils-linux package, sys-utils/dmesg.c. The timestamping displaying code is this function:

static struct tm *record_localtime(struct dmesg_control *ctl,
struct dmesg_record *rec, struct tm *tm)

{
        time_t t = ctl->boot_time + rec->tv.tv_sec;
        return localtime_r(&t, tm);
}
Quoted 7 lines
Quoted 2 lines

If you have any suggestion on how to modify it, I'm more than willing to do it.
If not, then I suggest I change the code to make the timestamp RO during runtime.

Hmm, If you allow to change the timestamp format only at boot time, it will make things easier. I just wonder if it would work correctly for early messages. For example, are there any messages printed before the real time clock is initialized? Which timestamp will they use?

0.0000 is printed out before the clock is initialized. I'll make sure it does
the right thing.

Quoted 4 lines

Also note that you still need to modify the dmesg code. It must not add boot_time when real time timestamp is used.

Yep. It looks like the output of the ctime and iso timestamps need to be verified.

Quoted 1 line

And you need to modify also the other tools, e.g. crash.

I'm going to talk with [email protected] about this tomorrow.

P.

Quoted 5 lines

Best Regards,
Petr

author
#10 lore raw
In reply to Petr Mladek
Quoted 10 lines · Petr Mladek

On Mon 2016-04-18 11:30:52, Prarit Bhargava wrote:

Hmm, If you allow to change the timestamp format only at boot time, it will make things easier. I just wonder if it would work correctly for early messages. For example, are there any messages printed before the real time clock is initialized? Which timestamp will they use?

Also note that you still need to modify the dmesg code. It must not add boot_time when real time timestamp is used.

I've got a util-linux patch in-hand that does this (sorry for the cut-and-paste) and I've verified that ctime, delta, iso, notime and reltime all appear to work 1) without my kernel patches applied,
2) with my kernel patches applied, and 3) with printk.time=[0-3] as kernel parameters.

sys-utils/dmesg.c +30 -5
index cf93331..c49a202 100644
@@ -1194,9 +1194,31 @@ static int which_time_format(const char *optarg)
 	errx(EXIT_FAILURE, _("unknown time format: %s"), optarg);
 }
 
-#ifdef TEST_DMESG
+static int needs_boot_time(void)
+{
+	FILE *fd;
+	int ret = 1;
+	int val;
+
+	/*
+	 * Newer kernels have /sys/modules/printk/parameter/time = [0-3]
+	 * where 0 = off, 1 = local clock, 2 = boot time, and 3 = real time.
+	 * If the file isn't present it means the functionality isn't there
+	 * and the boot_time offset is needed.
+	 */
+	fd = fopen("/sys/module/printk/parameters/time", "r");
+	if (!fd)
+		return ret;
+	fscanf(fd, "%d", &val);
+	if (val == 3)
+		ret = 0;
+	fclose(fd);
+	return ret;
+}
+
 static inline int dmesg_get_boot_time(struct timeval *tv)
 {
+#ifdef TEST_DMESG
 	char *str = getenv("DMESG_TEST_BOOTIME");
 	uintmax_t sec, usec;
 

@@ -1205,12 +1227,15 @@ static inline int dmesg_get_boot_time(struct timeval *tv)
 		tv->tv_usec = usec;
 		return tv->tv_sec >= 0 && tv->tv_usec >= 0 ? 0 : -EINVAL;
 	}
+#endif
+
+	if (needs_boot_time())
+		return get_boot_time(tv);
 
-	return get_boot_time(tv);
+	tv->tv_sec = 0;
+	tv->tv_usec = 0;
+	return 0;
 }
-#else
-# define dmesg_get_boot_time	get_boot_time
-#endif
 
 int main(int argc, char *argv[])
 {
Signature · 1 line
1.8.3.1
Quoted 2 lines

And you need to modify also the other tools, e.g. crash.

I spoke with [email protected] this morning and he agrees that no change should be necessary for crash. A quick test shows that the logging mechanism (dmesg or log) works after the patches are applied and printk is in REALTIME mode.

IMO dmesg is the big one and I will modify that after I see acceptance of this patch.

P.

maintainer
#11 lore raw
Quoted 79 lines · Prarit Bhargava
Quoted 10 lines · Petr Mladek

On Mon 2016-04-18 11:30:52, Prarit Bhargava wrote:

Hmm, If you allow to change the timestamp format only at boot time, it will make things easier. I just wonder if it would work correctly for early messages. For example, are there any messages printed before the real time clock is initialized? Which timestamp will they use?

Also note that you still need to modify the dmesg code. It must not add boot_time when real time timestamp is used.

I've got a util-linux patch in-hand that does this (sorry for the cut-and-paste) and I've verified that ctime, delta, iso, notime and reltime all appear to work 1) without my kernel patches applied,
2) with my kernel patches applied, and 3) with printk.time=[0-3] as kernel parameters.

sys-utils/dmesg.c +30 -5
index cf93331..c49a202 100644
@@ -1194,9 +1194,31 @@ static int which_time_format(const char *optarg)
 	errx(EXIT_FAILURE, _("unknown time format: %s"), optarg);
 }
 
-#ifdef TEST_DMESG
+static int needs_boot_time(void)
+{
+	FILE *fd;
+	int ret = 1;
+	int val;
+
+	/*
+	 * Newer kernels have /sys/modules/printk/parameter/time = [0-3]
+	 * where 0 = off, 1 = local clock, 2 = boot time, and 3 = real time.
+	 * If the file isn't present it means the functionality isn't there
+	 * and the boot_time offset is needed.
+	 */
+	fd = fopen("/sys/module/printk/parameters/time", "r");
+	if (!fd)
+		return ret;
+	fscanf(fd, "%d", &val);
+	if (val == 3)
+		ret = 0;
+	fclose(fd);
+	return ret;
+}
+
 static inline int dmesg_get_boot_time(struct timeval *tv)
 {
+#ifdef TEST_DMESG
 	char *str = getenv("DMESG_TEST_BOOTIME");
 	uintmax_t sec, usec;
 

@@ -1205,12 +1227,15 @@ static inline int dmesg_get_boot_time(struct timeval *tv)
 		tv->tv_usec = usec;
 		return tv->tv_sec >= 0 && tv->tv_usec >= 0 ? 0 : -EINVAL;
 	}
+#endif
+
+	if (needs_boot_time())
+		return get_boot_time(tv);
 
-	return get_boot_time(tv);
+	tv->tv_sec = 0;
+	tv->tv_usec = 0;
+	return 0;
 }
-#else
-# define dmesg_get_boot_time	get_boot_time
-#endif
 
 int main(int argc, char *argv[])
 {
Signature · 1 line
1.8.3.1

This produces the following result. The time stamp jumps when the timekeeping stuf gets initialized:

dmesg

[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=4
[    0.000000] NR_IRQS:524544 nr_irqs:456 16
[1461600428.402984] Console: colour dummy device 80x25
[1461600428.402984] console [tty0] enabled

dmesg --time-format ctime

[Thu Jan  1 01:00:00 1970] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=4
[Thu Jan  1 01:00:00 1970] NR_IRQS:524544 nr_irqs:456 16
[Mon Apr 25 18:07:08 2016] Console: colour dummy device 80x25
[Mon Apr 25 18:07:08 2016] console [tty0] enabled

dmesg --time-format iso

1970-01-01T01:00:00,000000+0100 RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=4
1970-01-01T01:00:00,000000+0100 NR_IRQS:524544 nr_irqs:456 16
2016-04-25T18:07:08,402984+0200 Console: colour dummy device 80x25
2016-04-25T18:07:08,402984+0200 console [tty0] enabled

dmesg --time-format reltime

[ +0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=4 [ +0.000000] NR_IRQS:524544 nr_irqs:456 16
[Apr25 18:07] Console: colour dummy device 80x25
[ +0.000000] console [tty0] enabled

I think that it would be better to fallback to the boot time before the timekeeping stuff is initialized. It is easy to detect because the timestamp is zero.

I played with it. Please find an alternative patch below. I have got the following output with it:

dmesg

[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=4
[    0.000000] NR_IRQS:524544 nr_irqs:456 16
[1461600428.402984] Console: colour dummy device 80x25
[1461600428.402984] console [tty0] enabled

dmesg --time-format ctime

[Mon Apr 25 18:07:08 2016]      Build-time adjustment of leaf fanout to 64.
[Mon Apr 25 18:07:08 2016]      RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4.
[Mon Apr 25 18:07:08 2016] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=4
[Mon Apr 25 18:07:08 2016] NR_IRQS:524544 nr_irqs:456 16

dmesg --time-format iso

2016-04-25T18:07:08,000000+0200         Build-time adjustment of leaf fanout to 64.
2016-04-25T18:07:08,000000+0200         RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4.
2016-04-25T18:07:08,000000+0200 RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=4
2016-04-25T18:07:08,000000+0200 NR_IRQS:524544 nr_irqs:456 16

dmesg --time-format reltime

[  +0.000000]   Build-time adjustment of leaf fanout to 64.
[  +0.000000]   RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4.
[  +0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=4
[  +0.000000] NR_IRQS:524544 nr_irqs:456 16
Quoted 8 lines
Quoted 3 lines

And you need to modify also the other tools, e.g. crash.

I spoke with [email protected] this morning and he agrees that no change should be necessary for crash. A quick test shows that the logging mechanism (dmesg or log) works after the patches are applied and printk is in REALTIME mode.

I see. crash shows the timestamp value as it. It does not have the ctime or iso modes that would add the boot time.

Quoted 3 lines

IMO dmesg is the big one and I will modify that after I see acceptance of this patch.

OK, here is my alternative patch based on your one:

dmesg.c renamed from dmesg.c.orig +33 -6
@@ -170,6 +170,7 @@ struct dmesg_control {
 	struct timeval	lasttime;	/* last printed timestamp */
 	struct tm	lasttm;		/* last localtime */
 	struct timeval	boot_time;	/* system boot time */
+	int		realtime_stamp; /* using realtime stamps */
 
 	int		action;		/* SYSLOG_ACTION_* */
 	int		method;		/* DMESG_METHOD_* */

@@ -800,7 +801,13 @@ static struct tm *record_localtime(struc
 				   struct dmesg_record *rec,
 				   struct tm *tm)
 {
-	time_t t = ctl->boot_time.tv_sec + rec->tv.tv_sec;
+	time_t t = rec->tv.tv_sec;
+	/*
+	 * Use the boot time also when the real time stamp is zero. It was
+	 * generated before the timekeeping stuff was initialized.
+	 */
+	if (!ctl->realtime_stamp || !t)
+		t += ctl->boot_time.tv_sec;
 	return localtime_r(&t, tm);
 }
 

@@ -1194,9 +1201,31 @@ static int which_time_format(const char
 	errx(EXIT_FAILURE, _("unknown time format: %s"), optarg);
 }
 
-#ifdef TEST_DMESG
+static int use_realtime_stamp(void)
+{
+	FILE *fd;
+	int ret = 0;
+	int val;
+
+	/*
+	 * Newer kernels have /sys/modules/printk/parameter/time = [0-3]
+	 * where 0 = off, 1 = local clock, 2 = boot time, and 3 = real time.
+	 * If the file isn't present it means the functionality isn't there
+	 * and the boot_time offset is needed.
+	 */
+	fd = fopen("/sys/module/printk/parameters/time", "r");
+	if (!fd)
+		return 0;
+	fscanf(fd, "%d", &val);
+	if (val == 3)
+		ret = 1;
+	fclose(fd);
+	return ret;
+}
+
 static inline int dmesg_get_boot_time(struct timeval *tv)
 {
+#ifdef TEST_DMESG
 	char *str = getenv("DMESG_TEST_BOOTIME");
 	uintmax_t sec, usec;
 

@@ -1205,12 +1234,9 @@ static inline int dmesg_get_boot_time(st
 		tv->tv_usec = usec;
 		return tv->tv_sec >= 0 && tv->tv_usec >= 0 ? 0 : -EINVAL;
 	}
-
+#endif
 	return get_boot_time(tv);
 }
-#else
-# define dmesg_get_boot_time	get_boot_time
-#endif
 
 int main(int argc, char *argv[])
 {

@@ -1396,6 +1422,7 @@ int main(int argc, char *argv[])
 	if (is_timefmt(&ctl, RELTIME) ||
 	    is_timefmt(&ctl, CTIME) ||
 	    is_timefmt(&ctl, ISO8601)) {
+		ctl.realtime_stamp = use_realtime_stamp();
 		if (dmesg_get_boot_time(&ctl.boot_time) != 0)
 			ctl.time_fmt = DMESG_TIMEFTM_NONE;
 	}
Quoted 3 lines

P.