Date: Sat, 1 Sep 2007 18:24:46 -0700 From: James Long <list@museum.rain.com> To: freebsd-questions@freebsd.org Subject: Recent update to RELENG_6 creates lots of calcru warnings Message-ID: <20070902012446.GA17048@ns.umpquanet.com>
next in thread | raw e-mail | index | archive | help
I'm running FreeBSD RELENG_6 on a Compaq DL380 G2 dual PIII-1.4GHz with
an SMP kernel. dmesg below.
Prior to about August 12, the system had been quite stable.
Since that time, I am finding lots of calcru warnings, which often
cause system services to fail when they see unorthodox time shifts.
Section 5.19 of the handbook appears not to be current any longer,
suggesting setting kern.timecounter.method=1.
kern.timecounter.hardware=i8254 also does not improve things.
Other suggestions?
Thanks,
Jim
Sep 1 18:00:30 ns sudo: james : TTY=ttyp0 ; PWD=/usr/local/www/sites/com.umpquanet/support ; USER=root ; COMMAND=/sbin/sysctl -w kern.timecounter.hardware=i8254
Sep 1 18:02:44 ns kernel: calcru: runtime went backwards from 1343309 usec to 1178478 usec for pid 3663 (hpasmd)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -1274607 usec for pid 3660 (hpasmd)
Sep 1 18:02:44 ns kernel: calcru: runtime went backwards from 6470361 usec to 5811413 usec for pid 995 (postgres)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -1099076 usec for pid 36 (pagedaemon)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -5928105 usec for pid 35 (fdc0)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -1526937 usec for pid 32 (acpi_cooling0)
Sep 1 18:02:44 ns kernel: calcru: runtime went backwards from 8015143 usec to 1437770 usec for pid 15 (yarrow)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -12360933 usec for pid 2 (g_event)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -2106022786 usec for pid 13 (swi4: clock sio)
Sep 1 18:02:44 ns kernel: calcru: runtime went backwards from 295074296 usec to 292484248 usec for pid 1 (init)
Sep 1 18:02:44 ns kernel: calcru: runtime went backwards from 1343309 usec to 1178478 usec for pid 3663 (hpasmd)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -1274607 usec for pid 3660 (hpasmd)
Sep 1 18:02:44 ns kernel: calcru: runtime went backwards from 6470361 usec to 5811413 usec for pid 995 (postgres)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -1099076 usec for pid 36 (pagedaemon)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -5928105 usec for pid 35 (fdc0)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -1526937 usec for pid 32 (acpi_cooling0)
Sep 1 18:02:44 ns kernel: calcru: runtime went backwards from 8015143 usec to 1437770 usec for pid 15 (yarrow)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -12360933 usec for pid 2 (g_event)
Sep 1 18:02:44 ns kernel: calcru: negative runtime of -2106022734 usec for pid 13 (swi4: clock sio)
Sep 1 18:02:44 ns kernel: calcru: runtime went backwards from 295074296 usec to 292484248 usec for pid 1 (init)
dmesg output:
Copyright (c) 1992-2007 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 6.2-STABLE #0: Mon Aug 27 17:24:37 PDT 2007
root@ns.umpquanet.com:/usr/obj/usr/src/sys/SMP-UMP
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Intel(R) Pentium(R) III CPU family 1400MHz (1390.66-MHz 686-class CPU)
Origin = "GenuineIntel" Id = 0x6b1 Stepping = 1
Features=0x383fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE>
real memory = 1073725440 (1023 MB)
avail memory = 1037357056 (989 MB)
ACPI APIC Table: <COMPAQ 00000083>
FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
cpu0 (BSP): APIC ID: 3
cpu1 (AP): APIC ID: 0
MADT: Forcing active-low polarity and level trigger for SCI
ioapic1 <Version 1.1> irqs 16-31 on motherboard
ioapic0 <Version 1.1> irqs 0-15 on motherboard
kbd1 at kbdmux0
ath_hal: 0.9.20.3 (AR5210, AR5211, AR5212, RF5111, RF5112, RF2413, RF5413)
acpi0: <COMPAQ P24> on motherboard
acpi0: Power Button (fixed)
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x240-0x243 on acpi0
cpu0: <ACPI CPU> on acpi0
cpu1: <ACPI CPU> on acpi0
pcib0: <ACPI Host-PCI bridge> on acpi0
pci0: <ACPI PCI bus> on pcib0
ciss0: <Compaq Smart Array 5i> port 0x2000-0x20ff mem 0xf5ec0000-0xf5efffff,0xf3ef0000-0xf3ef3fff irq 16 at device 1.0 on pci0
ciss0: [GIANT-LOCKED]
fxp0: <Intel 82559 Pro/100 Ethernet> port 0x2400-0x243f mem 0xf5eb0000-0xf5eb0fff,0xf5d00000-0xf5dfffff irq 18 at device 2.0 on pci0
miibus0: <MII bus> on fxp0
inphy0: <i82555 10/100 media interface> on miibus0
inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
fxp0: Ethernet address: 00:02:a5:ad:82:d5
fxp1: <Intel 82559 Pro/100 Ethernet> port 0x2440-0x247f mem 0xf5cf0000-0xf5cf0fff,0xf5b00000-0xf5bfffff irq 20 at device 4.0 on pci0
miibus1: <MII bus> on fxp1
inphy1: <i82555 10/100 media interface> on miibus1
inphy1: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
fxp1: Ethernet address: 00:02:a5:ad:82:d4
pci0: <base peripheral> at device 6.0 (no driver attached)
isab0: <PCI-ISA bridge> at device 15.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <ServerWorks ROSB4 UDMA33 controller> port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0x2c00-0x2c0f at device 15.1 on pci0
ata0: <ATA channel 0> on atapci0
ata1: <ATA channel 1> on atapci0
ohci0: <OHCI (generic) USB controller> mem 0xf3fd0000-0xf3fd0fff irq 22 at device 15.2 on pci0
ohci0: [GIANT-LOCKED]
usb0: OHCI version 1.0, legacy support
usb0: SMM does not respond, resetting
usb0: <OHCI (generic) USB controller> on ohci0
usb0: USB revision 1.0
uhub0: (0x1166) OHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 4 ports with 4 removable, self powered
pcib1: <ACPI Host-PCI bridge> on acpi0
pci1: <ACPI PCI bus> on pcib1
pcib2: <PCI-PCI bridge> at device 3.0 on pci1
pci2: <PCI bus> on pcib2
pci2: <display, VGA> at device 0.0 (no driver attached)
pci1: <memory> at device 3.1 (no driver attached)
pcib3: <ACPI Host-PCI bridge> on acpi0
pci7: <ACPI PCI bus> on pcib3
pci7: <base peripheral, PCI hot-plug controller> at device 7.0 (no driver attached)
acpi_tz0: <Thermal Zone> on acpi0
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
sio0: <Standard PC COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
sio0: type 16550A
fdc0: <floppy drive controller> port 0x3f2-0x3f5 irq 6 drq 2 on acpi0
fdc0: [FAST]
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
pmtimer0 on isa0
orm0: <ISA Option ROMs> at iomem 0xc0000-0xc7fff,0xc8000-0xcbfff,0xcc000-0xcd7ff,0xee000-0xeffff on isa0
ppc0: parallel port not found.
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
sio1: configured irq 3 not in bitmap of probed irqs 0
sio1: port may not be enabled
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Timecounters tick every 1.000 msec
acd0: CDROM <COMPAQ CD-ROM SN-124/N102> at ata0-master PIO4
sa0 at ciss0 bus 32 target 6 lun 0
sa0: <QUANTUM DLT7000 2255> Removable Sequential Access SCSI-2 device
sa0: 135.168MB/s transfers
da0 at ciss0 bus 0 target 0 lun 0
da0: <COMPAQ RAID 1 VOLUME OK> Fixed Direct Access SCSI-0 device
da0: 135.168MB/s transfers
da0: 34727MB (71122560 512 byte sectors: 255H 32S/T 8716C)
SMP: AP CPU #1 Launched!
Trying to mount root from ufs:/dev/da0s1a
calcru: negative runtime of -1298258 usec for pid 13 (swi4: clock sio)
calcru: negative runtime of -1298243 usec for pid 13 (swi4: clock sio)
calcru: negative runtime of -1298218 usec for pid 13 (swi4: clock sio)
calcru: negative runtime of -1298218 usec for pid 13 (swi4: clock sio)
calcru: negative runtime of -1298201 usec for pid 13 (swi4: clock sio)
calcru: negative runtime of -1298201 usec for pid 13 (swi4: clock sio)
calcru: negative runtime of -1298201 usec for pid 13 (swi4: clock sio)
calcru: negative runtime of -1298201 usec for pid 13 (swi4: clock sio)
calcru: negative runtime of -1297853 usec for pid 13 (swi4: clock sio)
calcru: negative runtime of -1297853 usec for pid 13 (swi4: clock sio)
... etc.
calcru: negative runtime of -1273295 usec for pid 3660 (hpasmd)
calcru: runtime went backwards from 6470361 usec to 5829070 usec for pid 995 (postgres)
calcru: negative runtime of -1098784 usec for pid 36 (pagedaemon)
calcru: negative runtime of -5926871 usec for pid 35 (fdc0)
calcru: negative runtime of -1526724 usec for pid 32 (acpi_cooling0)
calcru: runtime went backwards from 8015143 usec to 1450174 usec for pid 15 (yarrow)
calcru: negative runtime of -12349712 usec for pid 2 (g_event)
calcru: negative runtime of -2105724281 usec for pid 13 (swi4: clock sio)
calcru: runtime went backwards from 295074296 usec to 292484248 usec for pid 1 (init)
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20070902012446.GA17048>