Ntpd exiting due to assertion failure



  • NTP isn't working, my log is below.

    
    Jan 19 01:47:44	ntpd[57646]: exiting (due to assertion failure)
    Jan 19 01:47:44	ntpd[57646]: work_thread.c:271: INSIST(((void *)0) != req) failed
    Jan 19 01:47:43	ntpd[57646]: Listening on routing socket on fd #26 for interface updates
    Jan 19 01:47:43	ntpd[57646]: Listen normally on 5 lo0 [::1]:123
    Jan 19 01:47:43	ntpd[57646]: Listen normally on 4 lo0 127.0.0.1:123
    Jan 19 01:47:43	ntpd[57646]: setsockopt IPV6_MULTICAST_IF 0 for fe80::202:a5ff:fe4e:ed81%4 fails: Can't assign requested address
    Jan 19 01:47:43	ntpd[57646]: Listen normally on 3 em1 [fe80::202:a5ff:fe4e:ed81%4]:123
    Jan 19 01:47:43	ntpd[57646]: Listen normally on 2 em1 192.168.13.1:123
    Jan 19 01:47:43	ntpd[57646]: Listen and drop on 1 v4wildcard 0.0.0.0:123
    Jan 19 01:47:43	ntpd[57646]: Listen and drop on 0 v6wildcard [::]:123
    Jan 19 01:47:43	ntpd[57646]: proto: precision = 1.397 usec (-19)
    Jan 19 01:47:43	ntpd[57556]: Command line: /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid
    Jan 19 01:47:43	ntpd[57556]: ntpd 4.2.7p411@1.2483-o Wed Jan 15 17:47:32 UTC 2014 (1): Starting
    
    


  • For the record, my NTP is working. There are plenty of "Can't assign requested address" - now I wonder if those are "normal" messages that appeared in 2.1. At least mine does not crash.

    Jan 19 12:41:47 	ntpdate[44034]: step time server 203.174.83.202 offset 0.661536 sec
    Jan 19 12:41:47 	ntp: Successfully synced time after 1 attempts.
    Jan 19 12:41:47 	ntp: Starting NTP Daemon.
    Jan 19 12:41:47 	ntpd[46262]: ntpd 4.2.7p411@1.2483-o Wed Jan 15 17:47:30 UTC 2014 (1): Starting
    Jan 19 12:41:47 	ntpd[46262]: Command line: /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid
    Jan 19 12:41:47 	ntpd[46777]: proto: precision = 3.678 usec (-18)
    Jan 19 12:41:47 	ntpd[46777]: Listen and drop on 0 v6wildcard [::]:123
    Jan 19 12:41:47 	ntpd[46777]: Listen and drop on 1 v4wildcard 0.0.0.0:123
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 2 vr0 10.49.160.250:123
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 3 vr0 [fe80::20d:b9ff:fe24:5900%1]:123
    Jan 19 12:41:47 	ntpd[46777]: setsockopt IPV6_MULTICAST_IF 0 for fe80::20d:b9ff:fe24:5900%1 fails: Can't assign requested address
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 4 vr1 10.49.175.1:123
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 5 vr1 [fe80::20d:b9ff:fe24:5901%2]:123
    Jan 19 12:41:47 	ntpd[46777]: setsockopt IPV6_MULTICAST_IF 0 for fe80::20d:b9ff:fe24:5901%2 fails: Can't assign requested address
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 6 vr2 10.49.174.1:123
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 7 vr2 [fe80::20d:b9ff:fe24:5902%3]:123
    Jan 19 12:41:47 	ntpd[46777]: setsockopt IPV6_MULTICAST_IF 0 for fe80::20d:b9ff:fe24:5902%3 fails: Can't assign requested address
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 8 lo0 127.0.0.1:123
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 9 lo0 [::1]:123
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 10 lo0 [fe80::1%7]:123
    Jan 19 12:41:47 	ntpd[46777]: setsockopt IPV6_MULTICAST_IF 0 for fe80::1%7 fails: Can't assign requested address
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 11 ovpns3 [fe80::20d:b9ff:fe24:5900%8]:123
    Jan 19 12:41:47 	ntpd[46777]: setsockopt IPV6_MULTICAST_IF 0 for fe80::20d:b9ff:fe24:5900%8 fails: Can't assign requested address
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 12 ovpns3 10.50.160.1:123
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 13 ovpnc1 [fe80::20d:b9ff:fe24:5900%9]:123
    Jan 19 12:41:47 	ntpd[46777]: setsockopt IPV6_MULTICAST_IF 0 for fe80::20d:b9ff:fe24:5900%9 fails: Can't assign requested address
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 14 ovpnc1 10.49.235.2:123
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 15 ovpnc2 [fe80::20d:b9ff:fe24:5900%10]:123
    Jan 19 12:41:47 	ntpd[46777]: setsockopt IPV6_MULTICAST_IF 0 for fe80::20d:b9ff:fe24:5900%10 fails: Can't assign requested address
    Jan 19 12:41:47 	ntpd[46777]: Listen normally on 16 ovpnc2 10.49.251.2:123
    Jan 19 12:41:47 	ntpd[46777]: Listening on routing socket on fd #37 for interface updates
    

    The NTP status looks good:

    Status ▾ 	Server 	Ref ID 	Stratum 	Type 	When 	Poll 	Reach 	Delay 	Offset 	Jitter
    Active Peer 	203.174.83.202 	133.243.238.163 	2 	u 	55 	64 	77 	127.222 	50.485 	38.432
    


  • It looks like things start to go wrong here:

    
    Jan 19 01:47:44	ntpd[57646]: work_thread.c:271: INSIST(((void *)0) != req) failed
    
    


  • OK, I figured it out:

    Originally in 2.1, I had the following NTP servers defined:

    
    0.us.pool.ntp.org 1.us.pool.ntp.org 2.us.pool.ntp.org 3.us.pool.ntp.org 0.pfsense.pool.ntp.org tick.cerias.purdue.edu tock.cerias.purdue.edu tack.cerias.purdue.edu ntp.itd.umich.edu ntp.msu.edu nist.expertsmi.com nist.netservicesgroup.com atlas.digitalenigma.net pbody.digitalenigma.net nisttime.carsoncity.k12.mi.us time.nist.gov ac-ntp0.net.cmu.edu ac-ntp1.net.cmu.edu ac-ntp2.net.cmu.edu
    
    

    Now, I have to have a shorter list:

    
    0.us.pool.ntp.org 1.us.pool.ntp.org 2.us.pool.ntp.org 3.us.pool.ntp.org 0.pfsense.pool.ntp.org tick.cerias.purdue.edu tock.cerias.purdue.edu tack.cerias.purdue.edu ntp.itd.umich.edu ntp.msu.edu nist.expertsmi.com nist.netservicesgroup.com atlas.digitalenigma.net pbody.digitalenigma.net nisttime.carsoncity.k12.mi.us time.nist.gov ac-ntp0.net.cmu.edu
    
    

  • Rebel Alliance Developer Netgate

    @ccb056:

    OK, I figured it out:

    Originally in 2.1, I had the following NTP servers defined:
    Now, I have to have a shorter list:

    Given that we're running ntp-devel at the moment, consider reporting that to the NTP project: http://ntp.org/bugs.html

    We are not making any patches or changes to their code, so giving them a copy of your NTP config from /var/etc/ they should be able to reproduce the issue.


  • Rebel Alliance Developer Netgate

    @phil.davis:

    For the record, my NTP is working. There are plenty of "Can't assign requested address" - now I wonder if those are "normal" messages that appeared in 2.1. At least mine does not crash.

    
    Jan 19 12:41:47 	ntpd[46777]: setsockopt IPV6_MULTICAST_IF 0 for fe80::20d:b9ff:fe24:5900%1 fails: Can't assign requested address
    
    

    Note those all refer to multicast on scoped IPv6 link-local IPs. AFAIK that isn't something that will impact our usage.



  • Would it be possible to get support for pool directive to the pfSense GUI? I would also love to see the settings moved from General to Service -> NTP as a whole and have more control over NTP through the GUI. Maybe not for 2.1.X, but for 2.2 maybe?


  • Rebel Alliance Developer Netgate

    There is already some work to improve the NTP settings for dealing with GPS units on 2.2 in a separate thread.



  • @fragged:

    Would it be possible to get support for pool directive to the pfSense GUI? I would also love to see the settings moved from General to Service -> NTP as a whole and have more control over NTP through the GUI. Maybe not for 2.1.X, but for 2.2 maybe?

    Check this out:
    https://forum.pfsense.org/index.php/topic,67189.105.html


Log in to reply