From owner-freebsd-questions@FreeBSD.ORG Sun Sep 2 11:18:07 2007 Return-Path: Delivered-To: freebsd-questions@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id A615C16A418 for ; Sun, 2 Sep 2007 11:18:07 +0000 (UTC) (envelope-from kris@FreeBSD.org) Received: from weak.local (hub.freebsd.org [IPv6:2001:4f8:fff6::36]) by mx1.freebsd.org (Postfix) with ESMTP id EBC2713C459; Sun, 2 Sep 2007 11:18:06 +0000 (UTC) (envelope-from kris@FreeBSD.org) Message-ID: <46DA9BED.20804@FreeBSD.org> Date: Sun, 02 Sep 2007 13:18:05 +0200 From: Kris Kennaway User-Agent: Thunderbird 2.0.0.6 (Macintosh/20070728) MIME-Version: 1.0 To: James Long References: <20070902012446.GA17048@ns.umpquanet.com> In-Reply-To: <20070902012446.GA17048@ns.umpquanet.com> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Cc: freebsd-questions@freebsd.org Subject: Re: Recent update to RELENG_6 creates lots of calcru warnings X-BeenThere: freebsd-questions@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: User questions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 02 Sep 2007 11:18:07 -0000 James Long wrote: > 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 > real memory = 1073725440 (1023 MB) > avail memory = 1037357056 (989 MB) > ACPI APIC Table: > 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 irqs 16-31 on motherboard > ioapic0 irqs 0-15 on motherboard > kbd1 at kbdmux0 > ath_hal: 0.9.20.3 (AR5210, AR5211, AR5212, RF5111, RF5112, RF2413, RF5413) > acpi0: 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: on acpi0 > cpu1: on acpi0 > pcib0: on acpi0 > pci0: on pcib0 > ciss0: port 0x2000-0x20ff mem 0xf5ec0000-0xf5efffff,0xf3ef0000-0xf3ef3fff irq 16 at device 1.0 on pci0 > ciss0: [GIANT-LOCKED] > fxp0: port 0x2400-0x243f mem 0xf5eb0000-0xf5eb0fff,0xf5d00000-0xf5dfffff irq 18 at device 2.0 on pci0 > miibus0: on fxp0 > inphy0: on miibus0 > inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto > fxp0: Ethernet address: 00:02:a5:ad:82:d5 > fxp1: port 0x2440-0x247f mem 0xf5cf0000-0xf5cf0fff,0xf5b00000-0xf5bfffff irq 20 at device 4.0 on pci0 > miibus1: on fxp1 > inphy1: on miibus1 > inphy1: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto > fxp1: Ethernet address: 00:02:a5:ad:82:d4 > pci0: at device 6.0 (no driver attached) > isab0: at device 15.0 on pci0 > isa0: on isab0 > atapci0: port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0x2c00-0x2c0f at device 15.1 on pci0 > ata0: on atapci0 > ata1: on atapci0 > ohci0: 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: 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: on acpi0 > pci1: on pcib1 > pcib2: at device 3.0 on pci1 > pci2: on pcib2 > pci2: at device 0.0 (no driver attached) > pci1: at device 3.1 (no driver attached) > pcib3: on acpi0 > pci7: on pcib3 > pci7: at device 7.0 (no driver attached) > acpi_tz0: on acpi0 > atkbdc0: port 0x60,0x64 irq 1 on acpi0 > atkbd0: irq 1 on atkbdc0 > kbd0 at atkbd0 > atkbd0: [GIANT-LOCKED] > sio0: port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 > sio0: type 16550A > fdc0: 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: at iomem 0xc0000-0xc7fff,0xc8000-0xcbfff,0xcc000-0xcd7ff,0xee000-0xeffff on isa0 > ppc0: parallel port not found. > sc0: 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: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 > Timecounters tick every 1.000 msec > acd0: CDROM at ata0-master PIO4 > sa0 at ciss0 bus 32 target 6 lun 0 > sa0: Removable Sequential Access SCSI-2 device > sa0: 135.168MB/s transfers > da0 at ciss0 bus 0 target 0 lun 0 > da0: 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) > _______________________________________________ > freebsd-questions@freebsd.org mailing list > http://lists.freebsd.org/mailman/listinfo/freebsd-questions > To unsubscribe, send any mail to "freebsd-questions-unsubscribe@freebsd.org" > > Does reverting to the older kernel work? If so, can you isolate which commit caused the problem by doing a binary search of date ranges? This should be easy to do since the rate of changes to RELENG_6 is low. Kris