From owner-freebsd-questions@freebsd.org Tue Aug 16 11:27:23 2016 Return-Path: Delivered-To: freebsd-questions@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 ABFBBBBC1F4 for ; Tue, 16 Aug 2016 11:27:23 +0000 (UTC) (envelope-from Ephaeton@gmx.net) Received: from mout.gmx.net (mout.gmx.net [212.227.17.21]) (using TLSv1.2 with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "mout.gmx.net", Issuer "TeleSec ServerPass DE-1" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 2136A1BCB for ; Tue, 16 Aug 2016 11:27:22 +0000 (UTC) (envelope-from Ephaeton@gmx.net) Received: from hephaistos.local ([188.193.147.216]) by mail.gmx.com (mrgmx101) with ESMTPSA (Nemesis) id 0Lbi2Z-1atN1s1max-00lFoy for ; Tue, 16 Aug 2016 13:27:15 +0200 Received: by hephaistos.local (Postfix, from userid 1000) id F1521297CDF6; Tue, 16 Aug 2016 13:27:14 +0200 (CEST) Date: Tue, 16 Aug 2016 13:27:14 +0200 From: "Martin S. Weber" To: freebsd-questions@freebsd.org Subject: Re: Losing time like crazy (1s short per 10s) - how to investigate? Message-ID: <20160816112714.GA1241@hephaistos.local> Mail-Followup-To: freebsd-questions@freebsd.org References: <20160816112002.GA3083@hephaistos.local> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20160816112002.GA3083@hephaistos.local> User-Agent: Mutt/1.6.1 (2016-04-27) X-Provags-ID: V03:K0:15j6s4qdP048L6b3gELumHjpak9RGQQMBkQUVnTEuPJ2V9aKvB3 6wwIYCHfs1wb+zqclrP20THIahboacbZq9+zYUTCnEi2xqzfw0m7VBrPry3bjdVxH91TZ3h 10Jl1HksJqvuHROuk7eiFBBlk5sZUkFPWHKfDSp2icQ1BXgRfSVTGFf/WAERxANoAGDcTqK s3tgjVKgynYJfTVw01T/A== X-UI-Out-Filterresults: notjunk:1;V01:K0:pNtt+DVoUMA=:WcKobHQnZbKortSKUrDK+k Fy0/vjhCrumxEMcxPkFCx0sA/cBdCvj/GpUQdhIJ2pjPu1WTu2rL5MAfGHleeHmb1DP7VCmXH AsgKRykV3go3voFTpZ9PCtgbiX9f1IV//i5vzEDoTnRhB3lJySscww8oVkOY1WoTE43ks0gnK eBXjzvTwNo/Ypiv3CzGpZ2q1mxrKlJ9ezv+cPqc6ALHoC6eSMYbSrdcZ4ua7u0WEW4Fm/i08r j5Dd1Tv7Ky2I6xkZjrXuBnT6P9yykk4FJTPymjHmfOqEARKeTh6+1Ef+QZ6wA4ZOWVW7pTKIT hBbglnSrsH+Jceha0WqFYuC6FnO3KZ6Ice6YVchd+yF32D/tj4Iti5A0xHT7LFSBbCHvsLkQW BI31aRX6rs0VJl/SUpF/k2CxssxDPChGR0EV/zO3a53VITOME/BVhC36F5NxTCe4rpZqRvEgO XpPb6Q71hAMCXnBE9lsHCiQerR9iNYb7ys3ngVG+VjJtXeglNodXAl3wG94eYHrP3sgGCKKoQ cbnpt9A0a3Lbq6WVwphgC94hQPg5ttQpPzCPnR5pkjOdZIQFQO3Zn+8l+k92EV2m8UAyVHIyV h7u3nMNUtfRIp4JXqCeg8NrBiJc8mXnh7E1fqLEHB+2XHTGChKbSwrZDCctjaxtZhRuMCqikM cPdwzQ/SM3DYU1qWzymW3zUJwhS0yg/ZRhGjunP7ajV0M3mWxTmlvur7FJa935iM/oCRYx23D 4RLvoO77BPK2iRfT5XnjL1vL3INiEIblvlOFiKioS6PttQSU+X+VLK4SnLw= X-BeenThere: freebsd-questions@freebsd.org X-Mailman-Version: 2.1.22 Precedence: list List-Id: User questions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 16 Aug 2016 11:27:23 -0000 On 2016-08-16 13:20:02, Martin S. Weber wrote: > This is on FreeBSD 10.3-RELEASE-p7. I've only noticed this today, > so I'd suspect this is post the p7 update (although I haven't > investigated in that direction yet). I'm losing roughly a second > per 10 seconds wall time. Look at this crazy guy: > > # ntpd -q ; sleep 10; ntpd -q > 16 Aug 13:12:52 ntpd[48425]: ntpd 4.2.8p8-a (1): Starting > (...) > 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:06 ntpd[48426]: ntpd: time set +1.218972 s > ntpd: time set +1.218972s > > This is a CRAZY amount of skew. I've never noticed this before -- > (...) Note, with (kernel) p4 (userland) p6 (I freebsd-update'd rollback) this does not happen: # ntpd -q ; sleep 10 ; ntpd -q 16 Aug 13:24:05 ntpd[1198]: ntpd 4.2.8p8-a (1): Starting 16 Aug 13:24:05 ntpd[1198]: Command line: ntpd -q 16 Aug 13:24:05 ntpd[1198]: proto: precision = 0.260 usec (-22) 16 Aug 13:24:05 ntpd[1198]: leapsecond file ('/var/db/ntpd.leap-seconds.list'): good hash signature 16 Aug 13:24:05 ntpd[1198]: leapsecond file ('/var/db/ntpd.leap-seconds.list'): loaded, expire=2016-12-28T00:00:00Z last=2015-07-01T00:00:00Z ofs=36 16 Aug 13:24:05 ntpd[1198]: Listen and drop on 0 v6wildcard [::]:123 16 Aug 13:24:05 ntpd[1198]: Listen and drop on 1 v4wildcard 0.0.0.0:123 16 Aug 13:24:05 ntpd[1198]: Listen normally on 2 em0 10.10.1.79:123 16 Aug 13:24:05 ntpd[1198]: Listen normally on 3 lo0 [::1]:123 16 Aug 13:24:05 ntpd[1198]: Listen normally on 4 lo0 [fe80::1%2]:123 16 Aug 13:24:05 ntpd[1198]: Listen normally on 5 lo0 127.0.0.1:123 16 Aug 13:24:05 ntpd[1198]: Listening on routing socket on fd #26 for interface updates 16 Aug 13:24:06 ntpd[1198]: ntpd: time slew +0.008026 s ntpd: time slew +0.008026s 16 Aug 13:24:16 ntpd[1201]: ntpd 4.2.8p8-a (1): Starting 16 Aug 13:24:16 ntpd[1201]: Command line: ntpd -q 16 Aug 13:24:16 ntpd[1201]: proto: precision = 0.255 usec (-22) 16 Aug 13:24:16 ntpd[1201]: leapsecond file ('/var/db/ntpd.leap-seconds.list'): good hash signature 16 Aug 13:24:16 ntpd[1201]: leapsecond file ('/var/db/ntpd.leap-seconds.list'): loaded, expire=2016-12-28T00:00:00Z last=2015-07-01T00:00:00Z ofs=36 16 Aug 13:24:16 ntpd[1201]: Listen and drop on 0 v6wildcard [::]:123 16 Aug 13:24:16 ntpd[1201]: Listen and drop on 1 v4wildcard 0.0.0.0:123 16 Aug 13:24:16 ntpd[1201]: Listen normally on 2 em0 10.10.1.79:123 16 Aug 13:24:16 ntpd[1201]: Listen normally on 3 lo0 [::1]:123 16 Aug 13:24:16 ntpd[1201]: Listen normally on 4 lo0 [fe80::1%2]:123 16 Aug 13:24:16 ntpd[1201]: Listen normally on 5 lo0 127.0.0.1:123 16 Aug 13:24:16 ntpd[1201]: Listening on routing socket on fd #26 for interface updates 16 Aug 13:24:17 ntpd[1201]: ntpd: time slew +0.007526 s ntpd: time slew +0.007526s So, jumping to conclusions, p6->p7 makes all the difference. This is the skew since starting to write THIS email: 16 Aug 13:26:26 ntpd[1251]: ntpd: time slew -0.005940 s Looks way more reasonable to me. Time to PR? Regards, -Martin