I find myself in a situation where about 80% of the time new connection attempts fail, but they seem to randomly succeed the other 20% of the time. I would be overwhelmingly grateful if anyone could diagnose the issue.
Remarks:
- Server is running on Ubuntu 18.04.
- The issue remains when I disable ufw.
- As far as I know there isn't any issue with the router - the port forwarding seems to be working fine.
- I'm using port 1195 because I have another instance of openvpn running that uses port 1194. The other instance uses a similar configuration and is experiencing the same problem.
- The start of the problem may have coincided with me installing updates and rebooting the openvpn server, but I'm not 100% sure.
local 192.168.2.45
port 1195
proto udp
dev tun
ca cacert.pem
cert fremen.crt
key fremen.key
crl-verify my.crl
dh dh2048.pem
server 10.88.2.0 255.255.255.0
ifconfig-pool-persist /var/log/openvpn/ipp.txt
push "route 192.168.2.0 255.255.255.0"
push "dhcp-option DOMAIN xxxxxxxxxxx.local"
push "dhcp-option DNS 192.168.2.6"
push "dhcp-option DNS 192.168.2.37"
tls-auth ta-admin.key 0 # This file is secret
cipher AES-256-CBC
auth SHA512
tls-version-min 1.2
user nobody
group nogroup
persist-key
persist-tun
status /var/log/openvpn/openvpn-status.log
log-append /var/log/openvpn/openvpn.log
verb 6
mute 20
explicit-exit-notify 1
client
dev tun
proto udp
remote xxxx.xxxxxx.co.uk 1195
resolv-retry infinite
nobind
persist-key
persist-tun
ca cacert.pem
cert shinano.crt
key shinano.key
remote-cert-tls server
auth-user-pass
# auth-nocache
key-direction 1
tls-auth ta-admin.key 1
cipher AES-256-CBC
auth SHA512
verb 3
And here is what it looks like when the connection attempt is failing:
Tue Mar 31 06:08:54 2020 us=383680 533 variation(s) on previous 20 message(s) suppressed by --mute
Tue Mar 31 06:08:54 2020 us=383759 MULTI: multi_create_instance called
Tue Mar 31 06:08:54 2020 us=383818 88.97.53.229:54613 Re-using SSL/TLS context
Tue Mar 31 06:08:54 2020 us=383958 88.97.53.229:54613 Control Channel MTU parms [ L:1621 D:1140 EF:110 EB:0 ET:0 EL:3 ]
Tue Mar 31 06:08:54 2020 us=383989 88.97.53.229:54613 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Tue Mar 31 06:08:54 2020 us=384048 88.97.53.229:54613 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-256-CBC,auth SHA512,keysize 256,tls-auth,key-method 2,tls-server'
Tue Mar 31 06:08:54 2020 us=384069 88.97.53.229:54613 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1601,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-256-CBC,auth SHA512,keysize 256,tls-auth,key-method 2,tls-client'
Tue Mar 31 06:08:54 2020 us=384114 88.97.53.229:54613 UDPv4 READ [86] from [AF_INET]88.97.53.229:54613: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 pid=[ #1 ] [ ] pid=0 DATA len=0
Tue Mar 31 06:08:54 2020 us=384145 88.97.53.229:54613 TLS: Initial packet from [AF_INET]88.97.53.229:54613, sid=4e53796e 45e1c2c4
Tue Mar 31 06:08:54 2020 us=384201 88.97.53.229:54613 UDPv4 WRITE [98] to [AF_INET]88.97.53.229:54613: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 pid=[ #1 ] [ 0 ] pid=0 DATA len=0
Tue Mar 31 06:08:56 2020 us=762710 88.97.53.229:54613 UDPv4 WRITE [86] to [AF_INET]88.97.53.229:54613: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 pid=[ #2 ] [ ] pid=0 DATA len=0
Tue Mar 31 06:08:56 2020 us=821919 88.97.53.229:54613 UDPv4 READ [86] from [AF_INET]88.97.53.229:54613: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 pid=[ #2 ] [ ] pid=0 DATA len=0
Tue Mar 31 06:08:56 2020 us=822050 88.97.53.229:54613 UDPv4 WRITE [94] to [AF_INET]88.97.53.229:54613: P_ACK_V1 kid=0 pid=[ #3 ] [ 0 ]
Tue Mar 31 06:09:00 2020 us=324319 88.97.53.229:54613 UDPv4 WRITE [86] to [AF_INET]88.97.53.229:54613: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 pid=[ #4 ] [ ] pid=0 DATA len=0
Tue Mar 31 06:09:00 2020 us=485723 88.97.53.229:54613 UDPv4 READ [86] from [AF_INET]88.97.53.229:54613: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 pid=[ #3 ] [ ] pid=0 DATA len=0
Tue Mar 31 06:09:00 2020 us=485859 88.97.53.229:54613 UDPv4 WRITE [94] to [AF_INET]88.97.53.229:54613: P_ACK_V1 kid=0 pid=[ #5 ] [ 0 ]
Tue Mar 31 06:09:08 2020 us=342546 88.97.53.229:54613 UDPv4 WRITE [86] to [AF_INET]88.97.53.229:54613: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 pid=[ #6 ] [ ] pid=0 DATA len=0
Tue Mar 31 06:09:09 2020 us=33760 88.97.53.229:54613 UDPv4 READ [86] from [AF_INET]88.97.53.229:54613: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 pid=[ #4 ] [ ] pid=0 DATA len=0
Tue Mar 31 06:09:09 2020 us=33894 88.97.53.229:54613 UDPv4 WRITE [94] to [AF_INET]88.97.53.229:54613: P_ACK_V1 kid=0 pid=[ #7 ] [ 0 ]
And on the client side we just the familiar error: "TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)".
Running Wireshark on the client, when it's failing to connect there isn't any traffic arriving from the server. However, running tcpdump on the server, it does seem to be trying to send packets back.