Phantom OpenVPN client session



  • I am trying to track down this phantom OpenVPN client session that gets started soon after the firewall is booted up and somehow is not tracked by its pid so its never killed.

    I am running 8/31 snapshot with my own fixes for #3172 and #3174 incorporated. There is only one OpenVPN client configured on this firewall. It is bound to a gateway group which in turn has CARP VIPs for the primary and backup WAN links. There is a backup firewall in this CARP cluster as well but the OpenVPN client never starts on it.

    In the logs I have made the following substitutions:

    <fqdn_of_far_end_server>= DNS name of the far side OpenVPN server this client needs to connect to.
    <vip_tier1>= CARP VIP of primary WAN
    <vip_tier2>= CARP VIP of backup WAN
    <ip_of_far_end_server>= IP address of <fqdn_of_far_end_server>Log is from the moment the firewall boots up.

    
    001 | Sep 1 23:03:52 openvpn[24435]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Jul 24 2013
    002 | Sep 1 23:03:52 openvpn[24435]: WARNING: using --pull/--client and --ifconfig together is probably not what you want
    003 | Sep 1 23:03:52 openvpn[24435]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    004 | Sep 1 23:03:52 openvpn[24435]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    005 | Sep 1 23:03:52 openvpn[24435]: Control Channel Authentication: using '/var/etc/openvpn/client2.tls-auth' as a OpenVPN static key file
    006 | Sep 1 23:04:12 openvpn[16778]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Jul 24 2013
    007 | Sep 1 23:04:12 openvpn[16778]: WARNING: using --pull/--client and --ifconfig together is probably not what you want
    008 | Sep 1 23:04:12 openvpn[16778]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    009 | Sep 1 23:04:12 openvpn[16778]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    010 | Sep 1 23:04:12 openvpn[16778]: Control Channel Authentication: using '/var/etc/openvpn/client2.tls-auth' as a OpenVPN static key file
    011 | Sep 1 23:04:29 openvpn[16778]: RESOLVE: Cannot resolve host address: <fqdn_of_far_end_server>: hostname nor servname provided, or not known
    012 | Sep 1 23:04:29 openvpn[22772]: UDPv4 link local (bound): [AF_INET] <vip_tier2>013 | Sep 1 23:04:29 openvpn[22772]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    014 | Sep 1 23:04:30 openvpn[22772]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    015 | Sep 1 23:04:30 openvpn[22772]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    016 | Sep 1 23:04:30 openvpn[22772]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    017 | Sep 1 23:04:33 openvpn[22772]: TUN/TAP device ovpnc2 exists previously, keep at program end
    018 | Sep 1 23:04:33 openvpn[22772]: TUN/TAP device /dev/tun2 opened
    019 | Sep 1 23:04:33 openvpn[22772]: do_ifconfig, tt->ipv6=1, tt->did_ifconfig_ipv6_setup=0
    020 | Sep 1 23:04:33 openvpn[22772]: /sbin/ifconfig ovpnc2 192.168.240.38 192.168.240.37 mtu 1500 netmask 255.255.255.255 up
    021 | Sep 1 23:04:33 openvpn[22772]: /usr/local/sbin/ovpn-linkup ovpnc2 1500 1557 192.168.240.38 192.168.240.37 init
    022 | Sep 1 23:04:33 openvpn[22772]: Initialization Sequence Completed
    023 | Sep 1 23:04:33 openvpn[24435]: RESOLVE: Cannot resolve host address: <fqdn_of_far_end_server>: hostname nor servname provided, or not known
    024 | Sep 1 23:04:33 openvpn[26127]: UDPv4 link local (bound): [AF_INET] <vip_tier1>025 | Sep 1 23:04:33 openvpn[26127]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    026 | Sep 1 23:04:34 openvpn[26127]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    027 | Sep 1 23:04:34 openvpn[26127]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    028 | Sep 1 23:04:34 openvpn[26127]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    029 | Sep 1 23:04:36 openvpn[26127]: event_wait : Interrupted system call (code=4)
    030 | Sep 1 23:04:36 openvpn[26127]: SIGTERM[hard,] received, process exiting
    031 | Sep 1 23:04:36 openvpn[46582]: OpenVPN 2.3.2 amd64-portbld-freebsd8.3 [SSL (OpenSSL)] [LZO] [eurephia] [MH] [IPv6] built on Jul 24 2013
    032 | Sep 1 23:04:36 openvpn[46582]: WARNING: using --pull/--client and --ifconfig together is probably not what you want
    033 | Sep 1 23:04:36 openvpn[46582]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    034 | Sep 1 23:04:36 openvpn[46582]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    035 | Sep 1 23:04:36 openvpn[46582]: Control Channel Authentication: using '/var/etc/openvpn/client2.tls-auth' as a OpenVPN static key file
    036 | Sep 1 23:04:36 openvpn[46591]: UDPv4 link local (bound): [AF_INET] <vip_tier1>037 | Sep 1 23:04:36 openvpn[46591]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    038 | Sep 1 23:04:37 openvpn[46591]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    039 | Sep 1 23:04:37 openvpn[46591]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    040 | Sep 1 23:04:37 openvpn[46591]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    041 | Sep 1 23:04:40 openvpn[22772]: [<cn_of_far_end_server's_cert>] Inactivity timeout (--ping-restart), restarting
    042 | Sep 1 23:04:40 openvpn[22772]: SIGUSR1[soft,ping-restart] received, process restarting
    043 | Sep 1 23:04:42 openvpn[22772]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    044 | Sep 1 23:04:42 openvpn[22772]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    045 | Sep 1 23:04:42 openvpn[22772]: UDPv4 link local (bound): [AF_INET] <vip_tier2>046 | Sep 1 23:04:42 openvpn[22772]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    047 | Sep 1 23:04:43 openvpn[22772]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    048 | Sep 1 23:04:43 openvpn[22772]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    049 | Sep 1 23:04:43 openvpn[22772]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    050 | Sep 1 23:04:49 openvpn[46591]: [<cn_of_far_end_server's_cert>] Inactivity timeout (--ping-restart), restarting
    051 | Sep 1 23:04:49 openvpn[46591]: SIGUSR1[soft,ping-restart] received, process restarting
    052 | Sep 1 23:04:51 openvpn[46591]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    053 | Sep 1 23:04:51 openvpn[46591]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    054 | Sep 1 23:04:51 openvpn[46591]: UDPv4 link local (bound): [AF_INET] <vip_tier1>055 | Sep 1 23:04:51 openvpn[46591]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    056 | Sep 1 23:04:52 openvpn[46591]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    057 | Sep 1 23:04:52 openvpn[46591]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    058 | Sep 1 23:04:52 openvpn[46591]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    059 | Sep 1 23:04:57 openvpn[22772]: [<cn_of_far_end_server's_cert>] Inactivity timeout (--ping-restart), restarting
    060 | Sep 1 23:04:57 openvpn[22772]: SIGUSR1[soft,ping-restart] received, process restarting
    061 | Sep 1 23:04:59 openvpn[22772]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    062 | Sep 1 23:04:59 openvpn[22772]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    063 | Sep 1 23:04:59 openvpn[22772]: UDPv4 link local (bound): [AF_INET] <vip_tier2>064 | Sep 1 23:04:59 openvpn[22772]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    065 | Sep 1 23:05:00 openvpn[22772]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    066 | Sep 1 23:05:00 openvpn[22772]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    067 | Sep 1 23:05:00 openvpn[22772]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    068 | Sep 1 23:05:06 openvpn[46591]: [<cn_of_far_end_server's_cert>] Inactivity timeout (--ping-restart), restarting
    069 | Sep 1 23:05:06 openvpn[46591]: SIGUSR1[soft,ping-restart] received, process restarting
    070 | Sep 1 23:05:07 openvpn[22772]: Preserving previous TUN/TAP instance: ovpnc2
    071 | Sep 1 23:05:07 openvpn[22772]: NOTE: Pulled options changed on restart, will need to close and reopen TUN/TAP device.
    072 | Sep 1 23:05:07 openvpn[22772]: /usr/local/sbin/ovpn-linkdown ovpnc2 1500 1557 192.168.240.38 192.168.240.37 init
    073 | Sep 1 23:05:08 openvpn[46591]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    074 | Sep 1 23:05:08 openvpn[46591]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    075 | Sep 1 23:05:08 openvpn[46591]: UDPv4 link local (bound): [AF_INET] <vip_tier1>076 | Sep 1 23:05:08 openvpn[46591]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    077 | Sep 1 23:05:08 openvpn[22772]: TUN/TAP device ovpnc2 exists previously, keep at program end
    078 | Sep 1 23:05:08 openvpn[22772]: TUN/TAP device /dev/tun2 opened
    079 | Sep 1 23:05:08 openvpn[22772]: do_ifconfig, tt->ipv6=1, tt->did_ifconfig_ipv6_setup=0
    080 | Sep 1 23:05:08 openvpn[22772]: /sbin/ifconfig ovpnc2 192.168.240.38 192.168.240.37 mtu 1500 netmask 255.255.255.255 up
    081 | Sep 1 23:05:08 openvpn[22772]: /usr/local/sbin/ovpn-linkup ovpnc2 1500 1557 192.168.240.38 192.168.240.37 init
    082 | Sep 1 23:05:08 openvpn[22772]: Initialization Sequence Completed
    083 | Sep 1 23:05:09 openvpn[46591]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    084 | Sep 1 23:05:09 openvpn[46591]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    085 | Sep 1 23:05:09 openvpn[46591]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    086 | Sep 1 23:05:15 openvpn[22772]: [<cn_of_far_end_server's_cert>] Inactivity timeout (--ping-restart), restarting
    087 | Sep 1 23:05:15 openvpn[22772]: SIGUSR1[soft,ping-restart] received, process restarting
    088 | Sep 1 23:05:17 openvpn[22772]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    089 | Sep 1 23:05:17 openvpn[22772]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    090 | Sep 1 23:05:17 openvpn[22772]: UDPv4 link local (bound): [AF_INET] <vip_tier2>091 | Sep 1 23:05:17 openvpn[22772]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    092 | Sep 1 23:05:18 openvpn[22772]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    093 | Sep 1 23:05:18 openvpn[22772]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    094 | Sep 1 23:05:18 openvpn[22772]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    095 | Sep 1 23:05:24 openvpn[46591]: [<cn_of_far_end_server's_cert>] Inactivity timeout (--ping-restart), restarting
    096 | Sep 1 23:05:24 openvpn[46591]: SIGUSR1[soft,ping-restart] received, process restarting
    097 | Sep 1 23:05:27 openvpn[46591]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    098 | Sep 1 23:05:27 openvpn[46591]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    099 | Sep 1 23:05:27 openvpn[46591]: UDPv4 link local (bound): [AF_INET] <vip_tier1>100 | Sep 1 23:05:27 openvpn[46591]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    101 | Sep 1 23:05:28 openvpn[46591]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    102 | Sep 1 23:05:28 openvpn[46591]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    103 | Sep 1 23:05:28 openvpn[46591]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    104 | Sep 1 23:05:34 openvpn[22772]: [<cn_of_far_end_server's_cert>] Inactivity timeout (--ping-restart), restarting
    105 | Sep 1 23:05:34 openvpn[22772]: SIGUSR1[soft,ping-restart] received, process restarting
    106 | Sep 1 23:05:36 openvpn[22772]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    107 | Sep 1 23:05:36 openvpn[22772]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    108 | Sep 1 23:05:36 openvpn[22772]: UDPv4 link local (bound): [AF_INET] <vip_tier2>109 | Sep 1 23:05:36 openvpn[22772]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    110 | Sep 1 23:05:37 openvpn[22772]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    111 | Sep 1 23:05:37 openvpn[22772]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    112 | Sep 1 23:05:37 openvpn[22772]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    113 | Sep 1 23:05:39 openvpn[22772]: Preserving previous TUN/TAP instance: ovpnc2
    114 | Sep 1 23:05:39 openvpn[22772]: NOTE: Pulled options changed on restart, will need to close and reopen TUN/TAP device.
    115 | Sep 1 23:05:39 openvpn[22772]: /usr/local/sbin/ovpn-linkdown ovpnc2 1500 1557 192.168.240.38 192.168.240.37 init
    116 | Sep 1 23:05:40 openvpn[22772]: TUN/TAP device ovpnc2 exists previously, keep at program end
    117 | Sep 1 23:05:40 openvpn[22772]: TUN/TAP device /dev/tun2 opened
    118 | Sep 1 23:05:40 openvpn[22772]: do_ifconfig, tt->ipv6=1, tt->did_ifconfig_ipv6_setup=0
    119 | Sep 1 23:05:40 openvpn[22772]: /sbin/ifconfig ovpnc2 192.168.240.38 192.168.240.37 mtu 1500 netmask 255.255.255.255 up
    120 | Sep 1 23:05:40 openvpn[22772]: /usr/local/sbin/ovpn-linkup ovpnc2 1500 1557 192.168.240.38 192.168.240.37 init
    121 | Sep 1 23:05:40 openvpn[22772]: Initialization Sequence Completed
    122 | Sep 1 23:05:43 openvpn[46591]: [<cn_of_far_end_server's_cert>] Inactivity timeout (--ping-restart), restarting
    123 | Sep 1 23:05:43 openvpn[46591]: SIGUSR1[soft,ping-restart] received, process restarting
    124 | Sep 1 23:05:45 openvpn[46591]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    125 | Sep 1 23:05:45 openvpn[46591]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    126 | Sep 1 23:05:45 openvpn[46591]: UDPv4 link local (bound): [AF_INET] <vip_tier1>127 | Sep 1 23:05:45 openvpn[46591]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    128 | Sep 1 23:05:46 openvpn[46591]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    129 | Sep 1 23:05:46 openvpn[46591]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    130 | Sep 1 23:05:46 openvpn[46591]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    131 | Sep 1 23:05:52 openvpn[22772]: [<cn_of_far_end_server's_cert>] Inactivity timeout (--ping-restart), restarting
    132 | Sep 1 23:05:52 openvpn[22772]: SIGUSR1[soft,ping-restart] received, process restarting
    133 | Sep 1 23:05:54 openvpn[22772]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    134 | Sep 1 23:05:54 openvpn[22772]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    135 | Sep 1 23:05:54 openvpn[22772]: UDPv4 link local (bound): [AF_INET] <vip_tier2>136 | Sep 1 23:05:54 openvpn[22772]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    137 | Sep 1 23:05:55 openvpn[22772]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    138 | Sep 1 23:05:55 openvpn[22772]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    139 | Sep 1 23:05:55 openvpn[22772]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    140 | Sep 1 23:06:00 openvpn[46591]: [<cn_of_far_end_server's_cert>] Inactivity timeout (--ping-restart), restarting
    141 | Sep 1 23:06:00 openvpn[46591]: SIGUSR1[soft,ping-restart] received, process restarting
    142 | Sep 1 23:06:02 openvpn[46591]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    143 | Sep 1 23:06:02 openvpn[46591]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    144 | Sep 1 23:06:02 openvpn[46591]: UDPv4 link local (bound): [AF_INET] <vip_tier1>145 | Sep 1 23:06:02 openvpn[46591]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    146 | Sep 1 23:06:03 openvpn[46591]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    147 | Sep 1 23:06:03 openvpn[46591]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    148 | Sep 1 23:06:03 openvpn[46591]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    149 | Sep 1 23:06:08 openvpn[22772]: [<cn_of_far_end_server's_cert>] Inactivity timeout (--ping-restart), restarting
    150 | Sep 1 23:06:08 openvpn[22772]: SIGUSR1[soft,ping-restart] received, process restarting
    151 | Sep 1 23:06:10 openvpn[22772]: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    152 | Sep 1 23:06:10 openvpn[22772]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    153 | Sep 1 23:06:10 openvpn[22772]: UDPv4 link local (bound): [AF_INET] <vip_tier2>154 | Sep 1 23:06:10 openvpn[22772]: UDPv4 link remote: [AF_INET]<ip_of_far_end_server>:16001
    155 | Sep 1 23:06:10 openvpn[46591]: TUN/TAP device ovpnc2 exists previously, keep at program end
    156 | Sep 1 23:06:10 openvpn[46591]: Cannot open TUN/TAP dev /dev/tun2: Device busy (errno=16)
    157 | Sep 1 23:06:10 openvpn[46591]: Exiting due to fatal error
    158 | Sep 1 23:06:11 openvpn[22772]: WARNING: 'tun-ipv6' is present in remote config but missing in local config, remote='tun-ipv6'
    159 | Sep 1 23:06:11 openvpn[22772]: WARNING: 'ifconfig' is present in remote config but missing in local config, remote='ifconfig 192.168.240.38 192.168.240.37'
    160 | Sep 1 23:06:11 openvpn[22772]: [<cn_of_far_end_server's_cert>] Peer Connection Initiated with [AF_INET]<ip_of_far_end_server>:16001
    161 | Sep 1 23:06:44 openvpn[22772]: Preserving previous TUN/TAP instance: ovpnc2
    162 | Sep 1 23:06:44 openvpn[22772]: NOTE: Pulled options changed on restart, will need to close and reopen TUN/TAP device.
    163 | Sep 1 23:06:44 openvpn[22772]: /usr/local/sbin/ovpn-linkdown ovpnc2 1500 1557 192.168.240.38 192.168.240.37 init
    164 | Sep 1 23:06:45 openvpn[22772]: TUN/TAP device ovpnc2 exists previously, keep at program end
    165 | Sep 1 23:06:45 openvpn[22772]: TUN/TAP device /dev/tun2 opened
    166 | Sep 1 23:06:45 openvpn[22772]: do_ifconfig, tt->ipv6=1, tt->did_ifconfig_ipv6_setup=0
    167 | Sep 1 23:06:45 openvpn[22772]: /sbin/ifconfig ovpnc2 192.168.240.38 192.168.240.37 mtu 1500 netmask 255.255.255.255 up
    168 | Sep 1 23:06:45 openvpn[22772]: /usr/local/sbin/ovpn-linkup ovpnc2 1500 1557 192.168.240.38 192.168.240.37 init
    169 | Sep 1 23:06:45 openvpn[22772]: Initialization Sequence Completed</ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier2></cn_of_far_end_server's_cert></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier1></cn_of_far_end_server's_cert></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier2></cn_of_far_end_server's_cert></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier1></cn_of_far_end_server's_cert></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier2></cn_of_far_end_server's_cert></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier1></cn_of_far_end_server's_cert></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier2></cn_of_far_end_server's_cert></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier1></cn_of_far_end_server's_cert></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier2></cn_of_far_end_server's_cert></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier1></cn_of_far_end_server's_cert></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier2></cn_of_far_end_server's_cert></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier1></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier1></fqdn_of_far_end_server></ip_of_far_end_server></cn_of_far_end_server's_cert></ip_of_far_end_server></vip_tier2></fqdn_of_far_end_server> 
    

    Line 006: How come a second instance of OpenVPN is spawning when the first one is still running? Do we have two different sources starting the OpenVPN client?

    Line 011: Name resolution comes from DNSMasq. I guess it is not up yet. At this point pid 16778 either dies or morphs into 22772. Probably should select Infinitely resolve server.

    Line 012: pid 22772 is the phantom session. How it got started is unknown. Why did it bind with the VIP of the backup tier when the primary gateway is up? When all is said and done, this sessions is still up and running.

    Line 013: Magically now it was able to resolve the server name.

    Line 022: pid 22772 VPN connected. How it got connected with the backup (tier2) VIP?

    Line 023: This was the very first OpenVPN session that was started. Pid 24435 is no where to be found in the logs after this.

    Line 024: Second instance of the same VPN trying to come up.

    Line 030: Kaboom!

    Line 031: What started this instance now?

    Line 041: the phantom session times out. I guess because there is no way for traffic to get routed because default gateway is tier 1. Phantom session is still bound to tier 2 VIP.

    After this pid 46591 and 22772 keep connecting and the timing out.

    The event "Initialization Sequence Completed" is only logged by the phantom OpenVPN session. Never by 46591

    Line: 157: 46591 eventually crashes.

    And this is how the system sits from here on. /var/run/openvpn_client2.pid has 46591 in it. Any attempt to restart the client from the Web GUI just fails. And the phantom session is still running:

    [2.1-RC1][root@fw04]/var/run(9): ps -aux | grep openvpn
    root   22772  0.0  0.1 15536  5936  ??  SNs  11:04PM   0:00.64 /usr/local/sbin/openvpn --config /var/etc/openvpn/client2.conf
    root   11458  0.0  0.0  9068  1464   0  S+    1:28AM   0:00.00 grep openvpn
    

    /var/etc/openvpn/client2.conf has the correct VIP ip in there in the local statement. But I guess at some point early on in the bootup process when 22772 was spooling up it did not have the correct IP (instead had the IP of the backup tier VIP).

    So I suspect the problem is that during the boot process the OpenVPN client gets spawned twice. Possibly by two separate processes. One process is able to get the correct VIP and the other is not. The one that doesn't get the correct VIP (first one to start) survives. The one that is tracked in the /var/run/openvpn_client2.pid dies.

    Not sure where to look for the cause of the problem. Can anyone give me a brief lowdown of the startup process.

    Thanks,

    Shahid</fqdn_of_far_end_server></ip_of_far_end_server></vip_tier2></vip_tier1></fqdn_of_far_end_server>



  • Think I found the problem. The system log told the whole story.

    I have so many interfaces and vips that it takes it a while for the kernel to bring them all up. But monitoring kicks in before interfaces are up. Causing the default gateway to flap a couple of times and trigger repetitive restarts for various components.

    I made two changes to bootup.rc.

    1. Moved OpenVPN to start after IPsec.

    2. Added a 15 second sleep before $g['booting'] is unset.

    Seems to have fixed the problem. There is probably a more elegant solution than sleeping for 15 seconds.



  • We (a friend at my workplace and myself) are working on some rc.bootup changes to handle low-memory systems better - giving the option to slow down the boot process, checking free memory after each significant process is started and waiting until it stabilises before moving on. We are also thinking about moving the OpenVPN startup until later, as OpenVPN process startups are memory hogs, and it might be best to have all the other essential things up and running before OpenVPN.
    Hopefully there will be a proposed code solution later in the week.
    If you have any ideas to share to improve the boot process, let us all know.



  • We probably should start another thread on optimizing rc.bootup. –> http://forum.pfsense.org/index.php/topic,66188.0.html

    Shahid



  • @phil.davis:

    We (a friend at my workplace and myself) are working on some rc.bootup changes to handle low-memory systems better - giving the option to slow down the boot process, checking free memory after each significant process is started and waiting until it stabilises before moving on. We are also thinking about moving the OpenVPN startup until later, as OpenVPN process startups are memory hogs, and it might be best to have all the other essential things up and running before OpenVPN.
    Hopefully there will be a proposed code solution later in the week.
    If you have any ideas to share to improve the boot process, let us all know.

    As i said in the other thread its not openvpn the issue its the php.

    If you want to be smart enough you should optimize check_reload_status to check memory conditions or even not fire an similar even if its running.
    The simple hack to make all things work on lowmem systems would be to tell check_reload_status to serialize the events and wait for one to finish before starting another.

    That will give you predictable behviour on lowmem systems.


Log in to reply