From owner-freebsd-current  Fri Nov  6 11:28:09 1998
Return-Path: <owner-freebsd-current@FreeBSD.ORG>
Received: (from majordom@localhost)
          by hub.freebsd.org (8.8.8/8.8.8) id LAA17200
          for freebsd-current-outgoing; Fri, 6 Nov 1998 11:28:09 -0800 (PST)
          (envelope-from owner-freebsd-current@FreeBSD.ORG)
Received: from critter.freebsd.dk (critter.freebsd.dk [212.242.40.131])
          by hub.freebsd.org (8.8.8/8.8.8) with ESMTP id LAA17184
          for <current@FreeBSD.ORG>; Fri, 6 Nov 1998 11:28:01 -0800 (PST)
          (envelope-from phk@critter.freebsd.dk)
Received: from critter.freebsd.dk (localhost [127.0.0.1])
	by critter.freebsd.dk (8.9.1/8.8.5) with ESMTP id UAA05112;
	Fri, 6 Nov 1998 20:26:03 +0100 (CET)
To: Bill Paul <wpaul@skynet.ctr.columbia.edu>
cc: current@FreeBSD.ORG
Subject: Re: Grrr... calcru: negative time blah blah blah 
In-reply-to: Your message of "Fri, 06 Nov 1998 13:55:10 EST."
             <199811061855.NAA15525@skynet.ctr.columbia.edu> 
Date: Fri, 06 Nov 1998 20:26:00 +0100
Message-ID: <5110.910380360@critter.freebsd.dk>
From: Poul-Henning Kamp <phk@critter.freebsd.dk>
Sender: owner-freebsd-current@FreeBSD.ORG
Precedence: bulk
X-Loop: FreeBSD.ORG


The numbers in the tc_diag_buffer are basically the number of ticks
on the timecounter between each use of it.

>Timecounter "i8254"  frequency 1193182 Hz

Normally, the largest number of ticks should be the frequency of
the timecounter divided by 100, in this case 11931, (plus or minus
epsilon).

When smaller counts are in the buffer it means that one of the *time()
functions were called, so that is normal.

>debug.tc_diag_buffer: 11932 11932 11932 11937 [...]
>[...] 11932 11932 49982 50184 50259 11934 11930 [...]

This is bad, really really bad.  Best case sequence is:

	11932: hardclock()
	11932: hardclock()
	49982: {micro|nano}[run]time()
	50184: {micro|nano}[run]time()
	50259: hardclock()
	11934: hardclock()

At least 4 calls to hardclock() is missing here.  

Further bogosity:

>[...] 5817 23370 23693 24128 24318 11936  [...]
>[...] 11932 29733 31132 31195 11933 [...]
>[...] 11932 47338 47978 47986 48807 50401 51051 51072 51518 51730 1556 
>1658 1863 1950 2198 8500 8578 18966 19741 11920 11930 11931 11933 161 
>170 11932 11931 [...]

>Here are the sysctl results for test2 (with no apm0 device):

>kern.timecounter.frequency: 1193182

Which didn't make a difference for SMP, since we always use the i8254

>debug.tc_diag_buffer: [...]
>[...] 11927 44950 45524 45532 46430 48518 49258 49280 49747 49873 11933 [...]

Neither of the two tests seems to have triggered any of my tests
since "debug.tc_diag_stop" is still zero.

This is consistent with a model of "lost interrupts", which I think the
above data support.  A "reading the i8254 wrong" theory doesn't match
the values you have here, more +/- 256 values should have been present.

Does the problem also exist for a !SMP case ?

--
Poul-Henning Kamp             FreeBSD coreteam member
phk@FreeBSD.ORG               "Real hackers run -current on their laptop."
"ttyv0" -- What UNIX calls a $20K state-of-the-art, 3D, hi-res color terminal

To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-current" in the body of the message