Bug 18598

Summary: Incessant messages "microuptime() went backwards"
Product: Base System Reporter: y.grossel <y.grossel>
Component: kernAssignee: freebsd-bugs (Nobody) <bugs>
Status: Closed FIXED    
Severity: Affects Only Me    
Priority: Normal    
Version: Unspecified   
Hardware: Any   
OS: Any   

Description y.grossel 2000-05-16 13:40:00 UTC
While doing intense disk operations (using pax) the kernel suddenly started
to log infinite number of similar messages :

May 15 18:03:11 aldebaran /kernel: microuptime() went backwards (5991.702791 -> 5991,661169)
May 15 18:03:11 aldebaran /kernel: microuptime() went backwards (5991.702791 -> 5991,666666)
May 15 18:03:11 aldebaran /kernel: microuptime() went backwards (5991.702791 -> 5991,694225)
May 15 18:03:11 aldebaran /kernel: microuptime() went backwards (5991.711393 -> 5991,-694696436)

and so on until reboot.

Fix: 

-
How-To-Repeat: Don't know
Comment 1 joe 2000-05-16 20:10:57 UTC
> May 15 18:03:11 aldebaran /kernel: microuptime() went backwards (5991.702791 -> 5991,661169)
> May 15 18:03:11 aldebaran /kernel: microuptime() went backwards (5991.702791 -> 5991,666666)
> May 15 18:03:11 aldebaran /kernel: microuptime() went backwards (5991.702791 -> 5991,694225)
> May 15 18:03:11 aldebaran /kernel: microuptime() went backwards (5991.711393 -> 5991,-694696436)

I got this too last night when running postgresql for the first time:

FreeBSD genius.systems.pavilion.net 5.0-CURRENT FreeBSD 5.0-CURRENT #69: Tue May  2 14:12:50 BST 2000     joe@genius.systems.pavilion.net:/usr/src/sys/compile/GENIUS  i386

Joe
Comment 2 Poul-Henning Kamp freebsd_committer freebsd_triage 2000-05-18 23:19:07 UTC
State Changed
From-To: open->closed

We resolved this in email to be the APM bios changing the frequency 
of the i8254 under our feet.  Nothing much we can do in that case. 

Comment 3 Bruce Evans 2000-05-19 07:12:36 UTC
On Thu, 18 May 2000 phk@FreeBSD.ORG wrote:

> Synopsis: Incessant messages "microuptime() went backwards"
> 
> State-Changed-From-To: open->closed
> State-Changed-By: phk
> State-Changed-When: Thu May 18 15:19:07 PDT 2000
> State-Changed-Why: 
> We resolved this in email to be the APM bios changing the frequency
> of the i8254 under our feet.  Nothing much we can do in that case.

Um, we can easily make it jump forwards instead of backwards.  From
i386/isa/clock.c:

> static u_int
> i8254_get_timecount(struct timecounter *tc)
> {
> 	u_int count;
  	^^^^^
> ...
> 	low = inb(TIMER_CNTR0);
> 	high = inb(TIMER_CNTR0);
> 	count = timer0_max_count - ((high << 8) | low);
  	^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

This sometimes underflows to a large unsigned value if something changes
the actual maximum count to a value smaller than timer0_max_count
underneath us.  We really want `count' to be a small negative value instead
of a large positive one.

> 	if (count < i8254_lastcount ||
  	    ^^^^^^^^^^^^^^^^^^^^^^^
 
Since both variables in the comparison are unsigned, this doesn't detect
the underflow.

Possible workarounds:
1) Used signed ints more and/or
2) replace the large unsigned counts by 0.
3) Whenever a large unsigned count is detected, adjust timer0_max_count
   and associated variables to match it, or adjust timer0_max_count to
   match the actual hardware max count (which was presumably adjusted
   by APM), or adjust the hardware max count to match the original
   timer0_max_count.

Bruce