2.3.1 OpenVPN start up - "Socket bind failed - Address already in use"



  • Hi,

    I've a problem with my remote access OpenVPN servers after upgrade to 2.3.1 from 2.3. The OpenVPN daemon fails at firewall boot up of 1 or 2 of my 3 OpenVPN servers running on WAN address 1194 - 1196. As a result the server status and connections can not be monitored. See attached picture below.

    In the openvpn.log I get the massage

    TCP/UDP: Socket bind failed on local address [AF_INET]<wan address="">:1196: Address already in use</wan>
    

    The server is up anyway and accepts connections. In the log I also find

    UDPv4 link local (bound): [AF_INET]<wan address="">:1196</wan>
    

    But I can't see the server status and connected clients.

    The box is part of a HA-system in CARP mode, the other one is still at 2.2.6 and held the master each time I rebooted this one.

    If I disable all vpn servers before rebooting pfSense and enable them after again, everything works properly.

    Anybody an idea how this could be resolved?

    Here is the full openvpn.log of a firewall boot up:

    May 20 12:38:12 firewall2 openvpn[3046]: event_wait : Interrupted system call (code=4)
    May 20 12:38:12 firewall2 openvpn[3046]: /usr/local/sbin/ovpn-linkdown ovpns1 1500 1558 10.0.41.1 10.0.41.2 init
    May 20 12:38:12 firewall2 openvpn[3046]: SIGTERM[hard,] received, process exiting
    May 20 12:38:13 firewall2 openvpn[10019]: event_wait : Interrupted system call (code=4)
    May 20 12:38:13 firewall2 openvpn[10019]: /usr/local/sbin/ovpn-linkdown ovpns2 1500 1558 10.0.42.1 10.0.42.2 init
    May 20 12:38:13 firewall2 openvpn[10019]: SIGTERM[hard,] received, process exiting
    May 20 12:38:13 firewall2 openvpn[31277]: OpenVPN 2.3.11 amd64-portbld-freebsd10.3 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on May 16 2016
    May 20 12:38:13 firewall2 openvpn[31277]: library versions: OpenSSL 1.0.1s-freebsd  1 Mar 2016, LZO 2.09
    May 20 12:38:13 firewall2 openvpn[32944]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    May 20 12:38:13 firewall2 openvpn[32944]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    May 20 12:38:13 firewall2 openvpn[32944]: TUN/TAP device ovpns1 exists previously, keep at program end
    May 20 12:38:13 firewall2 openvpn[32944]: TUN/TAP device /dev/tun1 opened
    May 20 12:38:13 firewall2 openvpn[32944]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
    May 20 12:38:13 firewall2 openvpn[32944]: /sbin/ifconfig ovpns1 10.0.41.1 10.0.41.2 mtu 1500 netmask 255.255.255.255 up
    May 20 12:38:13 firewall2 openvpn[32944]: /usr/local/sbin/ovpn-linkup ovpns1 1500 1558 10.0.41.1 10.0.41.2 init
    May 20 12:38:13 firewall2 openvpn[32944]: UDPv4 link local (bound): [AF_INET]<wan address="">:1194
    May 20 12:38:13 firewall2 openvpn[32944]: UDPv4 link remote: [undef]
    May 20 12:38:13 firewall2 openvpn[32944]: Initialization Sequence Completed
    May 20 12:38:13 firewall2 openvpn[12163]: event_wait : Interrupted system call (code=4)
    May 20 12:38:13 firewall2 openvpn[12163]: /usr/local/sbin/ovpn-linkdown ovpns3 1500 1558 10.0.43.1 10.0.43.2 init
    May 20 12:38:13 firewall2 openvpn[34223]: OpenVPN 2.3.11 amd64-portbld-freebsd10.3 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on May 16 2016
    May 20 12:38:13 firewall2 openvpn[34223]: library versions: OpenSSL 1.0.1s-freebsd  1 Mar 2016, LZO 2.09
    May 20 12:38:13 firewall2 openvpn[35124]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    May 20 12:38:13 firewall2 openvpn[12163]: SIGTERM[hard,] received, process exiting
    May 20 12:38:13 firewall2 openvpn[35124]: Control Channel Authentication: using '/var/etc/openvpn/server2.tls-auth' as a OpenVPN static key file
    May 20 12:38:13 firewall2 openvpn[35124]: TUN/TAP device ovpns2 exists previously, keep at program end
    May 20 12:38:13 firewall2 openvpn[35124]: TUN/TAP device /dev/tun2 opened
    May 20 12:38:13 firewall2 openvpn[35124]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
    May 20 12:38:13 firewall2 openvpn[35124]: /sbin/ifconfig ovpns2 10.0.42.1 10.0.42.2 mtu 1500 netmask 255.255.255.255 up
    May 20 12:38:13 firewall2 openvpn[35124]: /usr/local/sbin/ovpn-linkup ovpns2 1500 1558 10.0.42.1 10.0.42.2 init
    May 20 12:38:13 firewall2 openvpn[35124]: UDPv4 link local (bound): [AF_INET]<wan address="">:1195
    May 20 12:38:13 firewall2 openvpn[35124]: UDPv4 link remote: [undef]
    May 20 12:38:13 firewall2 openvpn[35124]: Initialization Sequence Completed
    May 20 12:38:13 firewall2 openvpn[36863]: OpenVPN 2.3.11 amd64-portbld-freebsd10.3 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on May 16 2016
    May 20 12:38:13 firewall2 openvpn[36863]: library versions: OpenSSL 1.0.1s-freebsd  1 Mar 2016, LZO 2.09
    May 20 12:38:13 firewall2 openvpn[36867]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    May 20 12:38:13 firewall2 openvpn[36867]: Control Channel Authentication: using '/var/etc/openvpn/server3.tls-auth' as a OpenVPN static key file
    May 20 12:38:13 firewall2 openvpn[36867]: TUN/TAP device ovpns3 exists previously, keep at program end
    May 20 12:38:13 firewall2 openvpn[36867]: TUN/TAP device /dev/tun3 opened
    May 20 12:38:13 firewall2 openvpn[36867]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
    May 20 12:38:13 firewall2 openvpn[36867]: /sbin/ifconfig ovpns3 10.0.43.1 10.0.43.2 mtu 1500 netmask 255.255.255.255 up
    May 20 12:38:13 firewall2 openvpn[36867]: /usr/local/sbin/ovpn-linkup ovpns3 1500 1558 10.0.43.1 10.0.43.2 init
    May 20 12:38:13 firewall2 openvpn[36867]: UDPv4 link local (bound): [AF_INET]<wan address="">:1196
    May 20 12:38:13 firewall2 openvpn[36867]: UDPv4 link remote: [undef]
    May 20 12:38:13 firewall2 openvpn[36867]: Initialization Sequence Completed
    May 20 12:44:42 firewall2 openvpn[24631]: OpenVPN 2.3.11 amd64-portbld-freebsd10.3 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on May 16 2016
    May 20 12:44:42 firewall2 openvpn[24631]: library versions: OpenSSL 1.0.1s-freebsd  1 Mar 2016, LZO 2.09
    May 20 12:44:42 firewall2 openvpn[23894]: OpenVPN 2.3.11 amd64-portbld-freebsd10.3 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on May 16 2016
    May 20 12:44:42 firewall2 openvpn[23212]: OpenVPN 2.3.11 amd64-portbld-freebsd10.3 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on May 16 2016
    May 20 12:44:42 firewall2 openvpn[23212]: library versions: OpenSSL 1.0.1s-freebsd  1 Mar 2016, LZO 2.09
    May 20 12:44:42 firewall2 openvpn[23894]: library versions: OpenSSL 1.0.1s-freebsd  1 Mar 2016, LZO 2.09
    May 20 12:44:42 firewall2 openvpn[25862]: OpenVPN 2.3.11 amd64-portbld-freebsd10.3 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on May 16 2016
    May 20 12:44:42 firewall2 openvpn[25389]: OpenVPN 2.3.11 amd64-portbld-freebsd10.3 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on May 16 2016
    May 20 12:44:42 firewall2 openvpn[25200]: OpenVPN 2.3.11 amd64-portbld-freebsd10.3 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on May 16 2016
    May 20 12:44:42 firewall2 openvpn[25389]: library versions: OpenSSL 1.0.1s-freebsd  1 Mar 2016, LZO 2.09
    May 20 12:44:42 firewall2 openvpn[25862]: library versions: OpenSSL 1.0.1s-freebsd  1 Mar 2016, LZO 2.09
    May 20 12:44:42 firewall2 openvpn[25200]: library versions: OpenSSL 1.0.1s-freebsd  1 Mar 2016, LZO 2.09
    May 20 12:44:42 firewall2 openvpn[27205]: Could not retrieve default gateway from route socket:: No such process (errno=3)
    May 20 12:44:42 firewall2 openvpn[27205]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    May 20 12:44:42 firewall2 openvpn[27768]: Could not retrieve default gateway from route socket:: No such process (errno=3)
    May 20 12:44:42 firewall2 openvpn[27768]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    May 20 12:44:42 firewall2 openvpn[27392]: Could not retrieve default gateway from route socket:: No such process (errno=3)
    May 20 12:44:42 firewall2 openvpn[27392]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    May 20 12:44:42 firewall2 openvpn[27445]: Could not retrieve default gateway from route socket:: No such process (errno=3)
    May 20 12:44:42 firewall2 openvpn[27445]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    May 20 12:44:42 firewall2 openvpn[28060]: MANAGEMENT: Socket bind[5] failed on unix domain socket /var/etc/openvpn/server2.sock: Address already in use
    May 20 12:44:42 firewall2 openvpn[28060]: Exiting due to fatal error
    May 20 12:44:42 firewall2 openvpn[27497]: Could not retrieve default gateway from route socket:: No such process (errno=3)
    May 20 12:44:42 firewall2 openvpn[27497]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    May 20 12:44:42 firewall2 openvpn[27205]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    May 20 12:44:42 firewall2 openvpn[27445]: Control Channel Authentication: using '/var/etc/openvpn/server2.tls-auth' as a OpenVPN static key file
    May 20 12:44:42 firewall2 openvpn[27768]: Control Channel Authentication: using '/var/etc/openvpn/server3.tls-auth' as a OpenVPN static key file
    May 20 12:44:42 firewall2 openvpn[27205]: Could not retrieve default gateway from route socket:: No such process (errno=3)
    May 20 12:44:42 firewall2 openvpn[27445]: Could not retrieve default gateway from route socket:: No such process (errno=3)
    May 20 12:44:42 firewall2 openvpn[27205]: TUN/TAP device ovpns1 exists previously, keep at program end
    May 20 12:44:42 firewall2 openvpn[27768]: Could not retrieve default gateway from route socket:: No such process (errno=3)
    May 20 12:44:42 firewall2 openvpn[27445]: TUN/TAP device ovpns2 exists previously, keep at program end
    May 20 12:44:42 firewall2 openvpn[27205]: TUN/TAP device /dev/tun1 opened
    May 20 12:44:42 firewall2 openvpn[27205]: ioctl(TUNSIFMODE): Device busy: Device busy (errno=16)
    May 20 12:44:42 firewall2 openvpn[27768]: TUN/TAP device ovpns3 exists previously, keep at program end
    May 20 12:44:42 firewall2 openvpn[27205]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
    May 20 12:44:42 firewall2 openvpn[27445]: TUN/TAP device /dev/tun2 opened
    May 20 12:44:42 firewall2 openvpn[27445]: ioctl(TUNSIFMODE): Device busy: Device busy (errno=16)
    May 20 12:44:42 firewall2 openvpn[27205]: /sbin/ifconfig ovpns1 10.0.41.1 10.0.41.2 mtu 1500 netmask 255.255.255.255 up
    May 20 12:44:42 firewall2 openvpn[27445]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
    May 20 12:44:42 firewall2 openvpn[27768]: TUN/TAP device /dev/tun3 opened
    May 20 12:44:42 firewall2 openvpn[27445]: /sbin/ifconfig ovpns2 10.0.42.1 10.0.42.2 mtu 1500 netmask 255.255.255.255 up
    May 20 12:44:42 firewall2 openvpn[27768]: ioctl(TUNSIFMODE): Device busy: Device busy (errno=16)
    May 20 12:44:42 firewall2 openvpn[27497]: Control Channel Authentication: using '/var/etc/openvpn/server3.tls-auth' as a OpenVPN static key file
    May 20 12:44:42 firewall2 openvpn[27392]: Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    May 20 12:44:42 firewall2 openvpn[27768]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
    May 20 12:44:42 firewall2 openvpn[27768]: /sbin/ifconfig ovpns3 10.0.43.1 10.0.43.2 mtu 1500 netmask 255.255.255.255 up
    May 20 12:44:42 firewall2 openvpn[27497]: TCP/UDP: Socket bind failed on local address [AF_INET]<wan address="">:1196: Address already in use
    May 20 12:44:42 firewall2 openvpn[27392]: TCP/UDP: Socket bind failed on local address [AF_INET]<wan address="">:1194: Address already in use
    May 20 12:44:42 firewall2 openvpn[27497]: Exiting due to fatal error
    May 20 12:44:42 firewall2 openvpn[27392]: Exiting due to fatal error
    May 20 12:44:42 firewall2 openvpn[27445]: /usr/local/sbin/ovpn-linkup ovpns2 1500 1558 10.0.42.1 10.0.42.2 init
    May 20 12:44:42 firewall2 openvpn[27768]: /usr/local/sbin/ovpn-linkup ovpns3 1500 1558 10.0.43.1 10.0.43.2 init
    May 20 12:44:42 firewall2 openvpn[27205]: /usr/local/sbin/ovpn-linkup ovpns1 1500 1558 10.0.41.1 10.0.41.2 init
    May 20 12:44:42 firewall2 openvpn[27768]: UDPv4 link local (bound): [AF_INET]<wan address="">:1196
    May 20 12:44:42 firewall2 openvpn[27768]: UDPv4 link remote: [undef]
    May 20 12:44:42 firewall2 openvpn[27768]: Initialization Sequence Completed
    May 20 12:44:42 firewall2 openvpn[27445]: UDPv4 link local (bound): [AF_INET]<wan address="">:1195
    May 20 12:44:42 firewall2 openvpn[27445]: UDPv4 link remote: [undef]
    May 20 12:44:42 firewall2 openvpn[27445]: Initialization Sequence Completed
    May 20 12:44:42 firewall2 openvpn[27205]: UDPv4 link local (bound): [AF_INET]<wan address="">:1194
    May 20 12:44:42 firewall2 openvpn[27205]: UDPv4 link remote: [undef]
    May 20 12:44:42 firewall2 openvpn[27205]: Initialization Sequence Completed</wan></wan></wan></wan></wan></wan></wan></wan> 
    ```![firewall2-Status_OpenVPN.png](/public/_imported_attachments_/1/firewall2-Status_OpenVPN.png)
    ![firewall2-Status_OpenVPN.png_thumb](/public/_imported_attachments_/1/firewall2-Status_OpenVPN.png_thumb)


  • Hello,

    I'm having a similar issue. My OpenVPN servers show offline, but I can still make connections.

    Only a reboot will return the status online, but they will eventually show offline again.  The Dashboard shows "[error] Unable to contact daemon Service not running?"

    The issue did not start until 2.3.1

    May 21 22:52:32	openvpn	54907	OpenVPN 2.3.11 amd64-portbld-freebsd10.3 [SSL (OpenSSL)] [LZO] [MH] [IPv6] built on May 16 2016
    May 21 22:52:32	openvpn	54907	library versions: OpenSSL 1.0.1s-freebsd 1 Mar 2016, LZO 2.09
    May 21 22:52:32	openvpn	55163	NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    May 21 22:52:32	openvpn	55163	Control Channel Authentication: using '/var/etc/openvpn/server1.tls-auth' as a OpenVPN static key file
    May 21 22:52:32	openvpn	55163	TCP/UDP: Socket bind failed on local address [AF_INET]<wanip>:1194: Address already in use
    May 21 22:52:32	openvpn	55163	Exiting due to fatal error</wanip>
    


  • Update:
    The problem only occurs when the OpenVPN servers are listening on the WAN CARP VIP. If I set them to listen on an internal CARP VIP all servers and daemons start smoothly. I've tested it with 2 other CARP VIPs a couple of times, no failure.

    The WAN interfaces of the 2 pfSense boxes are connected to the WAN switch, which is also connected to the ISPs modem, no other devices there.
    CARP works without an issue.

    So what could be wrong with the WAN CARP VIP?

    Now I let the servers listen at an internal VIP on OPT2 on both, master and backup, and I forward the OpenVPN ports from WAN VIP to it. Now there is no fault at start up.