Re: [PATCH v2] printk: Add boottime and real timestamps

From: Mark Salyzyn
Date: Tue Aug 01 2017 - 15:47:00 EST


On 08/01/2017 10:35 AM, Prarit Bhargava wrote:

On 08/01/2017 01:00 PM, John Stultz wrote:
On Tue, Aug 1, 2017 at 5:55 AM, Prarit Bhargava <prarit@xxxxxxxxxx> wrote:
printk.time=1/CONFIG_PRINTK_TIME=1 adds a unmodified local hardware clock
timestamp to printk messages. The local hardware clock loses time each
day making it difficult to determine exactly when an issue has occurred in
the kernel log, and making it difficult to determine how kernel and
hardware issues relate to each other in real time.

Make printk output different timestampes by adding options for no
timestamp, the local hardware clock, the monotonic clock, 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.

Signed-off-by: Prarit Bhargava <prarit@xxxxxxxxxx>
...
diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 98fe715522e8..7a8870b4ddbb 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -1,8 +1,39 @@
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_MONO
+ bool "CLOCK_MONOTONIC"
+ help
+ Selecting this option causes the time stamps of printk() to be
+ stamped with the adjusted monotonic clock.
+
+ 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.
Its been asked already, but I've not yet seen an answer.
Sorry for missing this.

Is there a reason your not also adding PRINTK_TIME_BOOT here (which to
me would be more generally useful then REAL or MONO)?
REAL has been useful to me in debug cases where events on the system were timed
to the wall clock (ex cron job running at 3AM). I hadn't really thought much
about using BOOT TBH because MONO seemed to work just fine.

Mark Salyzyn, did you want BOOT or MONO?

P.

You must IMHO include MONO (default when on?), BOOT and REAL if you are offering the ability for the kernel to switch time base.

[TL;DR]

I had a partner request for Boottime (for kernel and userspace) for those that are providing products that focus more on sensors. We said no, case closed. This option in your patch would reopen that possibility.

We have too many use cases, too many partners all pulling in different directions. We have met with resistance moving userspace to monotonic to match kernel on phones, preference remains realtime for user space, and monotonic for kernel. Yet watch partners preferred moving all to monotonic time, but they required realtime (or could do with boottime) dual-print to monitor battery and power. We only wanted to print realtime (or monotonic depending on case) during time disruptions (suspend/resume mainly). With your proposal we may have less resistance to realtime for kernel and userspace, but we will have partners that insist on using monotonic none-the-less because we do not have control, so we _must_ provide the dual-time option for them.

The dual-time in disruptive cases depends a _lot_ on what happens with this patch. I am expecting mine to be very sensitive to the config settings (ie: if both select realtime, then no dual-time is printed), so my proposal is on hiatus until this is resolved.

-- Mark