"calcru: runtime went backwards" messages

2010-06-10 Thread Jansen Gotis
Hi, for the past couple of months since moving to RELENG_8 I've been
receiving "calcru: runtime went backwards" messages on the console.

My machine is a dual Pentium III 1.26GHz with an Intel SAI2 board.
Disabling EIST is not an option in my BIOS, and I've tried disabling
the ACPI timer as well as setting kern.timecounter.hardware=i8254.
I've also tried disabling cpufreq in my kernel configuration.

For what it's worth, I'm running base ntpd. I've also tried openntpd,
but no dice.

I did a binary search of the commit with which this started, and
apparently it's svn r204546, a summary of which can be seen here:
http://freshbsd.org/2010/03/02/01/56/55

The calcru messages appear whether vesa is loaded as a module
or compiled into the kernel.

If anyone needs more information, I'll be happy to provide it.


Best regards,
Jansen

= snippet of /var/log/messages relating to calcru messages =
Jun 10 22:41:42 hobbes kernel: calcru: runtime went backwards from
3502 usec to 3297 usec for pid 1106 (mksh)
Jun 10 22:41:42 hobbes kernel: calcru: runtime went backwards from
36785 usec to 35858 usec for pid 1114 (csh)
Jun 10 22:41:42 hobbes kernel: calcru: runtime went backwards from
13438 usec to 12652 usec for pid 1113 (su)
Jun 10 22:41:42 hobbes kernel: calcru: runtime went backwards from
14956 usec to 14081 usec for pid  (mksh)
Jun 10 22:41:42 hobbes kernel: calcru: runtime went backwards from
3323 usec to 3128 usec for pid  (mksh)
Jun 10 22:41:42 hobbes kernel: calcru: runtime went backwards from 610
usec to 574 usec for pid 549 (devd)
Jun 10 22:41:42 hobbes kernel: calcru: runtime went backwards from 517
usec to 486 usec for pid 548 (dhclient)
Jun 10 22:41:42 hobbes kernel: calcru: runtime went backwards from
1912 usec to 1800 usec for pid 532 (dhclient)
Jun 10 22:41:42 hobbes kernel: calcru: runtime went backwards from
39738 usec to 37412 usec for pid 532 (dhclient)
Jun 10 22:41:42 hobbes kernel: calcru: runtime went backwards from
3369010 usec to 3334846 usec for pid 1 (init)


= /var/run/dmesg.boot =
Copyright (c) 1992-2010 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 8.0-STABLE #0 r204546: Thu Jun 10 21:05:09 PHT 2010
jan...@hobbes.jansen.homenet:/usr/obj/usr/src/sys/LOCAL i386
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Intel(R) Pentium(R) III CPU family  1266MHz (1263.45-MHz 686-class CPU)
  Origin = "GenuineIntel"  Id = 0x6b1  Stepping = 1
  
Features=0x383fbff
real memory  = 2148007936 (2048 MB)
avail memory = 2090995712 (1994 MB)
ACPI APIC Table: 
FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
FreeBSD/SMP: 2 package(s) x 1 core(s)
 cpu0 (BSP): APIC ID:  3
 cpu1 (AP): APIC ID:  0
MADT: Forcing active-low polarity and level trigger for SCI
ioapic0  irqs 0-15 on motherboard
ioapic1  irqs 16-31 on motherboard
kbd1 at kbdmux0
netsmb_dev: loaded
smbios0:  at iomem 0xf6e90-0xf6eae on motherboard
smbios0: Version: 2.3, BCD Revision: 2.3
acpi0:  on motherboard
acpi0: [ITHREAD]
acpi0: Power Button (fixed)
acpi0: Sleep Button (fixed)
Timecounter "ACPI-safe" frequency 3579545 Hz quality 850
acpi_timer0: <32-bit timer at 3.579545MHz> port 0x508-0x50b on acpi0
pcib0:  port 0xcf8-0xcff on acpi0
pci0:  on pcib0
vgapci0:  port 0x2000-0x20ff mem
0xfa00-0xfaff,0xfb00-0xfb000fff at device 2.0 on pci0
fxp0:  port 0x2400-0x243f mem
0xfb001000-0xfb001fff,0xfb10-0xfb1f irq 18 at device 3.0 on
pci0
miibus0:  on fxp0
inphy0:  PHY 1 on miibus0
inphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
fxp0: Ethernet address: 00:03:47:a6:0d:4a
fxp0: [ITHREAD]
isab0:  at device 15.0 on pci0
isa0:  on isab0
atapci0:  port
0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0x2440-0x244f at device 15.1 on
pci0
ata0:  on atapci0
ata0: [ITHREAD]
ata1:  on atapci0
ata1: [ITHREAD]
ohci0:  mem 0xfb002000-0xfb002fff irq 9
at device 15.2 on pci0
ohci0: [ITHREAD]
usbus0:  on ohci0
pcib1:  on acpi0
pci1:  on pcib1
atapci1:  port
0x2480-0x24ff,0x2800-0x28ff mem
0xfb42-0xfb420fff,0xfb40-0xfb41 irq 20 at device 10.0 on
pci1
atapci1: [ITHREAD]
atapci1: [ITHREAD]
ata2:  on atapci1
ata2: SIGNATURE: 0101
ata2: [ITHREAD]
ata3:  on atapci1
ata3: [ITHREAD]
ata4:  on atapci1
ata4: [ITHREAD]
atrtc0:  port 0x70-0x71 irq 8 on acpi0
atkbdc0:  port 0x60,0x64 irq 1 on acpi0
atkbd0:  irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
atkbd0: [ITHREAD]
psm0:  irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
psm0: [ITHREAD]
psm0: model IntelliMouse Explorer, device ID 4
fdc0:  port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0
fdc0: [FILTER]
uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
uart0: [FILTER]
uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0
uart1: [FILTER]
ppc0:  port 0x378-0x37f,0x778-0x77f irq 7 drq 3 on acpi0
ppc0: SMC-like chipset (ECP/EPP/PS2/NIBBLE) in COMPATIBLE mo

Re: "calcru: runtime went backwards" messages

2010-06-10 Thread Jansen Gotis
On Fri, Jun 11, 2010 at 7:03 AM, Jilles Tjoelker  wrote:
> On Fri, Jun 11, 2010 at 12:35:05AM +0800, Jansen Gotis wrote:
>> Hi, for the past couple of months since moving to RELENG_8 I've been
>> receiving "calcru: runtime went backwards" messages on the console.
>

>
> This may well be a manifestation of a brokenness (which should not be
> unknown) in how FreeBSD stores CPU time utilization. The time is
> maintained in "CPU ticks" (CPU clock cycles), so if the clock frequency
> changes, the values of existing processes will be wrong (a jump when
> converted to seconds). When calcru detects this, it generates messages
> like the above. If this analysis is right, the messages can be ignored,
> but indicate that CPU time statistics may be inaccurate.
>

You're probably right, the messages can be ignored. I don't see any issues
other than the messages being printed on the console; I don't experience
freezing, etc. It just struck me as weird because searching the -current and
-stable mailing lists does not show anyone else having the issue as recently
as I have.

Just some more info to add which I forgot about last time...setting kern.hz to
100 did not help.

Thanks for the reply.


Best regards,
Jansen
___
freebsd-stable@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-stable
To unsubscribe, send any mail to "freebsd-stable-unsubscr...@freebsd.org"


Re: "calcru: runtime went backwards" messages

2010-06-11 Thread Jansen Gotis
On Sat, Jun 12, 2010 at 8:01 AM, Jeff Dowsley  wrote:
> You're not alone.  Noticed the calcru messages after a rebuild in May on a
> Compaq PIII, but assumed it wasn't doing any harm, and that it would
> eventually be fixed.
>
> JeffD
>

It appears to be related to VESA, because when support for it is neither loaded
as a module nor compiled into the kernel, the system does not print the
messages. Can you please verify that on your machine? Thanks.


Best regards,
Jansen
___
freebsd-stable@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-stable
To unsubscribe, send any mail to "freebsd-stable-unsubscr...@freebsd.org"