Problems with PIA-VPN Interface
-
I am attempting to set up a VLAN profile which goes out over PIA VPN for some docker services I run on my unraid server. I've been following a couple of different guides to get this going. For setting up the PIA cert and client I followed PIA's guide - https://www.privateinternetaccess.com/helpdesk/guides/routers/pfsense/pfsense-2-4-3-setup-guide. HOWEVER, I did not follow their outbound NAT manual rule settings. Instead, I followed this guide for routing all VLAN traffic over the interface - http://techtilt.com/how-to-setup-pia-vpn-on-a-vlan-in-pfsense-2-4-4.
I've now done this twice and both times it looked like things were working as expected. However, my home alarm system (which has a network connection) has gone off at ~6:10AM the last two mornings and I've discovered my network was down (no WAN access). Turning off the VPN interface seems to rectify things. I'm not really sure where to start looking for debug.
I did notice the following in my logs after this happened the first time:
send_interval 500ms loss_interval 2000ms time_period 60000ms report_interval 0ms data_len 0 alert_interval 1000ms latency_alarm 500ms loss_alarm 20% dest_addr 10.14.11.5 bind_addr 10.14.11.6 identifier "PIAVPN_VPNV4 "And I ended up setting up Codel limiter thinking maybe it was a bufferfloat issue. However, that did not seem to have any change as it happened again today. Any ideas?
EDIT - I probably should mentioned I'm on 2.4.4-RELEASE-p3 . I run on a Qotom-Q555G6-S05 standalone box.
Found some more log info that may be useful, around the time this all seems to happen.
Dec 13 06:10:46 php-fpm /rc.start_packages: Stopping service avahi Dec 13 06:10:46 avahi-daemon 42986 Got SIGTERM, quitting. Dec 13 06:10:46 avahi-daemon 42986 Leaving mDNS multicast group on interface igb4.9.IPv4 with address 192.168.9.1. Dec 13 06:10:46 avahi-daemon 42986 Leaving mDNS multicast group on interface igb4.5.IPv4 with address 192.168.5.1. Dec 13 06:10:46 php-fpm /rc.start_packages: Starting service avahi Dec 13 06:10:46 avahi-daemon 42986 Leaving mDNS multicast group on interface igb4.IPv4 with address 10.10.10.1. Dec 13 06:10:46 avahi-daemon 42986 avahi-daemon 0.7 exiting. Dec 13 06:10:46 avahi-daemon 37329 Found user 'avahi' (UID 558) and group 'avahi' (GID 558). Dec 13 06:10:46 avahi-daemon 37329 Successfully dropped root privileges. Dec 13 06:10:46 avahi-daemon 37329 avahi-daemon 0.7 starting up. Dec 13 06:10:46 avahi-daemon 37329 WARNING: No NSS support for mDNS detected, consider installing nss-mdns! Dec 13 06:10:46 avahi-daemon 37329 Loading service file /usr/local/etc/avahi/services/sftp-ssh.service. Dec 13 06:10:46 avahi-daemon 37329 Loading service file /usr/local/etc/avahi/services/ssh.service. Dec 13 06:10:46 avahi-daemon 37329 Joining mDNS multicast group on interface igb4.9.IPv4 with address 192.168.9.1. Dec 13 06:10:46 avahi-daemon 36337 Found user 'avahi' (UID 558) and group 'avahi' (GID 558). Dec 13 06:10:46 avahi-daemon 37329 New relevant interface igb4.9.IPv4 for mDNS. Dec 13 06:10:46 avahi-daemon 37329 Joining mDNS multicast group on interface igb4.5.IPv4 with address 192.168.5.1. Dec 13 06:10:46 avahi-daemon 37329 New relevant interface igb4.5.IPv4 for mDNS. Dec 13 06:10:46 avahi-daemon 37329 Joining mDNS multicast group on interface igb4.IPv4 with address 10.10.10.1. Dec 13 06:10:46 avahi-daemon 36337 Successfully dropped root privileges. Dec 13 06:10:46 avahi-daemon 36337 open(/var/run/avahi-daemon//pid): File exists Dec 13 06:10:46 avahi-daemon 36337 Failed to create PID file: File exists Dec 13 06:10:46 avahi-daemon 37329 New relevant interface igb4.IPv4 for mDNS. Dec 13 06:10:46 avahi-daemon 37329 Network interface enumeration completed. Dec 13 06:10:46 avahi-daemon 37329 Registering new address record for 192.168.9.1 on igb4.9.IPv4. Dec 13 06:10:46 avahi-daemon 37329 Registering new address record for 192.168.5.1 on igb4.5.IPv4. Dec 13 06:10:46 avahi-daemon 37329 Registering new address record for 10.10.10.1 on igb4.IPv4. Dec 13 06:10:46 avahi-daemon 37329 Registering new address record for 192.168.1.1 on igb4.IPv4. Dec 13 06:10:46 avahi-daemon 37329 Registering HINFO record with values 'AMD64'/'FREEBSD'. Dec 13 06:10:46 avahi-daemon 38058 Found user 'avahi' (UID 558) and group 'avahi' (GID 558). Dec 13 06:10:46 avahi-daemon 38058 Successfully dropped root privileges. Dec 13 06:10:46 avahi-daemon 38058 open(/var/run/avahi-daemon//pid): File exists Dec 13 06:10:46 avahi-daemon 38058 Failed to create PID file: File exists Dec 13 06:10:46 php_pfb [pfBlockerNG] filterlog daemon started Dec 13 06:10:46 php [pfBlockerNG] DNSBL parser daemon started Dec 13 06:10:47 avahi-daemon 37329 Server startup complete. Host name is pfSense.local. Local service cookie is 297149196. Dec 13 06:10:48 avahi-daemon 37329 Service "pfSense" (/usr/local/etc/avahi/services/ssh.service) successfully established. Dec 13 06:10:48 avahi-daemon 37329 Service "pfSense" (/usr/local/etc/avahi/services/sftp-ssh.service) successfully established.And
Dec 13 06:10:30 kernel ovpnc2: link state changed to DOWN Dec 13 06:10:30 check_reload_status Reloading filter Dec 13 06:10:31 kernel ovpnc2: link state changed to UP Dec 13 06:10:31 check_reload_status rc.newwanip starting ovpnc2 Dec 13 06:10:31 kernel config_aqm Unable to configure flowset, flowset busy! Dec 13 06:10:32 php-fpm 341 /rc.newwanip: rc.newwanip: Info: starting on ovpnc2. Dec 13 06:10:32 php-fpm 341 /rc.newwanip: rc.newwanip: on (IP address: 10.14.11.6) (interface: PIAVPN[opt5]) (real interface: ovpnc2). Dec 13 06:10:32 dhcpleases /etc/hosts changed size from original! Dec 13 06:10:32 php-fpm 341 /rc.newwanip: IP Address has changed, killing states on former IP Address 10.1.11.6. Dec 13 06:10:32 kernel config_aqm Unable to configure flowset, flowset busy! Dec 13 06:10:34 php-fpm 341 /rc.newwanip: Gateway, none 'available' for inet6, use the first one configured. '' Dec 13 06:10:34 rc.gateway_alarm 45113 >>> Gateway alarm: PIAVPN_VPNV4 (Addr:10.14.11.5 Alarm:1 RTT:0.000ms RTTsd:0.000ms Loss:100%) Dec 13 06:10:34 check_reload_status updating dyndns PIAVPN_VPNV4 Dec 13 06:10:34 check_reload_status Restarting ipsec tunnels Dec 13 06:10:34 check_reload_status Restarting OpenVPN tunnels/interfaces Dec 13 06:10:34 check_reload_status Reloading filter Dec 13 06:10:35 php-fpm 62417 /rc.openvpn: Gateway, none 'available' for inet6, use the first one configured. '' Dec 13 06:10:35 php-fpm 62417 /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use PIAVPN_VPNV4. Dec 13 06:10:40 dhcpleases /etc/hosts changed size from original! Dec 13 06:10:40 dhcpleases Could not deliver signal HUP to process because its pidfile (/var/run/unbound.pid) does not exist, No such process. Dec 13 06:10:41 dhcpleases kqueue error: unknown Dec 13 06:10:43 php-fpm 341 /rc.newwanip: Creating rrd update script Dec 13 06:10:45 php-fpm 341 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 10.1.11.6 -> 10.14.11.6 - Restarting packages. Dec 13 06:10:45 check_reload_status Starting packages Dec 13 06:10:46 php-fpm /rc.start_packages: Restarting/Starting all packages. Dec 13 06:10:46 php-fpm /rc.start_packages: Stopping service avahi Dec 13 06:10:46 avahi-daemon 42986 Got SIGTERM, quitting. Dec 13 06:10:46 avahi-daemon 42986 Leaving mDNS multicast group on interface igb4.9.IPv4 with address 192.168.9.1. Dec 13 06:10:46 avahi-daemon 42986 Leaving mDNS multicast group on interface igb4.5.IPv4 with address 192.168.5.1. Dec 13 06:10:46 php-fpm /rc.start_packages: Starting service avahi Dec 13 06:10:46 avahi-daemon 42986 Leaving mDNS multicast group on interface igb4.IPv4 with address 10.10.10.1. Dec 13 06:10:46 avahi-daemon 42986 avahi-daemon 0.7 exiting. Dec 13 06:10:46 avahi-daemon 37329 Found user 'avahi' (UID 558) and group 'avahi' (GID 558). Dec 13 06:10:46 avahi-daemon 37329 Successfully dropped root privileges. Dec 13 06:10:46 avahi-daemon 37329 avahi-daemon 0.7 starting up. Dec 13 06:10:46 avahi-daemon 37329 WARNING: No NSS support for mDNS detected, consider installing nss-mdns! Dec 13 06:10:46 avahi-daemon 37329 Loading service file /usr/local/etc/avahi/services/sftp-ssh.service. Dec 13 06:10:46 avahi-daemon 37329 Loading service file /usr/local/etc/avahi/services/ssh.service. Dec 13 06:10:46 avahi-daemon 37329 Joining mDNS multicast group on interface igb4.9.IPv4 with address 192.168.9.1. Dec 13 06:10:46 avahi-daemon 36337 Found user 'avahi' (UID 558) and group 'avahi' (GID 558). Dec 13 06:10:46 avahi-daemon 37329 New relevant interface igb4.9.IPv4 for mDNS. Dec 13 06:10:46 avahi-daemon 37329 Joining mDNS multicast group on interface igb4.5.IPv4 with address 192.168.5.1. Dec 13 06:10:46 avahi-daemon 37329 New relevant interface igb4.5.IPv4 for mDNS. Dec 13 06:10:46 avahi-daemon 37329 Joining mDNS multicast group on interface igb4.IPv4 with address 10.10.10.1. Dec 13 06:10:46 avahi-daemon 36337 Successfully dropped root privileges. Dec 13 06:10:46 avahi-daemon 36337 open(/var/run/avahi-daemon//pid): File exists Dec 13 06:10:46 avahi-daemon 36337 Failed to create PID file: File exists Dec 13 06:10:46 avahi-daemon 37329 New relevant interface igb4.IPv4 for mDNS. Dec 13 06:10:46 avahi-daemon 37329 Network interface enumeration completed. Dec 13 06:10:46 avahi-daemon 37329 Registering new address record for 192.168.9.1 on igb4.9.IPv4. Dec 13 06:10:46 avahi-daemon 37329 Registering new address record for 192.168.5.1 on igb4.5.IPv4. Dec 13 06:10:46 avahi-daemon 37329 Registering new address record for 10.10.10.1 on igb4.IPv4. Dec 13 06:10:46 avahi-daemon 37329 Registering new address record for 192.168.1.1 on igb4.IPv4. Dec 13 06:10:46 avahi-daemon 37329 Registering HINFO record with values 'AMD64'/'FREEBSD'. Dec 13 06:10:46 avahi-daemon 38058 Found user 'avahi' (UID 558) and group 'avahi' (GID 558). Dec 13 06:10:46 avahi-daemon 38058 Successfully dropped root privileges. Dec 13 06:10:46 avahi-daemon 38058 open(/var/run/avahi-daemon//pid): File exists Dec 13 06:10:46 avahi-daemon 38058 Failed to create PID file: File exists Dec 13 06:10:46 php_pfb [pfBlockerNG] filterlog daemon started Dec 13 06:10:46 php [pfBlockerNG] DNSBL parser daemon started Dec 13 06:10:47 avahi-daemon 37329 Server startup complete. Host name is pfSense.local. Local service cookie is 297149196. Dec 13 06:10:48 avahi-daemon 37329 Service "pfSense" (/usr/local/etc/avahi/services/ssh.service) successfully established. Dec 13 06:10:48 avahi-daemon 37329 Service "pfSense" (/usr/local/etc/avahi/services/sftp-ssh.service) successfully established.
-
Does anyone have any ideas of what may be causing my issue, or things I can look into? In short, I set up a VLAN dedicated to an outgoing VPN. Two mornings in a row something occurred at 6:10AMish that killed my WAN interface. I'm assuming there is a daily job that got triggered and somehow things went bad from there.
-
@statecowboy said in Problems with PIA-VPN Interface:
Dec 13 06:10:30 kernel ovpnc2: link state changed to DOWN
Dec 13 06:10:30 check_reload_status Reloading filter
Dec 13 06:10:31 kernel ovpnc2: link state changed to UPThe VPN went down and then came back up again. Everything shown after that is as a result of that gateway change. The OpenVPN log might have more info there.
The quality graph for the VPN gateway is curious though. Looks like it lost connectivity entirely when it went down and never recovered when it came back up.Steve
-
@stephenw10 said in Problems with PIA-VPN Interface:
@statecowboy said in Problems with PIA-VPN Interface:
Dec 13 06:10:30 kernel ovpnc2: link state changed to DOWN
Dec 13 06:10:30 check_reload_status Reloading filter
Dec 13 06:10:31 kernel ovpnc2: link state changed to UPThe VPN went down and then came back up again. Everything shown after that is as a result of that gateway change. The OpenVPN log might have more info there.
The quality graph for the VPN gateway is curious though. Looks like it lost connectivity entirely when it went down and never recovered when it came back up.Steve
Hi, sorry for the delayed response, didn't see I had a reply. Here are my logs from this time frame for OpenVPN.
Dec 13 06:10:17 openvpn 23211 [f3bda005164589f3c05ef144035e0777] Inactivity timeout (--ping-restart), restarting Dec 13 06:10:17 openvpn 23211 SIGUSR1[soft,ping-restart] received, process restarting Dec 13 06:10:22 openvpn 23211 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts Dec 13 06:10:22 openvpn 23211 TCP/UDP: Preserving recently used remote address: [AF_INET]199.229.249.137:1198 Dec 13 06:10:22 openvpn 23211 UDPv4 link local (bound): [AF_INET]*MY WAN IP*:0 Dec 13 06:10:22 openvpn 23211 UDPv4 link remote: [AF_INET]199.229.249.137:1198 Dec 13 06:10:22 openvpn 23211 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1550', remote='link-mtu 1542' Dec 13 06:10:22 openvpn 23211 WARNING: 'cipher' is used inconsistently, local='cipher AES-128-GCM', remote='cipher BF-CBC' Dec 13 06:10:22 openvpn 23211 WARNING: 'auth' is used inconsistently, local='auth [null-digest]', remote='auth SHA1' Dec 13 06:10:22 openvpn 23211 [f3bda005164589f3c05ef144035e0777] Peer Connection Initiated with [AF_INET]199.229.249.137:1198 Dec 13 06:10:23 openvpn 23211 AUTH: Received control message: AUTH_FAILED Dec 13 06:10:23 openvpn 23211 SIGUSR1[soft,auth-failure] received, process restarting Dec 13 06:10:28 openvpn 23211 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts Dec 13 06:10:28 openvpn 23211 TCP/UDP: Preserving recently used remote address: [AF_INET]199.229.249.137:1198 Dec 13 06:10:28 openvpn 23211 UDPv4 link local (bound): [AF_INET]*MY WAN IP*:0 Dec 13 06:10:28 openvpn 23211 UDPv4 link remote: [AF_INET]199.229.249.137:1198 Dec 13 06:10:29 openvpn 23211 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1550', remote='link-mtu 1542' Dec 13 06:10:29 openvpn 23211 WARNING: 'cipher' is used inconsistently, local='cipher AES-128-GCM', remote='cipher BF-CBC' Dec 13 06:10:29 openvpn 23211 WARNING: 'auth' is used inconsistently, local='auth [null-digest]', remote='auth SHA1' Dec 13 06:10:29 openvpn 23211 [f3bda005164589f3c05ef144035e0777] Peer Connection Initiated with [AF_INET]199.229.249.137:1198 Dec 13 06:10:30 openvpn 23211 Preserving previous TUN/TAP instance: ovpnc2 Dec 13 06:10:30 openvpn 23211 NOTE: Pulled options changed on restart, will need to close and reopen TUN/TAP device. Dec 13 06:10:30 openvpn 23211 ERROR: FreeBSD route delete command failed: external program exited with error status: 1 Dec 13 06:10:30 openvpn 23211 ERROR: FreeBSD route delete command failed: external program exited with error status: 1 Dec 13 06:10:30 openvpn 23211 ERROR: FreeBSD route delete command failed: external program exited with error status: 1 Dec 13 06:10:30 openvpn 23211 /usr/local/sbin/ovpn-linkdown ovpnc2 1500 1550 10.12.10.10 10.12.10.9 init Dec 13 06:10:31 openvpn 23211 TUN/TAP device ovpnc2 exists previously, keep at program end Dec 13 06:10:31 openvpn 23211 TUN/TAP device /dev/tun2 opened Dec 13 06:10:31 openvpn 23211 do_ifconfig, tt->did_ifconfig_ipv6_setup=0 Dec 13 06:10:31 openvpn 23211 /sbin/ifconfig ovpnc2 10.14.11.6 10.14.11.5 mtu 1500 netmask 255.255.255.255 up Dec 13 06:10:31 openvpn 23211 /usr/local/sbin/ovpn-linkup ovpnc2 1500 1550 10.14.11.6 10.14.11.5 init Dec 13 06:10:31 openvpn 23211 Initialization Sequence Completed -
Do you have a dynamic IP address on your WAN and does this happen everytime when your IP is renewed? Are you using unbound for DNS Resolution and is the unbound gateway set to your VPN client? If so, try to add a common DNS server (i.e. 8.8.8.8) at the General settings tab. Helped solved a similar problem for me.
Other possible source of this problem could be related to a cron job aiming to restart unbound when it crashes. Maybe search this forum, there are one or two threads that discuss this.
-
@statecowboy said in Problems with PIA-VPN Interface:
Dec 13 06:10:30 openvpn 23211 ERROR: FreeBSD route delete command failed: external program exited with error status: 1
That log implies the OpenVPN daemon is trying to modify the routing table and failed. You might have some routing conflict there with something OpenVPN is trying to use.
Steve
