OpenVPN Client cannot auto-reconnect

plax.kart

Hi all,

I'm having problems with auto-reconnecting on OVPN Client. In my setup, I've configured OVPN Server running on an EdgeRouter device and OVPN Client running on another OVPN EdgeRouter device. Everything works properly so far. The problems happened when the connection was dropped unexpectedly.

Case #1: I deliberately try to power off the Client device, wait for a few minutes to make sure the Client completely lost its VPN connection (by reading logs on OVPN Server), then I power on the Client device again. After waiting for about 60s, the connection is established successfully and both ends can communicate properly. This case is working normal as I expected.

Case #2: I deliberately unplug the network cable from the Client device, wait for a few minutes just like case #1, check the log on Server to make sure the VPN connection was lost completely, then plug in the network cable again into Client device. Now the problem is I cannot see any attempt to auto-reconnect on the Client device. I checked log on the Server and cannot see any failed connection or reattempt that come from the Client device.

So I guess when powering off then on, the OVPN Client device tries to re-establish the connection to the OVPN Server device. But when unplug and plug in the network cable, the OVPN Client still keep its running connection status and therefore cannot create proper VPN connection between two ends.

The OVPN log file shows nothing special but please let me know if you would like to have a look at it.

Are there any solutions to this issue?

Thank you.

openvpn vtun0 {
description "OpenVPN Server #1"
encryption aes256
hash sha256
mode server
openvpn-option "--port 1194"
openvpn-option "--proto udp"
openvpn-option --ccd-exclusive
openvpn-option "--client-config-dir /config/auth/ccd"
openvpn-option "--verb 4"
openvpn-option "--cipher AES-256-CBC"
openvpn-option "--tls-auth /config/auth/ta.key 0"
openvpn-option "--tls-cipher TLS-DHE-RSA-WITH-AES-256-CBC-SHA"
openvpn-option "--user nobody"
openvpn-option "--group nogroup"
openvpn-option "--keepalive 10 60"
openvpn-option "--log-append /var/log/openvpn.log"
openvpn-option "--crl-verify /config/auth/crl.pem"
openvpn-option --tls-server
openvpn-option --persist-key
openvpn-option --persist-tun
server {
subnet x.x.x.x/24
}
tls {
ca-cert-file /config/auth/ca.crt
cert-file /config/auth/server.pem
dh-file /config/auth/dh2048.pem
key-file /config/auth/server.key
}

client
dev tun
proto udp
remote x.x.x.x 1194

resolv-retry infinite
nobind
persist-key
persist-tun

remote-cert-tls server
cipher AES-256-CBC
auth SHA256
key-direction 1

verb 3
<key>
...
</key>
<cert>
...
</cert>
<ca>
...
</ca>
<tls-auth>
...
</tls-auth>

plax.kart

By the way, below are the logs from both OVPN Server and Client for case #2...

[xxxxxx] Inactivity timeout (--ping-restart), restarting
SIGUSR1[soft,ping-restart] received, client-instance restarting

ubnt openvpn[1851]: [server] Inactivity timeout (--ping-restart), restarting
ubnt openvpn[1851]: SIGUSR1[soft,ping-restart] received, process restarting
ubnt openvpn[1851]: Restart pause, 5 second(s)
ubnt openvpn[1851]: TCP/UDP: Preserving recently used remote address: [AF_INET]x.x.x.x:1194
ubnt openvpn[1851]: Socket Buffers: R=[294912->294912] S=[294912->294912]
ubnt openvpn[1851]: UDP link local: (not bound)
ubnt openvpn[1851]: UDP link remote: [AF_INET]x.x.x.x:1194
ubnt openvpn[1851]: [UNDEF] Inactivity timeout (--ping-restart), restarting
ubnt openvpn[1851]: SIGUSR1[soft,ping-restart] received, process restarting
ubnt openvpn[1851]: Restart pause, 5 second(s)
ubnt openvpn[1851]: TCP/UDP: Preserving recently used remote address: [AF_INET]x.x.x.x:1194
ubnt openvpn[1851]: Socket Buffers: R=[294912->294912] S=[294912->294912]
ubnt openvpn[1851]: UDP link local: (not bound)
ubnt openvpn[1851]: UDP link remote: [AF_INET]x.x.x.x:1194

plax.kart

FYI, even when I deliberately disable then re-enable the OVPN interface on EdgeRouter Client device, the VPN connection is still able to auto-reconnect by itself successfully.

So long story short, the only case OVPN Client device fails to auto-reconnect is when I unplug the network cable (break Internet connection) then plug it again after a few minutes. In this specific case, OVPN Client device seems like it could not establish the VPN connection by itself...

TinCanTech

Which version of openvpn are you using ?

plax.kart

Hi TinCanTech,

Please refer to the info on both OVPN Server and Client as follows:

sudo openvpn --help
OpenVPN 2.4.0 mips-unknown-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Oct 14 2018

Thank you.

plax.kart

@TinCanTech: I wonder can we write a script in Linux (Debian-based EdgeRouter) to auto-check the up/down state of VPN connection then automatically disable and re-enable the interface vtun0 whenever VPN connection losing connection? Such as up/down scripts in OVPN...

TinCanTech

plax.kart wrote can we write a script in Linux (Debian-based EdgeRouter) to auto-check the up/down state of VPN connection

Probably but the script would have to be run outside of openvpn.

plax.kart wrote OpenVPN 2.4.0

This is a little out of date ..

plax.kart wrote Linux (Debian-based EdgeRouter

You should find out if you can update your version of openvpn or not.

plax.kart wrote Case #2: I deliberately unplug the network cable from the Client device, wait for a few minutes just like case #1, check the log on Server to make sure the VPN connection was lost completely, then plug in the network cable again into Client device. Now the problem is I cannot see any attempt to auto-reconnect on the Client device. I checked log on the Server and cannot see any failed connection or reattempt that come from the Client device.

Please post your complete client log at verb 4 so we can see what the client is doing.

Pippin

Case #2:

Do you see recursive routing detected in the client log?
Do not use --persist-tun on the client...

plax.kart

Pippin wrote
Case #2:
Do you see recursive routing detected in the client log?
Do not use --persist-tun on the client...

@Pippin: Amazing! It just works beautifully and auto-reconnect every time I power off or unplug the cable. Thanks a lot 😃

There is some small issues though...firstly, when I leave the VPN connection running idle (inactivity) for about 5', the Client seems auto-disconnected but it can auto-reconnect right after that and everything keep working fine. Just wonder is it normal (with --keepalive 10 60 option on the Server ) or do we need to always keep the VPN connection up without any downtime during inactivity?

Second minor issue is the OVPN Client seems taking a bit long time to auto-reconnect. I saw the following information keep increasing 2 times from 5s to 10s, 20s, 40s, 80s, 160s... in the Client log, is this the reason why OVPN Client takes quite some time to auto-reconnect?

ubnt openvpn[1915]: Restart pause, 5 second(s)

Lastly, when I issue the command to restart OVPN Server instance sudo /etc/init.d/openvpn restart I got the some errors as follows and could not auto-reconnect for about 2-3 minutes, but eventually the Client was still able to auto-reconnect but it took some time and I don't think it's good...

Jun 24 21:52:44 ubnt openvpn[1887]: /sbin/ip route add 0.0.0.0/1 via x.x.x.x
Jun 24 21:52:44 ubnt openvpn[1887]: /sbin/ip route add 128.0.0.0/1 via x.x.x.x
Jun 24 21:52:44 ubnt openvpn[1887]: Initialization Sequence Completed
ubnt openvpn[1887]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1887]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1887]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1887]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1887]: message repeated 51 times: [ Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194]
ubnt openvpn[1887]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1887]: message repeated 3 times: [ Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194]
ubnt openvpn[1887]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1887]: message repeated 3 times: [ Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194]
ubnt openvpn[1887]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1887]: message repeated 3 times: [ Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194]
ubnt openvpn[1887]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1887]: message repeated 32 times: [ Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194]
ubnt openvpn[1887]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1887]: message repeated 15 times: [ Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194]
ubnt openvpn[1887]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1887]: message repeated 5 times: [ Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194]
ubnt openvpn[1887]: [server] Inactivity timeout (--ping-restart), restarting
Jun 24 21:58:48 ubnt openvpn[1887]: TCP/UDP: Closing socket
Jun 24 21:58:48 ubnt openvpn[1887]: /sbin/ip route del x.x.x.x/32
Jun 24 21:58:48 ubnt openvpn[1887]: ERROR: Linux route delete command failed: external program exited with error status: 2
Jun 24 21:58:48 ubnt openvpn[1887]: /sbin/ip route del 0.0.0.0/1
Jun 24 21:58:48 ubnt openvpn[1887]: /sbin/ip route del 128.0.0.0/1
Jun 24 21:58:48 ubnt openvpn[1887]: Closing TUN/TAP interface
Jun 24 21:58:48 ubnt openvpn[1887]: /sbin/ip addr del dev vtun0 x.x.x.x/24
Jun 24 21:58:48 ubnt openvpn[1887]: SIGUSR1[soft,ping-restart] received, process restarting
Jun 24 21:58:48 ubnt openvpn[1887]: Restart pause, 5 second(s)
Jun 24 21:58:53 ubnt openvpn[1887]: Re-using SSL/TLS context
Jun 24 21:58:53 ubnt openvpn[1887]: Control Channel MTU parms [ L:1621 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Jun 24 21:58:53 ubnt openvpn[1887]: Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Jun 24 21:58:53 ubnt openvpn[1887]: Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-256-CBC,auth SHA256,keysize 256,tls-auth,key-method 2,tls-client'
Jun 24 21:58:53 ubnt openvpn[1887]: Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-256-CBC,auth SHA256,keysize 256,tls-auth,key-method 2,tls-server'
Jun 24 21:58:53 ubnt openvpn[1887]: TCP/UDP: Preserving recently used remote address: [AF_INET]x.x.x.x:1194
Jun 24 21:58:53 ubnt openvpn[1887]: Socket Buffers: R=[294912->294912] S=[294912->294912]
Jun 24 21:58:53 ubnt openvpn[1887]: UDP link local: (not bound)
Jun 24 21:58:53 ubnt openvpn[1887]: UDP link remote: [AF_INET]x.x.x.x:1194
Jun 24 21:58:53 ubnt openvpn[1887]: TLS: Initial packet from [AF_INET]x.x.x.x:1194, sid=e362e8a1 1a985f82
Jun 24 21:58:54 ubnt openvpn[1887]: VERIFY OK: depth=1, CN=CA
Jun 24 21:58:54 ubnt openvpn[1887]: Validating certificate key usage
Jun 24 21:58:54 ubnt openvpn[1887]: ++ Certificate has key usage 00a0, expects 00a0
Jun 24 21:58:54 ubnt openvpn[1887]: VERIFY KU OK

By the way, can you please explain to me why just removing --persist-tun on the Client side would solve this auto-reconnect issue? Do we also need to get rid of --persist-key as well? I did notice "recursive routing" detected, please have a look at the following log:

ubnt openvpn[1915]: TUN/TAP device vtun0 opened
ubnt openvpn[1915]: TUN/TAP TX queue length set to 100
ubnt openvpn[1915]: do_ifconfig, tt->did_ifconfig_ipv6_setup=0
ubnt openvpn[1915]: /sbin/ip link set dev vtun0 up mtu 1500
ubnt openvpn[1915]: /sbin/ip addr add dev vtun0 x.x.x.x/24 broadcast x.x.x.255
ubnt openvpn[1915]: /sbin/ip route add x.x.x.x/32 via x.x.x.254
Jubnt openvpn[1915]: /sbin/ip route add 0.0.0.0/1 via x.x.x.x
ubnt openvpn[1915]: /sbin/ip route add 128.0.0.0/1 via x.x.x.x
ubnt openvpn[1915]: Initialization Sequence Completed
ubnt ntpd[2681]: ntpd exiting on signal 15 (Terminated)
ubnt openvpn[1915]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1915]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1915]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1915]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1915]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1915]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
ubnt openvpn[1915]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
message repeated 23 times: [ Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194]
ubnt openvpn[1915]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
message repeated 23 times: [ Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194]
ubnt openvpn[1915]: Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194
message repeated 15 times: [ Recursive routing detected, drop tun packet to [AF_INET]x.x.x.x:1194]
ubnt openvpn[1915]: [server] Inactivity timeout (--ping-restart), restarting
ubnt openvpn[1915]: TCP/UDP: Closing socket
ubnt openvpn[1915]: /sbin/ip route del x.x.x.x/32
ubnt openvpn[1915]: ERROR: Linux route delete command failed: external program exited with error status: 2
ubnt openvpn[1915]: /sbin/ip route del 0.0.0.0/1
ubnt openvpn[1915]: /sbin/ip route del 128.0.0.0/1
ubnt openvpn[1915]: Closing TUN/TAP interface
ubnt openvpn[1915]: /sbin/ip addr del dev vtun0 x.x.x.x/24
ubnt openvpn[1915]: SIGUSR1[soft,ping-restart] received, process restarting
ubnt openvpn[1915]: Restart pause, 5 second(s)
ubnt openvpn[1915]: Re-using SSL/TLS context
ubnt openvpn[1915]: Control Channel MTU parms [ L:1621 D:1172 EF:78 EB:0 ET:0 EL:3 ]
ubnt openvpn[1915]: Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-256-CBC,auth SHA256,keysize 256,tls-auth,key-method 2,tls-client'
Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-256-CBC,auth SHA256,keysize 256,tls-auth,key-method 2,tls-server'
ubnt openvpn[1915]: TCP/UDP: Preserving recently used remote address: [AF_INET]x.x.x.x:1194
ubnt openvpn[1915]: Socket Buffers: R=[294912->294912] S=[294912->294912]
ubnt openvpn[1915]: UDP link local: (not bound)
ubnt openvpn[1915]: UDP link remote: [AF_INET]x.x.x.x:1194
ubnt openvpn[1915]: TLS: Initial packet from [AF_INET]x.x.x.x:1194, sid=1c8c5ec8 04002646
ubnt openvpn[1915]: VERIFY OK: depth=1, CN=CA
ubnt openvpn[1915]: Validating certificate key usage
ubnt openvpn[1915]: ++ Certificate has key usage 00a0, expects 00a0
ubnt openvpn[1915]: VERIFY KU OK
ubnt openvpn[1915]: Validating certificate extended key usage
ubnt openvpn[1915]: ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
ubnt openvpn[1915]: VERIFY EKU OK
ubnt openvpn[1915]: VERIFY OK: depth=0, CN=server
ubnt openvpn[1915]: Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
ubnt openvpn[1915]: [server] Peer Connection Initiated with [AF_INET]x.x.x.x:1194
ubnt openvpn[1915]: SENT CONTROL [server]: 'PUSH_REQUEST' (status=1)
ubnt openvpn[1915]: PUSH: Received control message: 'PUSH_REPLY,route-gateway x.x.x.x,topology subnet,ping 10,ping-restart 60,redirect-gateway def1,ifconfig x.x.x.3 255.255.255.0,peer-id 0,cipher AES-256-GCM'
ubnt openvpn[1915]: OPTIONS IMPORT: timers and/or timeouts modified
ubnt openvpn[1915]: OPTIONS IMPORT: --ifconfig/up options modified
ubnt openvpn[1915]: OPTIONS IMPORT: route options modified
ubnt openvpn[1915]: OPTIONS IMPORT: route-related options modified
ubnt openvpn[1915]: OPTIONS IMPORT: peer-id set
ubnt openvpn[1915]: OPTIONS IMPORT: adjusting link_mtu to 1624
ubnt openvpn[1915]: OPTIONS IMPORT: data channel crypto options modified
ubnt openvpn[1915]: Data Channel MTU parms [ L:1552 D:1450 EF:52 EB:406 ET:0 EL:3 ]
ubnt openvpn[1915]: Data Channel Encrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
ubnt openvpn[1915]: Data Channel Decrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
ubnt openvpn[1915]: ROUTE_GATEWAY x.x.x.254/255.255.255.0 IFACE=eth0 HWADDR=b4:fb:e4:8a:e3:0e
ubnt openvpn[1915]: TUN/TAP device vtun0 opened
ubnt openvpn[1915]: TUN/TAP TX queue length set to 100
ubnt openvpn[1915]: do_ifconfig, tt->did_ifconfig_ipv6_setup=0
ubnt openvpn[1915]: /sbin/ip link set dev vtun0 up mtu 1500
ubnt openvpn[1915]: /sbin/ip addr add dev vtun0 x.x.x.3/24 broadcast x.x.x.255
ubnt openvpn[1915]: /sbin/ip route add x.x.x.x/32 via x.x.x.x
ubnt openvpn[1915]: /sbin/ip route add 0.0.0.0/1 via x.x.x.1
ubnt openvpn[1915]: /sbin/ip route add 128.0.0.0/1 via x.x.x.1
ubnt openvpn[1915]: Initialization Sequence Completed

@TinCanTech: I will increase the log level and get back to you asap. Thank you so much for your support!