Module Name:    src
Committed By:   kre
Date:           Tue Oct 30 19:40:36 UTC 2018

Modified Files:
        src/sbin/dmesg: dmesg.8 dmesg.c
        src/sys/kern: init_main.c

Log Message:
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...)


To generate a diff of this commit:
cvs rdiff -u -r1.25 -r1.26 src/sbin/dmesg/dmesg.8
cvs rdiff -u -r1.40 -r1.41 src/sbin/dmesg/dmesg.c
cvs rdiff -u -r1.499 -r1.500 src/sys/kern/init_main.c

Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.

Modified files:

Index: src/sbin/dmesg/dmesg.8
diff -u src/sbin/dmesg/dmesg.8:1.25 src/sbin/dmesg/dmesg.8:1.26
--- src/sbin/dmesg/dmesg.8:1.25	Thu Sep 20 10:03:31 2018
+++ src/sbin/dmesg/dmesg.8	Tue Oct 30 19:40:36 2018
@@ -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,

Index: src/sbin/dmesg/dmesg.c
diff -u src/sbin/dmesg/dmesg.c:1.40 src/sbin/dmesg/dmesg.c:1.41
--- src/sbin/dmesg/dmesg.c:1.40	Thu Sep 20 23:46:42 2018
+++ src/sbin/dmesg/dmesg.c	Tue Oct 30 19:40:36 2018
@@ -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, 19
 #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",

Index: src/sys/kern/init_main.c
diff -u src/sys/kern/init_main.c:1.499 src/sys/kern/init_main.c:1.500
--- src/sys/kern/init_main.c:1.499	Fri Oct 26 18:16:42 2018
+++ src/sys/kern/init_main.c	Tue Oct 30 19:40:35 2018
@@ -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) {

Reply via email to