From owner-freebsd-stable@FreeBSD.ORG Mon Oct 8 04:02:47 2012 Return-Path: Delivered-To: freebsd-stable@FreeBSD.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id 53926106566B; Mon, 8 Oct 2012 04:02:47 +0000 (UTC) (envelope-from jmg@h2.funkthat.com) Received: from h2.funkthat.com (gate2.funkthat.com [208.87.223.18]) by mx1.freebsd.org (Postfix) with ESMTP id 18CAE8FC16; Mon, 8 Oct 2012 04:02:46 +0000 (UTC) Received: from h2.funkthat.com (localhost [127.0.0.1]) by h2.funkthat.com (8.14.3/8.14.3) with ESMTP id q9842d0R083016 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Sun, 7 Oct 2012 21:02:39 -0700 (PDT) (envelope-from jmg@h2.funkthat.com) Received: (from jmg@localhost) by h2.funkthat.com (8.14.3/8.14.3/Submit) id q9842deT083015; Sun, 7 Oct 2012 21:02:39 -0700 (PDT) (envelope-from jmg) Date: Sun, 7 Oct 2012 21:02:39 -0700 From: John-Mark Gurney To: freebsd-stable@FreeBSD.org Message-ID: <20121008040239.GE1967@funkthat.com> Mail-Followup-To: freebsd-stable@FreeBSD.org Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline User-Agent: Mutt/1.4.2.3i X-Operating-System: FreeBSD 7.2-RELEASE i386 X-PGP-Fingerprint: 54BA 873B 6515 3F10 9E88 9322 9CB1 8F74 6D3F A396 X-Files: The truth is out there X-URL: http://resnet.uoregon.edu/~gurney_j/ X-Resume: http://resnet.uoregon.edu/~gurney_j/resume.html X-to-the-FBI-CIA-and-NSA: HI! HOW YA DOIN? can i haz chizburger? X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.2.2 (h2.funkthat.com [127.0.0.1]); Sun, 07 Oct 2012 21:02:39 -0700 (PDT) Cc: Subject: time keeps on slipping... slipping... X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 08 Oct 2012 04:02:47 -0000 I recently put together a new machine w/ a SuperMicro H8SCM and an AMD Opteron 4228 HE... I've having an issue where the clock on the machine skips around... The wierd part is that it's very sudden when it happens... ntp sometimes brings it back, but it can't when the clock gets too far ahread (1000 seconds), ntp dies... In order to catch it happening, I ran a sleep 60 loop fetching time from another server that keeps time correctly via: while sleep 60; do echo -n h2:; nc h2 13; date; ntpdate h2.funkthat.com; done here are some snippits: h2:Sun Oct 7 17:12:54 2012^M Sun Oct 7 17:12:54 PDT 2012 7 Oct 17:12:54 ntpdate[31036]: the NTP socket is in use, exiting h2:Sun Oct 7 17:13:48 2012^M Sun Oct 7 17:20:21 PDT 2012 7 Oct 17:20:21 ntpdate[31045]: the NTP socket is in use, exiting but then ntp brings it back in sync: h2:Sun Oct 7 17:28:49 2012^M Sun Oct 7 17:35:21 PDT 2012 7 Oct 17:35:21 ntpdate[31164]: the NTP socket is in use, exiting h2:Sun Oct 7 17:29:49 2012^M Sun Oct 7 17:29:49 PDT 2012 7 Oct 17:29:49 ntpdate[31170]: the NTP socket is in use, exiting It happens pretty often: Oct 7 00:19:13 gold ntpd[3721]: time reset -785.347912 s Oct 7 00:46:37 gold ntpd[3721]: time reset -392.673256 s Oct 7 01:04:24 gold ntpd[3721]: time reset -785.346533 s Oct 7 15:00:59 gold ntpd[3721]: time reset -392.681720 s Oct 7 16:32:11 gold ntpd[3721]: time reset -392.671268 s Oct 7 17:29:29 gold ntpd[3721]: time reset -392.671752 s Oct 7 18:04:37 gold ntpd[3721]: time reset -785.346987 s but as you can see above, the time slip happens abruptly.. looks like a rounding error or something... I'm now reducing the sleep to 5 seconds... but as you can see the sleep ends a few seconds early and local time suddenly jumped forward 6 minutes 33 seconds... $ sysctl kern.timecounter kern.timecounter.fast_gettime: 1 kern.timecounter.tick: 1 kern.timecounter.choice: TSC-low(1000) ACPI-safe(850) HPET(950) i8254(0) dummy(-1000000) kern.timecounter.hardware: TSC-low kern.timecounter.stepwarnings: 0 kern.timecounter.tc.i8254.mask: 65535 kern.timecounter.tc.i8254.counter: 11598 kern.timecounter.tc.i8254.frequency: 1193182 kern.timecounter.tc.i8254.quality: 0 kern.timecounter.tc.HPET.mask: 4294967295 kern.timecounter.tc.HPET.counter: 3257069245 kern.timecounter.tc.HPET.frequency: 14318180 kern.timecounter.tc.HPET.quality: 950 kern.timecounter.tc.ACPI-safe.mask: 16777215 kern.timecounter.tc.ACPI-safe.counter: 4219134510 kern.timecounter.tc.ACPI-safe.frequency: 3579545 kern.timecounter.tc.ACPI-safe.quality: 850 kern.timecounter.tc.TSC-low.mask: 4294967295 kern.timecounter.tc.TSC-low.counter: 2854866610 kern.timecounter.tc.TSC-low.frequency: 10937740 kern.timecounter.tc.TSC-low.quality: 1000 kern.timecounter.smp_tsc: 1 kern.timecounter.invariant_tsc: 1 $ sysctl kern.eventtimer kern.eventtimer.choice: LAPIC(400) i8254(100) RTC(0) kern.eventtimer.et.LAPIC.flags: 15 kern.eventtimer.et.LAPIC.frequency: 100002217 kern.eventtimer.et.LAPIC.quality: 400 kern.eventtimer.et.i8254.flags: 1 kern.eventtimer.et.i8254.frequency: 1193182 kern.eventtimer.et.i8254.quality: 100 kern.eventtimer.et.RTC.flags: 17 kern.eventtimer.et.RTC.frequency: 32768 kern.eventtimer.et.RTC.quality: 0 kern.eventtimer.periodic: 0 kern.eventtimer.timer: LAPIC kern.eventtimer.activetick: 1 kern.eventtimer.idletick: 0 kern.eventtimer.singlemul: 2 dmesg: Copyright (c) 1992-2012 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 9.1-PRERELEASE #3 r241041M: Sat Sep 29 22:38:03 PDT 2012 jmg@gold.funkthat.com:/usr/src.9stable/sys/amd64/compile/gold amd64 CPU: AMD Opteron(tm) Processor 4228 HE (2800.06-MHz K8-class CPU) Origin = "AuthenticAMD" Id = 0x600f12 Family = 0x15 Model = 0x1 Stepping = 2 Features=0x178bfbff Features2=0x1e98220b AMD Features=0x2e500800 AMD Features2=0x1c9bfff,> TSC: P-state invariant, performance statistics real memory = 17179869184 (16384 MB) avail memory = 16520966144 (15755 MB) Event timer "LAPIC" quality 400 ACPI APIC Table: <111111 APIC1503> FreeBSD/SMP: Multiprocessor System Detected: 6 CPUs FreeBSD/SMP: 1 package(s) x 6 core(s) cpu0 (BSP): APIC ID: 16 cpu1 (AP): APIC ID: 17 cpu2 (AP): APIC ID: 18 cpu3 (AP): APIC ID: 19 cpu4 (AP): APIC ID: 20 cpu5 (AP): APIC ID: 21 ioapic0 irqs 0-23 on motherboard kbd1 at kbdmux0 hpt27xx: RocketRAID 27xx controller driver v1.0 (Sep 28 2012 20:26:23) cryptosoft0: on motherboard acpi0: on motherboard acpi0: Power Button (fixed) acpi0: reservation of fee00000, 1000 (3) failed acpi0: reservation of ffb80000, 80000 (3) failed acpi0: reservation of fec10000, 20 (3) failed acpi0: reservation of 0, a0000 (3) failed acpi0: reservation of 100000, dff00000 (3) failed cpu0: on acpi0 cpu1: on acpi0 cpu2: on acpi0 cpu3: on acpi0 cpu4: on acpi0 cpu5: on acpi0 attimer0: port 0x40-0x43 irq 0 on acpi0 Timecounter "i8254" frequency 1193182 Hz quality 0 Event timer "i8254" frequency 1193182 Hz quality 100 atrtc0: port 0x70-0x71 irq 8 on acpi0 Event timer "RTC" frequency 32768 Hz quality 0 hpet0: iomem 0xfed00000-0xfed003ff on acpi0 Timecounter "HPET" frequency 14318180 Hz quality 950 Timecounter "ACPI-safe" frequency 3579545 Hz quality 850 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 pcib1: irq 16 at device 4.0 on pci0 pci1: on pcib1 hpt27xx0: mem 0xfe8a0000-0xfe8bffff,0xfe8c0000-0xfe8fffff irq 16 at device 0.0 on pci1 hpt27xx: adapter at PCI 1:0:0, IRQ 16 pcib2: irq 17 at device 9.0 on pci0 pci2: on pcib2 em0: port 0xd800-0xd81f mem 0xfe9e0000-0xfe9fffff,0xfe9dc000-0xfe9dffff irq 17 at device 0.0 on pci2 em0: Using MSIX interrupts with 3 vectors em0: Ethernet address: 00:25:90:xx:xx:xx pcib3: irq 18 at device 10.0 on pci0 pci3: on pcib3 em1: port 0xe800-0xe81f mem 0xfeae0000-0xfeafffff,0xfeadc000-0xfeadffff irq 18 at device 0.0 on pci3 em1: Using MSIX interrupts with 3 vectors em1: Ethernet address: 00:25:90:xx:xx:xx ahci0: port 0xc000-0xc007,0xb000-0xb003,0xa000-0xa007,0x9000-0x9003,0x8000-0x800f mem 0xfebfbc00-0xfebfbfff irq 22 at device 17.0 on pci0 ahci0: AHCI v1.10 with 6 3Gbps ports, Port Multiplier supported ahcich0: at channel 0 on ahci0 ahcich1: at channel 1 on ahci0 ahcich2: at channel 2 on ahci0 ahcich3: at channel 3 on ahci0 ahcich4: at channel 4 on ahci0 ahcich5: at channel 5 on ahci0 ohci0: mem 0xfebf9000-0xfebf9fff irq 16 at device 18.0 on pci0 usbus0 on ohci0 ohci1: mem 0xfebfa000-0xfebfafff irq 16 at device 18.1 on pci0 usbus1 on ohci1 ehci0: mem 0xfebfb800-0xfebfb8ff irq 17 at device 18.2 on pci0 usbus2: EHCI version 1.0 usbus2 on ehci0 ohci2: mem 0xfebf7000-0xfebf7fff irq 18 at device 19.0 on pci0 usbus3 on ohci2 ohci3: mem 0xfebf8000-0xfebf8fff irq 18 at device 19.1 on pci0 usbus4 on ohci3 ehci1: mem 0xfebfb400-0xfebfb4ff irq 19 at device 19.2 on pci0 usbus5: EHCI version 1.0 usbus5 on ehci1 pci0: at device 20.0 (no driver attached) atapci0: port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xff00-0xff0f at device 20.1 on pci0 ata1: at channel 1 on atapci0 isab0: at device 20.3 on pci0 isa0: on isab0 pcib4: at device 20.4 on pci0 pci4: on pcib4 vgapci0: mem 0xfc000000-0xfcffffff,0xfdffc000-0xfdffffff,0xfe000000-0xfe7fffff irq 20 at device 4.0 on pci4 ohci4: mem 0xfebf6000-0xfebf6fff irq 18 at device 20.5 on pci0 usbus6 on ohci4 acpi_button0: on acpi0 atkbdc0: port 0x60,0x64 irq 1 on acpi0 atkbd0: irq 1 on atkbdc0 kbd0 at atkbd0 atkbd0: [GIANT-LOCKED] uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0 orm0: at iomem 0xc0000-0xc7fff on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x300> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 ctl: CAM Target Layer loaded acpi_throttle0: on cpu0 hwpstate0: on cpu0 ZFS filesystem version 5 ZFS storage pool version 28 Timecounters tick every 1.000 msec hpt27xx: Attached device index 00 (Path 00 | Target 00 | E0/Sff) 00000000 hpt27xx: Attached device index 01 (Path 01 | Target 00 | E0/Sff) 00000000 hpt27xx: Attached device index 02 (Path 02 | Target 00 | E0/Sff) 00000000 hpt27xx: Attached device index 03 (Path 03 | Target 00 | E0/Sff) 00000000 hpt27xx: Device error information 0x80400002 hpt27xx: Device error information 0x80400002 hpt27xx: Attached device index 40 (Path 05 | Target 00 | E0/Sff) 00000000 hpt27xx: Attached device index 41 (Path 06 | Target 00 | E0/Sff) 00000000 hpt27xx: Attached device index 42 (Path 07 | Target 00 | E0/Sff) 00000000 hpt27xx0: [GIANT-LOCKED] usbus0: 12Mbps Full Speed USB v1.0 usbus1: 12Mbps Full Speed USB v1.0 usbus2: 480Mbps High Speed USB v2.0 usbus3: 12Mbps Full Speed USB v1.0 usbus4: 12Mbps Full Speed USB v1.0 usbus5: 480Mbps High Speed USB v2.0 usbus6: 12Mbps Full Speed USB v1.0 ugen0.1: at usbus0 uhub0: on usbus0 ugen1.1: at usbus1 uhub1: on usbus1 ugen2.1: at usbus2 uhub2: on usbus2 ugen3.1: at usbus3 uhub3: on usbus3 ugen4.1: at usbus4 uhub4: on usbus4 ugen5.1: at usbus5 uhub5: on usbus5 ugen6.1: at usbus6 uhub6: on usbus6 uhub6: 2 ports with 2 removable, self powered uhub0: 3 ports with 3 removable, self powered uhub1: 3 ports with 3 removable, self powered uhub3: 3 ports with 3 removable, self powered uhub4: 3 ports with 3 removable, self powered (probe7:hpt27xx0:0:7:0): INQUIRY. CDB: 12 0 0 0 24 0 (probe7:hpt27xx0:0:7:0): CAM status: Invalid Target ID (probe7:hpt27xx0:0:7:0): Error 22, Unretryable error [lots more hpt27xx probe lines through 254 deleted] da0 at hpt27xx0 bus 0 scbus8 target 0 lun 0 da0: Fixed Direct Access SCSI-0 device da0: 2861588MB (5860533168 512 byte sectors: 255H 63S/T 364801C) da1 at hpt27xx0 bus 0 scbus8 target 1 lun 0 da1: Fixed Direct Access SCSI-0 device da1: 2861588MB (5860533168 512 byte sectors: 255H 63S/T 364801C) da2 at hpt27xx0 bus 0 scbus8 target 2 lun 0 da2: Fixed Direct Access SCSI-0 device da2: 2861588MB (5860533168 512 byte sectors: 255H 63S/T 364801C) da3 at hpt27xx0 bus 0 scbus8 target 3 lun 0 da3: Fixed Direct Access SCSI-0 device da3: 2861588MB (5860533168 512 byte sectors: 255H 63S/T 364801C) da4 at hpt27xx0 bus 0 scbus8 target 4 lun 0 da4: Fixed Direct Access SCSI-0 device da4: 1907729MB (3907029168 512 byte sectors: 255H 63S/T 243201C) da5 at hpt27xx0 bus 0 scbus8 target 5 lun 0 da5: Fixed Direct Access SCSI-0 device da5: 953869MB (1953525168 512 byte sectors: 255H 63S/T 121601C) da6 at hpt27xx0 bus 0 scbus8 target 6 lun 0 da6: Fixed Direct Access SCSI-0 device da6: 1907729MB (3907029168 512 byte sectors: 255H 63S/T 243201C) ada0 at ahcich0 bus 0 scbus0 target 0 lun 0 ada0: ATA-9 SATA 3.x device ada0: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes) ada0: Command Queueing enabled ada0: 122104MB (250069680 512 byte sectors: 16H 63S/T 16383C) ada0: Previously was known as ad0 ada1 at ahcich1 bus 0 scbus1 target 0 lun 0 ada1: ATA-9 SATA 3.x device ada1: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes) ada1: Command Queueing enabled ada1: 122104MB (250069680 512 byte sectors: 16H 63S/T 16383C) ada1: Previously was known as ad1 ada2 at ahcich2 bus 0 scbus2 target 0 lun 0 ada2: ATA-7 SATA 1.x device ada2: 150.000MB/s transfers (SATA 1.x, UDMA6, PIO 8192bytes) ada2: Command Queueing enabled ada2: 953869MB (1953525168 512 byte sectors: 16H 63S/T 16383C) ada2: Previously was known as ad2 ada3 at ahcich3 bus 0 scbus3 target 0 lun 0 ada3: ATA-8 SATA 3.x device ada3: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes) ada3: Command Queueing enabled ada3: 1907729MB (3907029168 512 byte sectors: 16H 63S/T 16383C) ada3: Previously was known as ad3 SMP: AP CPU #1 Launched! SMP: AP CPU #3 Launched! SMP: AP CPU #5 Launched! SMP: AP CPU #2 Launched! SMP: AP CPU #4 Launched! Timecounter "TSC-low" frequency 10937740 Hz quality 1000 Enter passphrase for ada0p3: uhub5: 6 ports with 6 removable, self powered uhub2: 6 ports with 6 removable, self powered Trying to mount root from zfs:zroot []... I have switched my timecounter to HPET to see if things are different... Any clues? -- John-Mark Gurney Voice: +1 415 225 5579 "All that I will do, has been done, All that I have, has not."