[SOLVED] TLS Error: TLS key negotiation failed

carlosgallego · Post by **carlosgallego** » Tue May 21, 2013 3:26 pm

Hello everyone,

I have some trouble whit my vpn configuration.

OpenVPN is installed on CentOS 5.9 (SELinux and iptables disabled)
My CentOS is a virtual server on XENServer (iptables disabled)
My client has not have firewall configurated.

When I try to use my openvpn perfil, provides this error

Code: Select all

Tue May 21 09:21:44 2013 Control Channel MTU parms [ L:1574 D:138 EF:38 EB:0 ET:0 EL:0 ]
Tue May 21 09:21:44 2013 MANAGEMENT: >STATE:1369146104,RESOLVE,,,
Tue May 21 09:21:44 2013 Data Channel MTU parms [ L:1574 D:1450 EF:42 EB:135 ET:32 EL:0 AF:3/1 ]
Tue May 21 09:21:44 2013 Local Options hash (VER=V4): 'd79ca330'
Tue May 21 09:21:44 2013 Expected Remote Options hash (VER=V4): 'f7df56b8'
Tue May 21 09:21:44 2013 Socket Buffers: R=[8192->8192] S=[8192->8192]
Tue May 21 09:21:44 2013 UDPv4 link local: [undef]
Tue May 21 09:21:44 2013 UDPv4 link remote: 190.29.98.60:1194
Tue May 21 09:21:44 2013 MANAGEMENT: >STATE:1369146104,WAIT,,,
Tue May 21 09:21:44 2013 MANAGEMENT: >STATE:1369146104,AUTH,,,
Tue May 21 09:21:44 2013 TLS: Initial packet from SERVERIP:1194, sid=428f2c86 80b79723
Tue May 21 09:21:44 2013 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Tue May 21 09:21:44 2013 VERIFY OK: depth=1, C=CO, ST=ANT, L=MEDELLIN, O=ITCONSULTORES, OU=ITCONSULTORES, CN=vpn.itconsultores.com.co, name=ITCONSULTORES, emailAddress=carlos.gallego@itconsultores.com.co
Tue May 21 09:21:44 2013 VERIFY OK: depth=0, C=CO, ST=ANT, L=MEDELLIN, O=ITCONSULTORES, OU=ITCONSULTORES, CN=vpn.itconsultores.com.co, name=ITCONSULTORES, emailAddress=carlos.gallego@itconsultores.com.co
Tue May 21 09:22:44 2013 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Tue May 21 09:22:44 2013 TLS Error: TLS handshake failed
Tue May 21 09:22:44 2013 TCP/UDP: Closing socket
Tue May 21 09:22:44 2013 SIGTERM[soft,tls-error] received, process exiting
Tue May 21 09:22:44 2013 MANAGEMENT: >STATE:1369146164,EXITING,tls-error,,

This is my server config:

Code: Select all

port 1194
proto udp
dev tap0
reneg-sec 0
ca /etc/openvpn/easy-rsa/2.0/keys/ca.crt
cert /etc/openvpn/easy-rsa/2.0/keys/vpn.itconsultores.com.co.crt
key /etc/openvpn/easy-rsa/2.0/keys/vpn.itconsultores.com.co.key
dh /etc/openvpn/easy-rsa/2.0/keys/dh1024.pem
server 10.8.0.0 255.255.255.0
ifconfig-pool-persist ipp.txt
push "redirect-gateway def1 bypass-dhcp"
keepalive 10 120
comp-lzo
persist-key
persist-tun
status /var/log/openvpn-status.log
log         /var/log/openvpn.log
verb 6

Client Config:

Code: Select all

client
dev tap0
proto udp
remote vpn.itconsultores.com.co 1194
resolv-retry infinite
nobind
tun-mtu 1500
tun-mtu-extra 32
mssfix 1450
persist-key
persist-tun
ca ca.crt
auth-user-pass
comp-lzo
reneg-sec 0
verb 3

I am test whit UDP and TCP but no works.

Anyone can help me whit this?

Regards.

Post by **janjust** » Tue May 21, 2013 3:46 pm

this is almost always a firewall or intermediary router that is blocking access; check the iptables rules on both client and server.

carlosgallego · Post by **carlosgallego** » Tue May 21, 2013 4:00 pm

On the server

Code: Select all

[root@VPNITCON openvpn]# service iptables status
El cortafuegos está detenido.

The client I have made test whit Windows 7 and Windows XP, using OpenvpnGUI and Sophos VPN client,

Both windows does not has firewall installed, and the Windows Firewall is disabled.

The test is over the lan and the wan.

Thanks for your answer.

Carlos.

carlosgallego · Post by **carlosgallego** » Thu May 23, 2013 11:00 pm

I am testing on a different port and whit another protocol.

This is the log.

Code: Select all

Thu May 23 16:36:33 2013 Restart pause, 5 second(s)
Thu May 23 16:36:38 2013 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.
Thu May 23 16:36:38 2013 NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Thu May 23 16:36:38 2013 Re-using SSL/TLS context
Thu May 23 16:36:38 2013 LZO compression initialized
Thu May 23 16:36:38 2013 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu May 23 16:36:38 2013 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu May 23 16:36:38 2013 Local Options hash (VER=V4): '31fdf004'
Thu May 23 16:36:38 2013 Expected Remote Options hash (VER=V4): '3e6d1056'
Thu May 23 16:36:38 2013 Attempting to establish TCP connection with 190.29.98.60:1195
Thu May 23 16:36:38 2013 TCP connection established with 190.29.98.60:1195
Thu May 23 16:36:38 2013 Socket Buffers: R=[8192->8192] S=[8192->8192]
Thu May 23 16:36:38 2013 TCPv4_CLIENT link local: [undef]
Thu May 23 16:36:38 2013 TCPv4_CLIENT link remote: 190.29.98.60:1195
Thu May 23 16:36:38 2013 TLS: Initial packet from 190.29.98.60:1195, sid=67b9bb16 d0f7361e
Thu May 23 16:36:38 2013 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Thu May 23 16:36:38 2013 VERIFY OK: depth=1, C=CO, ST=ANT, L=MEDELLIN, O=ITCONSULTORES, OU=ITCONSULTORES, CN=vpn.itconsultores.com.co, name=ITCONSULTORES, emailAddress=carlos.gallego@itconsultores.com.co
Thu May 23 16:36:38 2013 VERIFY OK: depth=0, C=CO, ST=ANT, L=MEDELLIN, O=ITCONSULTORES, OU=ITCONSULTORES, CN=vpn.itconsultores.com.co, name=ITCONSULTORES, emailAddress=carlos.gallego@itconsultores.com.co
Thu May 23 16:36:38 2013 Connection reset, restarting [0]
Thu May 23 16:36:38 2013 TCP/UDP: Closing socket
Thu May 23 16:36:38 2013 SIGUSR1[soft,connection-reset] received, process restarting
Thu May 23 16:36:38 2013 Restart pause, 5 second(s)
Thu May 23 16:36:43 2013 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.
Thu May 23 16:36:43 2013 NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Thu May 23 16:36:43 2013 Re-using SSL/TLS context
Thu May 23 16:36:43 2013 LZO compression initialized
Thu May 23 16:36:43 2013 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu May 23 16:36:43 2013 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu May 23 16:36:43 2013 Local Options hash (VER=V4): '31fdf004'
Thu May 23 16:36:43 2013 Expected Remote Options hash (VER=V4): '3e6d1056'
Thu May 23 16:36:43 2013 Attempting to establish TCP connection with 190.29.98.60:1195
Thu May 23 16:36:43 2013 TCP/UDP: Closing socket
Thu May 23 16:36:43 2013 SIGTERM[hard,init_instance] received, process exiting

Any idea?

Post by **janjust** » Fri May 24, 2013 1:56 am

it seems the TCP connection is dropped by the remote end - what is shown in the server side log?
or could there be a (government) firewall that is filtering out openvpn traffic?

carlosgallego · Post by **carlosgallego** » Fri May 24, 2013 2:10 am

Thanks for your answer @janjust

Log on the server side.

Code: Select all

Thu May 23 20:02:25 2013 us=929417 MULTI: multi_create_instance called
Thu May 23 20:02:25 2013 us=929490 Re-using SSL/TLS context
Thu May 23 20:02:25 2013 us=929510 LZO compression initialized
Thu May 23 20:02:25 2013 us=929596 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu May 23 20:02:25 2013 us=929619 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu May 23 20:02:25 2013 us=929670 Local Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Thu May 23 20:02:25 2013 us=929684 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Thu May 23 20:02:25 2013 us=929708 Local Options hash (VER=V4): '3e6d1056'
Thu May 23 20:02:25 2013 us=929729 Expected Remote Options hash (VER=V4): '31fdf004'
Thu May 23 20:02:25 2013 us=929759 TCP connection established with 190.29.98.60:18134
Thu May 23 20:02:25 2013 us=929780 TCPv4_SERVER link local: [undef]
Thu May 23 20:02:25 2013 us=929796 TCPv4_SERVER link remote: 190.29.98.60:18134
Thu May 23 20:02:25 2013 us=930730 190.29.98.60:18134 TCPv4_SERVER READ [14] from 190.29.98.60:18134: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Thu May 23 20:02:25 2013 us=930775 190.29.98.60:18134 TLS: Initial packet from 190.29.98.60:18134, sid=38e9543e 75913372
Thu May 23 20:02:25 2013 us=930820 190.29.98.60:18134 TCPv4_SERVER WRITE [26] to 190.29.98.60:18134: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Thu May 23 20:02:25 2013 us=933212 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 0 ]
Thu May 23 20:02:25 2013 us=968658 190.29.98.60:18134 TCPv4_SERVER READ [114] from 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=100
Thu May 23 20:02:25 2013 us=968743 190.29.98.60:18134 TCPv4_SERVER WRITE [22] to 190.29.98.60:18134: P_ACK_V1 kid=0 [ 1 ]
Thu May 23 20:02:25 2013 us=968794 190.29.98.60:18134 TCPv4_SERVER READ [114] from 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Thu May 23 20:02:25 2013 us=968847 190.29.98.60:18134 TCPv4_SERVER WRITE [22] to 190.29.98.60:18134: P_ACK_V1 kid=0 [ 2 ]
Thu May 23 20:02:25 2013 us=968885 190.29.98.60:18134 TCPv4_SERVER READ [24] from 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=10
Thu May 23 20:02:25 2013 us=975212 190.29.98.60:18134 TCPv4_SERVER WRITE [126] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ 3 ] pid=1 DATA len=100
Thu May 23 20:02:25 2013 us=975267 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Thu May 23 20:02:25 2013 us=975312 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Thu May 23 20:02:25 2013 us=975355 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Thu May 23 20:02:26 2013 us=129628 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 1 ]
Thu May 23 20:02:26 2013 us=129706 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Thu May 23 20:02:26 2013 us=131889 190.29.98.60:18134 TCPv4_SERVER READ [30] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 2 3 4 ]
Thu May 23 20:02:26 2013 us=131965 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Thu May 23 20:02:26 2013 us=132025 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Thu May 23 20:02:26 2013 us=132099 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Thu May 23 20:02:26 2013 us=134032 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 5 ]
Thu May 23 20:02:26 2013 us=134112 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=100
Thu May 23 20:02:26 2013 us=136098 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 6 ]
Thu May 23 20:02:26 2013 us=136173 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=100
Thu May 23 20:02:26 2013 us=138360 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 7 ]
Thu May 23 20:02:26 2013 us=138435 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=100
Thu May 23 20:02:26 2013 us=138477 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 8 ]
Thu May 23 20:02:26 2013 us=138526 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=12 DATA len=100
Thu May 23 20:02:26 2013 us=140646 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 9 ]
Thu May 23 20:02:26 2013 us=140725 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=13 DATA len=100
Thu May 23 20:02:26 2013 us=142866 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 10 ]
Thu May 23 20:02:26 2013 us=142940 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=14 DATA len=100
Thu May 23 20:02:26 2013 us=144949 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 11 ]
Thu May 23 20:02:26 2013 us=145028 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=15 DATA len=100
Thu May 23 20:02:26 2013 us=145078 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 12 ]
Thu May 23 20:02:26 2013 us=145120 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=16 DATA len=100
Thu May 23 20:02:26 2013 us=147954 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 13 ]
Thu May 23 20:02:26 2013 us=148027 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=17 DATA len=100
Thu May 23 20:02:26 2013 us=149952 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 14 ]
Thu May 23 20:02:26 2013 us=150030 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=18 DATA len=100
Thu May 23 20:02:26 2013 us=151831 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 15 ]
Thu May 23 20:02:26 2013 us=151905 190.29.98.60:18134 TCPv4_SERVER WRITE [114] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=19 DATA len=100
Thu May 23 20:02:26 2013 us=151947 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 16 ]
Thu May 23 20:02:26 2013 us=151993 190.29.98.60:18134 TCPv4_SERVER WRITE [22] to 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ ] pid=20 DATA len=8
Thu May 23 20:02:26 2013 us=153740 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 17 ]
Thu May 23 20:02:26 2013 us=155581 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 18 ]
Thu May 23 20:02:26 2013 us=191382 190.29.98.60:18134 TCPv4_SERVER READ [22] from 190.29.98.60:18134: P_ACK_V1 kid=0 [ 19 ]
Thu May 23 20:02:26 2013 us=191452 190.29.98.60:18134 TCPv4_SERVER READ [126] from 190.29.98.60:18134: P_CONTROL_V1 kid=0 [ 20 ] pid=4 DATA len=100
Thu May 23 20:02:26 2013 us=191498 190.29.98.60:18134 TLS_ERROR: BIO read tls_read_plaintext error: error:140890C7:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:peer did not return a certificate
Thu May 23 20:02:26 2013 us=191533 190.29.98.60:18134 TLS Error: TLS object -> incoming plaintext read error
Thu May 23 20:02:26 2013 us=191547 190.29.98.60:18134 TLS Error: TLS handshake failed
Thu May 23 20:02:26 2013 us=191617 190.29.98.60:18134 Fatal TLS error (check_tls_errors_co), restarting
Thu May 23 20:02:26 2013 us=191635 190.29.98.60:18134 SIGUSR1[soft,tls-error] received, client-instance restarting
Thu May 23 20:02:26 2013 us=191676 TCP/UDP: Closing socket
Thu May 23 20:02:31 2013 us=203713 MULTI: multi_create_instance called
Thu May 23 20:02:31 2013 us=203749 Re-using SSL/TLS context
Thu May 23 20:02:31 2013 us=203766 LZO compression initialized
Thu May 23 20:02:31 2013 us=203839 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu May 23 20:02:31 2013 us=203862 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu May 23 20:02:31 2013 us=203909 Local Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Thu May 23 20:02:31 2013 us=203922 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Thu May 23 20:02:31 2013 us=203945 Local Options hash (VER=V4): '3e6d1056'
Thu May 23 20:02:31 2013 us=203966 Expected Remote Options hash (VER=V4): '31fdf004'
Thu May 23 20:02:31 2013 us=203993 TCP connection established with 190.29.98.60:18143
Thu May 23 20:02:31 2013 us=204013 TCPv4_SERVER link local: [undef]
Thu May 23 20:02:31 2013 us=204029 TCPv4_SERVER link remote: 190.29.98.60:18143
Thu May 23 20:02:31 2013 us=204492 190.29.98.60:18143 TCPv4_SERVER READ [14] from 190.29.98.60:18143: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Thu May 23 20:02:31 2013 us=204530 190.29.98.60:18143 TLS: Initial packet from 190.29.98.60:18143, sid=1ce9944a baa7396e
Thu May 23 20:02:31 2013 us=204574 190.29.98.60:18143 TCPv4_SERVER WRITE [26] to 190.29.98.60:18143: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Thu May 23 20:02:31 2013 us=209851 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 0 ]
Thu May 23 20:02:31 2013 us=248934 190.29.98.60:18143 TCPv4_SERVER READ [114] from 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=100
Thu May 23 20:02:31 2013 us=249020 190.29.98.60:18143 TCPv4_SERVER WRITE [22] to 190.29.98.60:18143: P_ACK_V1 kid=0 [ 1 ]
Thu May 23 20:02:31 2013 us=249070 190.29.98.60:18143 TCPv4_SERVER READ [114] from 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Thu May 23 20:02:31 2013 us=249123 190.29.98.60:18143 TCPv4_SERVER WRITE [22] to 190.29.98.60:18143: P_ACK_V1 kid=0 [ 2 ]
Thu May 23 20:02:31 2013 us=249160 190.29.98.60:18143 TCPv4_SERVER READ [24] from 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=10
Thu May 23 20:02:31 2013 us=255506 190.29.98.60:18143 TCPv4_SERVER WRITE [126] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ 3 ] pid=1 DATA len=100
Thu May 23 20:02:31 2013 us=255563 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Thu May 23 20:02:31 2013 us=255609 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Thu May 23 20:02:31 2013 us=255652 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Thu May 23 20:02:31 2013 us=437894 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 1 ]
Thu May 23 20:02:31 2013 us=437969 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Thu May 23 20:02:31 2013 us=440120 190.29.98.60:18143 TCPv4_SERVER READ [30] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 2 3 4 ]
Thu May 23 20:02:31 2013 us=440197 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Thu May 23 20:02:31 2013 us=440256 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Thu May 23 20:02:31 2013 us=440322 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Thu May 23 20:02:31 2013 us=442651 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 5 ]
Thu May 23 20:02:31 2013 us=442726 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=100
Thu May 23 20:02:31 2013 us=444615 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 6 ]
Thu May 23 20:02:31 2013 us=444695 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=100
Thu May 23 20:02:31 2013 us=446658 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 7 ]
Thu May 23 20:02:31 2013 us=446733 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=100
Thu May 23 20:02:31 2013 us=446776 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 8 ]
Thu May 23 20:02:31 2013 us=446824 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=12 DATA len=100
Thu May 23 20:02:31 2013 us=448589 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 9 ]
Thu May 23 20:02:31 2013 us=448663 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=13 DATA len=100
Thu May 23 20:02:31 2013 us=450568 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 10 ]
Thu May 23 20:02:31 2013 us=450646 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=14 DATA len=100
Thu May 23 20:02:31 2013 us=452460 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 11 ]
Thu May 23 20:02:31 2013 us=452535 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=15 DATA len=100
Thu May 23 20:02:31 2013 us=452577 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 12 ]
Thu May 23 20:02:31 2013 us=452624 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=16 DATA len=100
Thu May 23 20:02:31 2013 us=454764 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 13 ]
Thu May 23 20:02:31 2013 us=454838 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=17 DATA len=100
Thu May 23 20:02:31 2013 us=456746 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 14 ]
Thu May 23 20:02:31 2013 us=456820 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=18 DATA len=100
Thu May 23 20:02:31 2013 us=458740 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 15 ]
Thu May 23 20:02:31 2013 us=458819 190.29.98.60:18143 TCPv4_SERVER WRITE [114] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=19 DATA len=100
Thu May 23 20:02:31 2013 us=458863 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 16 ]
Thu May 23 20:02:31 2013 us=458904 190.29.98.60:18143 TCPv4_SERVER WRITE [22] to 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ ] pid=20 DATA len=8
Thu May 23 20:02:31 2013 us=460691 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 17 ]
Thu May 23 20:02:31 2013 us=462658 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 18 ]
Thu May 23 20:02:31 2013 us=497172 190.29.98.60:18143 TCPv4_SERVER READ [22] from 190.29.98.60:18143: P_ACK_V1 kid=0 [ 19 ]
Thu May 23 20:02:31 2013 us=497243 190.29.98.60:18143 TCPv4_SERVER READ [126] from 190.29.98.60:18143: P_CONTROL_V1 kid=0 [ 20 ] pid=4 DATA len=100
Thu May 23 20:02:31 2013 us=497289 190.29.98.60:18143 TLS_ERROR: BIO read tls_read_plaintext error: error:140890C7:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:peer did not return a certificate
Thu May 23 20:02:31 2013 us=497323 190.29.98.60:18143 TLS Error: TLS object -> incoming plaintext read error
Thu May 23 20:02:31 2013 us=497336 190.29.98.60:18143 TLS Error: TLS handshake failed
Thu May 23 20:02:31 2013 us=497405 190.29.98.60:18143 Fatal TLS error (check_tls_errors_co), restarting
Thu May 23 20:02:31 2013 us=497424 190.29.98.60:18143 SIGUSR1[soft,tls-error] received, client-instance restarting
Thu May 23 20:02:31 2013 us=497464 TCP/UDP: Closing socket
Thu May 23 20:02:36 2013 us=508185 MULTI: multi_create_instance called
Thu May 23 20:02:36 2013 us=508240 Re-using SSL/TLS context
Thu May 23 20:02:36 2013 us=508259 LZO compression initialized
Thu May 23 20:02:36 2013 us=508331 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu May 23 20:02:36 2013 us=508353 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu May 23 20:02:36 2013 us=508399 Local Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Thu May 23 20:02:36 2013 us=508414 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Thu May 23 20:02:36 2013 us=508436 Local Options hash (VER=V4): '3e6d1056'
Thu May 23 20:02:36 2013 us=508457 Expected Remote Options hash (VER=V4): '31fdf004'
Thu May 23 20:02:36 2013 us=508485 TCP connection established with 190.29.98.60:18144
Thu May 23 20:02:36 2013 us=508505 TCPv4_SERVER link local: [undef]
Thu May 23 20:02:36 2013 us=508520 TCPv4_SERVER link remote: 190.29.98.60:18144
Thu May 23 20:02:36 2013 us=509375 190.29.98.60:18144 TCPv4_SERVER READ [14] from 190.29.98.60:18144: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Thu May 23 20:02:36 2013 us=509418 190.29.98.60:18144 TLS: Initial packet from 190.29.98.60:18144, sid=85b8a75f c2a4463f
Thu May 23 20:02:36 2013 us=509462 190.29.98.60:18144 TCPv4_SERVER WRITE [26] to 190.29.98.60:18144: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Thu May 23 20:02:36 2013 us=512328 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 0 ]
Thu May 23 20:02:36 2013 us=545361 190.29.98.60:18144 TCPv4_SERVER READ [114] from 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=100
Thu May 23 20:02:36 2013 us=545452 190.29.98.60:18144 TCPv4_SERVER WRITE [22] to 190.29.98.60:18144: P_ACK_V1 kid=0 [ 1 ]
Thu May 23 20:02:36 2013 us=545504 190.29.98.60:18144 TCPv4_SERVER READ [114] from 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Thu May 23 20:02:36 2013 us=545557 190.29.98.60:18144 TCPv4_SERVER WRITE [22] to 190.29.98.60:18144: P_ACK_V1 kid=0 [ 2 ]
Thu May 23 20:02:36 2013 us=545595 190.29.98.60:18144 TCPv4_SERVER READ [24] from 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=10
Thu May 23 20:02:36 2013 us=551912 190.29.98.60:18144 TCPv4_SERVER WRITE [126] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ 3 ] pid=1 DATA len=100
Thu May 23 20:02:36 2013 us=551967 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Thu May 23 20:02:36 2013 us=552011 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Thu May 23 20:02:36 2013 us=552055 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Thu May 23 20:02:36 2013 us=745624 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 1 ]
Thu May 23 20:02:36 2013 us=745700 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Thu May 23 20:02:36 2013 us=747732 190.29.98.60:18144 TCPv4_SERVER READ [30] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 2 3 4 ]
Thu May 23 20:02:36 2013 us=747809 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Thu May 23 20:02:36 2013 us=747889 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Thu May 23 20:02:36 2013 us=747935 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Thu May 23 20:02:36 2013 us=749814 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 5 ]
Thu May 23 20:02:36 2013 us=749889 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=100
Thu May 23 20:02:36 2013 us=751759 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 6 ]
Thu May 23 20:02:36 2013 us=751834 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=100
Thu May 23 20:02:36 2013 us=753688 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 7 ]
Thu May 23 20:02:36 2013 us=753763 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=100
Thu May 23 20:02:36 2013 us=753806 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 8 ]
Thu May 23 20:02:36 2013 us=753854 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=12 DATA len=100
Thu May 23 20:02:36 2013 us=755645 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 9 ]
Thu May 23 20:02:36 2013 us=755720 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=13 DATA len=100
Thu May 23 20:02:36 2013 us=757708 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 10 ]
Thu May 23 20:02:36 2013 us=757782 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=14 DATA len=100
Thu May 23 20:02:36 2013 us=759736 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 11 ]
Thu May 23 20:02:36 2013 us=759810 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=15 DATA len=100
Thu May 23 20:02:36 2013 us=759857 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 12 ]
Thu May 23 20:02:36 2013 us=759900 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=16 DATA len=100
Thu May 23 20:02:36 2013 us=762278 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 13 ]
Thu May 23 20:02:36 2013 us=762352 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=17 DATA len=100
Thu May 23 20:02:36 2013 us=764310 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 14 ]
Thu May 23 20:02:36 2013 us=764383 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=18 DATA len=100
Thu May 23 20:02:36 2013 us=766241 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 15 ]
Thu May 23 20:02:36 2013 us=766319 190.29.98.60:18144 TCPv4_SERVER WRITE [114] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=19 DATA len=100
Thu May 23 20:02:36 2013 us=766363 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 16 ]
Thu May 23 20:02:36 2013 us=766404 190.29.98.60:18144 TCPv4_SERVER WRITE [22] to 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ ] pid=20 DATA len=8
Thu May 23 20:02:36 2013 us=768101 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 17 ]
Thu May 23 20:02:36 2013 us=770026 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 18 ]
Thu May 23 20:02:36 2013 us=805354 190.29.98.60:18144 TCPv4_SERVER READ [22] from 190.29.98.60:18144: P_ACK_V1 kid=0 [ 19 ]
Thu May 23 20:02:36 2013 us=805429 190.29.98.60:18144 TCPv4_SERVER READ [126] from 190.29.98.60:18144: P_CONTROL_V1 kid=0 [ 20 ] pid=4 DATA len=100
Thu May 23 20:02:36 2013 us=805476 190.29.98.60:18144 TLS_ERROR: BIO read tls_read_plaintext error: error:140890C7:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:peer did not return a certificate
Thu May 23 20:02:36 2013 us=805510 190.29.98.60:18144 TLS Error: TLS object -> incoming plaintext read error
Thu May 23 20:02:36 2013 us=805524 190.29.98.60:18144 TLS Error: TLS handshake failed
Thu May 23 20:02:36 2013 us=805593 190.29.98.60:18144 Fatal TLS error (check_tls_errors_co), restarting
Thu May 23 20:02:36 2013 us=805611 190.29.98.60:18144 SIGUSR1[soft,tls-error] received, client-instance restarting
Thu May 23 20:02:36 2013 us=805652 TCP/UDP: Closing socket
Thu May 23 20:02:41 2013 us=817146 MULTI: multi_create_instance called
Thu May 23 20:02:41 2013 us=817204 Re-using SSL/TLS context
Thu May 23 20:02:41 2013 us=817222 LZO compression initialized
Thu May 23 20:02:41 2013 us=817298 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu May 23 20:02:41 2013 us=817321 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu May 23 20:02:41 2013 us=817368 Local Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Thu May 23 20:02:41 2013 us=817382 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Thu May 23 20:02:41 2013 us=817405 Local Options hash (VER=V4): '3e6d1056'
Thu May 23 20:02:41 2013 us=817426 Expected Remote Options hash (VER=V4): '31fdf004'
Thu May 23 20:02:41 2013 us=817453 TCP connection established with 190.29.98.60:18148
Thu May 23 20:02:41 2013 us=817474 TCPv4_SERVER link local: [undef]
Thu May 23 20:02:41 2013 us=817490 TCPv4_SERVER link remote: 190.29.98.60:18148
Thu May 23 20:02:41 2013 us=818212 190.29.98.60:18148 TCPv4_SERVER READ [14] from 190.29.98.60:18148: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Thu May 23 20:02:41 2013 us=818255 190.29.98.60:18148 TLS: Initial packet from 190.29.98.60:18148, sid=07a86d15 9154cdba
Thu May 23 20:02:41 2013 us=818300 190.29.98.60:18148 TCPv4_SERVER WRITE [26] to 190.29.98.60:18148: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Thu May 23 20:02:41 2013 us=821159 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 0 ]
Thu May 23 20:02:41 2013 us=861842 190.29.98.60:18148 TCPv4_SERVER READ [114] from 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=100
Thu May 23 20:02:41 2013 us=861928 190.29.98.60:18148 TCPv4_SERVER WRITE [22] to 190.29.98.60:18148: P_ACK_V1 kid=0 [ 1 ]
Thu May 23 20:02:41 2013 us=861978 190.29.98.60:18148 TCPv4_SERVER READ [114] from 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Thu May 23 20:02:41 2013 us=862031 190.29.98.60:18148 TCPv4_SERVER WRITE [22] to 190.29.98.60:18148: P_ACK_V1 kid=0 [ 2 ]
Thu May 23 20:02:41 2013 us=862068 190.29.98.60:18148 TCPv4_SERVER READ [24] from 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=10
Thu May 23 20:02:41 2013 us=868434 190.29.98.60:18148 TCPv4_SERVER WRITE [126] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ 3 ] pid=1 DATA len=100
Thu May 23 20:02:41 2013 us=868493 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Thu May 23 20:02:41 2013 us=868539 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Thu May 23 20:02:41 2013 us=868582 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Thu May 23 20:02:42 2013 us=57743 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 1 ]
Thu May 23 20:02:42 2013 us=57820 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Thu May 23 20:02:42 2013 us=60446 190.29.98.60:18148 TCPv4_SERVER READ [30] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 2 3 4 ]
Thu May 23 20:02:42 2013 us=60523 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Thu May 23 20:02:42 2013 us=60603 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Thu May 23 20:02:42 2013 us=60649 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Thu May 23 20:02:42 2013 us=64891 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 5 ]
Thu May 23 20:02:42 2013 us=64967 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=100
Thu May 23 20:02:42 2013 us=67010 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 6 ]
Thu May 23 20:02:42 2013 us=67085 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=100
Thu May 23 20:02:42 2013 us=69081 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 7 ]
Thu May 23 20:02:42 2013 us=69156 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=100
Thu May 23 20:02:42 2013 us=69205 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 8 ]
Thu May 23 20:02:42 2013 us=69248 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=12 DATA len=100
Thu May 23 20:02:42 2013 us=71032 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 9 ]
Thu May 23 20:02:42 2013 us=71111 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=13 DATA len=100
Thu May 23 20:02:42 2013 us=73095 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 10 ]
Thu May 23 20:02:42 2013 us=73169 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=14 DATA len=100
Thu May 23 20:02:42 2013 us=75165 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 11 ]
Thu May 23 20:02:42 2013 us=75239 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=15 DATA len=100
Thu May 23 20:02:42 2013 us=75282 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 12 ]
Thu May 23 20:02:42 2013 us=75323 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=16 DATA len=100
Thu May 23 20:02:42 2013 us=77252 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 13 ]
Thu May 23 20:02:42 2013 us=77326 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=17 DATA len=100
Thu May 23 20:02:42 2013 us=79522 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 14 ]
Thu May 23 20:02:42 2013 us=79596 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=18 DATA len=100
Thu May 23 20:02:42 2013 us=81666 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 15 ]
Thu May 23 20:02:42 2013 us=81739 190.29.98.60:18148 TCPv4_SERVER WRITE [114] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=19 DATA len=100
Thu May 23 20:02:42 2013 us=81787 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 16 ]
Thu May 23 20:02:42 2013 us=81830 190.29.98.60:18148 TCPv4_SERVER WRITE [22] to 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ ] pid=20 DATA len=8
Thu May 23 20:02:42 2013 us=83832 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 17 ]
Thu May 23 20:02:42 2013 us=85858 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 18 ]
Thu May 23 20:02:42 2013 us=125877 190.29.98.60:18148 TCPv4_SERVER READ [22] from 190.29.98.60:18148: P_ACK_V1 kid=0 [ 19 ]
Thu May 23 20:02:42 2013 us=125952 190.29.98.60:18148 TCPv4_SERVER READ [126] from 190.29.98.60:18148: P_CONTROL_V1 kid=0 [ 20 ] pid=4 DATA len=100
Thu May 23 20:02:42 2013 us=126000 190.29.98.60:18148 TLS_ERROR: BIO read tls_read_plaintext error: error:140890C7:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:peer did not return a certificate
Thu May 23 20:02:42 2013 us=126033 190.29.98.60:18148 TLS Error: TLS object -> incoming plaintext read error
Thu May 23 20:02:42 2013 us=126047 190.29.98.60:18148 TLS Error: TLS handshake failed
Thu May 23 20:02:42 2013 us=126116 190.29.98.60:18148 Fatal TLS error (check_tls_errors_co), restarting
Thu May 23 20:02:42 2013 us=126135 190.29.98.60:18148 SIGUSR1[soft,tls-error] received, client-instance restarting
Thu May 23 20:02:42 2013 us=126176 TCP/UDP: Closing socket

Post by **janjust** » Fri May 24, 2013 11:08 am

This

Thu May 23 20:02:42 2013 us=126000 190.29.98.60:18148 TLS_ERROR: BIO read tls_read_plaintext error: error:140890C7:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:peer did not return a certificate

pretty much says it all... your client config does not include a client certificate ('cert' and 'key' parameters).

carlosgallego · Post by **carlosgallego** » Thu May 30, 2013 4:18 pm

Thanks janjust

The problem is solved, When i created the certs one of them failed by the file keys/index.txt

the file has cleaned and works fine.

Sorry for my english.

Post by **janjust** » Thu May 30, 2013 11:54 pm

Excellent, closing topic.

OpenVPN Support Forum

[SOLVED] TLS Error: TLS key negotiation failed

[SOLVED] TLS Error: TLS key negotiation failed

Re: TLS Error: TLS key negotiation failed

Re: TLS Error: TLS key negotiation failed

Re: TLS Error: TLS key negotiation failed

Re: TLS Error: TLS key negotiation failed

Re: TLS Error: TLS key negotiation failed

Re: TLS Error: TLS key negotiation failed

Re: TLS Error: TLS key negotiation failed

Re: TLS Error: TLS key negotiation failed