OPENVPN Server dies after 2.1.2 update, logs enclosed



  • After 2.1.2 my vpn server keeps dying and will not restart without reboot or port change.

    based on the original log message "openvpn[74226]: TCP/UDP: Socket bind failed on local address [AF_INET]...:1194: Address already in use" I tried changing the port from 1194 to 1195 and it worked for about a week before dying the same way. (I had thought it might be a conflict with my ooma which also uses 1194 even though this had never previously been an issue.

    Any idea what might be causing this issue? I tried wiping my drive, reinstalling the 2.1.2 image, and using my old config file and am now in the same boat after a week.

    here is the log before a restart, I have only altered my wan ip to ...:

    Apr 24 15:52:31
    openvpn[63980]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 15:52:31
    openvpn[63980]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 15:52:31
    openvpn[63980]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 15:52:31
    openvpn[63980]: TCP/UDP: Socket bind failed on local address [AF_INET]...:1195: Address already in use
    Apr 24 15:52:31
    openvpn[63980]: Exiting due to fatal error
    Apr 24 15:52:40
    openvpn[74226]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 15:52:40
    openvpn[74226]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 15:52:40
    openvpn[74226]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 15:52:40
    openvpn[74226]: TCP/UDP: Socket bind failed on local address [AF_INET]...:1195: Address already in use
    Apr 24 15:52:40
    openvpn[74226]: Exiting due to fatal error
    Apr 24 18:03:02
    openvpn[8964]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 18:03:02
    openvpn[8964]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 18:03:02
    openvpn[8964]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 18:03:02
    openvpn[8964]: TCP/UDP: Socket bind failed on local address [AF_INET]...:1195: Address already in use
    Apr 24 18:03:02
    openvpn[8964]: Exiting due to fatal error
    Apr 24 18:03:09
    openvpn[19196]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 18:03:09
    openvpn[19196]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 18:03:09
    openvpn[19196]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 18:03:09
    openvpn[19196]: TCP/UDP: Socket bind failed on local address [AF_INET]...:1195: Address already in use
    Apr 24 18:03:09
    openvpn[19196]: Exiting due to fatal error
    Apr 24 18:20:39
    openvpn[85488]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 18:20:39
    openvpn[85488]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 18:20:39
    openvpn[85488]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 18:20:39
    openvpn[85488]: TCP/UDP: Socket bind failed on local address [AF_INET]...:1195: Address already in use
    Apr 24 18:20:39
    openvpn[85488]: Exiting due to fatal error
    Apr 24 18:20:46
    openvpn[96403]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 18:20:46
    openvpn[96403]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 18:20:46
    openvpn[96403]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 18:20:46
    openvpn[96403]: TCP/UDP: Socket bind failed on local address [AF_INET]...:1195: Address already in use
    Apr 24 18:20:46
    openvpn[96403]: Exiting due to fatal error
    Apr 24 19:23:51
    openvpn[77609]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 19:23:51
    openvpn[77609]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 19:23:51
    openvpn[77609]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 19:23:51
    openvpn[77609]: TCP/UDP: Socket bind failed on local address [AF_INET]...:1195: Address already in use
    Apr 24 19:23:51
    openvpn[77609]: Exiting due to fatal error
    Apr 24 19:23:54
    openvpn[84055]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 19:23:54
    openvpn[84055]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 19:23:54
    openvpn[84055]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 19:23:54
    openvpn[84055]: TCP/UDP: Socket bind failed on local address [AF_INET]...:1195: Address already in use
    Apr 24 19:23:54
    openvpn[84055]: Exiting due to fatal error
    Apr 24 19:23:54
    openvpn[88361]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 19:23:54
    openvpn[88361]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 19:23:54
    openvpn[88361]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 19:23:54
    openvpn[88361]: TCP/UDP: Socket bind failed on local address [AF_INET]...:1195: Address already in use
    Apr 24 19:23:54
    openvpn[88361]: Exiting due to fatal error
    Apr 24 20:12:01
    openvpn[3389]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 20:12:01
    openvpn[3389]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 20:12:01
    openvpn[3389]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 20:12:01
    openvpn[3389]: TCP/UDP: Socket bind failed on local address [AF_INET]...:1195: Address already in use
    Apr 24 20:12:01
    openvpn[3389]: Exiting due to fatal error

    And after a restart :

    Apr 24 20:23:42
    openvpn[20117]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 20:23:43
    openvpn[20117]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 20:23:43
    openvpn[20117]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 20:23:43
    openvpn[20117]: TUN/TAP device ovpns1 exists previously, keep at program end
    Apr 24 20:23:43
    openvpn[20117]: TUN/TAP device /dev/tun1 opened
    Apr 24 20:23:43
    openvpn[20117]: do_ifconfig, tt->ipv6=1, tt->did_ifconfig_ipv6_setup=0
    Apr 24 20:23:43
    openvpn[20117]: /sbin/ifconfig ovpns1 10.9.9.1 10.9.9.2 mtu 1500 netmask 255.255.255.255 up
    Apr 24 20:23:43
    openvpn[20117]: /usr/local/sbin/ovpn-linkup ovpns1 1500 1558 10.9.9.1 10.9.9.2 init
    Apr 24 20:23:43
    openvpn[22381]: UDPv4 link local (bound): [AF_INET]...:1195
    Apr 24 20:23:43
    openvpn[22381]: UDPv4 link remote: [undef]
    Apr 24 20:23:43
    openvpn[22381]: Initialization Sequence Completed
    Apr 24 20:23:51
    openvpn[22381]: event_wait : Interrupted system call (code=4)
    Apr 24 20:23:51
    openvpn[22381]: /usr/local/sbin/ovpn-linkdown ovpns1 1500 1558 10.9.9.1 10.9.9.2 init
    Apr 24 20:23:51
    openvpn[22381]: SIGTERM[hard,] received, process exiting
    Apr 24 20:23:51
    openvpn[74839]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Mar 27 2014
    Apr 24 20:23:51
    openvpn[74839]: NOTE: the current –script-security setting may allow this configuration to call user-defined scripts
    Apr 24 20:23:51
    openvpn[74839]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    Apr 24 20:23:51
    openvpn[74839]: TUN/TAP device ovpns1 exists previously, keep at program end
    Apr 24 20:23:51
    openvpn[74839]: TUN/TAP device /dev/tun1 opened
    Apr 24 20:23:51
    openvpn[74839]: do_ifconfig, tt->ipv6=1, tt->did_ifconfig_ipv6_setup=0
    Apr 24 20:23:51
    openvpn[74839]: /sbin/ifconfig ovpns1 10.9.9.1 10.9.9.2 mtu 1500 netmask 255.255.255.255 up
    Apr 24 20:23:51
    openvpn[74839]: /usr/local/sbin/ovpn-linkup ovpns1 1500 1558 10.9.9.1 10.9.9.2 init
    Apr 24 20:23:51
    openvpn[79664]: UDPv4 link local (bound): [AF_INET]...:1195
    Apr 24 20:23:51
    openvpn[79664]: UDPv4 link remote: [undef]
    Apr 24 20:23:51
    openvpn[79664]: Initialization Sequence Completed

    Any ideas on how to resolve this issue? It seems like it is creating some type of ghost sessions perhaps?

    SYSLOG:

    Apr 25 16:10:20 check_reload_status: updating dyndns WAN_DHCP
    Apr 25 16:10:20 check_reload_status: Restarting ipsec tunnels
    Apr 25 16:10:20 check_reload_status: Restarting OpenVPN tunnels/interfaces
    Apr 25 16:10:20 check_reload_status: Reloading filter
    Apr 25 16:10:24 php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP.
    Apr 25 16:10:24 php: rc.openvpn: OpenVPN: Resync server1
    Apr 25 16:10:24 php: rc.dyndns.update: phpDynDNS (########.com): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
    Apr 25 16:10:24 check_reload_status: Reloading filter
    Apr 25 16:10:30 check_reload_status: updating dyndns WAN_DHCP
    Apr 25 16:10:30 check_reload_status: Restarting ipsec tunnels
    Apr 25 16:10:30 check_reload_status: Restarting OpenVPN tunnels/interfaces
    Apr 25 16:10:33 php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP.
    Apr 25 16:10:33 php: rc.openvpn: OpenVPN: Resync server1
    Apr 25 16:10:33 php: rc.dyndns.update: phpDynDNS (#######.com): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
    Apr 25 17:30:58 check_reload_status: updating dyndns WAN_DHCP
    Apr 25 17:30:58 check_reload_status: Restarting ipsec tunnels
    Apr 25 17:30:58 check_reload_status: Restarting OpenVPN tunnels/interfaces
    Apr 25 17:30:58 check_reload_status: Reloading filter
    Apr 25 17:31:01 php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP.
    Apr 25 17:31:01 php: rc.openvpn: OpenVPN: Resync server1
    Apr 25 17:31:01 check_reload_status: Reloading filter
    Apr 25 17:31:02 php: rc.dyndns.update: phpDynDNS (######.com): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
    Apr 25 17:31:07 check_reload_status: updating dyndns WAN_DHCP
    Apr 25 17:31:07 check_reload_status: Restarting ipsec tunnels
    Apr 25 17:31:07 check_reload_status: Restarting OpenVPN tunnels/interfaces
    Apr 25 17:31:10 php: rc.dyndns.update: phpDynDNS (########.com): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
    Apr 25 17:31:10 php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP.
    Apr 25 17:31:10 php: rc.openvpn: OpenVPN: Resync server1
    Apr 25 19:22:10 check_reload_status: updating dyndns WAN_DHCP
    Apr 25 19:22:10 check_reload_status: Restarting ipsec tunnels
    Apr 25 19:22:10 check_reload_status: Restarting OpenVPN tunnels/interfaces
    Apr 25 19:22:10 check_reload_status: Reloading filter
    Apr 25 19:22:14 php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP.
    Apr 25 19:22:14 php: rc.openvpn: OpenVPN: Resync server1
    Apr 25 19:22:14 php: rc.dyndns.update: phpDynDNS (########.com): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
    Apr 25 19:22:14 check_reload_status: Reloading filter
    Apr 25 19:22:15 check_reload_status: updating dyndns WAN_DHCP
    Apr 25 19:22:15 check_reload_status: Restarting ipsec tunnels
    Apr 25 19:22:15 check_reload_status: Restarting OpenVPN tunnels/interfaces
    Apr 25 19:22:18 php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP.
    Apr 25 19:22:18 php: rc.dyndns.update: phpDynDNS (#######.com): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
    Apr 25 19:22:18 php: rc.openvpn: OpenVPN: Resync server1



  • Do you use 1:1 NAT on this IP?



  • @viragomann:

    Do you use 1:1 NAT on this IP?

    No there is nothing in the advanced field. Should I set it? it was never an issue before…

    IPv4 Tunnel Network 10.9.9.0/27

    IPv4 Local Network/s 10.9.8.0/27

    Today I limited the concurrent sessions from 10 to 1 to see if it makes a difference, although I'm not sure why it would as it dies when I'm not even using it.



  • No there is nothing in the advanced field. Should I set it? it was never an issue before…

    I mean whether you are using your external IP for other purposes also.
    Maybe it is a problem if you have 1:1 NAT to forward the hole port range to an internal host.

    It seems like it is creating some type of ghost sessions perhaps?

    It's the same here. I have 3 OVPN servers up and each seems to be startet twice. But they work fine.



  • Exactly the same behavior at my setup:

    Apr 28 07:39:21 openvpn[63690]: Exiting due to fatal error
    Apr 28 07:39:21 openvpn[63690]: TCP/UDP: Socket bind failed on local address [AF_INET]xx.xx.xx.xx:1194: Address already in use

    Yesterday I saw that the openvpn server stopped, but after a manual restart the server worked again. Now the server remains up. but still reports these errors. Also the dash gives these messages:

    [error] Unable to contact daemon
    0         Service not running?

    Nothing changed in the setup except the upgrade to 2.1.2.



  • I have this same problem (and not fixed in 2.1.3 btw). The odd thing is I have two pfsense installations which are similar and I believe I set both of them up "the same way" but there are some differences in their details. Only one exhibits this bug.

    No idea if any of this is significant but my "good" configuration is pretty vanilla; Soekris box with the built-in four intel ports and only two active: one WAN one LAN. Works perfectly. The "bad" configuration is an identical Soekris box but with an extra 4 port intel card (8 ports total), and 6 configured active networks but still only one running an openvpn server. It's also openvpn on em1 ("LAN") in the good one and em2 ("OPT1") in the bad one. I would guess the difference is somewhere in all these details but I have not spent any time trying to find it.

    You can "fix" it by going to the shell and finding your openvpn process

    # ps auxww | grep openvpn

    and then killing it. Then restart from the GUI and "all will be well". Something isn't quite right in the startup scripts but I have not been able to narrow it down.



  • Same problem here after the upgrade to 2.1.3… :o



  • Exactly this very same issue I have on 2.1.3-RELEASE (amd64) – clean install

    Has anyone found a resolution to this issue yet?



  • Just started happening to me with 2.1.2-RELEASE (amd64).  Wasn't even logged into PfSense.  Abruptly i started getting the same message as others, by txt, so opened PfSense and found OpenVpn service was down and cron was trying to restart it.  Every restart produces the same message and OpenVpn won't start so I removed it from Cron to keep from getting annoyed by the repeating error message.  I'll try a cron 4am reboot and hope it resolves itself.



  • Found another forum post suggesting ps aux to find the ovpn PID then did a Kill "PID#" to stop the lost instance, then OpenVpn would start which caused NTP service to crash, once restarted caused ntop to crash, once restarted all appears stable. After this odd behavior I'll be rebooting next opportunity.  Solved for now…



  • Mine does the same with NTP as you described (after killing/restarting ovpn), but reloading that status page "fixes" NTP.



  • OpenVPN died again this afternoon. Service watchdog was not able to start it despite repeated attempts. Had to reboot to get it working again. So long to the countdown before another crash.

    Is anyone acknowledging this issue?



  • OP's logs seem to show gateway status going down and back up. When a gateway comes back up, the VPNs associated with it are restarted. Fix your gateway monitoring (set to an IP that replies reliably), or disable it, and it won't do that.



  • Gateway monitoring is disabled since initial install. It's not the case with gateway going down. I have re-checked again and the gateway has been running fine with no ping drops for days.



  • Something is triggering that code path. Maybe a WAN reconnection if a dynamic WAN type?



  • I'd like to add that I too have this problem, but it doesn't start until I max out the outbound bandwidth of my OpenVPN connection (which is used exclusively by OpenVPN)

    This is what the bandwidth graph looks like.  Some data goes through briefly, then the crash and repeat, like what is seen in the OP's logs.

    Also, the 'trick' to kill the OpenVPN process and restart it doesn't fix the problem for me.
    -nb



  • Help - same issue.  Once I max out my network connection OpenVPN crashes.  I have tried 2.11, 2.12, and 2.13 all of these versions appears by have the problem.  I have had very good success with 2.1 working with no problems and tried a clean installed 2.13, but once the network is maxed OPENVPN/connection  crashes.  Any assistance to fix this issue would be greatly appreciate.  I really want to transition to 2.1.3, but not at the expense of OpenVPN and stability.



  • It's not actually crashing from anything anyone's shown here. Something is triggering it to restart, seemingly most likely a gateway being flagged as down. Does anything in the gateways log correlate to the VPN reconnecting?



  • I've noticed I've started to get resets on pfsense connecting out as a openvpn client
    (didn't notice any problems on incoming connections but they may occur)
    not sure if it's the same things as discussed in this thread

    actually, the outgoing client connection seem to be up eventhough it's listed as down,
    I checked and traffic seems to flow ok out through it, but it's listed as down and if I restart it it only works occasionally (reboot better) and then it's listed as up,

    I have a faint memory it worked to restart openvpn earlier but as stated above dont seem to work anymore



  • Running snort?

    For the last 24 hours one out of three boxes snort is killing one of two openVPN tunnels (both clients) from this box, no idea why…

    ![Snort kills openVPN 21.05.2014.JPG](/public/imported_attachments/1/Snort kills openVPN 21.05.2014.JPG)
    ![Snort kills openVPN 21.05.2014.JPG_thumb](/public/imported_attachments/1/Snort kills openVPN 21.05.2014.JPG_thumb)



  • no snort, it's on 4G memcard btw,
    I have 'only' NUT (UPS addon, disabled) and crond packages installed,

    I have /had earlier similar setup to
    http://doc.pfsense.org/Create-OpenVPN-client-to-TUVPNcom.pdf
    (including the crond part at the end) but crond part was inactive lost/disabled since a few upgrades ago



  • I just had the same problem with fresh installation of 2.2 after running with no problems for about two weeks. No idea what triggered this behavior. I had to stop OpenVPN, go to shell and kill processes.

    Any solution to this?



  • @deltix:

    I just had the same problem

    There are at least 2 if not 3 completely different and unrelated problems described by others in this thread. At least one where Snort was blocking the VPN, at least one other that's probably from delayed DNS resolution and the client getting started multiple times (which is fixed in 2.2), and probably different unrelated ones for others. Please start a new thread with specifics on what you're seeing happen, and what OpenVPN logs you're getting at the time.