Page 1 of 1
TLS Error: TLS key negotiation failed to occur within 60 sec
Posted: Thu Sep 15, 2011 4:57 pm
by trevor
Hi,
I've recently tried installing openvpn on a ubuntu server and ran into a few problems but i seem to have fix most of them myself.
One that i cant seem to fix is:
Code: Select all
Thu Sep 15 17:18:06 2011 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Thu Sep 15 17:18:06 2011 TLS Error: TLS handshake failed
Thu Sep 15 17:18:06 2011 TCP/UDP: Closing socket
Thu Sep 15 17:18:06 2011 SIGUSR1[soft,tls-error] received, process restarting
Thu Sep 15 17:18:06 2011 Restart pause, 2 second(s)
I've read this is something to do with the firewall on the router, is this correct?
I have webmin installed and under "Linux Firewall" I have allowed UDP port 1194. Is there anywhere else i need to set this?
Here is my server.conf:
Code: Select all
port 1194
proto udp
dev tun
ca /etc/openvpn/easy-rsa/keys/ca.crt
cert /etc/openvpn/easy-rsa/keys/server.crt
key /etc/openvpn/easy-rsa/keys/server.key
dh dh1024.pem
server 10.8.0.0 255.255.255.0
ifconfig-pool-persist ipp.txt
push "redirect-gateway def1 bypass-dhcp"
push "dhcp-option DNS 208.67.222.222"
push "dhcp-option DNS 208.67.220.220"
keepalive 10 120
tls-auth ta.key 0
comp-lzo
persist-key
persist-tun
status openvpn-status.log
verb 3
Here is my server.opvn:
Code: Select all
client
dev tun
proto udp
remote 188.72.215.167 1194
resolv-retry infinite
nobind
persist-key
persist-tun
ca ca.crt
cert server.crt
key server.key
tls-auth ta.key 1
comp-lzo
verb 3
Here is my client.log:
Code: Select all
Thu Sep 15 17:17:06 2011 OpenVPN 2.0.9 Win32-MinGW [SSL] [LZO] built on Oct 1 2006
Thu Sep 15 17:17:06 2011 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.
Thu Sep 15 17:17:06 2011 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
Thu Sep 15 17:17:06 2011 Control Channel Authentication: using 'ta.key' as a OpenVPN static key file
Thu Sep 15 17:17:06 2011 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Thu Sep 15 17:17:06 2011 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Thu Sep 15 17:17:06 2011 LZO compression initialized
Thu Sep 15 17:17:06 2011 Control Channel MTU parms [ L:1542 D:166 EF:66 EB:0 ET:0 EL:0 ]
Thu Sep 15 17:17:06 2011 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Thu Sep 15 17:17:06 2011 Local Options hash (VER=V4): '504e774e'
Thu Sep 15 17:17:06 2011 Expected Remote Options hash (VER=V4): '14168603'
Thu Sep 15 17:17:06 2011 UDPv4 link local: [undef]
Thu Sep 15 17:17:06 2011 UDPv4 link remote: 188.72.215.167:1194
Thu Sep 15 17:18:06 2011 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Thu Sep 15 17:18:06 2011 TLS Error: TLS handshake failed
Thu Sep 15 17:18:06 2011 TCP/UDP: Closing socket
Thu Sep 15 17:18:06 2011 SIGUSR1[soft,tls-error] received, process restarting
Thu Sep 15 17:18:06 2011 Restart pause, 2 second(s)
Thu Sep 15 17:18:08 2011 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.
Thu Sep 15 17:18:08 2011 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
Thu Sep 15 17:18:08 2011 Re-using SSL/TLS context
Thu Sep 15 17:18:08 2011 LZO compression initialized
Thu Sep 15 17:18:08 2011 Control Channel MTU parms [ L:1542 D:166 EF:66 EB:0 ET:0 EL:0 ]
Thu Sep 15 17:18:08 2011 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Thu Sep 15 17:18:08 2011 Local Options hash (VER=V4): '504e774e'
Thu Sep 15 17:18:08 2011 Expected Remote Options hash (VER=V4): '14168603'
Thu Sep 15 17:18:08 2011 UDPv4 link local: [undef]
Thu Sep 15 17:18:08 2011 UDPv4 link remote: 188.72.215.167:1194
Thu Sep 15 17:18:25 2011 TCP/UDP: Closing socket
Thu Sep 15 17:18:25 2011 SIGTERM[hard,] received, process exiting
Im using Windows 7 with the OpenVPN GUI to connect.
Can anyone shed some light on my problem?
Thanks
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Thu Sep 15, 2011 9:12 pm
by janjust
it's most likely a firewall problem , either on the router or on the windows 7 pc itself.
but more importantly, upgrade to openvpn 2.2.1, as 2.0.9 is not supported (read : does NOT work) on windows 7.
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Thu Sep 15, 2011 9:35 pm
by trevor
Ok, i thought i had the newest version, obviously not. I've upgraded that now.
Can you help me check that the port is open on my server firewall? As far as im aware i have opened it. I am fairly new to linux, i only know the bare essentials!
Thanks
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Thu Sep 15, 2011 9:54 pm
by janjust
the log file snippet that you showed, was that from the client side or the server side? what does the other report?
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Thu Sep 15, 2011 10:03 pm
by trevor
The snippet at the top was from the client log. Its just an extract of the log i posted at the bottom.
Is the server log openvpn-status.log? If so, i got in there is:
Code: Select all
OpenVPN CLIENT LIST
Updated,Thu Sep 15 22:02:43 2011
Common Name,Real Address,Bytes Received,Bytes Sent,Connected Since
ROUTING TABLE
Virtual Address,Common Name,Real Address,Last Ref
GLOBAL STATS
Max bcast/mcast queue length,0
END
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Thu Sep 15, 2011 10:17 pm
by janjust
add the lines
Code: Select all
verb 4
log-append /var/log/openvpn.log
to the server config, restart the server and then look at what's in the file /var/log/openvpn.log - it might give you (or us) a clue.
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Thu Sep 15, 2011 10:28 pm
by trevor
Thanks very much.
Here is the server log:
Code: Select all
Thu Sep 15 22:20:32 2011 us=418716 Current Parameter Settings:
Thu Sep 15 22:20:32 2011 us=418921 config = '/etc/openvpn/server.conf'
Thu Sep 15 22:20:32 2011 us=418936 mode = 1
Thu Sep 15 22:20:32 2011 us=418949 persist_config = DISABLED
Thu Sep 15 22:20:32 2011 us=418961 persist_mode = 1
Thu Sep 15 22:20:32 2011 us=418973 show_ciphers = DISABLED
Thu Sep 15 22:20:32 2011 us=418985 show_digests = DISABLED
Thu Sep 15 22:20:32 2011 us=418997 show_engines = DISABLED
Thu Sep 15 22:20:32 2011 us=419008 genkey = DISABLED
Thu Sep 15 22:20:32 2011 us=419020 key_pass_file = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419032 show_tls_ciphers = DISABLED
Thu Sep 15 22:20:32 2011 us=419044 Connection profiles [default]:
Thu Sep 15 22:20:32 2011 us=419057 proto = udp
Thu Sep 15 22:20:32 2011 us=419069 local = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419081 local_port = 1193
Thu Sep 15 22:20:32 2011 us=419093 remote = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419105 remote_port = 1193
Thu Sep 15 22:20:32 2011 us=419194 remote_float = DISABLED
Thu Sep 15 22:20:32 2011 us=419206 bind_defined = DISABLED
Thu Sep 15 22:20:32 2011 us=419217 bind_local = ENABLED
Thu Sep 15 22:20:32 2011 us=419229 connect_retry_seconds = 5
Thu Sep 15 22:20:32 2011 us=419241 connect_timeout = 10
Thu Sep 15 22:20:32 2011 us=419253 connect_retry_max = 0
Thu Sep 15 22:20:32 2011 us=419265 socks_proxy_server = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419277 socks_proxy_port = 0
Thu Sep 15 22:20:32 2011 us=419288 socks_proxy_retry = DISABLED
Thu Sep 15 22:20:32 2011 us=419305 Connection profiles END
Thu Sep 15 22:20:32 2011 us=419317 remote_random = DISABLED
Thu Sep 15 22:20:32 2011 us=419329 ipchange = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419340 dev = 'tun'
Thu Sep 15 22:20:32 2011 us=419352 dev_type = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419364 dev_node = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419376 lladdr = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419387 topology = 1
Thu Sep 15 22:20:32 2011 us=419463 tun_ipv6 = DISABLED
Thu Sep 15 22:20:32 2011 us=419477 ifconfig_local = '10.8.0.1'
Thu Sep 15 22:20:32 2011 us=419489 ifconfig_remote_netmask = '10.8.0.2'
Thu Sep 15 22:20:32 2011 us=419500 ifconfig_noexec = DISABLED
Thu Sep 15 22:20:32 2011 us=419512 ifconfig_nowarn = DISABLED
Thu Sep 15 22:20:32 2011 us=419524 shaper = 0
Thu Sep 15 22:20:32 2011 us=419535 tun_mtu = 1500
Thu Sep 15 22:20:32 2011 us=419547 tun_mtu_defined = ENABLED
Thu Sep 15 22:20:32 2011 us=419559 link_mtu = 1500
Thu Sep 15 22:20:32 2011 us=419571 link_mtu_defined = DISABLED
Thu Sep 15 22:20:32 2011 us=419583 tun_mtu_extra = 0
Thu Sep 15 22:20:32 2011 us=419595 tun_mtu_extra_defined = DISABLED
Thu Sep 15 22:20:32 2011 us=419606 fragment = 0
Thu Sep 15 22:20:32 2011 us=419618 mtu_discover_type = -1
Thu Sep 15 22:20:32 2011 us=419630 mtu_test = 0
Thu Sep 15 22:20:32 2011 us=419642 mlock = DISABLED
Thu Sep 15 22:20:32 2011 us=419654 keepalive_ping = 10
Thu Sep 15 22:20:32 2011 us=419666 keepalive_timeout = 120
Thu Sep 15 22:20:32 2011 us=419678 inactivity_timeout = 0
Thu Sep 15 22:20:32 2011 us=419692 ping_send_timeout = 10
Thu Sep 15 22:20:32 2011 us=419704 ping_rec_timeout = 240
Thu Sep 15 22:20:32 2011 us=419716 ping_rec_timeout_action = 2
Thu Sep 15 22:20:32 2011 us=419728 ping_timer_remote = DISABLED
Thu Sep 15 22:20:32 2011 us=419740 remap_sigusr1 = 0
Thu Sep 15 22:20:32 2011 us=419752 explicit_exit_notification = 0
Thu Sep 15 22:20:32 2011 us=419764 persist_tun = ENABLED
Thu Sep 15 22:20:32 2011 us=419775 persist_local_ip = DISABLED
Thu Sep 15 22:20:32 2011 us=419787 persist_remote_ip = DISABLED
Thu Sep 15 22:20:32 2011 us=419799 persist_key = ENABLED
Thu Sep 15 22:20:32 2011 us=419811 mssfix = 1450
Thu Sep 15 22:20:32 2011 us=419822 passtos = DISABLED
Thu Sep 15 22:20:32 2011 us=419834 resolve_retry_seconds = 1000000000
Thu Sep 15 22:20:32 2011 us=419850 username = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419863 groupname = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419875 chroot_dir = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419898 cd_dir = '/etc/openvpn'
Thu Sep 15 22:20:32 2011 us=419911 writepid = '/var/run/openvpn.server.pid'
Thu Sep 15 22:20:32 2011 us=419923 up_script = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=419934 down_script = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420035 down_pre = DISABLED
Thu Sep 15 22:20:32 2011 us=420048 up_restart = DISABLED
Thu Sep 15 22:20:32 2011 us=420060 up_delay = DISABLED
Thu Sep 15 22:20:32 2011 us=420072 daemon = ENABLED
Thu Sep 15 22:20:32 2011 us=420084 inetd = 0
Thu Sep 15 22:20:32 2011 us=420095 log = ENABLED
Thu Sep 15 22:20:32 2011 us=420107 suppress_timestamps = DISABLED
Thu Sep 15 22:20:32 2011 us=420119 nice = 0
Thu Sep 15 22:20:32 2011 us=420131 verbosity = 4
Thu Sep 15 22:20:32 2011 us=420143 mute = 0
Thu Sep 15 22:20:32 2011 us=420155 gremlin = 0
Thu Sep 15 22:20:32 2011 us=420166 status_file = 'openvpn-status.log'
Thu Sep 15 22:20:32 2011 us=420178 status_file_version = 1
Thu Sep 15 22:20:32 2011 us=420190 status_file_update_freq = 60
Thu Sep 15 22:20:32 2011 us=420202 occ = ENABLED
Thu Sep 15 22:20:32 2011 us=420214 rcvbuf = 65536
Thu Sep 15 22:20:32 2011 us=420226 sndbuf = 65536
Thu Sep 15 22:20:32 2011 us=420237 sockflags = 0
Thu Sep 15 22:20:32 2011 us=420249 fast_io = DISABLED
Thu Sep 15 22:20:32 2011 us=420261 lzo = 7
Thu Sep 15 22:20:32 2011 us=420272 route_script = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420284 route_default_gateway = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420300 route_default_metric = 0
Thu Sep 15 22:20:32 2011 us=420312 route_noexec = DISABLED
Thu Sep 15 22:20:32 2011 us=420324 route_delay = 0
Thu Sep 15 22:20:32 2011 us=420336 route_delay_window = 30
Thu Sep 15 22:20:32 2011 us=420347 route_delay_defined = DISABLED
Thu Sep 15 22:20:32 2011 us=420360 route_nopull = DISABLED
Thu Sep 15 22:20:32 2011 us=420371 route_gateway_via_dhcp = DISABLED
Thu Sep 15 22:20:32 2011 us=420383 max_routes = 100
Thu Sep 15 22:20:32 2011 us=420395 allow_pull_fqdn = DISABLED
Thu Sep 15 22:20:32 2011 us=420408 route 10.8.0.0/255.255.255.0/nil/nil
Thu Sep 15 22:20:32 2011 us=420421 management_addr = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420433 management_port = 0
Thu Sep 15 22:20:32 2011 us=420445 management_user_pass = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420457 management_log_history_cache = 250
Thu Sep 15 22:20:32 2011 us=420468 management_echo_buffer_size = 100
Thu Sep 15 22:20:32 2011 us=420481 management_write_peer_info_file = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420493 management_client_user = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420505 management_client_group = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420516 management_flags = 0
Thu Sep 15 22:20:32 2011 us=420528 shared_secret_file = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420540 key_direction = 1
Thu Sep 15 22:20:32 2011 us=420552 ciphername_defined = ENABLED
Thu Sep 15 22:20:32 2011 us=420564 ciphername = 'BF-CBC'
Thu Sep 15 22:20:32 2011 us=420576 authname_defined = ENABLED
Thu Sep 15 22:20:32 2011 us=420588 authname = 'SHA1'
Thu Sep 15 22:20:32 2011 us=420600 prng_hash = 'SHA1'
Thu Sep 15 22:20:32 2011 us=420612 prng_nonce_secret_len = 16
Thu Sep 15 22:20:32 2011 us=420623 keysize = 0
Thu Sep 15 22:20:32 2011 us=420635 engine = DISABLED
Thu Sep 15 22:20:32 2011 us=420647 replay = ENABLED
Thu Sep 15 22:20:32 2011 us=420659 mute_replay_warnings = DISABLED
Thu Sep 15 22:20:32 2011 us=420671 replay_window = 64
Thu Sep 15 22:20:32 2011 us=420683 replay_time = 15
Thu Sep 15 22:20:32 2011 us=420695 packet_id_file = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420707 use_iv = ENABLED
Thu Sep 15 22:20:32 2011 us=420719 test_crypto = DISABLED
Thu Sep 15 22:20:32 2011 us=420730 tls_server = ENABLED
Thu Sep 15 22:20:32 2011 us=420742 tls_client = DISABLED
Thu Sep 15 22:20:32 2011 us=420754 key_method = 2
Thu Sep 15 22:20:32 2011 us=420766 ca_file = '/etc/openvpn/easy-rsa/keys/ca.crt'
Thu Sep 15 22:20:32 2011 us=420778 ca_path = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420789 dh_file = 'dh1024.pem'
Thu Sep 15 22:20:32 2011 us=420812 cert_file = '/etc/openvpn/easy-rsa/keys/server.crt'
Thu Sep 15 22:20:32 2011 us=420824 priv_key_file = '/etc/openvpn/easy-rsa/keys/server.key'
Thu Sep 15 22:20:32 2011 us=420837 pkcs12_file = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420853 cipher_list = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420866 tls_verify = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420878 tls_remote = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420889 crl_file = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=420901 ns_cert_type = 0
Thu Sep 15 22:20:32 2011 us=420913 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=420925 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=420937 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=420949 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=420961 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421057 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421070 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421082 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421093 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421105 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421117 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421129 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421141 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421153 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421165 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421177 remote_cert_ku[i] = 0
Thu Sep 15 22:20:32 2011 us=421189 remote_cert_eku = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=421200 tls_timeout = 2
Thu Sep 15 22:20:32 2011 us=421212 renegotiate_bytes = 0
Thu Sep 15 22:20:32 2011 us=421224 renegotiate_packets = 0
Thu Sep 15 22:20:32 2011 us=421236 renegotiate_seconds = 3600
Thu Sep 15 22:20:32 2011 us=421248 handshake_window = 60
Thu Sep 15 22:20:32 2011 us=421260 transition_window = 3600
Thu Sep 15 22:20:32 2011 us=421271 single_session = DISABLED
Thu Sep 15 22:20:32 2011 us=421283 tls_exit = DISABLED
Thu Sep 15 22:20:32 2011 us=421297 tls_auth_file = 'ta.key'
Thu Sep 15 22:20:32 2011 us=421309 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421322 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421334 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421346 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421358 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421369 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421381 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421393 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421405 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421417 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421429 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421441 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421453 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421465 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421477 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421489 pkcs11_protected_authentication = DISABLED
Thu Sep 15 22:20:32 2011 us=421502 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421514 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421526 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421538 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421550 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421562 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421575 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421587 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421599 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421611 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421623 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421646 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421659 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421671 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421684 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421696 pkcs11_private_mode = 00000000
Thu Sep 15 22:20:32 2011 us=421708 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421720 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421732 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421744 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421756 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421768 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421779 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421791 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421803 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421881 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421894 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421906 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421918 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421930 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421942 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421953 pkcs11_cert_private = DISABLED
Thu Sep 15 22:20:32 2011 us=421965 pkcs11_pin_cache_period = -1
Thu Sep 15 22:20:32 2011 us=421977 pkcs11_id = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=421989 pkcs11_id_management = DISABLED
Thu Sep 15 22:20:32 2011 us=422007 server_network = 10.8.0.0
Thu Sep 15 22:20:32 2011 us=422021 server_netmask = 255.255.255.0
Thu Sep 15 22:20:32 2011 us=422034 server_bridge_ip = 0.0.0.0
Thu Sep 15 22:20:32 2011 us=422047 server_bridge_netmask = 0.0.0.0
Thu Sep 15 22:20:32 2011 us=422060 server_bridge_pool_start = 0.0.0.0
Thu Sep 15 22:20:32 2011 us=422073 server_bridge_pool_end = 0.0.0.0
Thu Sep 15 22:20:32 2011 us=422085 push_entry = 'redirect-gateway def1 bypass-dhcp'
Thu Sep 15 22:20:32 2011 us=422097 push_entry = 'dhcp-option DNS 208.67.222.222'
Thu Sep 15 22:20:32 2011 us=422109 push_entry = 'dhcp-option DNS 208.67.220.220'
Thu Sep 15 22:20:32 2011 us=422121 push_entry = 'route 10.8.0.1'
Thu Sep 15 22:20:32 2011 us=422133 push_entry = 'topology net30'
Thu Sep 15 22:20:32 2011 us=422145 push_entry = 'ping 10'
Thu Sep 15 22:20:32 2011 us=422157 push_entry = 'ping-restart 120'
Thu Sep 15 22:20:32 2011 us=422169 ifconfig_pool_defined = ENABLED
Thu Sep 15 22:20:32 2011 us=422182 ifconfig_pool_start = 10.8.0.4
Thu Sep 15 22:20:32 2011 us=422195 ifconfig_pool_end = 10.8.0.251
Thu Sep 15 22:20:32 2011 us=422208 ifconfig_pool_netmask = 0.0.0.0
Thu Sep 15 22:20:32 2011 us=422220 ifconfig_pool_persist_filename = 'ipp.txt'
Thu Sep 15 22:20:32 2011 us=422232 ifconfig_pool_persist_refresh_freq = 600
Thu Sep 15 22:20:32 2011 us=422244 n_bcast_buf = 256
Thu Sep 15 22:20:32 2011 us=422256 tcp_queue_limit = 64
Thu Sep 15 22:20:32 2011 us=422268 real_hash_size = 256
Thu Sep 15 22:20:32 2011 us=422279 virtual_hash_size = 256
Thu Sep 15 22:20:32 2011 us=422296 client_connect_script = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=422308 learn_address_script = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=422320 client_disconnect_script = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=422332 client_config_dir = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=422344 ccd_exclusive = DISABLED
Thu Sep 15 22:20:32 2011 us=422356 tmp_dir = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=422367 push_ifconfig_defined = DISABLED
Thu Sep 15 22:20:32 2011 us=422380 push_ifconfig_local = 0.0.0.0
Thu Sep 15 22:20:32 2011 us=422393 push_ifconfig_remote_netmask = 0.0.0.0
Thu Sep 15 22:20:32 2011 us=422405 enable_c2c = DISABLED
Thu Sep 15 22:20:32 2011 us=422417 duplicate_cn = DISABLED
Thu Sep 15 22:20:32 2011 us=422429 cf_max = 0
Thu Sep 15 22:20:32 2011 us=422441 cf_per = 0
Thu Sep 15 22:20:32 2011 us=422452 max_clients = 1024
Thu Sep 15 22:20:32 2011 us=422475 max_routes_per_client = 256
Thu Sep 15 22:20:32 2011 us=422559 auth_user_pass_verify_script = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=422572 auth_user_pass_verify_script_via_file = DISABLED
Thu Sep 15 22:20:32 2011 us=422584 ssl_flags = 0
Thu Sep 15 22:20:32 2011 us=422596 port_share_host = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=422608 port_share_port = 0
Thu Sep 15 22:20:32 2011 us=422620 client = DISABLED
Thu Sep 15 22:20:32 2011 us=422632 pull = DISABLED
Thu Sep 15 22:20:32 2011 us=422644 auth_user_pass_file = '[UNDEF]'
Thu Sep 15 22:20:32 2011 us=422659 OpenVPN 2.1.0 i486-pc-linux-gnu [SSL] [LZO2] [EPOLL] [PKCS11] [MH] [PF_INET6] [eurephia] $
Thu Sep 15 22:20:32 2011 us=422822 NOTE: the current --script-security setting may allow this configuration to call user-def$
Thu Sep 15 22:20:32 2011 us=429719 Diffie-Hellman initialized with 1024 bit key
Thu Sep 15 22:20:32 2011 us=430325 /usr/bin/openssl-vulnkey -q -b 1024 -m <modulus omitted>
Thu Sep 15 22:20:32 2011 us=549441 Control Channel Authentication: using 'ta.key' as a OpenVPN static key file
Thu Sep 15 22:20:32 2011 us=549510 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authe$
Thu Sep 15 22:20:32 2011 us=549527 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authe$
Thu Sep 15 22:20:32 2011 us=549563 TLS-Auth MTU parms [ L:1542 D:166 EF:66 EB:0 ET:0 EL:0 ]
Thu Sep 15 22:20:32 2011 us=549768 ROUTE default_gateway=192.0.2.1
Thu Sep 15 22:20:32 2011 us=550039 TUN/TAP device tun0 opened
Thu Sep 15 22:20:32 2011 us=550070 TUN/TAP TX queue length set to 100
Thu Sep 15 22:20:32 2011 us=550109 /sbin/ifconfig tun0 10.8.0.1 pointopoint 10.8.0.2 mtu 1500
Thu Sep 15 22:20:32 2011 us=584957 /sbin/route add -net 10.8.0.0 netmask 255.255.255.0 gw 10.8.0.2
Thu Sep 15 22:20:32 2011 us=585992 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Thu Sep 15 22:20:32 2011 us=586522 Socket Buffers: R=[786426->131072] S=[8388608->131072]
Thu Sep 15 22:20:32 2011 us=586606 UDPv4 link local (bound): [undef]
Thu Sep 15 22:20:32 2011 us=586622 UDPv4 link remote: [undef]
Thu Sep 15 22:20:32 2011 us=586650 MULTI: multi_init called, r=256 v=256
Thu Sep 15 22:20:32 2011 us=586781 IFCONFIG POOL: base=10.8.0.4 size=62
Thu Sep 15 22:20:32 2011 us=586808 IFCONFIG POOL LIST
Thu Sep 15 22:20:32 2011 us=586863 Initialization Sequence Completed
Thu Sep 15 22:20:55 2011 us=788781 event_wait : Interrupted system call (code=4)
Thu Sep 15 22:20:55 2011 us=789000 TCP/UDP: Closing socket
Thu Sep 15 22:20:55 2011 us=789045 /sbin/route del -net 10.8.0.0 netmask 255.255.255.0
Thu Sep 15 22:20:55 2011 us=789742 Closing TUN/TAP interface
Thu Sep 15 22:20:55 2011 us=789770 /sbin/ifconfig tun0 0.0.0.0
Thu Sep 15 22:20:55 2011 us=866889 SIGTERM[hard,] received, process exiting
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Fri Sep 16, 2011 4:34 am
by ecrist
Your client is still only 2.1.0. The current version is 2.2.1. Upgrade then we will help.
Sent from my HTC Glacier using Tapatalk
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Fri Sep 16, 2011 7:48 am
by janjust
the VPN server is not showing any incoming traffic.
check the iptables settings on the vpn server:
and verify that inbound UDP port 1194 is allowed.
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Fri Sep 16, 2011 10:49 am
by trevor
Ecrist - I have downloaded and installed openvpn-2.2.1-install.exe. I did so when janjust first told me i didnt have the latest version.
Janjust - This is the output from that command:
Code: Select all
Chain INPUT (policy ACCEPT 33611 packets, 3689K bytes)
pkts bytes target prot opt in out source destination
14 980 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:1194
8 560 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:1193
I have tried using both 1193 and 1194. Should the source and destination be set? Is that my problem?
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Fri Sep 16, 2011 11:12 am
by janjust
port 1194 seems to be open on your server (I just did an 'nmap' scan).
What does
return? is there a rule blocking outbound traffic?
Is the windows client allowed to make a connection to the server? can the windows client actually reach (ping) the server?
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Fri Sep 16, 2011 11:25 am
by trevor
The output from that command is:
Code: Select all
Chain INPUT (policy ACCEPT 33934 packets, 3729K bytes)
pkts bytes target prot opt in out source destination
18 1092 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:1194
9 588 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:1193
Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
pkts bytes target prot opt in out source destination
Chain OUTPUT (policy ACCEPT 48020 packets, 37M bytes)
pkts bytes target prot opt in out source destination
I can ping the server from windows and connect to it using SSH. HTTP also works on it.
Is it worth getting my host to check that the port is open properly? They allow VPN so it shouldnt be anything VPN specific thats blocked.
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Fri Sep 16, 2011 11:29 am
by janjust
the firewall looks in order; the server log showed
Thu Sep 15 22:20:32 2011 us=586863 Initialization Sequence Completed
Thu Sep 15 22:20:55 2011 us=788781 event_wait : Interrupted system call (code=4)
this means that 23 seconds after the system came up it was shut down - was that you hitting ctrl-c ? is openvpn actually still running? can you do a
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Fri Sep 16, 2011 11:35 am
by trevor
Nope, i never hit ctrl + c.
Code: Select all
1 S root 22440 1 0 78 0 - 1067 stext Sep15 ? 00:00:00 /usr/sbin/openvpn --writepid /var/run/openvpn.server.pid --daemon ovpn-server --cd /etc/openvpn --config /etc/openvpn/server.conf --script-security 2
0 S spire 32686 17571 0 75 0 - 813 pipe_w 11:33 pts/2 00:00:00 grep --color=auto openvpn
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Fri Sep 16, 2011 12:11 pm
by janjust
do a
then restart the server with the new config file and try to connect the client again.
Re: TLS Error: TLS key negotiation failed to occur within 60
Posted: Fri Sep 16, 2011 12:27 pm
by trevor
Still getting the same error.
Very strange!