NTP problem: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
-
I found some threads about this error, but solutions did not worked for me.
Tried
sysctl -w kern.timecounter.hardware=ACPI-fast
, but it did not help any. I reverted back to TSC.My system is pfSense 2.6.0 on bare metal with Intel J4125 CPU. BIOS time and battery is also check'd.
Here is some logs and settings:
May 4 17:18:15 ntpd 85447 Soliciting pool server 193.182.111.13 May 4 17:18:14 ntpd 85447 Soliciting pool server 85.214.38.116 May 4 17:18:13 ntpd 85447 Soliciting pool server 162.159.200.1 May 4 17:18:12 ntpd 85447 0.0.0.0 c016 06 restart May 4 17:18:12 ntpd 85447 0.0.0.0 c011 01 freq_not_set May 4 17:18:12 ntpd 85447 0.0.0.0 c012 02 freq_set kernel 0.000 PPM May 4 17:18:12 ntpd 85447 kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 4 17:18:12 ntpd 85447 0.0.0.0 c01d 0d kern kernel time sync enabled May 4 17:18:12 ntpd 85447 kernel reports TIME_ERROR: 0x41: Clock Unsynchronized May 4 17:18:12 ntpd 85447 0.0.0.0 8811 81 mobilize assoc 51579 May 4 17:18:12 ntpd 85447 0.0.0.0 8811 81 mobilize assoc 51578 May 4 17:18:12 ntpd 85447 0.0.0.0 8811 81 mobilize assoc 51577 May 4 17:18:12 ntpd 85447 Listening on routing socket on fd #29 for interface updates May 4 17:18:12 ntpd 85447 Listen normally on 8 igb1.12 10.14.12.1:123 May 4 17:18:12 ntpd 85447 Listen normally on 7 igb1.12 [fe80::2f1:f3ff:fe1f:fdd3%11]:123 May 4 17:18:12 ntpd 85447 Listen normally on 6 lo0 10.10.10.1:123 May 4 17:18:12 ntpd 85447 Listen normally on 5 lo0 127.0.0.1:123 May 4 17:18:12 ntpd 85447 Listen normally on 4 lo0 [fe80::1%6]:123 May 4 17:18:12 ntpd 85447 Listen normally on 3 lo0 [::1]:123 May 4 17:18:12 ntpd 85447 Listen normally on 2 igb1 10.14.11.2:123 May 4 17:18:12 ntpd 85447 Listen normally on 1 igb1 10.14.11.1:123 May 4 17:18:12 ntpd 85447 Listen normally on 0 igb1 [fe80::2f1:f3ff:fe1f:fdd3%2]:123 May 4 17:18:12 ntpd 85447 gps base set to 2022-01-02 (week 2191) May 4 17:18:12 ntpd 85447 basedate set to 2021-12-31 May 4 17:18:12 ntpd 85447 proto: precision = 0.109 usec (-23) May 4 17:18:12 ntpd 85328 ---------------------------------------------------- May 4 17:18:12 ntpd 85328 available at https://www.nwtime.org/support May 4 17:18:12 ntpd 85328 corporation. Support and training for ntp-4 are May 4 17:18:12 ntpd 85328 Inc. (NTF), a non-profit 501(c)(3) public-benefit May 4 17:18:12 ntpd 85328 ntp-4 is maintained by Network Time Foundation, May 4 17:18:12 ntpd 85328 ---------------------------------------------------- May 4 17:18:12 ntpd 85328 Command line: /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid # ntpq -p remote refid st t when poll reach delay offset jitter ============================================================================== fi.pool.ntp.org .POOL. 16 p - 64 0 0.000 +0.000 0.000 de.pool.ntp.org .POOL. 16 p - 64 0 0.000 +0.000 0.000 se.pool.ntp.org .POOL. 16 p - 64 0 0.000 +0.000 0.000 # ntpq -c rv associd=0 status=c016 leap_alarm, sync_unspec, 1 event, restart, version="ntpd 4.2.8p15@1.3728-o Wed Jan 12 15:39:52 UTC 2022 (1)", processor="amd64", system="FreeBSD/12.3-STABLE", leap=11, stratum=16, precision=-23, rootdelay=0.000, rootdisp=2.295, refid=INIT, reftime=(no time), clock=e61d0a3e.02c71480 Wed, May 4 2022 17:20:46.010, peer=0, tc=3, mintc=3, offset=+0.000000, frequency=+0.000, sys_jitter=0.000000, clk_jitter=0.000, clk_wander=0.000 # cat /var/etc/ntpd.conf tinker panic 0 tos orphan 12 maxclock 5 pool fi.pool.ntp.org iburst maxpoll 9 prefer pool de.pool.ntp.org iburst maxpoll 9 pool se.pool.ntp.org iburst maxpoll 9 statsdir /var/log/ntp logconfig =syncall +clockall +peerall +sysall driftfile /var/db/ntpd.drift restrict default kod limited nomodify nopeer notrap restrict -6 default kod limited nomodify nopeer notrap restrict source kod limited nomodify notrap interface ignore all interface ignore wildcard interface listen igb1 interface listen igb1.12 interface listen lo0 # cat /var/db/ntpd.drift cat: /var/db/ntpd.drift: No such file or directory # host fi.pool.ntp.org fi.pool.ntp.org has address 162.159.200.1 fi.pool.ntp.org has address 162.159.200.123 fi.pool.ntp.org has address 195.148.70.12 fi.pool.ntp.org has address 95.216.138.141 # ntpdate fi.pool.ntp.org 4 May 17:26:57 ntpdate[98867]: adjust time server 95.217.188.206 offset +0.025176 sec
Anything to try?
-
That doesn't look like a problem to me unless you're actually seeing time inaccuracy?
It's normal to see ntpd report that when it first starts.If I restart it here for example:
May 4 16:58:19 ntpd 13097 ntpd exiting on signal 15 (Terminated) May 4 16:58:19 ntpd 13097 81.21.65.168 local addr 172.21.16.206 -> <null> May 4 16:58:19 ntpd 13097 178.62.18.76 local addr 172.21.16.206 -> <null> May 4 16:58:19 ntpd 13097 93.93.131.118 local addr 172.21.16.206 -> <null> May 4 16:58:19 ntpd 13097 178.62.250.107 local addr 172.21.16.206 -> <null> May 4 16:58:19 ntpd 37081 ntpd 4.2.8p15@1.3728-o Wed Mar 23 20:14:42 UTC 2022 (1): Starting May 4 16:58:19 ntpd 37081 Command line: /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid May 4 16:58:19 ntpd 37081 ---------------------------------------------------- May 4 16:58:19 ntpd 37081 ntp-4 is maintained by Network Time Foundation, May 4 16:58:19 ntpd 37081 Inc. (NTF), a non-profit 501(c)(3) public-benefit May 4 16:58:19 ntpd 37081 corporation. Support and training for ntp-4 are May 4 16:58:19 ntpd 37081 available at https://www.nwtime.org/support May 4 16:58:19 ntpd 37081 ---------------------------------------------------- May 4 16:58:19 ntpd 37106 proto: precision = 0.370 usec (-21) May 4 16:58:19 ntpd 37106 basedate set to 2022-03-11 May 4 16:58:19 ntpd 37106 gps base set to 2022-03-13 (week 2201) May 4 16:58:19 ntpd 37106 Listen and drop on 0 v6wildcard [::]:123 May 4 16:58:19 ntpd 37106 Listen and drop on 1 v4wildcard 0.0.0.0:123 May 4 16:58:19 ntpd 37106 Listen normally on 2 igc0 [fe80::92ec:77ff:fe1f:8c3f%1]:123 May 4 16:58:19 ntpd 37106 Listen normally on 3 igc0 192.168.206.1:123 May 4 16:58:19 ntpd 37106 Listen normally on 4 igc0 [fe80::1:1%1]:123 May 4 16:58:19 ntpd 37106 Listen normally on 5 igc1 [fe80::92ec:77ff:fe1f:8c40%2]:123 May 4 16:58:19 ntpd 37106 Listen normally on 6 igc1 10.23.10.1:123 May 4 16:58:19 ntpd 37106 Listen normally on 7 igc2 [fe80::92ec:77ff:fe1f:8c41%3]:123 May 4 16:58:19 ntpd 37106 Listen normally on 8 igc3 [fe80::92ec:77ff:fe1f:8c42%4]:123 May 4 16:58:19 ntpd 37106 Listen normally on 9 ix2 [fe80::92ec:77ff:fe1f:8c3e%7]:123 May 4 16:58:19 ntpd 37106 Listen normally on 10 ix3 [fe80::92ec:77ff:fe1f:8c3d%8]:123 May 4 16:58:19 ntpd 37106 Listen normally on 11 ix3 172.21.16.206:123 May 4 16:58:19 ntpd 37106 Listen normally on 12 lo0 [::1]:123 May 4 16:58:19 ntpd 37106 Listen normally on 13 lo0 [fe80::1%10]:123 May 4 16:58:19 ntpd 37106 Listen normally on 14 lo0 127.0.0.1:123 May 4 16:58:19 ntpd 37106 Listen normally on 15 ix3.229 [fe80::92ec:77ff:fe1f:8c3d%13]:123 May 4 16:58:19 ntpd 37106 Listen normally on 16 ix3.229 10.229.0.11:123 May 4 16:58:19 ntpd 37106 Listen normally on 17 pppoe0 10.5.200.10:123 May 4 16:58:19 ntpd 37106 Listen normally on 18 pppoe0 [fe80::92ec:77ff:fe1f:8c3f%15]:123 May 4 16:58:19 ntpd 37106 Listen normally on 19 ovpnc1 [fe80::92ec:77ff:fe1f:8c3f%14]:123 May 4 16:58:19 ntpd 37106 Listen normally on 20 ovpnc1 10.2.4.2:123 May 4 16:58:19 ntpd 37106 Listening on routing socket on fd #41 for interface updates May 4 16:58:19 ntpd 37106 kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized May 4 16:58:19 ntpd 37106 kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized May 4 16:58:22 ntpd 37106 Soliciting pool server 82.219.4.30
Steve
-
Thanks Steve for reply.
Yes it have problem. It slowly drifting behind. This time it was almost two minutes behind and I had to stop NTP service and manually run
ntpdate
command. Logs are same before and after this manual correction.Is it normal to see NTP request coming from pfBlockerNG virtual IP?
# tcpdump port 123 -nn tcpdump: verbose output suppressed, use -v or -vv for full protocol decode listening on tun_wg1, link-type NULL (BSD loopback), capture size 262144 bytes 23:36:32.846058 IP 10.10.10.1.123 > 78.46.150.245.123: NTPv4, Client, length 48 23:36:32.846546 IP 10.10.10.1.123 > 162.159.200.123.123: NTPv4, Client, length 48 23:36:40.846038 IP 10.10.10.1.123 > 194.58.202.20.123: NTPv4, Client, length 48 23:37:37.846043 IP 10.10.10.1.123 > 195.201.20.16.123: NTPv4, Client, length 48 23:37:38.846039 IP 10.10.10.1.123 > 192.26.105.26.123: NTPv4, Client, length 48 23:37:45.846046 IP 10.10.10.1.123 > 91.209.0.19.123: NTPv4, Client, length 48
-
@mixka said in NTP problem: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized:
# ntpq -p remote refid st t when poll reach delay offset jitter ============================================================================== fi.pool.ntp.org .POOL. 16 p - 64 0 0.000 +0.000 0.000 de.pool.ntp.org .POOL. 16 p - 64 0 0.000 +0.000 0.000 se.pool.ntp.org .POOL. 16 p - 64 0 0.000 +0.000 0.000
Did you see any other connections.. while you will see pool as a place holder, you should also see the actual servers your talking too with a reach of 377, etc.
I don't run pfblocker vip, I just use it for aliases that I use in my own rules. But yeah that seems odd - is that vip actually natted to your public IP? If it tries and go to the public?
-
Thank you @johnpoz
There is no other than pools shown.
I have pfBlockerNG with quite stock settings. I have disabled automatic firewall policies and run it with these manually made floating rules:
-
Check Status > Interfaces. Are you seeing the WAN trying to use the pfBlocker VIP as it's primary IP?
You might be hitting this: https://redmine.pfsense.org/issues/11545There probably isn't an outbound NAT rule for it so traffic to the actual NTP servers is failing.
Normally the pfBlocker VIP is on LAN so that should not be an issue.
Do you have specific interfaces set in NTP to listen on? It also uses those to send from and if you are only listening on LAN I could see that happening. Does it succeed if you deselect all the interfaces so it listens on all (the default)?
Steve
-
Can't find 10.10.10.1 on any interface on interfaces status page.
I had spesified listen interfaces for NTP. I had understood that selected interfaces was only for NTP server listen interfaces.
Cleared and restarted server. Now it looks much more promising.
# ntpq -p remote refid st t when poll reach delay offset jitter ============================================================================== fi.pool.ntp.org .POOL. 16 p - 64 0 0.000 +0.000 0.015 de.pool.ntp.org .POOL. 16 p - 64 0 0.000 +0.000 0.015 se.pool.ntp.org .POOL. 16 p - 64 0 0.000 +0.000 0.015 +static.52.142.2 194.58.205.20 2 u 3 64 3 2.802 +71.170 29.337 +time.cloudflare 10.79.8.177 3 u 3 64 3 1.786 +66.978 29.504 #ntp38.kashra-se 192.168.100.15 2 u 1 64 3 33.746 +63.356 30.095 #time.cloudflare 10.79.8.177 3 u 2 64 3 1.598 +66.590 30.244 *ntp2.vmar.se 192.36.143.150 2 u 3 64 3 7.929 +67.622 29.632 +168.119.4.163.p 31.209.85.243 2 u 5 64 3 36.175 +66.945 29.398 #ntp2.flashdance 192.36.143.153 2 u 1 64 3 10.534 +67.174 30.147 +94.130.49.186 ( 9.193.143.114 3 u 6 64 3 35.614 +68.530 28.799 #ntp.blockblueme 45.76.113.31 3 u 6 64 3 311.353 +78.537 30.032 # ntpq -c rv associd=0 status=0615 leap_none, sync_ntp, 1 event, clock_sync, version="ntpd 4.2.8p15@1.3728-o Wed Jan 12 15:39:52 UTC 2022 (1)", processor="amd64", system="FreeBSD/12.3-STABLE", leap=00, stratum=3, precision=-16, rootdelay=8.768, rootdisp=163.398, refid=147.78.229.141, reftime=e61d9bc2.5717bbc2 Thu, May 5 2022 3:41:38.340, clock=e61d9bd7.252f7a39 Thu, May 5 2022 3:41:59.145, peer=2324, tc=6, mintc=3, offset=+68.205317, frequency=+0.000, sys_jitter=5.356193, clk_jitter=27.235, clk_wander=0.000 # cat /var/etc/ntpd.conf tinker panic 0 tos orphan 12 maxclock 5 pool fi.pool.ntp.org iburst maxpoll 9 prefer pool de.pool.ntp.org iburst maxpoll 9 pool se.pool.ntp.org iburst maxpoll 9 statsdir /var/log/ntp logconfig =syncall +clockall +peerall +sysall driftfile /var/db/ntpd.drift restrict default kod limited nomodify nopeer notrap restrict -6 default kod limited nomodify nopeer notrap restrict source kod limited nomodify notrap # cat /var/db/ntpd.drift 0.000
Is there a way to make sure everything is working?
-
@mixka said in NTP problem: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized:
Is there a way to make sure everything is working?
Yeah that looks better - it should fairly quickly show reach of 377, if so then its working correctly.
I really don't see point to pointing to all of those pools. You should pick a pool for your region of the world and that should be more than enough..
-
Thank you @stephenw10 and @johnpoz this looks like it is working now.
I assigned only one pool to NTP and now reach column shows 377 for four servers. So this is golden. Thanks again!