NTP stuck in unsync state after 20.7.5

[Ricardo]

Hi all, is it just me, or others have also ntp problem after 20.7.5? Both of my routers are unable to sync time via ntp.
 I discovered it after upgrade to 20.7.5. Both worked fine in the past. Ntp log is not that helpful, firewall also seems to allow outbound NTP/UDP123, I dont recall changing anything related to NTP. Added multiple NTP servers (e.g. time.windows.com) but all behave the same way:

Unreach/Pending  162.159.200.1   .INIT.   16   u   -   64   0   0.000   +0.000   0.000



2020-11-24T09:25:03   ntpd[76735]   162.159.200.1 8011 81 mobilize assoc 25092
2020-11-24T09:25:03   ntpd[76735]   DNS pool.ntp.org -> 162.159.200.1
2020-11-24T09:25:03   ntpd[76735]   51.105.208.173 8011 81 mobilize assoc 25091
2020-11-24T09:25:03   ntpd[76735]   DNS time.windows.com -> 51.105.208.173
2020-11-24T09:25:03   ntpd[76735]   0.0.0.0 c016 06 restart
2020-11-24T09:25:03   ntpd[76735]   0.0.0.0 c012 02 freq_set kernel 49.289 PPM
2020-11-24T09:25:03   ntpd[76735]   kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized
2020-11-24T09:25:03   ntpd[76735]   0.0.0.0 c01d 0d kern kernel time sync enabled
2020-11-24T09:25:03   ntpd[76735]   kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized
2020-11-24T09:25:03   ntpd[76735]   148.6.0.1 8011 81 mobilize assoc 25090
2020-11-24T09:25:03   ntpd[76735]   Listening on routing socket on fd #31 for interface updates
2020-11-24T09:25:03   ntpd[76735]   Listen normally on 10 pppoe0 85.238.77.125:123
2020-11-24T09:25:03   ntpd[76735]   Listen normally on 9 pppoe0 [fe80::618d:21c:59ca:f801%8]:123
2020-11-24T09:25:03   ntpd[76735]   Listen normally on 8 pppoe0 [fe80::20d:b9ff:fe4b:b5c%8]:123
2020-11-24T09:25:03   ntpd[76735]   Listen normally on 7 lo0 127.0.0.1:123
2020-11-24T09:25:03   ntpd[76735]   Listen normally on 6 lo0 [fe80::1%5]:123
2020-11-24T09:25:03   ntpd[76735]   Listen normally on 5 lo0 [::1]:123
2020-11-24T09:25:03   ntpd[76735]   Listen normally on 4 igb2 [fe80::20d:b9ff:fe4b:b5e%3]:123
2020-11-24T09:25:03   ntpd[76735]   Listen normally on 3 igb2 192.168.1.1:123
2020-11-24T09:25:03   ntpd[76735]   Listen normally on 2 igb0 [fe80::20d:b9ff:fe4b:b5c%1]:123
2020-11-24T09:25:03   ntpd[76735]   Listen and drop on 1 v4wildcard 0.0.0.0:123
2020-11-24T09:25:03   ntpd[76735]   Listen and drop on 0 v6wildcard [::]:123
2020-11-24T09:25:03   ntpd[76735]   restrict: 'monitor' cannot be disabled while 'limited' is enabled
2020-11-24T09:25:03   ntpd[76735]   gps base set to 2020-08-23 (week 2120)
2020-11-24T09:25:03   ntpd[76735]   basedate set to 2020-08-20
2020-11-24T09:25:03   ntpd[76735]   proto: precision = 0.694 usec (-20)
2020-11-24T09:25:03   ntpd[82932]   ----------------------------------------------------
2020-11-24T09:25:03   ntpd[82932]   available at https://www.nwtime.org/support
2020-11-24T09:25:03   ntpd[82932]   corporation. Support and training for ntp-4 are
2020-11-24T09:25:03   ntpd[82932]   Inc. (NTF), a non-profit 501(c)(3) public-benefit
2020-11-24T09:25:03   ntpd[82932]   ntp-4 is maintained by Network Time Foundation,
2020-11-24T09:25:03   ntpd[82932]   ----------------------------------------------------
2020-11-24T09:25:03   ntpd[82932]   Command line: /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid
2020-11-24T09:25:03   ntpd[82932]   ntpd 4.2.8p15@1.3728-o Tue Sep 1 03:15:17 UTC 2020 (1): Starting

[Ricardo]

Ok it seems its just me. Good luck me to solve it...

[chemlud]

...I have a feeling not that many are using 20.7.5...

[Fright]

Hi
ntpd changes not mentioned on 20.7.5 release.

ntpd 4.2.8p15@1.3728-o

same as on my 20.7.4

2020-11-24T09:25:03   ntpd[76735]   162.159.200.1 8011 81 mobilize assoc 25092
2020-11-24T09:25:03   ntpd[76735]   DNS pool.ntp.org -> 162.159.200.1
2020-11-24T09:25:03   ntpd[76735]   51.105.208.173 8011 81 mobilize assoc 25091
2020-11-24T09:25:03   ntpd[76735]   DNS time.windows.com -> 51.105.208.173

what if not to use this servers. and enable only *.opnsense.pool.ntp.org?

[Ricardo]

Hi
ntpd changes not mentioned on 20.7.5 release.

ntpd 4.2.8p15@1.3728-o

same as on my 20.7.4

2020-11-24T09:25:03   ntpd[76735]   162.159.200.1 8011 81 mobilize assoc 25092
2020-11-24T09:25:03   ntpd[76735]   DNS pool.ntp.org -> 162.159.200.1
2020-11-24T09:25:03   ntpd[76735]   51.105.208.173 8011 81 mobilize assoc 25091
2020-11-24T09:25:03   ntpd[76735]   DNS time.windows.com -> 51.105.208.173

what if not to use this servers. and enable only *.opnsense.pool.ntp.org?

No improvement:

2020-11-26T15:27:21   ntpd[9757]   193.225.126.76 8011 81 mobilize assoc 11502
2020-11-26T15:27:21   ntpd[9757]   DNS 0.opnsense.pool.ntp.org -> 193.225.126.76
2020-11-26T15:27:21   ntpd[9757]   162.159.200.123 8011 81 mobilize assoc 11501
2020-11-26T15:27:21   ntpd[9757]   DNS pool.ntp.org -> 162.159.200.123
2020-11-26T15:27:20   ntpd[9757]   51.105.208.173 8011 81 mobilize assoc 11500
2020-11-26T15:27:20   ntpd[9757]   DNS time.windows.com -> 51.105.208.173
2020-11-26T15:27:20   ntpd[9757]   0.0.0.0 c016 06 restart
2020-11-26T15:27:20   ntpd[9757]   0.0.0.0 c012 02 freq_set kernel 49.289 PPM
2020-11-26T15:27:20   ntpd[9757]   kernel reports TIME_ERROR: 0x6041: Clock Unsynchronized
2020-11-26T15:27:20   ntpd[9757]   0.0.0.0 c01d 0d kern kernel time sync enabled
2020-11-26T15:27:20   ntpd[9757]   kernel reports TIME_ERROR: 0x6041: Clock Unsynchronized
2020-11-26T15:27:20   ntpd[9757]   148.6.0.1 8011 81 mobilize assoc 11499
2020-11-26T15:27:20   ntpd[9757]   Listening on routing socket on fd #31 for interface updates
2020-11-26T15:27:20   ntpd[9757]   Listen normally on 10 pppoe0 193.110.63.44:123
2020-11-26T15:27:20   ntpd[9757]   Listen normally on 9 pppoe0 [fe80::618d:21c:59ca:f801%8]:123
2020-11-26T15:27:20   ntpd[9757]   Listen normally on 8 pppoe0 [fe80::20d:b9ff:fe4b:b5c%8]:123
2020-11-26T15:27:20   ntpd[9757]   Listen normally on 7 lo0 127.0.0.1:123
2020-11-26T15:27:20   ntpd[9757]   Listen normally on 6 lo0 [fe80::1%5]:123
2020-11-26T15:27:20   ntpd[9757]   Listen normally on 5 lo0 [::1]:123
2020-11-26T15:27:20   ntpd[9757]   Listen normally on 4 igb2 [fe80::20d:b9ff:fe4b:b5e%3]:123
2020-11-26T15:27:20   ntpd[9757]   Listen normally on 3 igb2 192.168.1.1:123
2020-11-26T15:27:20   ntpd[9757]   Listen normally on 2 igb0 [fe80::20d:b9ff:fe4b:b5c%1]:123
2020-11-26T15:27:20   ntpd[9757]   Listen and drop on 1 v4wildcard 0.0.0.0:123
2020-11-26T15:27:20   ntpd[9757]   Listen and drop on 0 v6wildcard [::]:123
2020-11-26T15:27:20   ntpd[9757]   restrict: 'monitor' cannot be disabled while 'limited' is enabled
2020-11-26T15:27:20   ntpd[9757]   gps base set to 2020-08-23 (week 2120)
2020-11-26T15:27:20   ntpd[9757]   basedate set to 2020-08-20
2020-11-26T15:27:20   ntpd[9757]   proto: precision = 0.726 usec (-20)
2020-11-26T15:27:20   ntpd[42920]   ----------------------------------------------------
2020-11-26T15:27:20   ntpd[42920]   available at https://www.nwtime.org/support
2020-11-26T15:27:20   ntpd[42920]   corporation. Support and training for ntp-4 are
2020-11-26T15:27:20   ntpd[42920]   Inc. (NTF), a non-profit 501(c)(3) public-benefit
2020-11-26T15:27:20   ntpd[42920]   ntp-4 is maintained by Network Time Foundation,
2020-11-26T15:27:20   ntpd[42920]   ----------------------------------------------------
2020-11-26T15:27:20   ntpd[42920]   Command line: /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid
2020-11-26T15:27:20   ntpd[42920]   ntpd 4.2.8p15@1.3728-o Tue Sep 1 03:15:17 UTC 2020 (1): Starting
2020-11-26T15:27:20   ntpd[63112]   0.0.0.0 001d 0d kern kernel time sync disabled
2020-11-26T15:27:20   ntpd[63112]   162.159.200.123 local addr 193.110.63.44 -> <null>
2020-11-26T15:27:20   ntpd[63112]   162.159.200.123 8012 82 demobilize assoc 37962
2020-11-26T15:27:20   ntpd[63112]   51.105.208.173 local addr 193.110.63.44 -> <null>
2020-11-26T15:27:20   ntpd[63112]   51.105.208.173 8012 82 demobilize assoc 37961
2020-11-26T15:27:20   ntpd[63112]   148.6.0.1 local addr 193.110.63.44 -> <null>
2020-11-26T15:27:20   ntpd[63112]   148.6.0.1 8012 82 demobilize assoc 37960
2020-11-26T15:27:20   ntpd[63112]   ntpd exiting on signal 15 (Terminated)

[Fright]

hm.
can you try to force sync via shell?

Code: [Select]

ntpdate -u 193.225.126.76

[hushcoden]

I have a similar issue, log attached, but in the dashboard the clock is actually in sync 

[andrema2]

Me too.

Code: [Select]

2020-11-26T16:37:08 ntpd[74518] kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized
2020-11-26T16:37:08 ntpd[74518] kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized
2020-11-26T16:37:08 ntpd[74518] Listening on routing socket on fd #29 for interface updates
2020-11-26T16:37:08 ntpd[74518] Listen normally on 8 lo0 127.0.0.1:123
2020-11-26T16:37:08 ntpd[74518] Listen normally on 7 lo0 [fe80::1%6]:123
2020-11-26T16:37:08 ntpd[74518] Listen normally on 6 lo0 [::1]:123
2020-11-26T16:37:08 ntpd[74518] Listen normally on 5 igb1 [fe80::290:27ff:fee5:62c1%2]:123
2020-11-26T16:37:08 ntpd[74518] Listen normally on 4 igb1 10.2.2.1:123
2020-11-26T16:37:08 ntpd[74518] Listen normally on 3 igb0 192.168.15.2:123
2020-11-26T16:37:08 ntpd[74518] Listen normally on 2 igb0 [fe80::290:27ff:fee5:62c0%1]:123
2020-11-26T16:37:08 ntpd[74518] Listen and drop on 1 v4wildcard 0.0.0.0:123
2020-11-26T16:37:08 ntpd[74518] Listen and drop on 0 v6wildcard [::]:123
2020-11-26T16:37:08 ntpd[74518] restrict: 'monitor' cannot be disabled while 'limited' is enabled
2020-11-26T16:37:08 ntpd[74518] gps base set to 2020-08-23 (week 2120)
2020-11-26T16:37:08 ntpd[74518] basedate set to 2020-08-20
2020-11-26T16:37:08 ntpd[74518] proto: precision = 0.264 usec (-22)
2020-11-26T16:37:08 ntpd[28401] ----------------------------------------------------
2020-11-26T16:37:08 ntpd[28401] available at https://www.nwtime.org/support
2020-11-26T16:37:08 ntpd[28401] corporation.  Support and training for ntp-4 are
2020-11-26T16:37:08 ntpd[28401] Inc. (NTF), a non-profit 501(c)(3) public-benefit
2020-11-26T16:37:08 ntpd[28401] ntp-4 is maintained by Network Time Foundation,
2020-11-26T16:37:08 ntpd[28401] ----------------------------------------------------
2020-11-26T16:37:08 ntpd[28401] Command line: /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid
2020-11-26T16:37:08 ntpd[28401] ntpd 4.2.8p15@1.3728-o Tue Sep  1 03:12:27 UTC 2020 (1): Starting
2020-11-26T16:37:08 ntpd[74793] 52.67.171.238 local addr 192.168.15.2 -> <null>
2020-11-26T16:37:08 ntpd[74793] 192.36.143.130 local addr 192.168.15.2 -> <null>
2020-11-26T16:37:08 ntpd[74793] 143.107.229.211 local addr 192.168.15.2 -> <null>
2020-11-26T16:37:08 ntpd[74793] 162.159.200.1 local addr 192.168.15.2 -> <null>
2020-11-26T16:37:08 ntpd[74793] ntpd exiting on signal 15 (Terminated)

[Fright]

any clue in status table?
@hushcoden
@andrema2
20.7.5?

[andrema2]

Attached the image of my state page.

I'm also running 2.7.5

[hushcoden]

My status

[Fright]

@andrema2
imho your ntp works fine. looks like you did not enable logging in services-networktime-general
low Reach value due to recent ntpd restart
enable logging and you will see sync messages

[Fright]

@hushcoden
IMHO works fine
enable logging in General settings

[hushcoden]

Thanks Fright, so if it works fine, why the error?

Forgot to say I'm on 20.7.5

[Fright]

@hushcoden
can ignore the first couple of this messages after ntpd start
old ntpd feature
https://github.com/opnsense/src/blob/master/contrib/ntp/ntpd/ntp_loopfilter.c

Code: [Select]

* This code may be returned when ntp_adjtime() has just
* been called for the first time, quite a while after
* startup, when ntpd just starts to discipline the kernel
* time. In this case the occurrence of this message
* can be pretty confusing.
*
* HMS: How about a message when we begin kernel processing:
*    Determining kernel clock state...
* so an initial TIME_ERROR message is less confising,
* or skipping the first message (ugh),
* or ???
* msyslog(LOG_INFO, "kernel reports time synchronization lost");
*/
msyslog(LOG_INFO, "kernel reports TIME_ERROR: %#x: %s",
ptimex->status, des);