Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    NTPD crashes after starting OpenVPN service

    Scheduled Pinned Locked Moved 2.2 Snapshot Feedback and Problems - RETIRED
    16 Posts 2 Posters 6.4k Views
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • A Offline
      adam65535
      last edited by

      When I stop OpenVPN everything is fine.  As soon as I start OpenVPN the ntpd service shows as stopped.  I rebooted and the same result.  If I stop and then start OpenVPN the ntpd service changes to stopped on the service status page.

      2.2-ALPHA (i386)
      built on Sat Jun 14 01:00:55 CDT 2014
      FreeBSD 10.0-STABLE

      1 Reply Last reply Reply Quote 0
      • A Offline
        adam65535
        last edited by

        ntp logs when I start OpenVPN service (after it is stopped)… Time in reverse order... newest at the top

        Jun 15 04:23:42	ntpd[58012]: ntpd exiting on signal 15 (Terminated)
        Jun 15 04:23:40	ntpd[58012]: new interface(s) found: waking up resolver
        Jun 15 04:23:40	ntpd[58012]: Listen normally on 12 ovpns1 x.x.x.1:123
        Jun 15 04:23:40	ntpd[58012]: failed to init interface for address fe80::260:e0ff:fe04:5cfd%9
        Jun 15 04:23:40	ntpd[58012]: unable to create socket on ovpns1 (11) for fe80::260:e0ff:fe04:5cfd%9#123
        Jun 15 04:23:40	ntpd[58012]: bind(29) AF_INET6 fe80::260:e0ff:fe04:5cfd%9%9#123 flags 0x13 failed: Can't assign requested address
        Jun 15 04:23:19	ntpd[58012]: Deleting interface #10 ovpns1, x.x.x.1#123, interface stats: received=0, sent=0, dropped=0, active_time=68 secs
        Jun 15 04:23:19	ntpd[58012]: Deleting interface #9 ovpns1, fe80::260:e0ff:fe04:5cfd%9#123, interface stats: received=0, sent=0, dropped=0, active_time=68 secs
        

        OpenVPN logs when I stopped and started the OpenVPN service (again in reverse time order)

        Jun 15 04:23:41	openvpn[3292]: Initialization Sequence Completed
        Jun 15 04:23:41	openvpn[3292]: UDPv4 link remote: [undef]
        Jun 15 04:23:41	openvpn[3292]: UDPv4 link local (bound): [AF_INET]y.y.y.103:1194
        Jun 15 04:23:38	openvpn[445]: /usr/local/sbin/ovpn-linkup ovpns1 1500 1557 x.x.x.1 x.x.x.2 init
        Jun 15 04:23:38	openvpn[445]: /sbin/ifconfig ovpns1 x.x.x.1 x.x.x.2 mtu 1500 netmask 255.255.255.255 up
        Jun 15 04:23:38	openvpn[445]: do_ifconfig, tt->ipv6=1, tt->did_ifconfig_ipv6_setup=0
        Jun 15 04:23:38	openvpn[445]: TUN/TAP device /dev/tun1 opened
        Jun 15 04:23:38	openvpn[445]: TUN/TAP device ovpns1 exists previously, keep at program end
        Jun 15 04:23:38	openvpn[445]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
        Jun 15 04:23:38	openvpn[445]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
        Jun 15 04:23:38	openvpn[445]: library versions: OpenSSL 1.0.1g-freebsd 7 Apr 2014, LZO 2.06
        Jun 15 04:23:38	openvpn[445]: OpenVPN 2.3.4 i386-portbld-freebsd10.0 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on May 29 2014
        Jun 15 04:23:19	openvpn[38943]: SIGTERM[hard,] received, process exiting
        Jun 15 04:23:18	openvpn[38943]: /usr/local/sbin/ovpn-linkdown ovpns1 1500 1557 x.x.x.1 x.x.x.2 init
        Jun 15 04:23:18	openvpn[38943]: event_wait : Interrupted system call (code=4)
        
        1 Reply Last reply Reply Quote 0
        • A Offline
          adam65535
          last edited by

          In addition.  If I manually start ntpd though the services page after it stops it will start up without issues it seems.

          1 Reply Last reply Reply Quote 0
          • A Offline
            adam65535
            last edited by

            Added version info to first post.

            2.2-ALPHA (i386)
            built on Sat Jun 14 01:00:55 CDT 2014
            FreeBSD 10.0-STABLE

            1 Reply Last reply Reply Quote 0
            • A Offline
              adam65535
              last edited by

              Jun 15 04:24:01 pfsense kernel: pid 39066 (ntpd), uid 0: exited on signal 11 (core dumped)

              That is what happens when I start OpenVPN.

              1 Reply Last reply Reply Quote 0
              • A Offline
                adam65535
                last edited by

                I updated to the 27th snapshot a few days ago and I am still getting the ntpd crash when I start openvpn (I stop openvpn first without issue).  This with the 27th snapshot.  I uninstalled Suricata so that no packages are installed (except the OpenVPN export package) and I still get the ntpd crash.

                Jun 30 14:58:01 kernel: pid 34069 (ntpd), uid 0: exited on signal 11 (core dumped)

                2.2-ALPHA (i386)
                built on Fri Jun 27 00:02:52 CDT 2014
                FreeBSD 10.0-STABLE

                1 Reply Last reply Reply Quote 0
                • C Offline
                  charliem
                  last edited by

                  Can you post the contents of /var/etc/ntpd.conf on this system?

                  1 Reply Last reply Reply Quote 0
                  • A Offline
                    adam65535
                    last edited by

                    It looks pretty basic.

                    #
                    #
                    # pfSense ntp configuration file
                    #
                    
                    tinker panic 0
                    # Orphan mode stratum
                    tos orphan 12
                    
                    # GPS Setup
                    server 127.127.20.0 mode 0 minpoll 4 maxpoll 4 prefer
                    fudge 127.127.20.0 flag1 0 flag3 0
                    
                    # Upstream Servers
                    server 0.pfsense.pool.ntp.org iburst maxpoll 9
                    
                    disable monitor
                    statsdir /var/log/ntp
                    logconfig =syncall +clockall
                    driftfile /var/db/ntpd.drift
                    restrict default kod limited nomodify nopeer notrap
                    restrict -6 default kod limited nomodify nopeer notrap
                    
                    
                    1 Reply Last reply Reply Quote 0
                    • C Offline
                      charliem
                      last edited by

                      Can you add the two lines at the end:

                      interface ignore all
                      interface listen <interfaces you="" want="" ntpd="" on="">For my case, I listen only on my LAN interface.  I believe you can do this in the web gui (services - ntp) by selecting your interface(s) and hitting 'save'.  If you don't, it defaults to all interfaces.  Note that the interface choices you make don't seem to be carried over and highlighted next time you come back to the services - NTP page.</interfaces>

                      1 Reply Last reply Reply Quote 0
                      • A Offline
                        adam65535
                        last edited by

                        Thanks for the info.  I tried that a few hours ago by using the gui thinking that maybe it was because openvpn was on the external interface and it didn't make a difference.  It still crashes when I start openvpn.  I just tried it again too.  OpenVPN is configured to use the wan btw.  I only have 1 openvpn instance.

                        #
                        # pfSense ntp configuration file
                        #
                        
                        tinker panic 0
                        # Orphan mode stratum
                        tos orphan 12
                        
                        # GPS Setup
                        server 127.127.20.0 mode 0 minpoll 4 maxpoll 4 prefer
                        fudge 127.127.20.0 flag1 0 flag3 0
                        
                        # Upstream Servers
                        server 0.pfsense.pool.ntp.org iburst maxpoll 9
                        
                        disable monitor
                        statsdir /var/log/ntp
                        logconfig =syncall +clockall
                        driftfile /var/db/ntpd.drift
                        restrict default kod limited nomodify nopeer notrap
                        restrict -6 default kod limited nomodify nopeer notrap
                        
                        interface ignore all
                        interface listen rl1
                        

                        I changed it back to listen on all since it didn't make a difference.

                        1 Reply Last reply Reply Quote 0
                        • A Offline
                          adam65535
                          last edited by

                          Still getting this on the current snapshot…

                          2.2-ALPHA (i386)
                          built on Wed Jul 09 01:33:54 CDT 2014
                          FreeBSD 10.0-STABLE

                          1 Reply Last reply Reply Quote 0
                          • A Offline
                            adam65535
                            last edited by

                            Still happening for me with 2.2-beta.  If I stop openvpn everything looks fine.  Refresh services status and it shows openvpn as Stopped.  I start openvpn and now openvpn shows as Running but now ntpd shows as Stopped.  If I start ntpd service it will start just fine.

                            2.2-BETA (i386)
                            built on Thu Sep 18 17:43:56 CDT 2014
                            FreeBSD 10.1-PRERELEASE

                            For logs below…
                            L.L.L.# is the lan subnet
                            o.o.o.# is the openvpn subnet
                            e.e.e.# is external subnet

                            STOP OPENVPN:
                            status->services shows openvpn stopped and ntpd running

                            system general log:

                            Sep 19 02:16:48	kernel: ovpns1: link state changed to DOWN
                            Sep 19 02:16:48	check_reload_status: Reloading filter
                            Sep 19 02:17:25	check_reload_status: Syncing firewall
                            

                            openvpn log:

                            Sep 19 02:16:48	openvpn[69610]: event_wait : Interrupted system call (code=4)
                            Sep 19 02:16:48	openvpn[69610]: /usr/local/sbin/ovpn-linkdown ovpns1 1500 1557 o.o.o.1 o.o.o.2 init
                            Sep 19 02:16:49	openvpn[69610]: SIGTERM[hard,] received, process exiting
                            

                            ntpd log:

                            Sep 19 02:16:50	ntpd[26038]: Deleting interface #9 ovpns1, fe80::260:e0ff:fe04:5cfd%9#123, interface stats: received=0, sent=0, dropped=0, active_time=197 secs
                            Sep 19 02:16:50	ntpd[26038]: Deleting interface #10 ovpns1, o.o.o.1#123, interface stats: received=0, sent=0, dropped=0, active_time=197 secs
                            

                            START OPENVPN:
                            status->services shows openvpn started and ntpd stopped

                            system general log:

                            Sep 19 02:21:32	check_reload_status: Reloading filter
                            Sep 19 02:21:32	kernel: ovpns1: link state changed to UP
                            Sep 19 02:21:33	check_reload_status: rc.newwanip starting ovpns1
                            Sep 19 02:21:35	php-fpm[258]: /rc.newwanip: rc.newwanip: Informational is starting ovpns1.
                            Sep 19 02:21:35	php-fpm[258]: /rc.newwanip: rc.newwanip: on (IP address: o.o.o.1) (interface: []) (real interface: ovpns1).
                            Sep 19 02:21:35	php-fpm[258]: /rc.newwanip: pfSense package system has detected an ip change -> o.o.o.1 ... Restarting packages.
                            Sep 19 02:21:35	check_reload_status: Reloading filter
                            Sep 19 02:21:35	check_reload_status: Starting packages
                            Sep 19 02:21:37	php-fpm[257]: /rc.start_packages: Restarting/Starting all packages.
                            Sep 19 02:21:53	kernel: pid 82838 (ntpd), uid 0: exited on signal 11 (core dumped)
                            

                            openvpn log:

                            Sep 19 02:21:32	openvpn[68759]: OpenVPN 2.3.4 i386-portbld-freebsd10.0 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on Jul 10 2014
                            Sep 19 02:21:32	openvpn[68759]: library versions: OpenSSL 1.0.1i-freebsd 6 Aug 2014, LZO 2.06
                            Sep 19 02:21:32	openvpn[68759]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
                            Sep 19 02:21:32	openvpn[68759]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
                            Sep 19 02:21:32	openvpn[68759]: TUN/TAP device ovpns1 exists previously, keep at program end
                            Sep 19 02:21:32	openvpn[68759]: TUN/TAP device /dev/tun1 opened
                            Sep 19 02:21:32	openvpn[68759]: do_ifconfig, tt->ipv6=1, tt->did_ifconfig_ipv6_setup=0
                            Sep 19 02:21:32	openvpn[68759]: /sbin/ifconfig ovpns1 o.o.o.1 o.o.o.2 mtu 1500 netmask 255.255.255.255 up
                            Sep 19 02:21:32	openvpn[68759]: /usr/local/sbin/ovpn-linkup ovpns1 1500 1557 o.o.o.1 o.o.o.2 init
                            Sep 19 02:21:33	openvpn[70272]: UDPv4 link local (bound): [AF_INET]e.e.e.54:1194
                            Sep 19 02:21:33	openvpn[70272]: UDPv4 link remote: [undef]
                            Sep 19 02:21:33	openvpn[70272]: Initialization Sequence Completed
                            

                            ntp log:

                            Sep 19 02:21:35	ntpd[26038]: ntpd exiting on signal 15 (Terminated)
                            Sep 19 02:21:53	ntpdate[75961]: adjust time server 50.7.64.4 offset 0.001330 sec
                            Sep 19 02:21:53	ntp: Successfully synced time after 1 attempts.
                            Sep 19 02:21:53	ntp: Starting NTP Daemon.
                            Sep 19 02:21:53	ntpd[82655]: ntpd 4.2.7p475@1.2483-o Wed Sep 17 19:27:05 UTC 2014 (1): Starting
                            Sep 19 02:21:53	ntpd[82655]: Command line: /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid
                            Sep 19 02:21:53	ntpd[82838]: proto: precision = 1.011 usec (-20)
                            Sep 19 02:21:53	ntpd[82838]: Listen and drop on 0 v6wildcard [::]:123
                            Sep 19 02:21:53	ntpd[82838]: Listen and drop on 1 v4wildcard 0.0.0.0:123
                            Sep 19 02:21:53	ntpd[82838]: Listen normally on 2 rl0 [fe80::260:e0ff:fe04:5cfd%1]:123
                            Sep 19 02:21:53	ntpd[82838]: setsockopt IPV6_MULTICAST_IF 0 for fe80::260:e0ff:fe04:5cfd%1 fails: Can't assign requested address
                            Sep 19 02:21:53	ntpd[82838]: Listen normally on 3 rl0 e.e.e.54:123
                            Sep 19 02:21:53	ntpd[82838]: Listen normally on 4 rl1 L.L.L.1:123
                            Sep 19 02:21:53	ntpd[82838]: Listen normally on 5 rl1 [fe80::260:e0ff:fe04:5cfc%2]:123
                            Sep 19 02:21:53	ntpd[82838]: setsockopt IPV6_MULTICAST_IF 0 for fe80::260:e0ff:fe04:5cfc%2 fails: Can't assign requested address
                            Sep 19 02:21:53	ntpd[82838]: Listen normally on 6 lo0 127.0.0.1:123
                            Sep 19 02:21:53	ntpd[82838]: Listen normally on 7 lo0 [::1]:123
                            Sep 19 02:21:53	ntpd[82838]: Listen normally on 8 lo0 [fe80::1%7]:123
                            Sep 19 02:21:53	ntpd[82838]: setsockopt IPV6_MULTICAST_IF 0 for fe80::1%7 fails: Can't assign requested address
                            Sep 19 02:21:53	ntpd[82838]: Listen normally on 9 ovpns1 [fe80::260:e0ff:fe04:5cfd%9]:123
                            Sep 19 02:21:53	ntpd[82838]: setsockopt IPV6_MULTICAST_IF 0 for fe80::260:e0ff:fe04:5cfd%9 fails: Can't assign requested address
                            Sep 19 02:21:53	ntpd[82838]: Listen normally on 10 ovpns1 o.o.o.1:123
                            Sep 19 02:21:53	ntpd[82838]: Listening on routing socket on fd #31 for interface updates
                            Sep 19 02:21:53	ntpd[82838]: refclock_open /dev/gps0: Is a directory
                            Sep 19 02:21:53	ntpd[82838]: 127.127.20.0 local addr 127.0.0.1 -> 
                            
                            1 Reply Last reply Reply Quote 0
                            • C Offline
                              charliem
                              last edited by

                              Sounds remarkably like this long-running problem that was eventually reported solved in 2.1.1:
                              https://redmine.pfsense.org/issues/3045

                              1 Reply Last reply Reply Quote 0
                              • C Offline
                                charliem
                                last edited by

                                Seems that it may be related to the dynamic interface updating in ntpd.  Can you try adding "-U 0" to the command line to disable the dynamic interface updating?

                                For testing, you can do it like this from the command line:```
                                [2.2-BETA][root@pfsense.localdomain]/etc/inc(25): ps axfw | grep ntpd
                                82886  -  Ss    0:00.09 /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid
                                83198  0  S+    0:00.00 grep ntpd
                                [2.2-BETA][root@pfsense.localdomain]/etc/inc(26): killall ntpd
                                [2.2-BETA][root@pfsense.localdomain]/etc/inc(27): /usr/local/sbin/ntpd -g -U 0 -c /var/etc/ntpd.conf -p /var/run/ntpd.pid

                                
                                This may not be enough: The "-U 0" may end interval triggered scanning for interface changes, but ntpd is still listening for changes:
                                
                                > Sep 19 11:24:58 pfsense ntpd[5817]: Command line: /usr/local/sbin/ntpd -g -U 0 -c /var/etc/ntpd.conf -p /var/run/ntpd.pid
                                > Sep 19 11:24:58 pfsense ntpd[6063]: proto: precision = 0.330 usec (-21)
                                > Sep 19 11:24:58 pfsense ntpd[6063]: Listen and drop on 0 v6wildcard [::]:123
                                > Sep 19 11:24:58 pfsense ntpd[6063]: Listen and drop on 1 v4wildcard 0.0.0.0:123
                                > Sep 19 11:24:58 pfsense ntpd[6063]: Listen normally on 2 bge0 192.168.2.128:123
                                > Sep 19 11:24:58 pfsense ntpd[6063]: Listen normally on 3 bge0 [fe80::2e0:66ff:fe6e:260%1]:123
                                > Sep 19 11:24:58 pfsense ntpd[6063]: setsockopt IPV6_MULTICAST_IF 0 for fe80::2e0:66ff:fe6e:260%1 fails: Can't assign requested address
                                > Sep 19 11:24:58 pfsense ntpd[6063]: Listen normally on 4 lo0 127.0.0.1:123
                                > Sep 19 11:24:58 pfsense ntpd[6063]: Listen normally on 5 lo0 [::1]:123
                                > Sep 19 11:24:58 pfsense ntpd[6063]: Listening on routing socket on fd #26 for interface updates  <==== Here; is '-U 0' not working?
                                > Sep 19 11:24:58 pfsense ntpd[6063]: refclock_atom: /dev/pps0: Is a directory
                                > Sep 19 11:24:58 pfsense ntpd[6063]: 127.127.22.0 local addr 127.0.0.1 -> <null>Sep 19 11:24:58 pfsense ntpd[6063]: GPS_NMEA(0) serial /dev/gps0 open at 9600 bps
                                > Sep 19 11:24:58 pfsense ntpd[6063]: 0.0.0.0 c01d 0d kern kernel time sync enabled
                                > Sep 19 11:24:58 pfsense ntpd[6063]: 0.0.0.0 c012 02 freq_set kernel -31.400 PPM
                                > Sep 19 11:24:58 pfsense ntpd[6063]: 0.0.0.0 c016 06 restart
                                > Sep 19 11:24:58 pfsense ntpd[6063]: DNS 0.pfsense.pool.ntp.org -> 50.116.55.65
                                > Sep 19 11:24:58 pfsense ntpd[6063]: DNS 1.fedora.pool.ntp.org -> 66.228.35.252
                                > Sep 19 11:24:59 pfsense ntpd[6063]: 0.0.0.0 c615 05 clock_sync
                                > Sep 19 11:25:00 pfsense ntpd[6063]: 0.0.0.0 041d 0d kern PPS enabled</null>
                                
                                Looking through ntpd source (ntpd.c), it seems that the variable disable_dynamic_updates is only set if [ (!HAVE_LINUX_CAPABILITIES) and (!HAVE_SOLARIS_PRIVS) and (we are not root user) ]
                                1 Reply Last reply Reply Quote 0
                                • A Offline
                                  adam65535
                                  last edited by

                                  I modified the two scripts below to add the -U 0 option and now it works.  Note that ntpd does show down as soon as you start openvpn just like it did before (because ntpdate_sync_once.sh gets run which forces an ntpdate to sync the time and then it starts ntpd again) but if you refresh the service status page ntpd does eventually start up after a few seconds.  Before it just stayed as Stopped status no matter how many times I refreshed the services status page.  I don't see the crashes by ntpd anymore now either in the system/general log.

                                  /etc/inc/system.inc
                                  /usr/local/sbin/ntpdate_sync_once.sh

                                  It looks like it is working properly now adding -U 0 to both the system.inc and ntpdate_sync_once.sh script.  Interestingly I don't see the -U 0 in the freebsd man page doing a google search.

                                  
                                  [2.2-BETA][root@pfsense]/etc/inc(89): ps ax | grep ntp
                                  80956  -  S      0:00.02 /bin/sh /usr/local/sbin/ntpdate_sync_once.sh
                                  88622  -  S      0:00.03 /usr/local/sbin/ntpdate -s -t 5 0.pfsense.pool.ntp.org
                                   1226  0  S+     0:00.01 grep ntp
                                  [2.2-BETA][root@pfsense]/etc/inc(90): ps ax | grep ntp
                                   2125  -  Ss     0:00.11 /usr/local/sbin/ntpd -U 0 -g -c /var/etc/ntpd.conf -p 
                                   5647  0  S+     0:00.01 grep ntp
                                  
                                  1 Reply Last reply Reply Quote 0
                                  • C Offline
                                    charliem
                                    last edited by

                                    @adam65535:

                                    It looks like it is working properly now adding -U 0 to both the system.inc and ntpdate_sync_once.sh script.

                                    Great, I'm glad it works!  Since the forum where this was first discussed is closed (2.1 beta feedback, https://forum.pfsense.org/index.php?topic=62099.msg341908#msg341908), can you post a short note to redmine: https://redmine.pfsense.org/issues/3045  This is a crutch rather than a proper fix, but it should be a big clue to the devs who can do a real fix.  That's above my pay grade though :)

                                    Interestingly I don't see the -U 0 in the freebsd man page doing a google search.

                                    Dynamic interface scanning has been in ntpd for a while, since about 2006: http://bugs.ntp.org/show_bug.cgi?id=622

                                    1 Reply Last reply Reply Quote 0
                                    • First post
                                      Last post
                                    Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.