Good day. We’ve been battling with our OpenVPN
client in Vista for a few weeks now. We are getting TLS handshake errors
trying to connect with the 2.1_rc4 client. From the remote site, we can make
a connection using Windows XP and Mac OS X (using Tunnelblick) without incident.
When we try to connect from the same location with Vista, we receive the error “TLS Error: TLS handshake
failed”. This does not seem to be a firewall issue, as
suggested by the OpenVPN FAQ. In Vista, we “Run as Administrator”
the client, Windows Firewall is disabled, and no third-party internet security
software is installed. Logs with verbosity 6 are pasted below; endpoints
have been masked. We recently updated our server to the latest version of
OpenVPN; it did not help.
Client log:
Tue
May 08 06:13:12 2007 us=253000 TCP connection established with xxx.xxx.xxx.xxx:1194
Tue
May 08 06:13:12 2007 us=253000 Socket Buffers: R=[8192->8192]
S=[8192->8192]
Tue
May 08 06:13:12 2007 us=253000 TCPv4_CLIENT link local: [undef]
Tue
May 08 06:13:12 2007 us=253000 TCPv4_CLIENT link remote: xxx.xxx.xxx.xxx:1194
Tue
May 08 06:13:12 2007 us=253000 TCPv4_CLIENT WRITE [14] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Tue
May 08 06:13:12 2007 us=846000 TCPv4_CLIENT READ [26] from xxx.xxx.xxx.xxx:1194:
P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Tue
May 08 06:13:12 2007 us=846000 TLS: Initial packet from xxx.xxx.xxx.xxx:1194,
sid=d62c2525 b81130f7
Tue
May 08 06:13:12 2007 us=846000 TCPv4_CLIENT WRITE [22] to xxx.xxx.xxx.xxx:1194:
P_ACK_V1 kid=0 [ 0 ]
Tue
May 08 06:13:12 2007 us=846000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:15 2007 us=139000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:17 2007 us=432000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:19 2007 us=725000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:22 2007 us=19000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:24 2007 us=109000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:26 2007 us=200000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:28 2007 us=290000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:30 2007 us=380000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:32 2007 us=455000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:34 2007 us=561000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:36 2007 us=667000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:38 2007 us=773000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:40 2007 us=879000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:42 2007 us=985000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:44 2007 us=15000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:46 2007 us=74000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:48 2007 us=133000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:50 2007 us=208000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:52 2007 us=267000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:54 2007 us=529000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:56 2007 us=791000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:13:59 2007 us=53000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:14:01 2007 us=300000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:14:03 2007 us=453000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:14:05 2007 us=496000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:14:07 2007 us=540000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:14:09 2007 us=583000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:14:11 2007 us=627000 TCPv4_CLIENT WRITE [102] to xxx.xxx.xxx.xxx:1194:
P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Tue
May 08 06:14:12 2007 us=657000 TLS Error: TLS key negotiation failed to occur
within 60 seconds (check your network connectivity)
Tue
May 08 06:14:12 2007 us=657000 TLS Error: TLS handshake failed
Tue
May 08 06:14:12 2007 us=657000 Fatal TLS error (check_tls_errors_co),
restarting
Tue
May 08 06:14:12 2007 us=657000 TCP/UDP: Closing socket
Tue
May 08 06:14:12 2007 us=657000 SIGUSR1[soft,tls-error] received, process
restarting
Tue
May 08 06:14:12 2007 us=657000 Restart pause, 5 second(s)
Server log:
May
3 01:57:27 myserver openvpn[845]: TCPv4_SERVER link local: [undef]
May
3 01:57:27 myserver openvpn[845]: TCPv4_SERVER link remote: xxx.xxx.xxx.xxx :60692
May
3 01:57:27 myserver openvpn[845]: xxx.xxx.xxx.xxx :60692 TLS: Initial packet
from xxx.xxx.xxx.xxx :60692, sid=d57f5f9d bf74b2db
May
3 01:57:33 myserver isakmpd[9817]: isakmpd: quick mode done: src: xx.xx.xx.xx
dst: xxx.xxx.xxx.xxx
May
3 01:57:48 myserver openvpn[845]: xxx.xxx.xxx.xxx :60692 Connection reset,
restarting [-1]
May
3 01:57:48 myserver openvpn[845]: xxx.xxx.xxx.xxx :60692
SIGUSR1[soft,connection-reset] received, client-instance restarting
May
3 01:57:48 myserver openvpn[845]: TCP/UDP: Closing socket
Much thanks for any assistance.
-Ed