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:

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


This is the initial connection log (after a reboot of the router, which explains the initial timestamps):

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 emailAddress=secure@privateinternetaccess.com 
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 emailAddress=secure@privateinternetaccess.com 
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, emailAddress=secure@privateinternetaccess.com
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

  • Posts: 279
    The 8 hours sounds like a deliberate policy to "kick you off", so as to free up bandwidth/resources for others - no point asking PIA at the moment as they seem to have gone on permanent holdiay!

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

    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:

    Jun 6 10:31:04 DD-WRT daemon.notice openvpn[2652]: SIGUSR1[hard,] received, process restarting
    Jun 6 10:31:04 DD-WRT daemon.notice openvpn[2652]: Restart pause, 5 second(s)
    Jun 6 10:31:09 DD-WRT daemon.warn openvpn[2652]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
    Jun 6 10:31:09 DD-WRT daemon.notice openvpn[2652]: TCP/UDP: Preserving recently used remote address: [AF_INET]46.166.190.220:1198
    Jun 6 10:31:09 DD-WRT daemon.notice openvpn[2652]: Socket Buffers: R=[180224->360448] S=[180224->360448]
    Jun 6 10:31:09 DD-WRT daemon.notice openvpn[2652]: UDPv4 link local: (not bound)
    Jun 6 10:31:09 DD-WRT daemon.notice openvpn[2652]: UDPv4 link remote: [AF_INET]46.166.190.220:1198
    Jun 6 10:31:09 DD-WRT daemon.notice openvpn[2652]: TLS: Initial packet from [AF_INET]46.166.190.220:1198, sid=b582ac27 17c04612
    Jun 6 10:31:09 DD-WRT daemon.notice openvpn[2652]: 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, emailAddress=secure@privateinternetaccess.com
    Jun 6 10:31:09 DD-WRT daemon.notice openvpn[2652]: VERIFY KU OK
    Jun 6 10:31:09 DD-WRT daemon.notice openvpn[2652]: NOTE: --mute triggered...
    Jun 6 10:31:09 DD-WRT daemon.notice openvpn[2652]: 5 variation(s) on previous 3 message(s) suppressed by --mute
    Jun 6 10:31:09 DD-WRT daemon.notice openvpn[2652]: [3c68400533af8cb5c065f111c45e7e68] Peer Connection Initiated with [AF_INET]46.166.190.220:1198
    Jun 6 10:31:10 DD-WRT daemon.notice openvpn[2652]: SENT CONTROL [3c68400533af8cb5c065f111c45e7e68]: 'PUSH_REQUEST' (status=1)
    Jun 6 10:31:10 DD-WRT daemon.notice openvpn[2652]: AUTH: Received control message: AUTH_FAILED
    Jun 6 10:31:10 DD-WRT daemon.notice openvpn[2652]: /tmp/openvpncl/route-down.sh tun1 1500 1622 10.44.10.6 10.44.10.5 init
    Jun 6 10:31:10 DD-WRT daemon.notice openvpn[2652]: Closing TUN/TAP interface
    Jun 6 10:31:10 DD-WRT daemon.notice openvpn[2652]: /sbin/ifconfig tun1 0.0.0.0
    Jun 6 10:31:10 DD-WRT daemon.notice openvpn[2652]: SIGTERM[soft,auth-failure] received, process exiting
  • Posts: 279
    How is the persist-tun hardcoded?
    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?

  • edited June 6 Posts: 9
    To the best of my knowledge, the config is auto generated by DD-WRT when the OpenVPN client starts. It then auto generates the config file in /tmp/openvpncl/openvpn.conf. The content of this file is what I listed in my first post. Only the lines below "###Keep Alive" is what I have added in the Additional Config field. Everything above that is generated by the GUI settings as well as some predefined values (i.e. persist-tun being one of them)  :/

    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.
    Post edited by KlaatuBaradaNikto on
  • I'm still trying to figure out how to remove the "persist-tun" setting.
    But I guess my question really is: "Why do I get an AUTH_FAILED message, when restarting the VPN connection with SIGUSR1?".
  • Posts: 279
    >>I'm still trying to figure out how to remove the "persist-tun" setting.

    Login to your router (normally 192.168.1.1 ) and follow the settings on the link I gave you.

  • I don't have "persist-tun" in the additional config field. However! The config which DD-WRT actually uses is generated into a file on the device in /tmp/openvpncl/openvpn.conf. There "persist-tun" is still present. I can't delete it from that file, since it is auto generated on client startup.
  • Posts: 279
    Get yourself WinSCP (free), login and navigate to /etc/openvpn. Edit the ovpn file directly there.
  • Posts: 3
    Can we get a response from an employee at PIA about this issue? I am having the same exact problem, and I am absolutely pulling my hair out trying to resolve it. My setup is nearly identical to KlaatuBaradaNikto except I am using an Asus router running Merlin firmware. I am using selective routing for specific IPs only, and those clients can be idle or unconnected for long periods of time, apparently causing a timeout of the VPN connection. Every time the router tries to automatically reconnect to the VPN, it gets an authentication error, identical to what KlaatuBaradaNikto posted in his logs. 
  • Hi lahma,

    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.
  • Posts: 3
    Klaatu, I really appreciate the advice. So, with this workaround you are still experiencing intermittent disconnects, but your router is at least able to immediately reauthenticate in order to reconnect to the VPN? How often are you seeing disconnects/reconnects? My connection is being reset every 8 hours like clock work... Clearly this is being done intentionally on PIA's side.
  • My connection is also being disconnected after exactly 8 hours of inactivity. I am also using selective routing (I called it policy based routing). I use the VPN connection on devices which are either off or out of range of my wifi for long periods of time (over 8 hours). After exactly 8 hours the connection is broken, but because of the workaround I mentioned earlier, it is immediately re-established (even getting the same public IP address).
    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.
  • edited September 3 Posts: 5
    Try adding the following to your ovpn config on client side

    pull-filter ignore "auth-token"

    It's a problem introduced with OpenVPN 2.4 
    Post edited by nospamjl on
  • Posts: 279
    @nospamjl - can you give some explanation on what that does and where you found it etc?
  • edited September 4 Posts: 1
    I'm getting this exact issue starting yesterday on PfSense 2.3.4-p1. Connection is normally totally stable, but I'm now getting;

    Sep 4 18:02:00openvpn32508SIGUSR1[soft,ping-restart] received, process restarting
    Sep 4 18:02:00openvpn32508[832cdsfdsa5sf66urd400af90] Inactivity timeout (--ping-restart), restarting
    Sep 4 17:52:07openvpn32508Initialization Sequence Completed

    @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.
    Post edited by tadmin on
  • @nospamjl
    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).
  • Posts: 279
    @nospamjl Thanks for taking the time to repsond.

    @Klatuvaradanictoe Why did you substitute pull-filter ignore "auth-token" with auth-retry interact? They are two different commands!

  • edited September 6 Posts: 9
    @PiaVipper
    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.
    Post edited by KlaatuBaradaNikto on
  • Posts: 279
    You lost me - they do two different things, so it is not "either / or". You said "when I use that setting instead of" which doesn't make sense. Maybe you meant "as well as"?
  • edited September 9 Posts: 5
    I wonder if this is a WAN DHCP renewal problem, ie. even if the IP doesn't change on WAN the lease expires.

    Update. Maybe not. 
    Post edited by nospamjl on
  • edited September 11 Posts: 5
    Ignore

    Post edited by nospamjl on
Sign In or Register to comment.