[Openvpn-users] Fatal TLS error (check_tls_errors

Discussion:

[Openvpn-users] Fatal TLS error (check_tls_errors_co), restarting

josh

2008-05-27 15:22:51 UTC

I'm seeing the following on an OpenVPN client (OpenSolaris) connecting
to a Solaris OpenVPN endpoint. We have roughly 180 clients connected
to two different T1000's, all using the same config files. We have a
handful of clients that are using TCP for connectivity instead of UDP
(not my idea, but the clients) This particular store is connected via
TCP.

I'm attaching the server.config, client startup script, and server.log
from when this error is happening.

Here's a snippet of the log file on the client:

Tue May 27 08:23:36 2008 Initialization Sequence Completed
Tue May 27 09:22:39 2008 [vpn] Inactivity timeout (--ping-restart), restarting
delete net 192.168.244.0: gateway 192.168.244.1
delete net 172.35.1.0: gateway 192.168.244.1
delete net 10.0.0.0: gateway 192.168.244.1
Tue May 27 09:22:39 2008 SIGUSR1[soft,ping-restart] received, process restarting
Tue May 27 09:22:44 2008 IMPORTANT: OpenVPN's default port number is
now 1194, based on an official port number assignment by IANA.
OpenVPN 2.0-beta16 and earlier used
5000 as the default port.
Tue May 27 09:22:44 2008 WARNING: No server certificate verification
method has been enabled. See http://openvpn.net/howto.html#mitm for
more info.
Tue May 27 09:22:44 2008 Attempting to establish TCP connection with
x.x.x.x:1194
Tue May 27 09:22:44 2008 TCP connection established with x.x.x.x:1194
Tue May 27 09:22:44 2008 TCPv4_CLIENT link local: [undef]
Tue May 27 09:22:44 2008 TCPv4_CLIENT link remote: x.x.x.x:1194
Tue May 27 09:22:46 2008 [vpn] Peer Connection Initiated with x.x.x.x:1194
Tue May 27 09:22:47 2008 TUN/TAP device tun1 opened
Tue May 27 09:22:47 2008 /usr/sbin/ifconfig tun1 192.168.244.53
192.168.244.1 mtu 1500 up
Tue May 27 09:22:47 2008 /usr/sbin/ifconfig tun1 netmask 255.255.255.255
add net 10.0.0.0: gateway 192.168.244.1
add net 172.35.1.0: gateway 192.168.244.1
add net 192.168.244.0: gateway 192.168.244.1
Tue May 27 09:22:47 2008 Initialization Sequence Completed
Tue May 27 10:23:46 2008 TLS Error: TLS key negotiation failed to
occur within 60 seconds (check your network connectivity)
Tue May 27 10:23:46 2008 TLS Error: TLS handshake failed
Tue May 27 10:23:46 2008 Fatal TLS error (check_tls_errors_co), restarting
delete net 192.168.244.0: gateway 192.168.244.1
delete net 172.35.1.0: gateway 192.168.244.1
delete net 10.0.0.0: gateway 192.168.244.1
Tue May 27 10:23:46 2008 SIGUSR1[soft,tls-error] received, process restarting
Tue May 27 10:23:51 2008 IMPORTANT: OpenVPN's default port number is
now 1194, based on an official port number assignment by IANA.
OpenVPN 2.0-beta16 and earlier used
5000 as the default port.
Tue May 27 10:23:51 2008 WARNING: No server certificate verification
method has been enabled. See http://openvpn.net/howto.html#mitm for
more info.
Tue May 27 10:23:51 2008 Attempting to establish TCP connection with
x.x.x.x:1194
Tue May 27 10:23:51 2008 TCP connection established with x.x.x.x:1194
Tue May 27 10:23:51 2008 TCPv4_CLIENT link local: [undef]
Tue May 27 10:23:51 2008 TCPv4_CLIENT link remote: x.x.x.x:1194
Tue May 27 10:23:55 2008 [vpn] Peer Connection Initiated with x.x.x.x:1194
Tue May 27 10:23:56 2008 TUN/TAP device tun1 opened
Tue May 27 10:23:56 2008 /usr/sbin/ifconfig tun1 192.168.244.53
192.168.244.1 mtu 1500 up

Thanks!

Jan Just Keijser

2008-05-27 16:39:57 UTC

Permalink

Hi Josh,

The log messages on both client and server side show that the TLS
handshake is failing; 9 out of 10 times , this means that there's
firewall blocking traffic somewhere (e.g. at the client site). Can you
run tcpdump on both ends to see what is going on?

also, in your prev email you did not post the client.conf but a connect
script instead ;-)

cheers,

JJK

Post by josh
I'm seeing the following on an OpenVPN client (OpenSolaris) connecting
to a Solaris OpenVPN endpoint. We have roughly 180 clients connected
to two different T1000's, all using the same config files. We have a
handful of clients that are using TCP for connectivity instead of UDP
(not my idea, but the clients) This particular store is connected via
TCP.
I'm attaching the server.config, client startup script, and server.log
from when this error is happening.
Tue May 27 08:23:36 2008 Initialization Sequence Completed
Tue May 27 09:22:39 2008 [vpn] Inactivity timeout (--ping-restart), restarting
delete net 192.168.244.0: gateway 192.168.244.1
delete net 172.35.1.0: gateway 192.168.244.1
delete net 10.0.0.0: gateway 192.168.244.1
Tue May 27 09:22:39 2008 SIGUSR1[soft,ping-restart] received, process restarting
Tue May 27 09:22:44 2008 IMPORTANT: OpenVPN's default port number is
now 1194, based on an official port number assignment by IANA.
OpenVPN 2.0-beta16 and earlier used
5000 as the default port.
Tue May 27 09:22:44 2008 WARNING: No server certificate verification
method has been enabled. See http://openvpn.net/howto.html#mitm for
more info.
Tue May 27 09:22:44 2008 Attempting to establish TCP connection with
x.x.x.x:1194
Tue May 27 09:22:44 2008 TCP connection established with x.x.x.x:1194
Tue May 27 09:22:44 2008 TCPv4_CLIENT link local: [undef]
Tue May 27 09:22:44 2008 TCPv4_CLIENT link remote: x.x.x.x:1194
Tue May 27 09:22:46 2008 [vpn] Peer Connection Initiated with x.x.x.x:1194
Tue May 27 09:22:47 2008 TUN/TAP device tun1 opened
Tue May 27 09:22:47 2008 /usr/sbin/ifconfig tun1 192.168.244.53
192.168.244.1 mtu 1500 up
Tue May 27 09:22:47 2008 /usr/sbin/ifconfig tun1 netmask 255.255.255.255
add net 10.0.0.0: gateway 192.168.244.1
add net 172.35.1.0: gateway 192.168.244.1
add net 192.168.244.0: gateway 192.168.244.1
Tue May 27 09:22:47 2008 Initialization Sequence Completed
Tue May 27 10:23:46 2008 TLS Error: TLS key negotiation failed to
occur within 60 seconds (check your network connectivity)
Tue May 27 10:23:46 2008 TLS Error: TLS handshake failed
Tue May 27 10:23:46 2008 Fatal TLS error (check_tls_errors_co), restarting
delete net 192.168.244.0: gateway 192.168.244.1
delete net 172.35.1.0: gateway 192.168.244.1
delete net 10.0.0.0: gateway 192.168.244.1
Tue May 27 10:23:46 2008 SIGUSR1[soft,tls-error] received, process restarting
Tue May 27 10:23:51 2008 IMPORTANT: OpenVPN's default port number is
now 1194, based on an official port number assignment by IANA.
OpenVPN 2.0-beta16 and earlier used
5000 as the default port.
Tue May 27 10:23:51 2008 WARNING: No server certificate verification
method has been enabled. See http://openvpn.net/howto.html#mitm for
more info.
Tue May 27 10:23:51 2008 Attempting to establish TCP connection with
x.x.x.x:1194
Tue May 27 10:23:51 2008 TCP connection established with x.x.x.x:1194
Tue May 27 10:23:51 2008 TCPv4_CLIENT link local: [undef]
Tue May 27 10:23:51 2008 TCPv4_CLIENT link remote: x.x.x.x:1194
Tue May 27 10:23:55 2008 [vpn] Peer Connection Initiated with x.x.x.x:1194
Tue May 27 10:23:56 2008 TUN/TAP device tun1 opened
Tue May 27 10:23:56 2008 /usr/sbin/ifconfig tun1 192.168.244.53
192.168.244.1 mtu 1500 up

josh

2008-05-27 16:51:40 UTC

Permalink

Jan,
I posted the client.conf as we are not using a client config but a
connect script.
(I just called the attachment client.conf)

"I'm attaching the server.config, client startup script, and server.log
from when this error is happening."

There is no firewall blocking the traffic, otherwise it would never
connect. The client does connect to the server, but drops every hour
on the hour (for this particular client)

client# nmap -P0 -sV -p 1194 -e bfe0 z.z.z.z

Starting Nmap 4.20 ( http://insecure.org ) at 2008-05-27 12:50 EDT
Interesting ports on z.z.z.z:
PORT STATE SERVICE VERSION
1194/tcp open openvpn OpenVPN

Service detection performed. Please report any incorrect results at
http://insecure.org/nmap/submit/ .
Nmap finished: 1 IP address (1 host up) scanned in 3.932 seconds

Post by Jan Just Keijser
Hi Josh,
The log messages on both client and server side show that the TLS handshake
is failing; 9 out of 10 times , this means that there's firewall blocking
traffic somewhere (e.g. at the client site). Can you run tcpdump on both
ends to see what is going on?
also, in your prev email you did not post the client.conf but a connect
script instead ;-)
cheers,
JJK

Jan Just Keijser

2008-05-27 16:54:51 UTC

Permalink

Hi Josh,

OK my bad for not reading that correctly... the connection drops every
hour on the hour: I'd investigate the local DHCP settings; let's rule
out a DHCP release/renewal problem first.

cheers,

JJK

Post by josh
Jan,
I posted the client.conf as we are not using a client config but a
connect script.
(I just called the attachment client.conf)
"I'm attaching the server.config, client startup script, and server.log
from when this error is happening."
There is no firewall blocking the traffic, otherwise it would never
connect. The client does connect to the server, but drops every hour
on the hour (for this particular client)
client# nmap -P0 -sV -p 1194 -e bfe0 z.z.z.z
Starting Nmap 4.20 ( http://insecure.org ) at 2008-05-27 12:50 EDT
PORT STATE SERVICE VERSION
1194/tcp open openvpn OpenVPN
Service detection performed. Please report any incorrect results at
http://insecure.org/nmap/submit/ .
Nmap finished: 1 IP address (1 host up) scanned in 3.932 seconds

josh

2008-05-27 17:00:58 UTC

Permalink

Not a problem. Currently the DHCP release is happening every 12
hours, not every hour. Right now I have the OpenVPN client plugged
directly into the DSL modem to rule out a misconfiguration on the
Netgear switch that it's connected to (these clients are all remote
and not managed by me, the only device that I have access to is the
openvpn client itself) We've found some other locations where the
DHCP lease on the DSL modem was set to one hour and have had it
changed to a week and those locations have been more stable since that
change.

Post by Jan Just Keijser
Hi Josh,
OK my bad for not reading that correctly... the connection drops every hour
on the hour: I'd investigate the local DHCP settings; let's rule out a DHCP
release/renewal problem first.
cheers,
JJK

Jan Just Keijser

2008-05-27 20:23:40 UTC

Permalink

Hi Josh,

try playing with the
reneg-sec
hand-window
values; the first one is by default set to 3600, the second to 60 ; most
likely the hourly key renegotation is failing. Does this particular
client also take a long time to connect?

HTH,

JJK

Post by josh
Not a problem. Currently the DHCP release is happening every 12
hours, not every hour. Right now I have the OpenVPN client plugged
directly into the DSL modem to rule out a misconfiguration on the
Netgear switch that it's connected to (these clients are all remote
and not managed by me, the only device that I have access to is the
openvpn client itself) We've found some other locations where the
DHCP lease on the DSL modem was set to one hour and have had it
changed to a week and those locations have been more stable since that
change.

josh

2008-05-27 20:42:34 UTC

Permalink

Jan-

Post by Jan Just Keijser
Hi Josh,
try playing with the
reneg-sec
hand-window
values; the first one is by default set to 3600, the second to 60 ; most
likely the hourly key renegotation is failing. Does this particular client
also take a long time to connect?

Actually since plugging the client machine directly into the DSL
modem, the issue seems to have gone away. It's been connected for
almost 3 hours without issue. I'll definitely start tweaking those
two values you mentioned (reneg-sec and hand-window) if we still have
issues. (And it normally does not take this machine long to connect)

Thanks,
Josh

josh

2008-05-27 20:44:42 UTC

Permalink

Jan,

Post by josh
Actually since plugging the client machine directly into the DSL
modem, the issue seems to have gone away. It's been connected for
almost 3 hours without issue. I'll definitely start tweaking those
two values you mentioned (reneg-sec and hand-window) if we still have
issues. (And it normally does not take this machine long to connect)

Rather it's been connected for almost 90 minutes with no issue...
(I was looking at the wrong client when I said almost 3 hours)

Josh