Solved Really bad clock skew after upgrade

U

Unixnut

Hi all,

I recently upgraded my main server to 13.0-RELEASE-p4, and since then I have noticed the clock can't keep sync. It has drifted as much as 12 hours out of sync, despite ntpd running.

After investigating further, it seems that the clock will drift about 3.5 seconds every minute. I have tried with ntpd enabled and disabled, with no change.

At the moment I am forcing the machine into approximate time keeping using the below (which also illustrates the drift over 2 mins):

Code: 
root@Mnemosyne:~ # perl -e "while(1) { system('ntpdate chronos'); sleep(120); } "
 3 Sep 09:34:22 ntpdate[57112]: step time server 192.168.42.200 offset +12.480596 sec
 3 Sep 09:36:35 ntpdate[3822]: step time server 192.168.42.200 offset +6.933638 sec
 3 Sep 09:38:48 ntpdate[46086]: step time server 192.168.42.200 offset +6.925549 sec
 3 Sep 09:41:02 ntpdate[91641]: step time server 192.168.42.200 offset +7.160535 sec
 3 Sep 09:43:15 ntpdate[35922]: step time server 192.168.42.200 offset +6.705718 sec
 3 Sep 09:45:28 ntpdate[83972]: step time server 192.168.42.200 offset +7.150969 sec
 3 Sep 09:47:41 ntpdate[26272]: step time server 192.168.42.200 offset +7.038713 sec
 3 Sep 09:49:54 ntpdate[86971]: step time server 192.168.42.200 offset +6.595963 sec
 3 Sep 09:52:07 ntpdate[30945]: step time server 192.168.42.200 offset +7.259224 sec
 3 Sep 09:54:20 ntpdate[73020]: step time server 192.168.42.200 offset +6.710433 sec
 3 Sep 09:56:33 ntpdate[21868]: step time server 192.168.42.200 offset +6.813922 sec
 3 Sep 09:58:46 ntpdate[62818]: step time server 192.168.42.200 offset +6.925944 sec
 3 Sep 10:00:59 ntpdate[15254]: step time server 192.168.42.200 offset +7.038149 sec
 3 Sep 10:03:12 ntpdate[55843]: step time server 192.168.42.200 offset +6.819024 sec
 3 Sep 10:05:25 ntpdate[97260]: step time server 192.168.42.200 offset +6.926079 sec
 3 Sep 10:07:39 ntpdate[38818]: step time server 192.168.42.200 offset +7.146834 sec
 3 Sep 10:09:52 ntpdate[81000]: step time server 192.168.42.200 offset +7.037698 sec
 3 Sep 10:12:05 ntpdate[29782]: step time server 192.168.42.200 offset +6.819971 sec
 3 Sep 10:14:18 ntpdate[70384]: step time server 192.168.42.200 offset +6.931456 sec
 3 Sep 10:16:31 ntpdate[15662]: step time server 192.168.42.200 offset +6.927489 sec
 3 Sep 10:18:44 ntpdate[57086]: step time server 192.168.42.200 offset +6.817528 sec
 3 Sep 10:20:57 ntpdate[2895]: step time server 192.168.42.200 offset +6.813379 sec

Has anyone seen this before? The closest I have found when searching is this thread:

forums.freebsd.org

Terrible clock skew

Hi everyone, I've been experiencing some terrible clock skew and just can't figure it out. By terrible I mean I'm losing 30 minutes a day. The loss only occurs when I bring the system under heavy load. The load is multiple Rsync backups to a ZFS pool(with gzip compression) backed by a 16 disk...
forums.freebsd.org forums.freebsd.org

However that seems to be temperature related. In my case the above happens whether my system is at 20C (near idle) and 60C (fully loaded), so it is not temperature related in my case.

Not sure what the problem is. The only change is the upgrade, and a reboot which was requested as part of the upgrade (the machine has been running non stop for almost a year beforehand).
 
Does ntpd ever sync?
What servers are you trying to talk to, can you actually reach them and are they stable?
The "running non stop for almost a year", what version did you upgrade from?
If this machine only needs to act as a client, can you install and configure openntpd? From a client perspective is is much simpler, simpler config.
You may want to stop ntpd, rm /var/db/ntpd.drift /var/db/ntp/ntpd.drift then restart ntpd.

I've run into cases in the past where an existing drift file mucks things up a bit.

You may want to provide a bit more information about the hardware.
 
> Does ntpd ever sync?

Yes, on start up "ntpd -g" is run so it syncs up. It starts with an accurate time, then just drifts.

> What servers are you trying to talk to, can you actually reach them and are they stable?

The Server is "Chronos", it is a local stratum-1 machine, serving 28 other clients with no issues with timekeeping

> The "running non stop for almost a year", what version did you upgrade from?

FreeBSD 12.2-RELEASE-p9

> If this machine only needs to act as a client, can you install and configure openntpd? From a client perspective is is much simpler, simpler config.

I can try, but if ntpd has worked so well so far, why would there be an issue with the config?

> You may want to stop ntpd, rm /var/db/ntpd.drift /var/db/ntp/ntpd.drift then restart ntpd.

I shall try this, as I have not done so yet.

> You may want to provide a bit more information about the hardware.

Hardware is a ASUS M5A78L-M/USB3 Motherboard, with an AMD FX 6-core processor, 16GB of RAM. Machine is used as a File server (ZFS) and host for jails.
 
The openntpd was just a suggestion, help try and rule things out. If ntpd from base worked fine, then yes, of course the config should be fine.
I'm at my limit on help, but the drift file stuff I've seen give weird problems in the past.

I wonder if there may be some kind of power state that happens, causing throttling of something or just "not an update" of the clock.
I'm sure others with more knowledge or ideas will chime in when they see the thread.
 
No, suggestions are welcome, so thanks for your input. In fact, removing the drift file seems to have fixed the issue. With ntpd running, over 10 mins there has been no clock skew:


Code: 
root@Mnemosyne:~ # perl -e "while(1) { system('date'); sleep(120); } "
Fri Sep  3 11:05:50 BST 2021
Fri Sep  3 11:07:50 BST 2021
Fri Sep  3 11:09:50 BST 2021
Fri Sep  3 11:11:50 BST 2021
Fri Sep  3 11:13:50 BST 2021

Although now I suspect that ntpd was masking the issue before. If I disable ntpd, the clock skew returns. I would expect the clock to not drift so widely without ntp sync. If I bring the stratrum 1 machine down for any reason, it means this server will rapidly go out of time sync.
 
  • Like
Reactions: mer
That is interesting what happens when you stop ntpd.
About the only thing I can think of is power state somehow. Maybe double check whatever services are running, anything like powerd or equivalent stop them. There may be something in logfile/dmesg indicating changes.

Saving cost on the electric bill is always a good thing, but not at the cost of other failures. I like power saving on laptops when on battery, but servers and desktops/laptops plugged into AC, I'd rather have them run full bore.
 
So, I decided to disable ntpd on two of my Freebsd machines, Mnemosyne, and Athena (Dual 6 core Opteron, 32GB ECC RAM - still on FreeBSD 12.2-RELEASE-p9). Over a 10 minute period the clock skew was very different:

Code: 
root@Mnemosyne:~ # perl -e "while(1) { system('ntpdate chronos'); sleep(120); } "
 3 Sep 11:20:52 ntpdate[32366]: step time server 192.168.42.200 offset +6.190943 sec
 3 Sep 11:23:06 ntpdate[80893]: step time server 192.168.42.200 offset +6.932335 sec
 3 Sep 11:25:19 ntpdate[26599]: step time server 192.168.42.200 offset +6.934450 sec
 3 Sep 11:27:31 ntpdate[69540]: step time server 192.168.42.200 offset +6.601500 sec
 3 Sep 11:29:45 ntpdate[8784]: step time server 192.168.42.200 offset +7.151887 sec


Code: 
root@athena:~ # perl -e "while(1) { system('ntpdate chronos'); sleep(120); } "
 3 Sep 11:21:07 ntpdate[1817]: adjust time server 192.168.42.200 offset +0.000883 sec
 3 Sep 11:23:13 ntpdate[1828]: adjust time server 192.168.42.200 offset -0.000487 sec
 3 Sep 11:25:19 ntpdate[1833]: adjust time server 192.168.42.200 offset -0.001832 sec
 3 Sep 11:27:25 ntpdate[1834]: adjust time server 192.168.42.200 offset -0.000262 sec
 3 Sep 11:29:31 ntpdate[1835]: adjust time server 192.168.42.200 offset -0.001975 sec

As can be seen, Athena keeps time much better over the 10 minute period without ntp sync, compared to Mnemosyne. Digging further to see why this may be the case.
 
  • Like
Reactions: mer
mer said:
That is interesting what happens when you stop ntpd.
About the only thing I can think of is power state somehow. Maybe double check whatever services are running, anything like powerd or equivalent stop them. There may be something in logfile/dmesg indicating changes.

Saving cost on the electric bill is always a good thing, but not at the cost of other failures. I like power saving on laptops when on battery, but servers and desktops/laptops plugged into AC, I'd rather have them run full bore.
Click to expand...

Yes, I agree, and for the purposes of debugging I have disabled power saving on the machine, but it had no effect on the clock skew.
 
Well after more digging through the forums, I have come across this post:

forums.freebsd.org

Upgrade from 9.1 to 9.2 clock issue

I just upgraded three nearly identical servers (Intel sr1500 chassis) from 9.1-RELEASE to 9.2-RELEASE using freebsd-update Since the upgrade, two of the three cannot keep time properly. Even with ntpd running. Of the two having problems they list four clocks: Timecounter "i8254" frequency...
forums.freebsd.org forums.freebsd.org

From that I learnt a bit about how timers work in FreeBSD, so I decided to compare how the timers are configured on my two machines:

Code: 
root@Mnemosyne:~ # grep -r Timecounter /var/log/
/var/log/dmesg.yesterday:Timecounter "TSC-low" frequency 1854480622 Hz quality 1000
/var/log/dmesg.yesterday:Timecounter "i8254" frequency 1193182 Hz quality 0
/var/log/dmesg.yesterday:Timecounter "HPET" frequency 14318180 Hz quality 950
/var/log/dmesg.yesterday:Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
/var/log/dmesg.yesterday:Timecounters tick every 1.000 msec
root@Mnemosyne:~ # sysctl kern.timecounter.hardware
kern.timecounter.hardware: TSC-low


Code: 
root@athena:~ # grep -r Timecounter /var/log/
/var/log/messages:Sep  3 08:44:15 athena kernel: Timecounter "TSC" frequency 2009299370 Hz quality 800
/var/log/messages:Sep  3 08:44:15 athena kernel: Timecounter "i8254" frequency 1193182 Hz quality 0
/var/log/messages:Sep  3 08:44:15 athena kernel: Timecounter "HPET" frequency 25000000 Hz quality 950
/var/log/messages:Sep  3 08:44:15 athena kernel: Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
/var/log/messages:Sep  3 08:44:15 athena kernel: Timecounters tick every 1.000 msec
root@athena:~ # sysctl kern.timecounter.hardware
kern.timecounter.hardware: HPET

It seems that they have different settings for "kern.timecounter.hardware". The thread posted above mentions that HPET fixed the issue for them, so as a test, I have decided to switch Mnemosyne to using HPET.

Will now test and post an update in about 10 mins.
 
  • Like
Reactions: mer
Yep, that seems to have fixed the issue, both machines are now within acceptable parameters:

Code: 
root@Mnemosyne:~ # perl -e "while(1) { system('ntpdate chronos'); sleep(120); } "
 3 Sep 11:39:33 ntpdate[17048]: adjust time server 192.168.42.200 offset +0.001258 sec
 3 Sep 11:41:39 ntpdate[60466]: adjust time server 192.168.42.200 offset +0.003599 sec
 3 Sep 11:43:46 ntpdate[5206]: adjust time server 192.168.42.200 offset +0.002759 sec
 3 Sep 11:45:52 ntpdate[68037]: adjust time server 192.168.42.200 offset +0.003268 sec
 3 Sep 11:47:58 ntpdate[11045]: adjust time server 192.168.42.200 offset +0.002819 sec
 3 Sep 11:50:04 ntpdate[51577]: adjust time server 192.168.42.200 offset +0.001046 sec
 3 Sep 11:52:10 ntpdate[96755]: adjust time server 192.168.42.200 offset +0.003147 sec

Code: 
root@athena:~ # perl -e "while(1) { system('ntpdate chronos'); sleep(120); } "
 3 Sep 11:39:34 ntpdate[1859]: adjust time server 192.168.42.200 offset -0.001840 sec
 3 Sep 11:41:40 ntpdate[1864]: adjust time server 192.168.42.200 offset +0.001976 sec
 3 Sep 11:43:46 ntpdate[1865]: adjust time server 192.168.42.200 offset +0.000426 sec
 3 Sep 11:45:52 ntpdate[1884]: adjust time server 192.168.42.200 offset +0.001496 sec
 3 Sep 11:47:58 ntpdate[1885]: adjust time server 192.168.42.200 offset +0.000762 sec
 3 Sep 11:50:05 ntpdate[1886]: adjust time server 192.168.42.200 offset -0.001096 sec
 3 Sep 11:52:11 ntpdate[1891]: adjust time server 192.168.42.200 offset +0.001073 sec

So the issue was with using "TSC-low" as the HW timer. What I don't know is why this would change. On athena HPET has a higher quality, but on Mnemosyne TSC-low has a higher quality, making FreeBSD choose that as its clock source.

I don't know if "quality" is something that is configurable (in which case there may have been a change in defaults from FreeBSD 12 to FreeBSD 13) or it is somehow calculated. Perhaps someone with more knowledge of the innards of FreeBSD can answer that.

I also found this forum thread:
https://forums.freebsd.org/threads/tsc-low-as-timecounter-slows-system-clock-by-a-factor-of-4.68619/

So it seems TSC-low coupled with sleep states on some CPU's causes this issue, although I did disable powerd. Perhaps I needed to disable sleep states in the BIOS to fully correct this issue.

Still, I would rather keep power management if there is a way to keep time sync, so HPET + ntp will be my solution. From my perspective, I think this issue is solved, thanks for your help! :)
 
You must log in or register to reply here.
Back
Top