Inactivity timeout (--ping-restart)
I am having an issue maintaining a permanent VPN tunnel connection. Please bear with me, while I explain my problem.
My setup:
I have a VPN Client connection running more or less sucessfully on a Linksys EA8500 router with DD-WRT installed. This FW implements the latest OpenVPN 2.4.2 client. I am using policy based routing to only allow a couple of devices to use the VPN tunnel. These devices are not always on, so there might be long periods of time, where no traffic is going through the VPN tunnel.
My problem:
The OpenVPN connection to PIA is established successfully. It is also stable - but only as long as there is traffic. When traffic ceases for a period of exactly 8 hours, the client reports an "Inactivity timeout (--ping-restart)" message, and tries to re-establish a connection, which ultimately fails with the error: "AUTH: Received control message: AUTH_FAILED".
I have now for the past 3 weeks tried to solve this problem, but have been unable to find a solution. I believe there is an issue with how the re-authentication works, or rather doesn't work?
I have seen forum posts describing this problem with PIA VPN on multiple platforms (DD-WRT, Merlin, Ubuntu, PfSense etc). But as far as I know, nothing has solved this.
I hope some bright mind knows what the issue is, and how I can solve it. To test it, I am now using policy based routing to only allow a certain IP range to use the VPN tunnel. This IP range doesn't contian any devices, so no traffic is generated. Exactly 8 hours after start the problem manifests itself.
Here is the config I use:
This is the initial connection log (after a reboot of the router, which explains the initial timestamps):
This is the syslog of the error:
I hope someone (including PIA support) can shed some light unto why the re-authentication fails?
Best regards.
My setup:
I have a VPN Client connection running more or less sucessfully on a Linksys EA8500 router with DD-WRT installed. This FW implements the latest OpenVPN 2.4.2 client. I am using policy based routing to only allow a couple of devices to use the VPN tunnel. These devices are not always on, so there might be long periods of time, where no traffic is going through the VPN tunnel.
My problem:
The OpenVPN connection to PIA is established successfully. It is also stable - but only as long as there is traffic. When traffic ceases for a period of exactly 8 hours, the client reports an "Inactivity timeout (--ping-restart)" message, and tries to re-establish a connection, which ultimately fails with the error: "AUTH: Received control message: AUTH_FAILED".
I have now for the past 3 weeks tried to solve this problem, but have been unable to find a solution. I believe there is an issue with how the re-authentication works, or rather doesn't work?
I have seen forum posts describing this problem with PIA VPN on multiple platforms (DD-WRT, Merlin, Ubuntu, PfSense etc). But as far as I know, nothing has solved this.
I hope some bright mind knows what the issue is, and how I can solve it. To test it, I am now using policy based routing to only allow a certain IP range to use the VPN tunnel. This IP range doesn't contian any devices, so no traffic is generated. Exactly 8 hours after start the problem manifests itself.
Here is the config I use:
client
resolv-retry infinite
nobind
persist-key
persist-tun
script-security 2
dev tun1
proto udp4
cipher aes-128-cbc
auth sha1
auth-user-pass /tmp/openvpncl/credentials
remote nl.privateinternetaccess.com 1198
comp-lzo
redirect-private def1
route-noexec
tls-client
tun-mtu 1500
mtu-disc yes
fast-io
tls-cipher TLS-RSA-WITH-AES-128-CBC-SHA
### Keep Alive
reneg-sec 300
ping 10
ping-restart 60
### Speed Tweaks
sndbuf 523216
rcvbuf 523216
push "sndbuf 523216"
push "rcvbuf 523216"
### General
remote-cert-tls server
disable-occ
Clientlog:
19700101 01:00:26 W WARNING: file '/tmp/openvpncl/credentials' is group or others accessible
19700101 01:00:26 I OpenVPN 2.4.2 arm-unknown-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Jun 4 2017
19700101 01:00:26 I library versions: OpenSSL 1.0.2k 26 Jan 2017 LZO 2.09
19700101 01:00:26 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:16
19700101 01:00:26 W NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
19700101 01:00:26 I TCP/UDP: Preserving recently used remote address: [AF_INET]46.166.190.237:1198
19700101 01:00:26 Socket Buffers: R=[180224->360448] S=[180224->360448]
19700101 01:00:26 I UDPv4 link local: (not bound)
19700101 01:00:26 I UDPv4 link remote: [AF_INET]46.166.190.237:1198
19700101 01:00:27 TLS: Initial packet from [AF_INET]46.166.190.237:1198 sid=41a8f72f a0408e26
19700101 01:00:27 W WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
19700101 01:00:27 N VERIFY ERROR: depth=1 error=certificate is not yet valid: C=US ST=CA L=LosAngeles O=Private Internet Access OU=Private Internet Access CN=Private Internet Access name=Private Internet Access [email protected]
19700101 01:00:27 N OpenSSL: error:14090086:lib(20):func(144):reason(134)
19700101 01:00:27 N TLS_ERROR: BIO read tls_read_plaintext error
19700101 01:00:27 NOTE: --mute triggered...
19700101 01:00:27 2 variation(s) on previous 3 message(s) suppressed by --mute
19700101 01:00:27 I SIGUSR1[soft tls-error] received process restarting
19700101 01:00:27 Restart pause 5 second(s)
20170605 10:08:17 W NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
20170605 10:08:17 I TCP/UDP: Preserving recently used remote address: [AF_INET]46.166.190.129:1198
20170605 10:08:17 Socket Buffers: R=[180224->360448] S=[180224->360448]
20170605 10:08:17 I UDPv4 link local: (not bound)
20170605 10:08:17 I UDPv4 link remote: [AF_INET]46.166.190.129:1198
20170605 10:08:17 TLS: Initial packet from [AF_INET]46.166.190.129:1198 sid=1b2ef809 f0b62f59
20170605 10:08:17 VERIFY OK: depth=1 C=US ST=CA L=LosAngeles O=Private Internet Access OU=Private Internet Access CN=Private Internet Access name=Private Internet Access [email protected]
20170605 10:08:17 VERIFY KU OK
20170605 10:08:17 NOTE: --mute triggered...
20170605 10:08:17 4 variation(s) on previous 3 message(s) suppressed by --mute
20170605 10:08:17 W WARNING: 'link-mtu' is used inconsistently local='link-mtu 1558' remote='link-mtu 1542'
20170605 10:08:17 W WARNING: 'cipher' is used inconsistently local='cipher AES-128-CBC' remote='cipher BF-CBC'
20170605 10:08:17 Control Channel: TLSv1.2 cipher TLSv1/SSLv3 AES128-SHA 2048 bit RSA
20170605 10:08:17 I [45fed619c241cff79f632062f18a003c] Peer Connection Initiated with [AF_INET]46.166.190.129:1198
20170605 10:08:19 SENT CONTROL [45fed619c241cff79f632062f18a003c]: 'PUSH_REQUEST' (status=1)
20170605 10:08:19 PUSH: Received control message: 'PUSH_REPLY redirect-gateway def1 dhcp-option DNS 209.222.18.222 dhcp-option DNS 209.222.18.218 ping 10 comp-lzo no route 10.5.10.1 topology net30 ifconfig 10.5.10.6 10.5.10.5 auth-token'
20170605 10:08:19 OPTIONS IMPORT: timers and/or timeouts modified
20170605 10:08:19 NOTE: --mute triggered...
20170605 10:08:19 4 variation(s) on previous 3 message(s) suppressed by --mute
20170605 10:08:19 Data Channel Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
20170605 10:08:19 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
20170605 10:08:19 Data Channel Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
20170605 10:08:19 NOTE: --mute triggered...
20170605 10:08:19 1 variation(s) on previous 3 message(s) suppressed by --mute
20170605 10:08:19 I TUN/TAP device tun1 opened
20170605 10:08:19 TUN/TAP TX queue length set to 100
20170605 10:08:19 D do_ifconfig tt->did_ifconfig_ipv6_setup=0
20170605 10:08:19 I /sbin/ifconfig tun1 10.5.10.6 pointopoint 10.5.10.5 mtu 1500
20170605 10:08:19 I Initialization Sequence Completed
This is the syslog of the error:
Jun 5 18:09:11 DD-WRT daemon.notice openvpn[2164]: [45fed619c241cff79f632062f18a003c] Inactivity timeout (--ping-restart), restarting
Jun 5 18:09:11 DD-WRT daemon.notice openvpn[2164]: SIGUSR1[soft,ping-restart] received, process restarting
Jun 5 18:09:11 DD-WRT daemon.notice openvpn[2164]: Restart pause, 5 second(s)
Jun 5 18:09:16 DD-WRT daemon.warn openvpn[2164]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun 5 18:09:16 DD-WRT daemon.notice openvpn[2164]: TCP/UDP: Preserving recently used remote address: [AF_INET]46.166.190.129:1198
Jun 5 18:09:16 DD-WRT daemon.notice openvpn[2164]: Socket Buffers: R=[180224->360448] S=[180224->360448]
Jun 5 18:09:16 DD-WRT daemon.notice openvpn[2164]: UDPv4 link local: (not bound)
Jun 5 18:09:16 DD-WRT daemon.notice openvpn[2164]: UDPv4 link remote: [AF_INET]46.166.190.129:1198
Jun 5 18:09:16 DD-WRT daemon.notice openvpn[2164]: TLS: Initial packet from [AF_INET]46.166.190.129:1198, sid=e6e09b7b 388a3c2d
Jun 5 18:09:16 DD-WRT daemon.notice openvpn[2164]: VERIFY OK: depth=1, C=US, ST=CA, L=LosAngeles, O=Private Internet Access, OU=Private Internet Access, CN=Private Internet Access, name=Private Internet Access, [email protected]
Jun 5 18:09:16 DD-WRT daemon.notice openvpn[2164]: VERIFY KU OK
Jun 5 18:09:16 DD-WRT daemon.notice openvpn[2164]: NOTE: --mute triggered...
Jun 5 18:09:16 DD-WRT daemon.notice openvpn[2164]: 4 variation(s) on previous 3 message(s) suppressed by --mute
Jun 5 18:09:16 DD-WRT daemon.warn openvpn[2164]: WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1558', remote='link-mtu 1542'
Jun 5 18:09:16 DD-WRT daemon.warn openvpn[2164]: WARNING: 'cipher' is used inconsistently, local='cipher AES-128-CBC', remote='cipher BF-CBC'
Jun 5 18:09:16 DD-WRT daemon.notice openvpn[2164]: Control Channel: TLSv1.2, cipher TLSv1/SSLv3 AES128-SHA, 2048 bit RSA
Jun 5 18:09:16 DD-WRT daemon.notice openvpn[2164]: [45fed619c241cff79f632062f18a003c] Peer Connection Initiated with [AF_INET]46.166.190.129:1198
Jun 5 18:09:17 DD-WRT daemon.notice openvpn[2164]: SENT CONTROL [45fed619c241cff79f632062f18a003c]: 'PUSH_REQUEST' (status=1)
Jun 5 18:09:18 DD-WRT daemon.notice openvpn[2164]: AUTH: Received control message: AUTH_FAILED
Jun 5 18:09:18 DD-WRT daemon.notice openvpn[2164]: /tmp/openvpncl/route-down.sh tun1 1500 1622 10.5.10.6 10.5.10.5 init
Jun 5 18:09:18 DD-WRT daemon.notice openvpn[2164]: Closing TUN/TAP interface
Jun 5 18:09:18 DD-WRT daemon.notice openvpn[2164]: /sbin/ifconfig tun1 0.0.0.0
Jun 5 18:09:18 DD-WRT daemon.notice openvpn[2164]: SIGTERM[soft,auth-failure] received, process exiting
I hope someone (including PIA support) can shed some light unto why the re-authentication fails?
Best regards.
Comments
However, for general connection issues, you could try simply removing the "persist-tun" line. It might even work in your case too.
Please report back after trying.
Thanks for your comment. That is something I'd love to try. Unfortunately the persist-tun option is hardcoded into the connection options in DD-WRT. I'm trying to figure out through their forum, how to go about removing that for test purposes.
Just for your information, I have now found a way to test this without waiting 8 hours. I send the SIGUSR1 signal (which is the signal generated after the Inactivity Timeout) to the OpenVPN client with the command: "killall -s SIGUSR1 openvpn". This triggers the same error:
Have a look here, particularly (16.):
https://www.privateinternetaccess.com/pages/client-support/dd-wrt-openvpn. Surely you can simply remove that line and save?
Or you could simply hash it out in your config?
Since the config has already been used after creation, it doesn't change anything, if I edit the /tmp/openvpncl/openvpn.conf afterwards. It will just be overwritten again, when I restart the client.
But I guess my question really is: "Why do I get an AUTH_FAILED message, when restarting the VPN connection with SIGUSR1?".
Login to your router (normally 192.168.1.1 ) and follow the settings on the link I gave you.
I've had an open support ticket for this issue since the 5th of June, and still haven't gotten any solution (or even suggestion) from PIA support.
I found my own work-around, which works on DD-WRT at least, maybe you can give that a try in your firmware as well; I've added the line "auth-retry interact" to the additional options field. One of the very first things I tried when encountering the issue was "auth-retry nointeract", since the manual states: "Use this option for unattended clients". But if you try using the "auth-retry nointeract" the client will repeatedly try to authenticate using the same authentication token, which keeps failing - resulting in an endless loop. Only with "auth-retry interact" will the client requery for an auth-user-pass username/password and/or private key password before attempting a reconnection. At least that is my theory.
It has been working for me since then, even though the correct solution would still be to figure out why the authentication token is invalid after a SIGUSR1 signal in the first place.
I have given up on finding the real reason, because I think it would require PIA to look for the cause of the authentication failure on the server side.
P.S. If it is possible in your firmware to remove the "persist-tun" option, you could also give that a try.
pull-filter ignore "auth-token"
It's a problem introduced with OpenVPN 2.4
@nospamjl
I agree this will fix the Auth_Failed errors on reconnect, but this won't stop the tunnel from going down due to "Inactivity timeout". Maybe a solution for the op, but I'm hoping somebody may have any further ideas what could be causing the timeout?
Connection to several IPSec links have remained up fine, so I can't see it being a local issue.
Thanks for chiming in. The setting you suggested does make more sense. Unfortunately when I use that setting instead of "auth-retry interact", the VPN connection is reset every hour (I presume since I use the additional option "reneg-sec 3600"). This was for some reason not the case when using "auth-retry interact".
Again - I think your setting is more correct, only in my case the "auth-retry interact" workaround performs a bit better (unless I want to remove "reneg-sec" option).
@Klatuvaradanictoe Why did you substitute pull-filter ignore "auth-token" with auth-retry interact? They are two different commands!
I know they are two different commands. But they are both workarounds for a problem concerning the usage of auth-token. Please read this thread in its entirety for reference.
We are basically fighting 2 issues:
1. After 8 hours of inactivity the VPN connection is reset due to Inactivity timeout (--ping-restart).
2. When the connection is reset the authentication fails because of the usage of auth-token.
Update. Maybe not.