OpenVPN reconnect fails, manual restart works

networkingopenvpn

I have set up an OpenVPN server on an Azure virtual machine. For the setup I used the script from https://github.com/Nyr/openvpn-install.

I then connect to the server using sudo openvpn --config client.ovpn this works perfectly. I then disconnect the Ethernet cable from the client machine and then reconnect it. The client then tries to reconnect, however it never succeeds. I then tried killing the client (ctrl+c) and restarting it with the same command – this works.

The client is currently on an office network with at least two NAT layers. Ultimately the client will be on a rather unstable client's network, where I have no control of the network setup.

I get the same behavior no matter if I use TCPor UDP.

Why is the behavior of reconnect different from stopping and then starting the OpenVPN client?

If all fails I could of course make a wrapper script which restarts the OpenVPN client, but I would of course prefer not to do this.

Both the server and client runs Ubuntu server 18.04

The header of the .ovpn file is:

client
dev tun
proto udp
sndbuf 0
rcvbuf 0
remote <host> 1194
resolv-retry infinite
nobind
persist-key
persist-tun
remote-cert-tls server
auth SHA512
cipher AES-256-CBC
setenv opt block-outside-dns
key-direction 1
verb 3

Log from the OpenVPN client when using UDP (the TCP one looks very similair):

$ sudo openvpn --config client.ovpn
Mon Jan 28 13:24:35 2019 Unrecognized option or missing or extra parameter(s) in client.ovpn:14: block-outside-dns (2.4.4)
Mon Jan 28 13:24:35 2019 OpenVPN 2.4.4 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Sep  5 2018
Mon Jan 28 13:24:35 2019 library versions: OpenSSL 1.1.0g  2 Nov 2017, LZO 2.08                        
Mon Jan 28 13:24:35 2019 Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Mon Jan 28 13:24:35 2019 Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Mon Jan 28 13:24:35 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]<server_ip>:1194
Mon Jan 28 13:24:35 2019 Socket Buffers: R=[212992->212992] S=[212992->212992]                                             
Mon Jan 28 13:24:35 2019 UDP link local: (not bound)    
Mon Jan 28 13:24:35 2019 UDP link remote: [AF_INET]<server_ip>:1194       
Mon Jan 28 13:24:35 2019 TLS: Initial packet from [AF_INET]<server_ip>:1194, sid=<> 78915078
Mon Jan 28 13:24:35 2019 VERIFY OK: depth=1, CN=ChangeMe                                               
Mon Jan 28 13:24:35 2019 VERIFY KU OK                                         
Mon Jan 28 13:24:35 2019 Validating certificate extended key usage
Mon Jan 28 13:24:35 2019 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Mon Jan 28 13:24:35 2019 VERIFY EKU OK
Mon Jan 28 13:24:35 2019 VERIFY OK: depth=0, CN=server
Mon Jan 28 13:24:35 2019 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Mon Jan 28 13:24:35 2019 [server] Peer Connection Initiated with [AF_INET]<server_ip>:1194
Mon Jan 28 13:24:36 2019 SENT CONTROL [server]: 'PUSH_REQUEST' (status=1)
Mon Jan 28 13:24:36 2019 PUSH: Received control message: 'PUSH_REPLY,redirect-gateway def1 bypass-dhcp,dhcp-option DNS 1.1.1.1,dhcp-option DNS 1.0.0.1,route-gateway 10.8.0.1,topology subnet,ping 10,ping-restart 120,ifconfig 10.8.0.3 255.2
55.255.0,peer-id 0,cipher AES-256-GCM'
Mon Jan 28 13:24:36 2019 OPTIONS IMPORT: timers and/or timeouts modified
Mon Jan 28 13:24:36 2019 OPTIONS IMPORT: --ifconfig/up options modified
Mon Jan 28 13:24:36 2019 OPTIONS IMPORT: route options modified
Mon Jan 28 13:24:36 2019 OPTIONS IMPORT: route-related options modified
Mon Jan 28 13:24:36 2019 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Mon Jan 28 13:24:36 2019 OPTIONS IMPORT: peer-id set
Mon Jan 28 13:24:36 2019 OPTIONS IMPORT: adjusting link_mtu to 1624
Mon Jan 28 13:24:36 2019 OPTIONS IMPORT: data channel crypto options modified
Mon Jan 28 13:24:36 2019 Data Channel: using negotiated cipher 'AES-256-GCM'
Mon Jan 28 13:24:36 2019 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Mon Jan 28 13:24:36 2019 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Mon Jan 28 13:24:36 2019 ROUTE_GATEWAY 192.169.0.1/255.255.255.0 IFACE=enp0s31f6 HWADDR=<mac>
Mon Jan 28 13:24:36 2019 TUN/TAP device tun0 opened
Mon Jan 28 13:24:36 2019 TUN/TAP TX queue length set to 100
Mon Jan 28 13:24:36 2019 do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Mon Jan 28 13:24:36 2019 /sbin/ip link set dev tun0 up mtu 1500
Mon Jan 28 13:24:36 2019 /sbin/ip addr add dev tun0 10.8.0.3/24 broadcast 10.8.0.255
Mon Jan 28 13:24:36 2019 /sbin/ip route add <server_ip>/32 via 192.169.0.1
Mon Jan 28 13:24:36 2019 /sbin/ip route add 0.0.0.0/1 via 10.8.0.1
Mon Jan 28 13:24:36 2019 /sbin/ip route add 128.0.0.0/1 via 10.8.0.1
Mon Jan 28 13:24:36 2019 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Mon Jan 28 13:24:36 2019 Initialization Sequence Completed
Mon Jan 28 13:28:47 2019 [server] Inactivity timeout (--ping-restart), restarting
Mon Jan 28 13:28:47 2019 SIGUSR1[soft,ping-restart] received, process restarting
Mon Jan 28 13:28:47 2019 Restart pause, 5 second(s)
Mon Jan 28 13:28:52 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]<server_ip>:1194
Mon Jan 28 13:28:52 2019 Socket Buffers: R=[212992->212992] S=[212992->212992]
Mon Jan 28 13:28:52 2019 UDP link local: (not bound)
Mon Jan 28 13:28:52 2019 UDP link remote: [AF_INET]<server_ip>:1194
Mon Jan 28 13:29:52 2019 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Mon Jan 28 13:29:52 2019 TLS Error: TLS handshake failed                                                                                                                                                                                      
Mon Jan 28 13:29:52 2019 SIGUSR1[soft,tls-error] received, process restarting                                                                                                                                                                 
Mon Jan 28 13:29:52 2019 Restart pause, 5 second(s)                                                                                                                                                                                           
Mon Jan 28 13:29:57 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]<server_ip>:1194
Mon Jan 28 13:29:57 2019 Socket Buffers: R=[212992->212992] S=[212992->212992]                                               
Mon Jan 28 13:29:57 2019 UDP link local: (not bound)                                                                         
Mon Jan 28 13:29:57 2019 UDP link remote: [AF_INET]<server_ip>:1194                                 
Mon Jan 28 13:30:57 2019 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Mon Jan 28 13:30:57 2019 TLS Error: TLS handshake failed
Mon Jan 28 13:30:57 2019 SIGUSR1[soft,tls-error] received, process restarting
Mon Jan 28 13:30:57 2019 Restart pause, 5 second(s)                                                  
Mon Jan 28 13:31:02 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]<server_ip>:1194
Mon Jan 28 13:31:02 2019 Socket Buffers: R=[212992->212992] S=[212992->212992]
Mon Jan 28 13:31:02 2019 UDP link local: (not bound)              
Mon Jan 28 13:31:02 2019 UDP link remote: [AF_INET]<server_ip>:1194                                                    
Mon Jan 28 13:32:02 2019 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Mon Jan 28 13:32:02 2019 TLS Error: TLS handshake failed
Mon Jan 28 13:32:02 2019 SIGUSR1[soft,tls-error] received, process restarting                              
Mon Jan 28 13:32:02 2019 Restart pause, 5 second(s)                                          
Mon Jan 28 13:32:07 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]<server_ip>:1194
Mon Jan 28 13:32:07 2019 Socket Buffers: R=[212992->212992] S=[212992->212992]                                                                                                                                                                
Mon Jan 28 13:32:07 2019 UDP link local: (not bound)
Mon Jan 28 13:32:07 2019 UDP link remote: [AF_INET]<server_ip>:1194  
Mon Jan 28 13:33:07 2019 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Mon Jan 28 13:33:07 2019 TLS Error: TLS handshake failed       
Mon Jan 28 13:33:07 2019 SIGUSR1[soft,tls-error] received, process restarting
Mon Jan 28 13:33:07 2019 Restart pause, 5 second(s)                                      
Mon Jan 28 13:33:12 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]<server_ip>:1194
Mon Jan 28 13:33:12 2019 Socket Buffers: R=[212992->212992] S=[212992->212992]
Mon Jan 28 13:33:12 2019 UDP link local: (not bound)                         
Mon Jan 28 13:33:12 2019 UDP link remote: [AF_INET]<server_ip>:1194      
Mon Jan 28 13:34:13 2019 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Mon Jan 28 13:34:13 2019 TLS Error: TLS handshake failed                                         
Mon Jan 28 13:34:13 2019 SIGUSR1[soft,tls-error] received, process restarting                            
Mon Jan 28 13:34:13 2019 Restart pause, 5 second(s)
Mon Jan 28 13:34:18 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]<server_ip>:1194
Mon Jan 28 13:34:18 2019 Socket Buffers: R=[212992->212992] S=[212992->212992]
Mon Jan 28 13:34:18 2019 UDP link local: (not bound)           
Mon Jan 28 13:34:18 2019 UDP link remote: [AF_INET]<server_ip>:1194              
Mon Jan 28 13:35:18 2019 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Mon Jan 28 13:35:18 2019 TLS Error: TLS handshake failed          
Mon Jan 28 13:35:18 2019 SIGUSR1[soft,tls-error] received, process restarting
Mon Jan 28 13:35:18 2019 Restart pause, 10 second(s)                                                                             
Mon Jan 28 13:35:28 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]<server_ip>:1194
Mon Jan 28 13:35:28 2019 Socket Buffers: R=[212992->212992] S=[212992->212992]   

Best Answer

I found the solution.

In the client ovpn file, disable the persist-tun by

;persist-tun

and then try it out.

References:
- https://forums.openvpn.net/viewtopic.php?t=22020
- https://forums.openvpn.net/viewtopic.php?f=6&t=22325&p=64015#p64015