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) {