From owner-freebsd-current@freebsd.org Fri Oct 20 16:32:44 2017 Return-Path: Delivered-To: freebsd-current@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 63D5FE3A3CA for ; Fri, 20 Oct 2017 16:32:44 +0000 (UTC) (envelope-from ian@freebsd.org) Received: from pmta2.delivery6.ore.mailhop.org (pmta2.delivery6.ore.mailhop.org [54.200.129.228]) (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 4572781ECD for ; Fri, 20 Oct 2017 16:32:43 +0000 (UTC) (envelope-from ian@freebsd.org) X-MHO-User: 3091dd6a-b5b4-11e7-b50b-53dc5ecda239 X-Report-Abuse-To: https://support.duocircle.com/support/solutions/articles/5000540958-duocircle-standard-smtp-abuse-information X-Originating-IP: 73.78.92.27 X-Mail-Handler: DuoCircle Outbound SMTP Received: from ilsoft.org (unknown [73.78.92.27]) by outbound2.ore.mailhop.org (Halon) with ESMTPSA id 3091dd6a-b5b4-11e7-b50b-53dc5ecda239; Fri, 20 Oct 2017 16:31:57 +0000 (UTC) Received: from rev (rev [172.22.42.240]) by ilsoft.org (8.15.2/8.15.2) with ESMTP id v9KGWeDq011455; Fri, 20 Oct 2017 10:32:41 -0600 (MDT) (envelope-from ian@freebsd.org) Message-ID: <1508517160.1383.63.camel@freebsd.org> Subject: Re: host, bhyve vm and ntpd From: Ian Lepore To: Boris Samorodov , freebsd-current@FreeBSD.org Date: Fri, 20 Oct 2017 10:32:40 -0600 In-Reply-To: References: <2931f1cc-6574-b58d-4b94-5f77fa5cdb85@passap.ru> <1508512327.1383.55.camel@freebsd.org> <39bf2426-2edf-d485-7c81-519e931154be@passap.ru> Content-Type: text/plain; charset="koi8-r" X-Mailer: Evolution 3.18.5.1 FreeBSD GNOME Team Port Mime-Version: 1.0 Content-Transfer-Encoding: 8bit X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 20 Oct 2017 16:32:44 -0000 On Fri, 2017-10-20 at 18:36 +0300, Boris Samorodov wrote: > 20.10.2017 18:31, Boris Samorodov ΠΙΫΕΤ: > > > > 20.10.2017 18:12, Ian Lepore ΠΙΫΕΤ: > > > > > > On Fri, 2017-10-20 at 14:46 +0300, Boris Samorodov wrote: > > > > > > > > Hi All, > > > > > > > > I have got a host: > > > > --- > > > > bhyve-host% uname -a > > > > FreeBSD sm.bsnet 12.0-CURRENT FreeBSD 12.0-CURRENT #3 r322868: Fri Aug > > > > 25 05:25:26 MSK 2017 > > > > bsam@builder.bsnet:/usr/obj/usr/src/sys/GENERIC-FASTššamd64 amd64 > > > > --- > > > > > > > > And a bhyve vm: > > > > --- > > > > bhyve-vm: uname -a > > > > FreeBSD builder.bsnet 12.0-CURRENT FreeBSD 12.0-CURRENT #58 r324782: Fri > > > > Oct 20 05:12:17 MSK 2017 > > > > bsam@builder.bsnet:/usr/obj/usr/src/sys/PKG64Xššamd64 amd64 > > > > --- > > > > > > > > The only difference at kernel configs is a colored console. :-) > > > > > > > > And here I get some weird (is it?) result at the VM (I expect ntpd to be > > > > more stable): > > > > --- > > > > bhyve-vm% for t in `jot 10`; do ntpq -pn; sleep 64; done > > > > šššššremotešššššššššššrefidššššššst t when poll reachšššdelayšššoffset > > > > jitter > > > > ============================================================================== > > > > šXX.XX.XX.1ššššššXX.XX.XX.245ššššš4 ušššš9ššš64šššš3šššš0.605ššš-1.202 > > > > 316.407 > > > > šXX.XX.XX.1ššššššXX.XX.XX.245ššššš4 ušššš7ššš64šššš7šššš0.605ššš-1.202 > > > > 358.395 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 ušššš5ššš64ššš17šššš0.615šš-328.42 > > > > 181.405 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 ušššš3ššš64ššš37šššš0.615šš-328.42 > > > > 214.868 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš67ššš64ššš37šššš0.615šš-328.42 > > > > 214.868 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš63ššš64ššš77šššš0.615šš-328.42 > > > > 268.618 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš60ššš64šš177šššš0.615šš-328.42 > > > > 333.175 > > > > šXX.XX.XX.1šššššš.STEP.šššššššššš16 u 1910ššš64šššš0šššš0.000šššš0.000 > > > > 0.000 > > > > šXX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš27ššš64šššš1šššš0.703šš-262.63 > > > > 0.004 > > > > šXX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš31ššš64šššš1šššš0.649šš-331.43 > > > > 68.800 > > > > --- > > > > > > > > At the same time host's results are very stable: > > > > --- > > > > bhyve-host% for t in `jot 10`; do ntpq -pn; sleep 64; done > > > > šššššremotešššššššššššrefidššššššst t when poll reachšššdelayšššoffset > > > > jitter > > > > ============================================================================== > > > > > > > > > > > > > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 ušššš1ššš64šššš1šššš0.401šššš0.176 > > > > 0.106 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 ušššš6ššš64šššš3šššš0.401šššš0.176 > > > > 0.459 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 ušššš3ššš64šššš7šššš0.401šššš0.176 > > > > 0.940 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš67ššš64šššš7šššš0.401šššš0.176 > > > > 0.940 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš64ššš64ššš17šššš0.401šššš0.176 > > > > 1.566 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš60ššš64ššš37šššš0.448šššš1.275 > > > > 1.739 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš55ššš64ššš77šššš0.448šššš1.275 > > > > 2.365 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš53ššš64šš177šššš0.448šššš1.275 > > > > 3.110 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš50ššš64šš377šššš0.448šššš1.275 > > > > 3.929 > > > > *XX.XX.XX.1ššššššXX.XX.XX.245ššššš4 uššš45ššš64šš377šššš0.443šššš8.750 > > > > 4.722 > > > > --- > > > > > > > > The network is organized via bridge -- host igb and vm tap interfaces > > > > are members of one bridge. > > > > > > > > Are those results expected? Does it smell like a bug? Should I dig > > > > furter? > > > > > > > So it is repeatedly stepping the clock in the VM? (Set > > > kern.timecounter.stepwarnings=1 to log steps). > > No kernel/ntpd messages for 20 minutes after setting this sysctl. > > > > > > > > šThat is usually a sign > > > that the chosen timecounter is running at a different frequency than it > > > claimed to be when it registered itself -- the host may not be > > > emulating the timer hardware properly in the guest. šWhat is the output > > > of sysctl kern.timecounter in the vm? > > --- > > bhyve-vm% sysctl kern.timecounter > > > > kern.timecounter.tsc_shift: 1 > > kern.timecounter.smp_tsc_adjust: 0 > > kern.timecounter.smp_tsc: 0 > > kern.timecounter.invariant_tsc: 1 > > kern.timecounter.fast_gettime: 1 > > kern.timecounter.tick: 1 > > kern.timecounter.choice: ACPI-fast(900) HPET(950) i8254(0) TSC-low(-100) > > dummy(-1000000) > > kern.timecounter.hardware: HPET > > kern.timecounter.alloweddeviation: 5 > > kern.timecounter.stepwarnings: 1 > > kern.timecounter.tc.ACPI-fast.quality: 900 > > kern.timecounter.tc.ACPI-fast.frequency: 3579545 > > kern.timecounter.tc.ACPI-fast.counter: 4161213491 > > kern.timecounter.tc.ACPI-fast.mask: 4294967295 > > kern.timecounter.tc.HPET.quality: 950 > > kern.timecounter.tc.HPET.frequency: 10000000 > > kern.timecounter.tc.HPET.counter: 3518036865 > > kern.timecounter.tc.HPET.mask: 4294967295 > > kern.timecounter.tc.i8254.quality: 0 > > kern.timecounter.tc.i8254.frequency: 1193182 > > kern.timecounter.tc.i8254.counter: 47597 > > kern.timecounter.tc.i8254.mask: 65535 > > kern.timecounter.tc.TSC-low.quality: -100 > > kern.timecounter.tc.TSC-low.frequency: 1199886114 > > kern.timecounter.tc.TSC-low.counter: 1274338278 > > kern.timecounter.tc.TSC-low.mask: 4294967295 > > --- > BTW, here is the host kern.timecounter: > --- > kern.timecounter.tsc_shift: 1 > kern.timecounter.smp_tsc_adjust: 0 > kern.timecounter.smp_tsc: 1 > kern.timecounter.invariant_tsc: 1 > kern.timecounter.fast_gettime: 1 > kern.timecounter.tick: 1 > kern.timecounter.choice: ACPI-fast(900) HPET(950) i8254(0) TSC-low(1000) > dummy(-1000000) > kern.timecounter.hardware: TSC-low > kern.timecounter.alloweddeviation: 5 > kern.timecounter.stepwarnings: 0 > kern.timecounter.tc.ACPI-fast.quality: 900 > kern.timecounter.tc.ACPI-fast.frequency: 3579545 > kern.timecounter.tc.ACPI-fast.counter: 9047194 > kern.timecounter.tc.ACPI-fast.mask: 16777215 > kern.timecounter.tc.HPET.quality: 950 > kern.timecounter.tc.HPET.frequency: 14318180 > kern.timecounter.tc.HPET.counter: 2232552795 > kern.timecounter.tc.HPET.mask: 4294967295 > kern.timecounter.tc.i8254.quality: 0 > kern.timecounter.tc.i8254.frequency: 1193182 > kern.timecounter.tc.i8254.counter: 43410 > kern.timecounter.tc.i8254.mask: 65535 > kern.timecounter.tc.TSC-low.quality: 1000 > kern.timecounter.tc.TSC-low.frequency: 1200067168 > kern.timecounter.tc.TSC-low.counter: 2463146362 > kern.timecounter.tc.TSC-low.mask: 4294967295 > --- > > > > > > > > > Also, what is the output of ntptime(8) in the vm? > > --- > > bhyve-vm% ntptime > > > > ntp_gettime() returns code 0 (OK) > > š time dd94930f.20ea2900ššFri, Oct 20 2017 18:21:51.128, (.128573699), > > š maximum error 1309110 us, estimated error 3 us, TAI offset 37 > > ntp_adjtime() returns code 0 (OK) > > š modes 0x0 (), > > š offset 0.000 us, frequency 0.000 ppm, interval 1 s, > > š maximum error 1309110 us, estimated error 3 us, > > š status 0x2001 (PLL,NANO), > > š time constant 6, precision 0.001 us, tolerance 496 ppm, > > --- > > > > Ian, thank you for your help! > > > It seems odd to me that the frequency of the host HPET is 14.3mhz and that of the guest is 10.0mhz, but maybe that's a normal condition for bhyve. šI did find some google hits[1] for bhyve guest timekeeping trouble with the HPET timer which was solved by switching to a different timecounter. šTimecounter choices can't be controlled from loader.conf, so I guess a sysctl.conf entry of kern.timecounter.hardware="ACPI-fast" is the only way to fix that. šYou can also just do that command interactively first and see if it stops the time steps and ntp settles down. This would be a workaround, not a fix per se. šIf the time steps go away, then something in bhyve's emulation of HPET (maybe only on some hardware?) must be buggy. [1] https://lists.freebsd.org/pipermail/freebsd-virtualization/2015-April/003492.html -- Ian