lkml.org 
[lkml]   [2017]   [Aug]   [17]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
Patches in this message
/
SubjectRe: [PATCH 2/2 v7] printk: Add monotonic, boottime, and realtime timestamps
From
Date
On 08/17/2017 06:15 AM, Prarit Bhargava wrote:
> printk.time=1/CONFIG_PRINTK_TIME=1 adds a unmodified local hardware clock
> timestamp to printk messages. The local hardware clock loses time each
> day making it difficult to determine exactly when an issue has occurred in
> the kernel log, and making it difficult to determine how kernel and
> hardware issues relate to each other in real time.
Congrats, greatly eases merges into older kernels, and has eliminated
the churn this could place on all the configured systems out there.

Sadly, one of my suggestions did not quite go the way I expected ;-}
easy to correct, and fix (I missed a spot in my original suggestion, as
code changed underfoot over the set ;-/). (see bottom)

<discussion type="maybe out of the scope for this patch">

I am not convinced that user space is entirely at a disadvantage with
this 'feature' enabled. Before interpreting it can read
/sys/module/printk/parameters/time, then sniff for the flowing content
for time breaks (watch for printk: timestamp set to <string>). Of
course, the value in 'time' is current, so it would be _wrong_ during
flow of previous content until the first time break shows up if it
really was being switched that often.

(echo local ; echo disabled ; echo boottime ; echo monotonic ; echo
realtime ; echo local ) > /sys/module/printk/parameters/time

[ 473.589169] printk: timestamp set to local
printk: timestamp set to disabled
[ 473.545384] printk: timestamp set to boottime
[ 473.549924] printk: timestamp set to monotonic
[1502957708.055265] printk: timestamp set to realtime
[ 473.612024] printk: timestamp set to local

A 'fix' would be to add a letter after the timestamp if not local. For
example:

[ 473.589169] printk: timestamp set to local
printk: timestamp set to disabled
[ 473.545384b] printk: timestamp set to boottime
[ 473.549924m] printk: timestamp set to monotonic
[1502957708.055265U] printk: timestamp set to realtime
[ 473.612024] printk: timestamp set to local

(I used U instead of r, because it is actually UTC, and did not add 'l'
because it is a long standing default)

But there would be concern over a change in time format API, so maybe it
should be relegated to a CONFIG_PRINTK_TIME_DEBUG 'feature' only to add
the timebase letters?

</discussion>

. . .

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 8817ed5ee6a3..2e3321f6604b 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1273,7 +1273,7 @@ static int printk_time_set(const char *val, const
struct kernel_param *kp)

if (printk_time_source == PRINTK_TIME_UNDEFINED)
printk_time_source = _printk_time;
-#ifndef PRINTK_TIME_DEBUG
+#ifndef CONFIG_PRINTK_TIME_DEBUG
else if ((printk_time_source != _printk_time) &&
(_printk_time != PRINTK_TIME_DISABLE)) {
/*
@@ -1288,7 +1288,9 @@ static int printk_time_set(const char *val, const
struct kernel_param *kp)
#endif

printk_time = _printk_time;
+#ifndef CONFIG_PRINTK_TIME_DEBUG
if (printk_time_source > PRINTK_TIME_DISABLE)
+#endif
printk_set_timestamp();
pr_info("printk: timestamp set to %s\n",

> +
> +config PRINTK_TIME_TYPE
> + int
> + depends on PRINTK
> + range 1 5
> + default 1 if !PRINTK_TIME
> + default 2 if PRINTK_TIME_LOCAL
> + default 3 if PRINTK_TIME_BOOT
> + default 4 if PRINTK_TIME_MONO
> + default 5 if PRINTK_TIME_REAL
> +
>
diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 1fb23d851ca2..2517ed69d7f8 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -60,6 +60,22 @@ config PRINTK_TIME_TYPE
default 4 if PRINTK_TIME_MONO
default 5 if PRINTK_TIME_REAL

+config PRINTK_TIME_DEBUG
+ bool "Allow runtime reselection of any timebase on printks"
+ depends on PRINTK
+ help
+ Selecting this option causes time stamps of the printk()
+ messages to be changed freely at runtime on the output of
+ the syslog() system call and at the console. Without this
+ option, one can only enable or disable the configuration
+ selected timebase.
+
+ Runtime adjustment can be set via
+ /sys/module/printk/paramters/time as follows with a string:
+ 0/N/n/disable, 1/Y/y/local, b/boot, m/monotonic, r/realtime.
+ eg: echo local >/sys/module/printk/parameters/time
+ echo realtime >/sys/module/printk/parameters/time
+
config MESSAGE_LOGLEVEL_DEFAULT
int "Default message log level (1-15)"
range 1 15

The last bit should probably be adjusted to eliminate details, maybe
keep the example as it will stand the test of time, and merely reference
the Documentation tree w.r.t. printk.time=

\
 
 \ /
  Last update: 2017-08-17 17:31    [W:0.085 / U:2.172 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site