OPNsense Forum
Archive => 20.7 Legacy Series => Topic started by: Ricardo on November 24, 2020, 09:42:04 am
-
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
-
Ok it seems its just me. Good luck me to solve it...
-
...I have a feeling not that many are using 20.7.5...
-
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?
-
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)
-
hm.
can you try to force sync via shell?
ntpdate -u 193.225.126.76
-
I have a similar issue, log attached, but in the dashboard the clock is actually in sync ::)
-
Me too.
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)
-
any clue in status table?
@hushcoden
@andrema2
20.7.5?
-
Attached the image of my state page.
I'm also running 2.7.5
-
My status
-
@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
-
@hushcoden
IMHO works fine
enable logging in General settings
-
Thanks Fright, so if it works fine, why the error?
Forgot to say I'm on 20.7.5
-
@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
* 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);
-
hm.
can you try to force sync via shell?
ntpdate -u 193.225.126.76
I did it:
root@localhost:~ # ntpdate -u 148.6.0.1
30 Nov 11:33:56 ntpdate[4218]: adjust time server 148.6.0.1 offset -0.070479 sec
But the status page still shows:
Unreach/Pending 148.6.0.1 .INIT. 16 u - 512 0 0.000 +0.000 0.000
The GUI: Services: Network Time: Log File: does not show anything regarding ongoing attempts. I have no clue what additional logging should be enabled, I already enabled all of this:
Network time \ General \ Syslog logging:
Enable logging of peer messages (default: disabled). --> CHECKED
Enable logging of system messages (default: disabled). --> CHECKED
Statistics logging These options will create persistent daily log files in /var/log/ntp:
Enable logging of reference clock statistics (default: disabled). --> CHECKED
Enable logging of clock discipline statistics (default: disabled). --> CHECKED
Enable logging of NTP peer statistics (default: disabled). --> CHECKED
-
can you restart nptd and take a look at firewall-diagnostics-statesdump (with :123 filter). what source IP ntpd use?
or just try this one?
https://forum.netgate.com/topic/131506/ntp-not-working-solved-totally
-
I restarted the NTPd several times, thats what can be seen in the logs I added earlier.
But all of a sudden, it recovered "by magic" yesterday @16:00:05 on both of my problematic router:
RouterA:
2020-11-30T16:00:42 ntpd[4570] 148.6.0.1 901a 8a sys_peer
2020-11-30T16:00:32 ntpd[4570] 148.6.0.1 8014 84 reachable
2020-11-30T16:00:32 ntpd[4570] 162.159.200.1 901a 8a sys_peer
2020-11-30T16:00:22 ntpd[4570] 51.105.208.173 8014 84 reachable
2020-11-30T16:00:15 ntpd[4570] 0.0.0.0 0615 05 clock_sync
2020-11-30T16:00:15 ntpd[4570] 185.82.232.254 901a 8a sys_peer
2020-11-30T16:00:10 ntpd[4570] 162.159.200.1 8014 84 reachable
2020-11-30T16:00:05 ntpd[4570] 185.82.232.254 8014 84 reachable
------------------------
RouterB:
2020-11-30T22:12:32 ntpd[63817] 148.6.0.1 961d 8d popcorn 0.000441 s
2020-11-30T15:59:00 ntpd[63817] 0.0.0.0 c615 05 clock_sync
2020-11-30T15:59:00 ntpd[63817] 0.0.0.0 c612 02 freq_set kernel 31.454 PPM
2020-11-30T15:59:00 ntpd[63817] kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
2020-11-30T15:54:23 ntpd[63817] 51.105.208.173 8014 84 reachable
2020-11-30T15:53:27 ntpd[63817] 148.6.0.1 901a 8a sys_peer
2020-11-30T15:53:21 ntpd[63817] 148.6.0.1 8014 84 reachable
2020-11-30T15:53:21 ntpd[63817] 0.0.0.0 c618 08 no_sys_peer
2020-11-30T15:53:16 ntpd[63817] 0.0.0.0 0614 04 freq_mode
2020-11-30T15:53:23 ntpd[63817] 0.0.0.0 061c 0c clock_step -6.165238 s
2020-11-30T15:53:23 ntpd[63817] 51.105.208.173 901a 8a sys_peer
2020-11-30T15:53:13 ntpd[63817] 51.105.208.173 8014 84 reachable
2020-11-26T10:11:32 ntpd[63817] 51.105.208.173 8011 81 mobilize assoc 43919
-------------------------
I did not change anything in the config around that time. These 2 routers are connected through a site-2-site IPSEC VPN, that may be the only single clue I can think of what could cause this NTP time sync issue (NTP peers were partially different on the 2 routers, so I would rather rule out that the issue was on the remote time source).
-
glad it works )
the only way I managed to reproduce your behavior (no sync. log stop at "..mobilize assoc ..") is to unbind the ntpd from the interfaces with Internet access (wan).
so i think it has to do with connectivity from the selected interfaces. it's hard to say what exactly interfered with connections (next time you can try to trace the packets, check nat rules etc).
-
glad it works )
the only way I managed to reproduce your behavior (no sync. log stop at "..mobilize assoc ..") is to unbind the ntpd from the interfaces with Internet access (wan).
so i think it has to do with connectivity from the selected interfaces. it's hard to say what exactly interfered with connections (next time you can try to trace the packets, check nat rules etc).
I dont like these automagical resolutions, as I have no idea what fixed it, and when (not if, but when..) it comes back again, I will stuck at the same situation.
The NTPd is set to listen on "all" interface. To be more precise, in the GUI it looks like there is "nothing" selected under the NTPd listening interface, so it means it listens on everything.
https://docs.opnsense.org/manual/ntpd.html --> Interface(s): "Interfaces to bind to, when none is selected it listens to all"
Slightly offtopic:
Franco said somewhere in this forum earlier that this default (=listen on ALL interface) should NEVER be changed for Unbound DNS, otherwise it will cause a big clusterf*ck of issues. So I was curious not to change this for NTPd either. But unfortunately this is not in the docs in any written and discoverable form (for the Unbound DNS, the docs dont warn the user either: https://docs.opnsense.org/manual/unbound.html --> "Network Interfaces:
Interface IP addresses used for responding to queries from clients. If an interface has both IPv4 and IPv6 IPs, both are used. Queries to other interface IPs not selected are discarded. The default behavior is to respond to queries on every available IPv4 and IPv6 address." --> No warning about "do NOT mess with listening interface setup, otherwise you break the whole world!"
So back to NTPd: I saw in the firewall status Live view, as the router sent out NTP packets (UDP123) towards the resolved public IPs of the time servers, using the WAN interface, using the actual WAN IP at the time of writing. So that looked also correct to me.
-
do NOT mess with listening interface setup, otherwise you break the whole world!
I agree. that's why I mentioned that I got the error only by changing the bindings.
I saw in the firewall status Live view, as the router sent out NTP packets (UDP123) towards the resolved public IPs of the time servers, using the WAN interface, using the actual WAN IP at the time of writing. So that looked also correct to me.
well. it remains to wait for it to happen again and try to figure it out on the second try )
i will test the log detail with the "logconfig=all" parameter in .conf. maybe useful in the future
-
Slightly offtopic:
Franco said somewhere in this forum earlier that this default (=listen on ALL interface) should NEVER be changed for Unbound DNS, otherwise it will cause a big clusterf*ck of issues. So I was curious not to change this for NTPd either. But unfortunately this is not in the docs in any written and discoverable form (for the Unbound DNS, the docs dont warn the user either: https://docs.opnsense.org/manual/unbound.html --> "Network Interfaces:
Interface IP addresses used for responding to queries from clients. If an interface has both IPv4 and IPv6 IPs, both are used. Queries to other interface IPs not selected are discarded. The default behavior is to respond to queries on every available IPv4 and IPv6 address." --> No warning about "do NOT mess with listening interface setup, otherwise you break the whole world!"
I excluded WAN from unbound listen interfaces long time ago. No hell broke loose ever since regarding DNS. Iirc the problem was, if an interface is removed that is listed specifically.
-
@Ricardo
so I tried and I don't know how to make the ntpd write more messages to the log (I tried both command line options and options in .conf).
what is written with the gui options enabled is the most..
it looks like next time it remains to rely on firewall logs and packet capture to figure out what is going on
-
@Ricardo
so I tried and I don't know how to make the ntpd write more messages to the log (I tried both command line options and options in .conf).
what is written with the gui options enabled is the most..
it looks like next time it remains to rely on firewall logs and packet capture to figure out what is going on
Is the same NTPd software more chattier (more verbose) on other BSD / Linux platforms, if you want it to be so?
-
to be honest, no idea. but did not googled a single example of a log with more verbose output than the one that is on the opn (with all flags on GUI config).