Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1701254 > unrolled thread

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

Started byJohn Stultz <john.stultz@linaro.org>
First post2017-08-01 19:10 +0200
Last post2017-08-01 21:50 +0200
Articles 5 — 4 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.


Contents

  Re: [PATCH v2] printk: Add boottime and real timestamps John Stultz <john.stultz@linaro.org> - 2017-08-01 19:10 +0200
    Re: [PATCH v2] printk: Add boottime and real timestamps Prarit Bhargava <prarit@redhat.com> - 2017-08-01 19:40 +0200
      Re: [PATCH v2] printk: Add boottime and real timestamps John Stultz <john.stultz@linaro.org> - 2017-08-01 19:50 +0200
      Re: [PATCH v2] printk: Add boottime and real timestamps Thomas Gleixner <tglx@linutronix.de> - 2017-08-01 21:20 +0200
      Re: [PATCH v2] printk: Add boottime and real timestamps Mark Salyzyn <salyzyn@android.com> - 2017-08-01 21:50 +0200

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

FromJohn Stultz <john.stultz@linaro.org>
Date2017-08-01 19:10 +0200
SubjectRe: [PATCH v2] printk: Add boottime and real timestamps
Message-ID<u9IQa-6Iq-19@gated-at.bofh.it>
On Tue, Aug 1, 2017 at 5:55 AM, Prarit Bhargava <prarit@redhat.com> 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@redhat.com>
...
> 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.
Is there a reason your not also adding PRINTK_TIME_BOOT here (which to
me would be more generally useful then REAL or MONO)?

thanks
-john

[toc] | [next] | [standalone]


#1701270

FromPrarit Bhargava <prarit@redhat.com>
Date2017-08-01 19:40 +0200
Message-ID<u9Jjc-6XQ-21@gated-at.bofh.it>
In reply to#1701254

On 08/01/2017 01:00 PM, John Stultz wrote:
> On Tue, Aug 1, 2017 at 5:55 AM, Prarit Bhargava <prarit@redhat.com> 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@redhat.com>
> ...
>> 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.

[toc] | [prev] | [next] | [standalone]


#1701275

FromJohn Stultz <john.stultz@linaro.org>
Date2017-08-01 19:50 +0200
Message-ID<u9JsS-71o-11@gated-at.bofh.it>
In reply to#1701270
On Tue, Aug 1, 2017 at 10:35 AM, Prarit Bhargava <prarit@redhat.com> wrote:
>
>
> On 08/01/2017 01:00 PM, John Stultz wrote:
>> 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?

I know Mark has specific formatting needs, so I'm not going to speak
for him, but BOOT is actually a nice improvement over MONO, since it
includes suspend time, and avoids inconsistencies due to userspace
tweaking the time, which REALTIME has.  So for debugging suspend
related issues and being able to understand how much time a system has
spent in suspend vs not it would be quite useful.

thanks
-john

[toc] | [prev] | [next] | [standalone]


#1701359

FromThomas Gleixner <tglx@linutronix.de>
Date2017-08-01 21:20 +0200
Message-ID<u9KRY-82o-29@gated-at.bofh.it>
In reply to#1701270
On Tue, 1 Aug 2017, Prarit Bhargava wrote:
> On 08/01/2017 01:00 PM, John Stultz wrote:
> > 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?

We really want both.

Thanks,

	tglx

[toc] | [prev] | [next] | [standalone]


#1701394

FromMark Salyzyn <salyzyn@android.com>
Date2017-08-01 21:50 +0200
Message-ID<u9Ll0-8cw-9@gated-at.bofh.it>
In reply to#1701270
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@redhat.com> 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@redhat.com>
>> ...
>>> 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

[toc] | [prev] | [standalone]


Back to top | Article view | linux.kernel


csiph-web