From owner-freebsd-bugs@freebsd.org Tue Aug 16 11:38:21 2016 Return-Path: Delivered-To: freebsd-bugs@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 2ECC0BBC582 for ; Tue, 16 Aug 2016 11:38:21 +0000 (UTC) (envelope-from bugzilla-noreply@freebsd.org) Received: from kenobi.freebsd.org (kenobi.freebsd.org [IPv6:2001:1900:2254:206a::16:76]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 1E3D61336 for ; Tue, 16 Aug 2016 11:38:21 +0000 (UTC) (envelope-from bugzilla-noreply@freebsd.org) Received: from bugs.freebsd.org ([127.0.1.118]) by kenobi.freebsd.org (8.15.2/8.15.2) with ESMTP id u7GBcK04045598 for ; Tue, 16 Aug 2016 11:38:20 GMT (envelope-from bugzilla-noreply@freebsd.org) From: bugzilla-noreply@freebsd.org To: freebsd-bugs@FreeBSD.org Subject: [Bug 211897] horrible time skew under 10.3-R-p7 Date: Tue, 16 Aug 2016 11:38:21 +0000 X-Bugzilla-Reason: AssignedTo X-Bugzilla-Type: new X-Bugzilla-Watch-Reason: None X-Bugzilla-Product: Base System X-Bugzilla-Component: kern X-Bugzilla-Version: 10.3-RELEASE X-Bugzilla-Keywords: X-Bugzilla-Severity: Affects Only Me X-Bugzilla-Who: freebsd-bugzilla@ayaken.net X-Bugzilla-Status: New X-Bugzilla-Resolution: X-Bugzilla-Priority: --- X-Bugzilla-Assigned-To: freebsd-bugs@FreeBSD.org X-Bugzilla-Flags: X-Bugzilla-Changed-Fields: bug_id short_desc product version rep_platform op_sys bug_status bug_severity priority component assigned_to reporter cc Message-ID: Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable X-Bugzilla-URL: https://bugs.freebsd.org/bugzilla/ Auto-Submitted: auto-generated MIME-Version: 1.0 X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.22 Precedence: list List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 16 Aug 2016 11:38:21 -0000 https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D211897 Bug ID: 211897 Summary: horrible time skew under 10.3-R-p7 Product: Base System Version: 10.3-RELEASE Hardware: amd64 OS: Any Status: New Severity: Affects Only Me Priority: --- Component: kern Assignee: freebsd-bugs@FreeBSD.org Reporter: freebsd-bugzilla@ayaken.net CC: freebsd-amd64@FreeBSD.org CC: freebsd-amd64@FreeBSD.org With 10.3-R-p7, I lose roughly one second of time every 10 seconds of (real) wall clock time. Look and behold: # ntpd -q ; sleep 10; ntpd -q 16 Aug 13:12:52 ntpd[48425]: ntpd 4.2.8p8-a (1): Starting 16 Aug 13:12:52 ntpd[48425]: Command line: ntpd -q 16 Aug 13:12:52 ntpd[48425]: proto: precision =3D 0.230 usec (-22) 16 Aug 13:12:52 ntpd[48425]: leapsecond file ('/var/db/ntpd.leap-seconds.list'): good hash signature 16 Aug 13:12:52 ntpd[48425]: leapsecond file ('/var/db/ntpd.leap-seconds.list'): loaded, expire=3D2016-12-28T00:00:00Z last=3D2015-07-01T00:00:00Z ofs=3D36 16 Aug 13:12:52 ntpd[48425]: Listen and drop on 0 v6wildcard [::]:123 16 Aug 13:12:52 ntpd[48425]: Listen and drop on 1 v4wildcard 0.0.0.0:123 16 Aug 13:12:52 ntpd[48425]: Listen normally on 2 em0 10.10.1.79:123 16 Aug 13:12:52 ntpd[48425]: Listen normally on 3 lo0 [::1]:123 16 Aug 13:12:52 ntpd[48425]: Listen normally on 4 lo0 [fe80::1%2]:123 16 Aug 13:12:52 ntpd[48425]: Listen normally on 5 lo0 127.0.0.1:123 16 Aug 13:12:52 ntpd[48425]: Listening on routing socket on fd #26 for interface updates 16 Aug 13:12:54 ntpd[48425]: ntpd: time set +0.891676 s ntpd: time set +0.891676s 16 Aug 13:13:04 ntpd[48426]: ntpd 4.2.8p8-a (1): Starting 16 Aug 13:13:04 ntpd[48426]: Command line: ntpd -q 16 Aug 13:13:04 ntpd[48426]: proto: precision =3D 0.229 usec (-22) 16 Aug 13:13:04 ntpd[48426]: leapsecond file ('/var/db/ntpd.leap-seconds.list'): good hash signature 16 Aug 13:13:04 ntpd[48426]: leapsecond file ('/var/db/ntpd.leap-seconds.list'): loaded, expire=3D2016-12-28T00:00:00Z last=3D2015-07-01T00:00:00Z ofs=3D36 16 Aug 13:13:04 ntpd[48426]: Listen and drop on 0 v6wildcard [::]:123 16 Aug 13:13:04 ntpd[48426]: Listen and drop on 1 v4wildcard 0.0.0.0:123 16 Aug 13:13:04 ntpd[48426]: Listen normally on 2 em0 10.10.1.79:123 16 Aug 13:13:04 ntpd[48426]: Listen normally on 3 lo0 [::1]:123 16 Aug 13:13:04 ntpd[48426]: Listen normally on 4 lo0 [fe80::1%2]:123 16 Aug 13:13:04 ntpd[48426]: Listen normally on 5 lo0 127.0.0.1:123 16 Aug 13:13:04 ntpd[48426]: Listening on routing socket on fd #26 for interface updates 16 Aug 13:13:06 ntpd[48426]: ntpd: time set +1.218972 s ntpd: time set +1.218972s some five minutes later: 16 Aug 13:17:58 ntpd[48461]: Listening on routing socket on fd #26 for interface updates 16 Aug 13:18:31 ntpd[48461]: ntpd: time set +32.207535 s ntpd: time set +32.207535s When downgrading from -p7 to -p4(kernel)/-p6(userland), this time skew disappears (i.e., clock's running like it's supposed to). Matthew@ has suggested my hardware might be the culprit, so here's my dmesg= as well: Copyright (c) 1992-2016 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 10.3-RELEASE-p4 #0: Sat May 28 12:23:44 UTC 2016 root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC amd64 FreeBSD clang version 3.4.1 (tags/RELEASE_34/dot1-final 208032) 20140512 CPU: Intel(R) Core(TM) i7-4790K CPU @ 4.00GHz (4000.07-MHz K8-class CPU) Origin=3D"GenuineIntel" Id=3D0x306c3 Family=3D0x6 Model=3D0x3c Steppi= ng=3D3 =20 Features=3D0xbfebfbff =20 Features2=3D0x7ffafbbf AMD Features=3D0x2c100800 AMD Features2=3D0x21 Structured Extended Features=3D0x2fbb XSAVE Features=3D0x1 VT-x: PAT,HLT,MTF,PAUSE,EPT,UG,VPID TSC: P-state invariant, performance statistics real memory =3D 17179869184 (16384 MB) avail memory =3D 16485646336 (15721 MB) Event timer "LAPIC" quality 600 ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 8 CPUs FreeBSD/SMP: 1 package(s) x 4 core(s) x 2 SMT threads cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 1 cpu2 (AP): APIC ID: 2 cpu3 (AP): APIC ID: 3 cpu4 (AP): APIC ID: 4 cpu5 (AP): APIC ID: 5 cpu6 (AP): APIC ID: 6 cpu7 (AP): APIC ID: 7 random: initialized ioapic0 irqs 0-23 on motherboard Cuse4BSD v0.1.36 @ /dev/cuse kbd1 at kbdmux0 acpi0: on motherboard acpi0: Power Button (fixed) cpu0: on acpi0 cpu1: on acpi0 cpu2: on acpi0 cpu3: on acpi0 cpu4: on acpi0 cpu5: on acpi0 cpu6: on acpi0 cpu7: on acpi0 hpet0: iomem 0xfed00000-0xfed003ff on acpi0 Timecounter "HPET" frequency 14318180 Hz quality 950 Event timer "HPET" frequency 14318180 Hz quality 550 atrtc0: port 0x70-0x77 irq 8 on acpi0 Event timer "RTC" frequency 32768 Hz quality 0 attimer0: port 0x40-0x43,0x50-0x53 irq 0 on acpi0 Timecounter "i8254" frequency 1193182 Hz quality 0 Event timer "i8254" frequency 1193182 Hz quality 100 Timecounter "ACPI-fast" frequency 3579545 Hz quality 900 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1808-0x180b on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 pcib1: irq 16 at device 1.0 on pci0 pci1: on pcib1 vgapci0: port 0xe000-0xe07f mem 0xf6000000-0xf6ffffff,0xe0000000-0xefffffff,0xf0000000-0xf1ffffff irq 16 at device 0.0 on pci1 nvidia0: on vgapci0 vgapci0: child nvidia0 requested pci_enable_io vgapci0: child nvidia0 requested pci_enable_io vgapci0: Boot video device hdac0: mem 0xf7080000-0xf7083fff irq 17 at device 0.1 on pci1 xhci0: mem 0xf7120000-0xf712ffff i= rq 16 at device 20.0 on pci0 xhci0: 32 bytes context size, 64-bit DMA xhci0: Port routing mask set to 0xffffffff usbus0 on xhci0 pci0: at device 22.0 (no driver attached) em0: port 0xf040-0xf05f mem 0xf7100000-0xf711ffff,0xf7138000-0xf7138fff irq 20 at device 25.0 on pci0 em0: Using an MSI interrupt em0: Ethernet address: 74:d4:35:e8:9f:6d ehci0: mem 0xf7137000-0xf713= 73ff irq 16 at device 26.0 on pci0 usbus1: EHCI version 1.0 usbus1 on ehci0 hdac1: mem 0xf7130000-0xf7133fff irq 2= 2 at device 27.0 on pci0 pcib2: irq 16 at device 28.0 on pci0 pci2: on pcib2 pcib3: irq 19 at device 28.3 on pci0 pci3: on pcib3 pcib4: irq 19 at device 0.0 on pci3 pci4: on pcib4 ehci1: mem 0xf7136000-0xf713= 63ff irq 23 at device 29.0 on pci0 usbus2: EHCI version 1.0 usbus2 on ehci1 isab0: at device 31.0 on pci0 isa0: on isab0 ahci0: port 0xf090-0xf097,0xf080-0xf083,0xf070-0xf077,0xf060-0xf063,0xf020-0xf03f mem 0xf7135000-0xf71357ff irq 19 at device 31.2 on pci0 ahci0: AHCI v1.30 with 6 6Gbps ports, Port Multiplier not 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 ahciem0: on ahci0 acpi_button0: on acpi0 acpi_button1: on acpi0 acpi_tz0: on acpi0 acpi_tz1: on acpi0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=3D0x300> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 atkbdc0: at port 0x60,0x64 on isa0 atkbd0: irq 1 on atkbdc0 kbd0 at atkbd0 atkbd0: [GIANT-LOCKED] ppc0: cannot reserve I/O port range est0: on cpu0 est1: on cpu1 est2: on cpu2 est3: on cpu3 est4: on cpu4 est5: on cpu5 est6: on cpu6 est7: on cpu7 Timecounters tick every 1.000 msec hdacc0: at cad 0 on hdac0 hdaa0: at nid 1 on hdacc0 pcm0: at nid 4 on hdaa0 pcm1: at nid 5 on hdaa0 pcm2: at nid 6 on hdaa0 pcm3: at nid 7 on hdaa0 hdacc1: at cad 2 on hdac1 hdaa1: at nid 1 on hdacc1 pcm4: at nid 20,22,21 and 24,26 on hdaa1 pcm5: at nid 27 and 25 on hdaa1 pcm6: at nid 17 on hdaa1 pcm7: at nid 30 on hdaa1 random: unblocking device. usbus0: 5.0Gbps Super Speed USB v3.0 usbus1: 480Mbps High Speed USB v2.0 usbus2: 480Mbps High Speed USB v2.0 ugen1.1: at usbus1 uhub0: on usbus1 ugen0.1: <0x8086> at usbus0 uhub1: <0x8086 XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0 ugen2.1: at usbus2 uhub2: on usbus2 ada0 at ahcich0 bus 0 scbus0 target 0 lun 0 ada0: ATA8-ACS SATA 3.x device ada0: Serial Number 7E4920015823 ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 512bytes) ada0: Command Queueing enabled ada0: 244198MB (500118192 512 byte sectors) ada0: Previously was known as ad4 ada1 at ahcich1 bus 0 scbus1 target 0 lun 0 ada1: ACS-2 ATA SATA 3.x device ada1: Serial Number Z4Z1SGN2 ada1: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 8192bytes) ada1: Command Queueing enabled ada1: 1907729MB (3907029168 512 byte sectors) ada1: quirks=3D0x1<4K> ada1: Previously was known as ad6 ada2 at ahcich4 bus 0 scbus4 target 0 lun 0 ada2: ACS-2 ATA SATA 3.x device ada2: Serial Number S21HNXBG402860T ada2: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 512bytes) ada2: Command Queueing enabled ada2: 476940MB (976773168 512 byte sectors) ada2: quirks=3D0x1<4K> ada2: Previously was known as ad12 ses0 at ahciem0 bus 0 scbus6 target 0 lun 0 ses0: SEMB S-E-S 2.00 device ses0: SEMB SES Device cd0 at ahcich3 bus 0 scbus3 target 0 lun 0 cd0: Removable CD-ROM SCSI device cd0: Serial Number R93E68DFB01WVT cd0: 150.000MB/s transfers (SATA 1.x, UDMA5, ATAPI 12bytes, PIO 8192bytes) cd0: Attempt to query device size failed: NOT READY, Medium not present - t= ray closed SMP: AP CPU #1 Launched! SMP: AP CPU #3 Launched! SMP: AP CPU #2 Launched! SMP: AP CPU #6 Launched! SMP: AP CPU #7 Launched! SMP: AP CPU #4 Launched! SMP: AP CPU #5 Launched! Timecounter "TSC-low" frequency 2000036900 Hz quality 1000 Root mount waiting for: usbus2 usbus1 usbus0 uhub2: 2 ports with 2 removable, self powered uhub0: 2 ports with 2 removable, self powered uhub1: 21 ports with 21 removable, self powered Root mount waiting for: usbus2 usbus1 usbus0 ugen0.2: at usbus0 ukbd0: on usbus0 kbd2 at ukbd0 ugen2.2: at usbus2 uhub3: on usbus2 ugen1.2: at usbus1 uhub4: on usbus1 uhub4: 6 ports with 6 removable, self powered uhub3: 8 ports with 8 removable, self powered ugen0.3: at usbus0 Root mount waiting for: usbus0 ugen0.4: at usbus0 ugen0.5: at usbus0 Trying to mount root from ufs:/dev/ada2p2 [rw]... uhid0: on usbus0 ukbd0: at uhub1, port 5, addr 1 (disconnected) ums0: on usbus0 uhid0: at uhub1, port 5, addr 1 (disconnected) ums0: 5 buttons and [XYZT] coordinates ID=3D16 ums0: 0 buttons and [T] coordinates ID=3D0 uaudio0: on usbus0 uaudio0: Play: 48000 Hz, 2 ch, 16-bit S-LE PCM format, 2x8ms buffer. uaudio0: Play: 44100 Hz, 2 ch, 16-bit S-LE PCM format, 2x8ms buffer. uaudio0: Play: 32000 Hz, 2 ch, 16-bit S-LE PCM format, 2x8ms buffer. uaudio0: No recording. uaudio0: No MIDI sequencer. pcm8: on uaudio0 uaudio0: HID volume keys found. kbd2 at vkbd0 ums0: at uhub1, port 6, addr 2 (disconnected) kbd3 at vkbd1 kbd4 at vkbd2 kbd5 at vkbd3 em0: link state changed to UP These are my running services: # service -e /etc/rc.d/hostid /etc/rc.d/hostid_save /etc/rc.d/cleanvar /etc/rc.d/ip6addrctl /etc/rc.d/devd /etc/rc.d/newsyslog /etc/rc.d/syslogd /etc/rc.d/dmesg /etc/rc.d/virecover /usr/local/etc/rc.d/apcupsd /usr/local/etc/rc.d/uhidd /etc/rc.d/motd /etc/rc.d/ntpd /etc/rc.d/powerd /usr/local/etc/rc.d/postfix /usr/local/etc/rc.d/dbus /etc/rc.d/mixer /usr/local/etc/rc.d/microcode_update /usr/local/etc/rc.d/hald /etc/rc.d/sshd /etc/rc.d/cron /etc/rc.d/gptboot /etc/rc.d/bgfsck My ports are up-to-date (ports head sucked & built & installed as of "earli= er today") --=20 You are receiving this mail because: You are the assignee for the bug.=