Error: TLS Authentication Failed on OpenVpn, happens randomly

dgeorgilakis · Dec 28, 2018, 8:04 PM

Hello Guys.
I implemented 5 new openvpn servers with radius and ldap authentication, so that each department has its own subnet and its own firewall policies.

The issue that we are facing is that our clients (linux mac and windows OS) started to disconnect randomly, after 10 min - 8 hours.
After that, no one could reconnect again, unless if the connection was closed manually. Also sometimes even though, the connection was closed manually, some clients couldn't establish new connection. Probably the connection was not closed from the server side.
This is strange because server allows concurrent connections with the same common name.

Today I faced the issue again on my Mac OS through terminal. I checked immediately if my ISP changed my public ip but it was the same.
On my firewall I have a dnat on my public ip to a DMZ vlan as you can see below (10.0.110.11) which permits openvpn ports.

I made some changes since my first configuration.
The changes that I made are:

Add my internal ntp server to the Pfsense Service and pushed it through openvpn.
Disabled ncp
Also I changed the keepalive to 30 120 but then I turned it back to its default
The same happens to all the other clients on my different openvpn servers.
Add also for windows clients on my server and on client config:
tun-mtu 1500 fragment 1300 mssfix but then i rolled it back since i didn't
see any change

Your help guys would be appreciated.

Here are the logs of my OpenVPN server.

Dec 28 18:42:16 demovpn openvpn: user 'secret' authenticated
Dec 28 20:42:16 demovpn openvpn[47932]: x.x.x.x:1194 [secret] Peer Connection Initiated with [AF_INET]x.x.x.x:1194
Dec 28 20:42:16 demovpn openvpn[47932]: secret/x.x.x.x:1194 MULTI_sva: pool returned IPv4=192.168.95.2, IPv6=(Not enabled)
Dec 28 21:02:51 demovpn openvpn[47932]: secret/x.x.x.x:1194 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Dec 28 21:02:51 demovpn openvpn[47932]: secret/x.x.x.x:1194 TLS Error: TLS handshake failed
Dec 28 21:04:21 demovpn openvpn[47932]: secret/x.x.x.x:1194 [secret] Inactivity timeout (--ping-restart), restarting

Here are the client logs

Fri Dec 28 20:42:10 2018 OpenVPN 2.4.6 x86_64-apple-darwin17.5.0 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [MH/RECVDA] [AEAD] built on May  1 2018
Fri Dec 28 20:42:10 2018 library versions: OpenSSL 1.0.2q  20 Nov 2018, LZO 2.10
Enter Auth Username:secret
Enter Auth Password:
Fri Dec 28 20:42:15 2018 TCP/UDP: Preserving recently used remote address: [AF_INET]x.x.x.x:1194
Fri Dec 28 20:42:15 2018 UDP link local (bound): [AF_INET][undef]:1194
Fri Dec 28 20:42:15 2018 UDP link remote: [AF_INET]x.x.x.x:1194
Fri Dec 28 20:42:16 2018 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Fri Dec 28 20:42:16 2018 [openvpn-int-ca] Peer Connection Initiated with [AF_INET]x.x.x.x:1194
Fri Dec 28 20:42:17 2018 Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:5: block-outside-dns (2.4.6)
Fri Dec 28 20:42:17 2018 Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:6: register-dns (2.4.6)
Fri Dec 28 20:42:17 2018 Opening utun (connect(AF_SYS_CONTROL)): Resource busy (errno=16)
Fri Dec 28 20:42:17 2018 Opening utun (connect(AF_SYS_CONTROL)): Resource busy (errno=16)
Fri Dec 28 20:42:17 2018 Opening utun (connect(AF_SYS_CONTROL)): Resource busy (errno=16)
Fri Dec 28 20:42:17 2018 Opening utun (connect(AF_SYS_CONTROL)): Resource busy (errno=16)
Fri Dec 28 20:42:17 2018 Opening utun (connect(AF_SYS_CONTROL)): Resource busy (errno=16)
Fri Dec 28 20:42:17 2018 Opened utun device utun5
Fri Dec 28 20:42:17 2018 do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Fri Dec 28 20:42:17 2018 /sbin/ifconfig utun5 delete
ifconfig: ioctl (SIOCDIFADDR): Can't assign requested address
Fri Dec 28 20:42:17 2018 NOTE: Tried to delete pre-existing tun/tap instance -- No Problem if failure
Fri Dec 28 20:42:17 2018 /sbin/ifconfig utun5 192.168.95.2 192.168.95.2 netmask 255.255.255.0 mtu 1500 up
add net 192.168.95.0: gateway 192.168.95.2
add net x.x.0.0: gateway 192.168.95.1
Fri Dec 28 20:42:17 2018 Initialization Sequence Completed
Fri Dec 28 21:01:46 2018 [openvpn-int-ca] Inactivity timeout (--ping-restart), restarting
Fri Dec 28 21:01:46 2018 SIGUSR1[soft,ping-restart] received, process restarting
Fri Dec 28 21:01:51 2018 TCP/UDP: Preserving recently used remote address: [AF_INET]x.x.x.x:1194
Fri Dec 28 21:01:51 2018 UDP link local (bound): [AF_INET][undef]:1194
Fri Dec 28 21:01:51 2018 UDP link remote: [AF_INET]x.x.x.x:1194

And here are the server config

dev ovpns1
verb 3
dev-type tun
dev-node /dev/tun1
writepid /var/run/openvpn_server1.pid
#user nobody
#group nobody
script-security 3
daemon
keepalive 10 60
ping-timer-rem
persist-tun
persist-key
proto udp4
cipher AES-128-CBC
auth SHA256
up /usr/local/sbin/ovpn-linkup
down /usr/local/sbin/ovpn-linkdown
client-connect /usr/local/sbin/openvpn.attributes.sh
client-disconnect /usr/local/sbin/openvpn.attributes.sh
local 10.0.110.11
tls-server
server 192.168.95.0 255.255.255.0
client-config-dir /var/etc/openvpn-csc/server1
username-as-common-name
plugin /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so /usr/local/sbin/ovpn_auth_verify_async user UmFkaXVzX09yY2E= true server1 1194
tls-verify "/usr/local/sbin/ovpn_auth_verify tls 'openvpn-int-ca' 1"
lport 1194
management /var/etc/openvpn/server1.sock unix
push "route x.x.0.0 255.0.0.0"
push "dhcp-option DOMAIN xxxxxxxxxxx
push "dhcp-option DNS x.x.0.10"
push "dhcp-option DNS x.x.0.15"
push "block-outside-dns"
push "register-dns"
push "dhcp-option NTP x.x.0.10"
push "dhcp-option NTP x.x.0.15"
duplicate-cn
ca /var/etc/openvpn/server1.ca
cert /var/etc/openvpn/server1.cert
key /var/etc/openvpn/server1.key
dh /etc/dh-parameters.2048
tls-auth /var/etc/openvpn/server1.tls-auth 0
ncp-disable
persist-remote-ip
float
topology subnet

and my client config without of course the certs and key

dev tun
persist-tun
persist-key
cipher AES-128-CBC
auth SHA256
tls-client
client
resolv-retry infinite
remote x.x.x.x 1194 udp
verify-x509-name "openvpn-int-ca" name
auth-user-pass
remote-cert-tls server

Thank you for your time

Rico · Jan 2, 2019, 7:37 AM

This is error is mostly just down to basic connection problems.
For testing I'd skip options like float and so on, try with some very basic setup.
Increase the verb level to get a more detailed Log.

-Rico

netblues · Jan 2, 2019, 7:41 AM

I would get a permanent ping running from client to vpn host external ip and see if you had packet loss.
Failed tls negotiation doesn't have much to configure, once it works, always works.

dgeorgilakis · Jan 2, 2019, 7:37 AM

@rico please can you specify the options that I have to skip/remove?
The verbosity level changed to 5, so I will update you when I connect to the VPN

dgeorgilakis · Jan 2, 2019, 7:41 AM

@netblues Permanent ping is up and running. I will update you as soon as I have news.

Rico · Jan 2, 2019, 9:49 AM

For me a basic RA Server Config looks like this

dev ovpns1
verb 1
dev-type tun
dev-node /dev/tun1
writepid /var/run/openvpn_server1.pid
#user nobody
#group nobody
script-security 3
daemon
keepalive 10 60
ping-timer-rem
persist-tun
persist-key
proto udp4
cipher AES-256-GCM
auth SHA256
up /usr/local/sbin/ovpn-linkup
down /usr/local/sbin/ovpn-linkdown
client-connect /usr/local/sbin/openvpn.attributes.sh
client-disconnect /usr/local/sbin/openvpn.attributes.sh
local 192.168.74.131
tls-server
server 10.0.0.1 255.255.255.0
client-config-dir /var/etc/openvpn-csc/server1
username-as-common-name
plugin /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so /usr/local/sbin/ovpn_auth_verify_async user TG9jYWwgRGF0YWJhc2U= false server1 1194
tls-verify "/usr/local/sbin/ovpn_auth_verify tls 'test' 1"
lport 1194
management /var/etc/openvpn/server1.sock unix
push "route 192.168.1.1 255.255.255.0"
ca /var/etc/openvpn/server1.ca
cert /var/etc/openvpn/server1.cert
key /var/etc/openvpn/server1.key
dh /etc/dh-parameters.2048
tls-auth /var/etc/openvpn/server1.tls-auth 0
ncp-disable
compress
topology subnet

-Rico

dgeorgilakis · Jan 3, 2019, 7:49 PM

This post is deleted!

dgeorgilakis · Jan 3, 2019, 8:01 PM

Guys I removed the flow option and I was disconnected again after 1 hour
Also I forgot to mention that I have implemented 802.1x security on my Juniper switches through the same NPS server. (windows 2012 R2) so that my colleagues can access network only after authentication.
So the difference on my NPS is that I have first my VPN policy then Wireless 802.1x and finally the wired 802.1x.

Is there any possibility that Radius/NPS looses connection (LAN) with openvpn server or the order of policies affect each other and automatically disconnects me?
The server config is just like @Rico but with the below differences on server

tun-mtu 1500
fragment 1300
mssfix
keepalive 30 120

and on my client

tun-mtu 1500
fragment 1300
mssfix
ping 10
ping-restart 30

Server logs

Jan  3 20:04:40 demovpn openvpn[23620]: secret/x.x.x.x:1194 MULTI: Learn: 192.168.95.2 -> secret/x.x.x.x:1194
Jan  3 20:04:40 demovpn openvpn[23620]: secret/x.x.x.x:1194 MULTI: primary virtual IP for secret/x.x.x.x:1194: 192.168.95.2
Jan  3 20:04:40 demovpn openvpn[23620]: secret/x.x.x.x:1194 PUSH: Received control message: 'PUSH_REQUEST'
Jan  3 21:03:04 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS: new session incoming connection from [AF_INET]x.x.x.x:1194
Jan  3 21:04:04 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jan  3 21:04:04 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS Error: TLS handshake failed
Jan  3 21:04:39 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS: soft reset sec=0 bytes=66431304/-1 pkts=230648/0
Jan  3 21:05:39 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jan  3 21:05:39 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS Error: TLS handshake failed
Jan  3 21:05:39 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Jan  3 21:06:54 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jan  3 21:06:54 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS Error: TLS handshake failed
Jan  3 21:06:55 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS: Initial packet from [AF_INET]x.x.x.x:1194, sid=51757c47 f972d37e
Jan  3 21:07:08 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS: new session incoming connection from [AF_INET]x.x.x.x:1194
Jan  3 21:07:55 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
connectivity)
Jan  3 21:09:08 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS Error: TLS handshake failed
Jan  3 21:10:23 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jan  3 21:10:23 demovpn openvpn[23620]: secret/x.x.x.x:1194 TLS Error: TLS handshake failed
Jan  3 21:11:23 demovpn openvpn[23620]: secret/x.x.x.x:1194 [UNDEF] Inactivity timeout (--ping-restart), restarting
Jan  3 21:11:23 demovpn openvpn[23620]: secret/x.x.x.x:1194 SIGUSR1[soft,ping-restart] received, client-instance restarting

dgeorgilakis · Jan 4, 2019, 11:21 AM

Is there any possibility the issue of "Tls key negotiation failed" to start from the NPS server?
I mean, if for some reason NPS server looses connection with the Openvpn server, is it possible my connection to go down? or nps is just for the initial authentication?

dgeorgilakis · Jan 4, 2019, 11:52 AM

Update: From Public Static IP I have not been disconnected since yesterday morning.
So, all the disconnections are from Dynamic Public ip

dgeorgilakis · Jan 9, 2019, 11:09 AM

Guys any update???? Your help will be appreciated