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.
    

    VPN.PNG
    WAN.PNG



  • 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.


  • Netgate Administrator

    @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 UP

    The 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 UP

    The 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.


  • Netgate Administrator

    @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


Log in to reply