TLS Error: TLS key negotiation failed to occur within 60 sec

trevor · Post by **trevor** » Thu Sep 15, 2011 4:57 pm

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

Post by **janjust** » Thu Sep 15, 2011 9:12 pm

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.

trevor · Post by **trevor** » Thu Sep 15, 2011 9:35 pm

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

Post by **janjust** » Thu Sep 15, 2011 9:54 pm

the log file snippet that you showed, was that from the client side or the server side? what does the other report?

trevor · Post by **trevor** » Thu Sep 15, 2011 10:03 pm

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

Post by **janjust** » Thu Sep 15, 2011 10:17 pm

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.

trevor · Post by **trevor** » Thu Sep 15, 2011 10:28 pm

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

Post by **ecrist** » Fri Sep 16, 2011 4:34 am

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

Post by **janjust** » Fri Sep 16, 2011 7:48 am

the VPN server is not showing any incoming traffic.
check the iptables settings on the vpn server:

Code: Select all

  iptables -L INPUT -n -v

and verify that inbound UDP port 1194 is allowed.

trevor · Post by **trevor** » Fri Sep 16, 2011 10:49 am

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?

Post by **janjust** » Fri Sep 16, 2011 11:12 am

port 1194 seems to be open on your server (I just did an 'nmap' scan).
What does

Code: Select all

iptables -L -n -v

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?

trevor · Post by **trevor** » Fri Sep 16, 2011 11:25 am

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.

Post by **janjust** » Fri Sep 16, 2011 11:29 am

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

Code: Select all

ps -elf | grep openvpn

trevor · Post by **trevor** » Fri Sep 16, 2011 11:35 am

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

Post by **janjust** » Fri Sep 16, 2011 12:11 pm

do a

Code: Select all

killall openvpn

then restart the server with the new config file and try to connect the client again.

trevor · Post by **trevor** » Fri Sep 16, 2011 12:27 pm

Still getting the same error.
Very strange!

OpenVPN Support Forum

TLS Error: TLS key negotiation failed to occur within 60 sec

TLS Error: TLS key negotiation failed to occur within 60 sec

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60

Re: TLS Error: TLS key negotiation failed to occur within 60