Correct the 6 second offset issue between the time reported by

dmesg -T and the actual time a message was produced, noted on
current-users by Geoff Wing (Oct 27, 2018).

The size of the offset would depend upon architecture, and processor,
but was the delay from starting the clocks to initialising the time
of day (after mounting root, in case that is needed).

Change the kernel to set boottime to be the time at which the
clocks were started, rather than the time at which it is init'd
(by subtracting the interval between).

Correct dmesg to properly compute the ToD based upon the
boottime (which is a timespec, not a timeval, and has been
since Jan 2009) and the time logged in the message.

Note that this can (rarely) be 1 second earlier than date reports.
This occurs  when the time when the message was logged was actually
in the next second, but the timecounters have not yet processed
the tick, and so the time of the last tick, near the end of the
previous second, is reported instead.   Since times are always
truncated, rather than rounded, it is occasionally possible to
observe that disparity (if you try hard enough).

IOW: sys/kern/subr_prf.c:addtstamp() uses getnanouptime() rather
than nanouptime().

Note in dmesg(8) that -T conversions are gibberish other than
when the message comes from current the running kernel.  (It
could be fixed when -M is used, for messages generated by the
kernel whose corpse is being observed.   But hasn't been...)
This commit is contained in:
kre 2018-10-30 19:40:35 +00:00
parent d903176946
commit 7008793d77
3 changed files with 31 additions and 9 deletions

View File

@ -1,4 +1,4 @@
.\" $NetBSD: dmesg.8,v 1.25 2018/09/20 10:03:31 kre Exp $
.\" $NetBSD: dmesg.8,v 1.26 2018/10/30 19:40:36 kre Exp $
.\"
.\" Copyright (c) 1980, 1991, 1993
.\" The Regents of the University of California. All rights reserved.
@ -29,7 +29,7 @@
.\"
.\" @(#)dmesg.8 8.1 (Berkeley) 6/5/93
.\"
.Dd September 18, 2018
.Dd October 30, 2018
.Dt DMESG 8
.Os
.Sh NAME
@ -98,6 +98,12 @@ The
command appeared in
.Bx 3.0 .
.Sh BUGS
The
.Fl T
option will report nonsense when displaying lines from
the message buffer that were not added by the current
running kernel.
.Pp
When
.Fl TT
is used, the duration is always given with maximum units of hours,

View File

@ -1,4 +1,4 @@
/* $NetBSD: dmesg.c,v 1.40 2018/09/20 23:46:42 kre Exp $ */
/* $NetBSD: dmesg.c,v 1.41 2018/10/30 19:40:36 kre Exp $ */
/*-
* Copyright (c) 1991, 1993
* The Regents of the University of California. All rights reserved.
@ -38,7 +38,7 @@ __COPYRIGHT("@(#) Copyright (c) 1991, 1993\
#if 0
static char sccsid[] = "@(#)dmesg.c 8.1 (Berkeley) 6/5/93";
#else
__RCSID("$NetBSD: dmesg.c,v 1.40 2018/09/20 23:46:42 kre Exp $");
__RCSID("$NetBSD: dmesg.c,v 1.41 2018/10/30 19:40:36 kre Exp $");
#endif
#endif /* not lint */
@ -151,7 +151,7 @@ main(int argc, char *argv[])
#ifndef SMALL
char tbuf[64];
char *memf, *nlistf;
struct timeval boottime;
struct timespec boottime;
struct timespec lasttime;
intmax_t sec;
long nsec, fsec;
@ -168,7 +168,7 @@ main(int argc, char *argv[])
radix = "."; /* could also select "," */
boottime.tv_sec = 0;
boottime.tv_usec = 0;
boottime.tv_nsec = 0;
lasttime.tv_sec = 0;
lasttime.tv_nsec = 0;
deltas = quiet = humantime = 0;
@ -337,6 +337,13 @@ main(int argc, char *argv[])
struct tm tm;
t = boottime.tv_sec + sec;
if (nsec + boottime.tv_nsec >=
( 1L /* 1 second */
* 1000L /* ms */
* 1000L /* us */
* 1000L /* ns */ ))
t++;
if (localtime_r(&t, &tm) != NULL) {
strftime(tbuf, sizeof(tbuf),
"%a %b %e %H:%M:%S %Z %Y",

View File

@ -1,4 +1,4 @@
/* $NetBSD: init_main.c,v 1.499 2018/10/26 18:16:42 martin Exp $ */
/* $NetBSD: init_main.c,v 1.500 2018/10/30 19:40:35 kre Exp $ */
/*-
* Copyright (c) 2008, 2009 The NetBSD Foundation, Inc.
@ -97,7 +97,7 @@
*/
#include <sys/cdefs.h>
__KERNEL_RCSID(0, "$NetBSD: init_main.c,v 1.499 2018/10/26 18:16:42 martin Exp $");
__KERNEL_RCSID(0, "$NetBSD: init_main.c,v 1.500 2018/10/30 19:40:35 kre Exp $");
#include "opt_ddb.h"
#include "opt_inet.h"
@ -663,7 +663,16 @@ main(void)
* munched in mi_switch() after the time got set.
*/
getnanotime(&time);
boottime = time;
{
struct timespec ut;
/*
* was:
* boottime = time;
* but we can do better
*/
nanouptime(&ut);
timespecsub(&time, &ut, &boottime);
}
mutex_enter(proc_lock);
LIST_FOREACH(p, &allproc, p_list) {