lkml.org 
[lkml]   [2020]   [Sep]   [23]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
From
SubjectRe: [PATCH 1/2] printk: Store all three timestamps
Date
On 2020-09-23, Petr Mladek <pmladek@suse.com> wrote:
> printk() historically shows the timestamps from the monotonic clock.

printk() uses the local clock, not the monotonic clock.

> It is fast, available early during boot, in any context, and even
> without using any lock.
>
> There are repeated requests [1][2][3] to show the timestamps from other
> clocks. The main motivation is to make it easier to correlate the kernel
> and userspace logs. Where userspace logs usually use the real time
> clock.
>
> Unfortunately, it is not possible to simply replace the default clock.
> Userspace tools, like journalctl, dmesg, expect to get the timestamps
> from the mono via /dev/kmsg interface or syslog syscall [4].
> Also administrators would be confused when logs from different
> systems use different clocks depending on kernel version or
> build option [5].
>
> As a result, the mono clock has to stay as the default clock
> and has to be used in the current user interfaces.

Actually this series is changing the default clock from local to
monotonic. I for one welcome this change (and wish ftrace would do it as
well), but it is a change.

> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 1560649cbd35..0ed8901916f4 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -520,10 +522,10 @@ static int log_store(u32 caller_id, int facility, int level,
> r.info->facility = facility;
> r.info->level = level & 7;
> r.info->flags = flags & 0x1f;
> - if (ts_nsec > 0)
> - r.info->ts_nsec = ts_nsec;
> + if (ts)
> + r.info->ts = *ts;
> else
> - r.info->ts_nsec = local_clock();
> + ktime_get_fast_timestamps(&r.info->ts);

I am wondering if we still want to keep the local_clock() as well (and
as the default). ftrace also uses it by default, which means traces and
printk logs could be coordinated by default until now.

The two clocks can vary quite a bit. I have a laptop where the local
clock drifts away from monotonic at about 50us per second.

> diff --git a/kernel/printk/printk_ringbuffer.h b/kernel/printk/printk_ringbuffer.h
> index 0adaa685d1ca..09082c8472d3 100644
> --- a/kernel/printk/printk_ringbuffer.h
> +++ b/kernel/printk/printk_ringbuffer.h
> @@ -14,7 +15,7 @@
> */
> struct printk_info {
> u64 seq; /* sequence number */
> - u64 ts_nsec; /* timestamp in nanoseconds */
> + struct ktime_timestamps ts; /* timestamps */
> u16 text_len; /* length of text message */
> u8 facility; /* syslog facility */
> u8 flags:5; /* internal record flags */

If we wanted to keep the local clock, should the local clock be a part
of struct ktime_timestamps? Or should struct printk_info maintain that
separately (either as @ts_nsec or @ts_local or whatever).

John Ogness

\
 
 \ /
  Last update: 2020-09-24 00:13    [W:0.142 / U:3.112 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site