Re: About dmesg time and uptime

[Thomas Gleixner]

On Wed, 21 Mar 2018, Qixuan Wu wrote:
>    I have a doubt in kernel 4.9 about dmesg time and uptime. Would you
> please to help to clarify whether it's bug or not.
>    Below is our log. The dmesg time second is large than uptime second.
> 
> [25049978.919097] bond0.700: port 9(veth4e77160) entered forwarding state
> [25049978.926455] bond0.700: port 9(veth4e77160) entered forwarding state
> [chenggang.qcg@e80g10383 ~]$ cat /proc/uptime
> 25023128.55 1416627078.34
> 
>    I found dmesg second is just directly get from tsc (x86 64 platform).
> While the uptime is get by a complicated computation.

Well it's not a complicated computation. It simply uses the timekeeping
infrastructure.

The dmesg timestamp comes from sched_clock() which is TSC based and it is
using a coarse calibration value obtained at boot time.

The timekeeping infrastructure is using a fine grained calibration which
can be further adjusted by NTP/PTP.

So yes, this can drift apart. The error from your numbers above is about
0.1% which is not an unusual value.

There is a patch is mainline which feed the fine grained calibration value
into sched_clock to make this slighty better, but it wont be perfect. See:

     aa7b630ea023 ("x86/tsc: Feed refined TSC calibration into sched_clock()")

There is also an effort to base dmesg time stamps on monotonic time, which
will fix this problem completely, but that's still work in progress.

Thanks,

	tglx