Re: "dmesg -T" date doesn't match "date" output

[Geoff Wing <gcw%pobox.com@localhost>]

On Saturday 2018-10-27 19:03 +0700, Robert Elz output:
:    Date:        Sat, 27 Oct 2018 17:39:16 +1100
:    From:        Geoff Wing <gcw%pobox.com@localhost>
:    Message-ID:  <20181027063916.GA2977%primenet.com.au@localhost>
:
:  | dates output by "dmesg -T" are not matching real time.  Using a program
:  | to generate a segfault dmesg is showing times in the future:
:
:dmesg times come from "seconds since boot" which is what is actually
:logged, added to boottime.   The seconds since boot is, I believe, a monotonic
:counter which counts at timer rate, unadjusted for clock errors.
:
:I'd assume you're running NTP or similar to sync your clock, and that it
:is constantly slowing down your timer - apparently by 6 seconds since
:boot, which suggests that either your clock is wildly inaccurate, or that
:your system has been up for a fairly lengthy time (at least a week probably).
:
:What does dmesg say without the -T, or perhaps using -TT
:
:The dmesg man page should perhaps explain all of this a little better.

I've tried on two -current amd64 machines and both were showing similar issues.
The dmesg time matches what appears in kern.boottime but I don't see a 5-6
second step in rc.log when ntpdate is run.  Something fishy is going on.

# ./segfault; date; dmesg -T | tail -1; dmesg -TT | tail -1
[1]    871 segmentation fault  ./segfault
Sun Oct 28 09:37:49 AEDT 2018
[Sun Oct 28 09:37:55 AEDT 2018] pid 871 (segfault), uid 0: exited on signal 11 (core not dumped, err = 1)
[PT1M13.006S] pid 871 (segfault), uid 0: exited on signal 11 (core not dumped, err = 1)
# sysctl kern.boottime
kern.boottime = Sun Oct 28 09:36:42 2018
# ntpq -p
     remote           refid      st t when poll reach   delay   offset  jitter
==============================================================================
 XXXXXXXXXXXX    XXXXXXXXXXXXXX   3 s    3  128    7    0.588   -4.308   3.546
 XXXXXXXXXXXX    XXXXXXXXXXXXXX   3 s    7  128    3    0.228   -3.728   0.066
 XXXXXXXXXXXX    XXXXXXXXXXXXXX   4 s   62  128    7    0.100   -4.151   2.945
+XXXXXXXXXXXX    XXXXXXXXXXXXXX   3 u   28   64    3    0.812   -2.945   2.411
*XXXXXXXXXXXX    XXXXXXXXXXXXXX   3 u   80  128    1   12.870   -6.306   0.032

( from /var/run/rc.log )
[running /etc/rc.d/ntpdate]
Setting date via ntp.
28 Oct 09:37:01 ntpdate[229]: step time server XXXXXXXXXXXXXX offset 0.304666 sec

Regards,
Geoff