[solved] connection works only after service -stop -start

scallywag · Post by **scallywag** » Tue Jun 07, 2011 2:52 am

Hello Forum,

my new installation on debian only works after i use:

- "service openvpn stop"

- connect with the client and wait for error: connection reset by peer

- "service openvpn start"

then the client connects. otherwise there is the "TLS negotiation error" and the client can't connect.

A connection via lan works fine. This problem just happen over wan. After the connection is established, i can ping the server and everything works fine. Is this strange behavior? What do you think is the cause for it? Many thanks!
S

server-syslog after connecting

Code: Select all

Jun  7 04:35:58 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1183 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1183: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Jun  7 04:35:59 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1183 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.xxx:1183: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Jun  7 04:36:25 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1183 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jun  7 04:36:25 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1183 TLS Error: TLS handshake failed
Jun  7 04:36:25 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1183 SIGUSR1[soft,tls-error] received, client-instance restarting
Jun  7 04:36:27 ecivresit ovpn-server[1187]: MULTI: multi_create_instance called
Jun  7 04:36:27 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1184 Re-using SSL/TLS context
Jun  7 04:36:27 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1184 LZO compression initialized
Jun  7 04:36:27 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1184 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Jun  7 04:36:27 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1184 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Jun  7 04:36:27 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1184 Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Jun  7 04:36:27 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1184 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Jun  7 04:36:27 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1184 Local Options hash (VER=V4): '530fdded'
Jun  7 04:36:27 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1184 Expected Remote Options hash (VER=V4): '41690919'
Jun  7 04:36:27 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1184 UDPv4 READ [14] from [AF_INET]xxx.xxx.xxx.xxx:1184: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Jun  7 04:36:27 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1184 TLS: Initial packet from [AF_INET]xxx.xxx.xxx.xxx:1184, sid=9ba9a2b4 e354e68a
Jun  7 04:36:27 ecivresit ovpn-server[1187]: xxx.xxx.xxx.xxx:1184 UDPv4 WRITE [26] to [AF_INET]xxx.xxx.xxx.xxx:1184: P_CONTROL_HARD_RESET_SERVER_V2 kid=0

client.ovpn

Code: Select all

client
dev tun
proto udp
remote xxx.dyndns.com 1194
ifconfig 10.8.0.2 10.8.0.1
resolv-retry infinite
nobind
persist-key
persist-tun
ca ca.crt
cert ersterclient.crt
key ersterclient.key
ns-cert-type server
comp-lzo
verb 3
redirect-gateway def1
float

server.conf

Code: Select all

port 1194
proto udp
dev tun
ca /etc/openvpn/keys/ca.crt
cert /etc/openvpn/keys/server.crt
key /etc/openvpn/keys/server.key
dh /etc/openvpn/keys/dh1024.pem
server 10.8.0.0 255.255.255.0
tls-server
ifconfig-pool-persist ipp.txt
push "route 10.8.0.0 255.255.255.0"
ifconfig 10.8.0.1 10.8.0.2
client-to-client
keepalive 10 120
comp-lzo
max-clients 3
user openvpn
group openvpn
persist-key
persist-tun
status openvpn-status.log
verb 6

Post by **janjust** » Tue Jun 07, 2011 8:28 am

remove the line

ifconfig 10.8.0.2 10.8.0.1

from the client config and the line

ifconfig 10.8.0.1 10.8.0.2

from the server config; after the server restarts it will be assigned the IP 10.8.0.1 ; the first client will be assigned 10.8.0.6.

scallywag · Post by **scallywag** » Tue Jun 07, 2011 9:30 am

thanks for your answer janjust,
but the exact problem still exist.

Post by **janjust** » Tue Jun 07, 2011 10:12 am

please reconnect the client (with 'verb 5' in the client config) and post the sanitized client log file. that should shed some light on what is failing...

scallywag · Post by **scallywag** » Tue Jun 07, 2011 10:34 am

the entire log
"read UDPv4: Connection reset by peer (WSAECONNRESET) (code=10054)" means that i stop openvpn on server.

Code: Select all

Tue Jun 07 12:16:03 2011 us=919524 Current Parameter Settings:
Tue Jun 07 12:16:03 2011 us=919676   config = 'client.ovpn'
Tue Jun 07 12:16:03 2011 us=919707   mode = 0
Tue Jun 07 12:16:03 2011 us=919747   show_ciphers = DISABLED
Tue Jun 07 12:16:03 2011 us=919775   show_digests = DISABLED
Tue Jun 07 12:16:03 2011 us=919802   show_engines = DISABLED
Tue Jun 07 12:16:03 2011 us=919829   genkey = DISABLED
Tue Jun 07 12:16:03 2011 us=919856   key_pass_file = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=919881   show_tls_ciphers = DISABLED
Tue Jun 07 12:16:03 2011 us=919906   proto = 0
Tue Jun 07 12:16:03 2011 us=919929   local = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=919956   remote_list[0] = {'xxx.dyndns.com', 1194}
Tue Jun 07 12:16:03 2011 us=919980   remote_random = DISABLED
Tue Jun 07 12:16:03 2011 us=920003   local_port = 1194
Tue Jun 07 12:16:03 2011 us=920028   remote_port = 1194
Tue Jun 07 12:16:03 2011 us=920051   remote_float = ENABLED
Tue Jun 07 12:16:03 2011 us=920075   ipchange = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=920097   bind_local = DISABLED
Tue Jun 07 12:16:03 2011 us=920149   dev = 'tun'
Tue Jun 07 12:16:03 2011 us=920171   dev_type = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=920193   dev_node = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=920216   tun_ipv6 = DISABLED
Tue Jun 07 12:16:03 2011 us=920240   ifconfig_local = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=920263   ifconfig_remote_netmask = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=920286   ifconfig_noexec = DISABLED
Tue Jun 07 12:16:03 2011 us=920310   ifconfig_nowarn = DISABLED
Tue Jun 07 12:16:03 2011 us=920332   shaper = 0
Tue Jun 07 12:16:03 2011 us=920355   tun_mtu = 1500
Tue Jun 07 12:16:03 2011 us=920377   tun_mtu_defined = ENABLED
Tue Jun 07 12:16:03 2011 us=920400   link_mtu = 1500
Tue Jun 07 12:16:03 2011 us=920423   link_mtu_defined = DISABLED
Tue Jun 07 12:16:03 2011 us=920446   tun_mtu_extra = 0
Tue Jun 07 12:16:03 2011 us=920469   tun_mtu_extra_defined = DISABLED
Tue Jun 07 12:16:03 2011 us=920492   fragment = 0
Tue Jun 07 12:16:03 2011 us=920515   mtu_discover_type = -1
Tue Jun 07 12:16:03 2011 us=920537   mtu_test = 0
Tue Jun 07 12:16:03 2011 us=920559   mlock = DISABLED
Tue Jun 07 12:16:03 2011 us=920581   keepalive_ping = 0
Tue Jun 07 12:16:03 2011 us=920604   keepalive_timeout = 0
Tue Jun 07 12:16:03 2011 us=920627   inactivity_timeout = 0
Tue Jun 07 12:16:03 2011 us=920649   ping_send_timeout = 0
Tue Jun 07 12:16:03 2011 us=920672   ping_rec_timeout = 120
Tue Jun 07 12:16:03 2011 us=920695   ping_rec_timeout_action = 2
Tue Jun 07 12:16:03 2011 us=920718   ping_timer_remote = DISABLED
Tue Jun 07 12:16:03 2011 us=920740   remap_sigusr1 = 0
Tue Jun 07 12:16:03 2011 us=920763   explicit_exit_notification = 0
Tue Jun 07 12:16:03 2011 us=920786   persist_tun = ENABLED
Tue Jun 07 12:16:03 2011 us=920808   persist_local_ip = DISABLED
Tue Jun 07 12:16:03 2011 us=920832   persist_remote_ip = DISABLED
Tue Jun 07 12:16:03 2011 us=920854   persist_key = ENABLED
Tue Jun 07 12:16:03 2011 us=920877   mssfix = 1450
Tue Jun 07 12:16:03 2011 us=920901   resolve_retry_seconds = 1000000000
Tue Jun 07 12:16:03 2011 us=920924   connect_retry_seconds = 5
Tue Jun 07 12:16:03 2011 us=920947   username = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=920970   groupname = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=920992   chroot_dir = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=921014   cd_dir = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=921037   writepid = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=921059   up_script = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=921081   down_script = '[UNDEF]'
Tue Jun 07 12:16:03 2011 us=921104   down_pre = DISABLED
Tue Jun 07 12:16:03 2011 us=921127   up_restart = DISABLED
Tue Jun 07 12:16:03 2011 us=921150   up_delay = DISABLED
Tue Jun 07 12:16:03 2011 us=921172   daemon = DISABLED
Tue Jun 07 12:16:03 2011 us=921194   inetd = 0
Tue Jun 07 12:16:03 2011 us=921215   log = DISABLED
Tue Jun 07 12:16:03 2011 us=921238   suppress_timestamps = DISABLED
Tue Jun 07 12:16:03 2011 us=921261   nice = 0
Tue Jun 07 12:16:03 2011 us=921303   verbosity = 5
Tue Jun 07 12:16:04 2011 us=117730   mute = 0
Tue Jun 07 12:16:04 2011 us=117752   gremlin = 0
Tue Jun 07 12:16:04 2011 us=117760   status_file = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=117767   status_file_version = 1
Tue Jun 07 12:16:04 2011 us=117773   status_file_update_freq = 60
Tue Jun 07 12:16:04 2011 us=117780   occ = ENABLED
Tue Jun 07 12:16:04 2011 us=117786   rcvbuf = 0
Tue Jun 07 12:16:04 2011 us=117792   sndbuf = 0
Tue Jun 07 12:16:04 2011 us=117799   socks_proxy_server = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=117810   socks_proxy_port = 0
Tue Jun 07 12:16:04 2011 us=117817   socks_proxy_retry = DISABLED
Tue Jun 07 12:16:04 2011 us=117823   fast_io = DISABLED
Tue Jun 07 12:16:04 2011 us=117829   comp_lzo = ENABLED
Tue Jun 07 12:16:04 2011 us=117836   comp_lzo_adaptive = ENABLED
Tue Jun 07 12:16:04 2011 us=117842   route_script = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=117849   route_default_gateway = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=117855   route_noexec = DISABLED
Tue Jun 07 12:16:04 2011 us=124893   route_delay = 0
Tue Jun 07 12:16:04 2011 us=124925   route_delay_window = 30
Tue Jun 07 12:16:04 2011 us=124932   route_delay_defined = ENABLED
Tue Jun 07 12:16:04 2011 us=124946   [redirect_default_gateway local=0]
Tue Jun 07 12:16:04 2011 us=124953   management_addr = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=124960   management_port = 0
Tue Jun 07 12:16:04 2011 us=124966   management_user_pass = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=124973   management_log_history_cache = 250
Tue Jun 07 12:16:04 2011 us=124980   management_echo_buffer_size = 100
Tue Jun 07 12:16:04 2011 us=124987   management_query_passwords = DISABLED
Tue Jun 07 12:16:04 2011 us=124994   management_hold = DISABLED
Tue Jun 07 12:16:04 2011 us=125001   shared_secret_file = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=125007   key_direction = 0
Tue Jun 07 12:16:04 2011 us=125013   ciphername_defined = ENABLED
Tue Jun 07 12:16:04 2011 us=125020   ciphername = 'BF-CBC'
Tue Jun 07 12:16:04 2011 us=134891   authname_defined = ENABLED
Tue Jun 07 12:16:04 2011 us=134912   authname = 'SHA1'
Tue Jun 07 12:16:04 2011 us=134919   keysize = 0
Tue Jun 07 12:16:04 2011 us=134926   engine = DISABLED
Tue Jun 07 12:16:04 2011 us=134932   replay = ENABLED
Tue Jun 07 12:16:04 2011 us=134938   mute_replay_warnings = DISABLED
Tue Jun 07 12:16:04 2011 us=134945   replay_window = 64
Tue Jun 07 12:16:04 2011 us=134952   replay_time = 15
Tue Jun 07 12:16:04 2011 us=134958   packet_id_file = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=134964   use_iv = ENABLED
Tue Jun 07 12:16:04 2011 us=134970   test_crypto = DISABLED
Tue Jun 07 12:16:04 2011 us=134976   tls_server = DISABLED
Tue Jun 07 12:16:04 2011 us=134983   tls_client = ENABLED
Tue Jun 07 12:16:04 2011 us=135149   key_method = 2
Tue Jun 07 12:16:04 2011 us=135158   ca_file = 'ca.crt'
Tue Jun 07 12:16:04 2011 us=135164   dh_file = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=148920   cert_file = 'ersterclient.crt'
Tue Jun 07 12:16:04 2011 us=148942   priv_key_file = 'ersterclient.key'
Tue Jun 07 12:16:04 2011 us=148950   pkcs12_file = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=148956   cryptoapi_cert = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=148963   cipher_list = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=148969   tls_verify = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=148975   tls_remote = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=148982   crl_file = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=148988   ns_cert_type = 64
Tue Jun 07 12:16:04 2011 us=148994   tls_timeout = 2
Tue Jun 07 12:16:04 2011 us=149000   renegotiate_bytes = 0
Tue Jun 07 12:16:04 2011 us=149006   renegotiate_packets = 0
Tue Jun 07 12:16:04 2011 us=149013   renegotiate_seconds = 3600
Tue Jun 07 12:16:04 2011 us=149020   handshake_window = 60
Tue Jun 07 12:16:04 2011 us=149026   transition_window = 3600
Tue Jun 07 12:16:04 2011 us=149032   single_session = DISABLED
Tue Jun 07 12:16:04 2011 us=159039   tls_exit = DISABLED
Tue Jun 07 12:16:04 2011 us=159062   tls_auth_file = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=159078   server_network = 0.0.0.0
Tue Jun 07 12:16:04 2011 us=159085   server_netmask = 0.0.0.0
Tue Jun 07 12:16:04 2011 us=159097   server_bridge_ip = 0.0.0.0
Tue Jun 07 12:16:04 2011 us=159104   server_bridge_netmask = 0.0.0.0
Tue Jun 07 12:16:04 2011 us=159111   server_bridge_pool_start = 0.0.0.0
Tue Jun 07 12:16:04 2011 us=159118   server_bridge_pool_end = 0.0.0.0
Tue Jun 07 12:16:04 2011 us=159125   ifconfig_pool_defined = DISABLED
Tue Jun 07 12:16:04 2011 us=159132   ifconfig_pool_start = 0.0.0.0
Tue Jun 07 12:16:04 2011 us=159139   ifconfig_pool_end = 0.0.0.0
Tue Jun 07 12:16:04 2011 us=159147   ifconfig_pool_netmask = 0.0.0.0
Tue Jun 07 12:16:04 2011 us=159154   ifconfig_pool_persist_filename = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=159162   ifconfig_pool_persist_refresh_freq = 600
Tue Jun 07 12:16:04 2011 us=159168   ifconfig_pool_linear = DISABLED
Tue Jun 07 12:16:04 2011 us=173323   n_bcast_buf = 256
Tue Jun 07 12:16:04 2011 us=173345   tcp_queue_limit = 64
Tue Jun 07 12:16:04 2011 us=173352   real_hash_size = 256
Tue Jun 07 12:16:04 2011 us=173359   virtual_hash_size = 256
Tue Jun 07 12:16:04 2011 us=173365   client_connect_script = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=173372   learn_address_script = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=173379   client_disconnect_script = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=173386   client_config_dir = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=173392   ccd_exclusive = DISABLED
Tue Jun 07 12:16:04 2011 us=173399   tmp_dir = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=173405   push_ifconfig_defined = DISABLED
Tue Jun 07 12:16:04 2011 us=173414   push_ifconfig_local = 0.0.0.0
Tue Jun 07 12:16:04 2011 us=173422   push_ifconfig_remote_netmask = 0.0.0.0
Tue Jun 07 12:16:04 2011 us=173428   enable_c2c = DISABLED
Tue Jun 07 12:16:04 2011 us=181842   duplicate_cn = DISABLED
Tue Jun 07 12:16:04 2011 us=181864   cf_max = 0
Tue Jun 07 12:16:04 2011 us=181870   cf_per = 0
Tue Jun 07 12:16:04 2011 us=181877   max_clients = 1024
Tue Jun 07 12:16:04 2011 us=181883   max_routes_per_client = 256
Tue Jun 07 12:16:04 2011 us=181890   client_cert_not_required = DISABLED
Tue Jun 07 12:16:04 2011 us=181897   username_as_common_name = DISABLED
Tue Jun 07 12:16:04 2011 us=181904   auth_user_pass_verify_script = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=181911   auth_user_pass_verify_script_via_file = DISABLED
Tue Jun 07 12:16:04 2011 us=181918   client = ENABLED
Tue Jun 07 12:16:04 2011 us=181924   pull = ENABLED
Tue Jun 07 12:16:04 2011 us=181930   auth_user_pass_file = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=181939   show_net_up = DISABLED
Tue Jun 07 12:16:04 2011 us=181945   route_method = 0
Tue Jun 07 12:16:04 2011 us=181952   ip_win32_defined = DISABLED
Tue Jun 07 12:16:04 2011 us=181958   ip_win32_type = 3
Tue Jun 07 12:16:04 2011 us=196040   dhcp_masq_offset = 0
Tue Jun 07 12:16:04 2011 us=196061   dhcp_lease_time = 31536000
Tue Jun 07 12:16:04 2011 us=196068   tap_sleep = 0
Tue Jun 07 12:16:04 2011 us=196074   dhcp_options = DISABLED
Tue Jun 07 12:16:04 2011 us=196081   dhcp_renew = DISABLED
Tue Jun 07 12:16:04 2011 us=196087   dhcp_pre_release = DISABLED
Tue Jun 07 12:16:04 2011 us=196093   dhcp_release = DISABLED
Tue Jun 07 12:16:04 2011 us=196099   domain = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=196105   netbios_scope = '[UNDEF]'
Tue Jun 07 12:16:04 2011 us=196112   netbios_node_type = 0
Tue Jun 07 12:16:04 2011 us=196118   disable_nbt = DISABLED
Tue Jun 07 12:16:04 2011 us=196131 OpenVPN 2.0.9 Win32-MinGW [SSL] [LZO] built on Oct  1 2006
Tue Jun 07 12:16:04 2011 us=196434 IMPORTANT: OpenVPN's default port number is now 1194, based on an official port number assignment by IANA.  OpenVPN 2.0-beta16 and earlier used 5000 as the default port.
Tue Jun 07 12:16:04 2011 us=222667 LZO compression initialized
Tue Jun 07 12:16:04 2011 us=222740 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Tue Jun 07 12:16:04 2011 us=341441 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Tue Jun 07 12:16:04 2011 us=341575 Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Tue Jun 07 12:16:04 2011 us=341607 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Tue Jun 07 12:16:04 2011 us=351053 Local Options hash (VER=V4): '41690919'
Tue Jun 07 12:16:04 2011 us=351151 Expected Remote Options hash (VER=V4): '530fdded'
Tue Jun 07 12:16:04 2011 us=351227 Socket Buffers: R=[8192->8192] S=[8192->8192]
Tue Jun 07 12:16:04 2011 us=356404 UDPv4 link local: [undef]
Tue Jun 07 12:16:04 2011 us=356479 UDPv4 link remote: xxx.xxx.xxx.xxx:1194
Tue Jun 07 12:16:04 2011 us=368609 TLS: Initial packet from xxx.xxx.xxx.xxx:1194, sid=855e0703 750559fb
Tue Jun 07 12:17:03 2011 us=688766 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Tue Jun 07 12:17:03 2011 us=688860 TLS Error: TLS handshake failed
Tue Jun 07 12:17:03 2011 us=700303 TCP/UDP: Closing socket
Tue Jun 07 12:17:03 2011 us=701577 SIGUSR1[soft,tls-error] received, process restarting
Tue Jun 07 12:17:03 2011 us=701603 Restart pause, 2 second(s)
Tue Jun 07 12:17:05 2011 us=701799 IMPORTANT: OpenVPN's default port number is now 1194, based on an official port number assignment by IANA.  OpenVPN 2.0-beta16 and earlier used 5000 as the default port.
Tue Jun 07 12:17:05 2011 us=701909 Re-using SSL/TLS context
Tue Jun 07 12:17:05 2011 us=701962 LZO compression initialized
Tue Jun 07 12:17:05 2011 us=702073 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Tue Jun 07 12:17:05 2011 us=773425 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Tue Jun 07 12:17:05 2011 us=773547 Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Tue Jun 07 12:17:05 2011 us=773579 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Tue Jun 07 12:17:05 2011 us=773630 Local Options hash (VER=V4): '41690919'
Tue Jun 07 12:17:05 2011 us=773672 Expected Remote Options hash (VER=V4): '530fdded'
Tue Jun 07 12:17:05 2011 us=773729 Socket Buffers: R=[8192->8192] S=[8192->8192]
Tue Jun 07 12:17:05 2011 us=793705 UDPv4 link local: [undef]
Tue Jun 07 12:17:05 2011 us=793741 UDPv4 link remote: xxx.xxx.xxx.xxx:1194
Tue Jun 07 12:17:05 2011 us=804586 TLS: Initial packet from xxx.xxx.xxx.xxx:1194, sid=e1f7932d a02b167e
Tue Jun 07 12:17:40 2011 us=756370 TCP/UDP: Closing socket
Tue Jun 07 12:17:40 2011 us=756843 SIGTERM[hard,] received, process exiting
WRRWWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWWRRWWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWTue Jun 07 12:17:40 2011 us=830599 Current Parameter Settings:
Tue Jun 07 12:17:40 2011 us=830673   config = 'client.ovpn'
Tue Jun 07 12:17:40 2011 us=830715   mode = 0
Tue Jun 07 12:17:40 2011 us=830757   show_ciphers = DISABLED
Tue Jun 07 12:17:40 2011 us=830795   show_digests = DISABLED
Tue Jun 07 12:17:40 2011 us=830832   show_engines = DISABLED
Tue Jun 07 12:17:40 2011 us=830867   genkey = DISABLED
Tue Jun 07 12:17:40 2011 us=830901   key_pass_file = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=830933   show_tls_ciphers = DISABLED
Tue Jun 07 12:17:40 2011 us=830964   proto = 0
Tue Jun 07 12:17:40 2011 us=830993   local = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831023   remote_list[0] = {'xxx.dyndns.com', 1194}
Tue Jun 07 12:17:40 2011 us=831050   remote_random = DISABLED
Tue Jun 07 12:17:40 2011 us=831077   local_port = 1194
Tue Jun 07 12:17:40 2011 us=831101   remote_port = 1194
Tue Jun 07 12:17:40 2011 us=831126   remote_float = ENABLED
Tue Jun 07 12:17:40 2011 us=831149   ipchange = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831171   bind_local = DISABLED
Tue Jun 07 12:17:40 2011 us=831193   dev = 'tun'
Tue Jun 07 12:17:40 2011 us=831214   dev_type = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831234   dev_node = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831253   tun_ipv6 = DISABLED
Tue Jun 07 12:17:40 2011 us=831272   ifconfig_local = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831291   ifconfig_remote_netmask = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831309   ifconfig_noexec = DISABLED
Tue Jun 07 12:17:40 2011 us=831326   ifconfig_nowarn = DISABLED
Tue Jun 07 12:17:40 2011 us=831342   shaper = 0
Tue Jun 07 12:17:40 2011 us=831358   tun_mtu = 1500
Tue Jun 07 12:17:40 2011 us=831374   tun_mtu_defined = ENABLED
Tue Jun 07 12:17:40 2011 us=831389   link_mtu = 1500
Tue Jun 07 12:17:40 2011 us=831404   link_mtu_defined = DISABLED
Tue Jun 07 12:17:40 2011 us=831418   tun_mtu_extra = 0
Tue Jun 07 12:17:40 2011 us=831432   tun_mtu_extra_defined = DISABLED
Tue Jun 07 12:17:40 2011 us=831447   fragment = 0
Tue Jun 07 12:17:40 2011 us=831459   mtu_discover_type = -1
Tue Jun 07 12:17:40 2011 us=831472   mtu_test = 0
Tue Jun 07 12:17:40 2011 us=831485   mlock = DISABLED
Tue Jun 07 12:17:40 2011 us=831497   keepalive_ping = 0
Tue Jun 07 12:17:40 2011 us=831509   keepalive_timeout = 0
Tue Jun 07 12:17:40 2011 us=831520   inactivity_timeout = 0
Tue Jun 07 12:17:40 2011 us=831532   ping_send_timeout = 0
Tue Jun 07 12:17:40 2011 us=831543   ping_rec_timeout = 120
Tue Jun 07 12:17:40 2011 us=831554   ping_rec_timeout_action = 2
Tue Jun 07 12:17:40 2011 us=831565   ping_timer_remote = DISABLED
Tue Jun 07 12:17:40 2011 us=831576   remap_sigusr1 = 0
Tue Jun 07 12:17:40 2011 us=831586   explicit_exit_notification = 0
Tue Jun 07 12:17:40 2011 us=831596   persist_tun = ENABLED
Tue Jun 07 12:17:40 2011 us=831606   persist_local_ip = DISABLED
Tue Jun 07 12:17:40 2011 us=831616   persist_remote_ip = DISABLED
Tue Jun 07 12:17:40 2011 us=831626   persist_key = ENABLED
Tue Jun 07 12:17:40 2011 us=831635   mssfix = 1450
Tue Jun 07 12:17:40 2011 us=831645   resolve_retry_seconds = 1000000000
Tue Jun 07 12:17:40 2011 us=831654   connect_retry_seconds = 5
Tue Jun 07 12:17:40 2011 us=831664   username = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831673   groupname = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831681   chroot_dir = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831690   cd_dir = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831698   writepid = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831707   up_script = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831715   down_script = '[UNDEF]'
Tue Jun 07 12:17:40 2011 us=831724   down_pre = DISABLED
Tue Jun 07 12:17:40 2011 us=831732   up_restart = DISABLED
Tue Jun 07 12:17:40 2011 us=831740   up_delay = DISABLED
Tue Jun 07 12:17:40 2011 us=831748   daemon = DISABLED
Tue Jun 07 12:17:40 2011 us=831756   inetd = 0
Tue Jun 07 12:17:40 2011 us=831763   log = DISABLED
Tue Jun 07 12:17:40 2011 us=831771   suppress_timestamps = DISABLED
Tue Jun 07 12:17:40 2011 us=831779   nice = 0
Tue Jun 07 12:17:40 2011 us=831787   verbosity = 5
Tue Jun 07 12:17:41 2011 us=18654   mute = 0
Tue Jun 07 12:17:41 2011 us=18725   gremlin = 0
Tue Jun 07 12:17:41 2011 us=18750   status_file = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=18773   status_file_version = 1
Tue Jun 07 12:17:41 2011 us=18796   status_file_update_freq = 60
Tue Jun 07 12:17:41 2011 us=18819   occ = ENABLED
Tue Jun 07 12:17:41 2011 us=18840   rcvbuf = 0
Tue Jun 07 12:17:41 2011 us=18862   sndbuf = 0
Tue Jun 07 12:17:41 2011 us=18886   socks_proxy_server = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=18917   socks_proxy_port = 0
Tue Jun 07 12:17:41 2011 us=18940   socks_proxy_retry = DISABLED
Tue Jun 07 12:17:41 2011 us=18963   fast_io = DISABLED
Tue Jun 07 12:17:41 2011 us=19027   comp_lzo = ENABLED
Tue Jun 07 12:17:41 2011 us=19124   comp_lzo_adaptive = ENABLED
Tue Jun 07 12:17:41 2011 us=19147   route_script = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=19171   route_default_gateway = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=52753   route_noexec = DISABLED
Tue Jun 07 12:17:41 2011 us=52776   route_delay = 0
Tue Jun 07 12:17:41 2011 us=52783   route_delay_window = 30
Tue Jun 07 12:17:41 2011 us=52789   route_delay_defined = ENABLED
Tue Jun 07 12:17:41 2011 us=52801   [redirect_default_gateway local=0]
Tue Jun 07 12:17:41 2011 us=52808   management_addr = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=52814   management_port = 0
Tue Jun 07 12:17:41 2011 us=52821   management_user_pass = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=52827   management_log_history_cache = 250
Tue Jun 07 12:17:41 2011 us=52835   management_echo_buffer_size = 100
Tue Jun 07 12:17:41 2011 us=52842   management_query_passwords = DISABLED
Tue Jun 07 12:17:41 2011 us=52850   management_hold = DISABLED
Tue Jun 07 12:17:41 2011 us=52856   shared_secret_file = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=52862   key_direction = 0
Tue Jun 07 12:17:41 2011 us=52869   ciphername_defined = ENABLED
Tue Jun 07 12:17:41 2011 us=77111   ciphername = 'BF-CBC'
Tue Jun 07 12:17:41 2011 us=77133   authname_defined = ENABLED
Tue Jun 07 12:17:41 2011 us=77139   authname = 'SHA1'
Tue Jun 07 12:17:41 2011 us=77146   keysize = 0
Tue Jun 07 12:17:41 2011 us=77152   engine = DISABLED
Tue Jun 07 12:17:41 2011 us=77158   replay = ENABLED
Tue Jun 07 12:17:41 2011 us=77165   mute_replay_warnings = DISABLED
Tue Jun 07 12:17:41 2011 us=77171   replay_window = 64
Tue Jun 07 12:17:41 2011 us=77178   replay_time = 15
Tue Jun 07 12:17:41 2011 us=77185   packet_id_file = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=77191   use_iv = ENABLED
Tue Jun 07 12:17:41 2011 us=77198   test_crypto = DISABLED
Tue Jun 07 12:17:41 2011 us=77205   tls_server = DISABLED
Tue Jun 07 12:17:41 2011 us=77212   tls_client = ENABLED
Tue Jun 07 12:17:41 2011 us=77218   key_method = 2
Tue Jun 07 12:17:41 2011 us=77225   ca_file = 'ca.crt'
Tue Jun 07 12:17:41 2011 us=77232   dh_file = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=77238   cert_file = 'ersterclient.crt'
Tue Jun 07 12:17:41 2011 us=100398   priv_key_file = 'ersterclient.key'
Tue Jun 07 12:17:41 2011 us=100419   pkcs12_file = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=100426   cryptoapi_cert = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=100433   cipher_list = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=100439   tls_verify = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=100445   tls_remote = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=100452   crl_file = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=100458   ns_cert_type = 64
Tue Jun 07 12:17:41 2011 us=100464   tls_timeout = 2
Tue Jun 07 12:17:41 2011 us=100471   renegotiate_bytes = 0
Tue Jun 07 12:17:41 2011 us=100478   renegotiate_packets = 0
Tue Jun 07 12:17:41 2011 us=100484   renegotiate_seconds = 3600
Tue Jun 07 12:17:41 2011 us=100491   handshake_window = 60
Tue Jun 07 12:17:41 2011 us=100497   transition_window = 3600
Tue Jun 07 12:17:41 2011 us=100504   single_session = DISABLED
Tue Jun 07 12:17:41 2011 us=100511   tls_exit = DISABLED
Tue Jun 07 12:17:41 2011 us=125015   tls_auth_file = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=125067   server_network = 0.0.0.0
Tue Jun 07 12:17:41 2011 us=125074   server_netmask = 0.0.0.0
Tue Jun 07 12:17:41 2011 us=125087   server_bridge_ip = 0.0.0.0
Tue Jun 07 12:17:41 2011 us=125094   server_bridge_netmask = 0.0.0.0
Tue Jun 07 12:17:41 2011 us=125101   server_bridge_pool_start = 0.0.0.0
Tue Jun 07 12:17:41 2011 us=125108   server_bridge_pool_end = 0.0.0.0
Tue Jun 07 12:17:41 2011 us=125115   ifconfig_pool_defined = DISABLED
Tue Jun 07 12:17:41 2011 us=125123   ifconfig_pool_start = 0.0.0.0
Tue Jun 07 12:17:41 2011 us=125130   ifconfig_pool_end = 0.0.0.0
Tue Jun 07 12:17:41 2011 us=125137   ifconfig_pool_netmask = 0.0.0.0
Tue Jun 07 12:17:41 2011 us=125145   ifconfig_pool_persist_filename = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=125153   ifconfig_pool_persist_refresh_freq = 600
Tue Jun 07 12:17:41 2011 us=125160   ifconfig_pool_linear = DISABLED
Tue Jun 07 12:17:41 2011 us=153533   n_bcast_buf = 256
Tue Jun 07 12:17:41 2011 us=153712   tcp_queue_limit = 64
Tue Jun 07 12:17:41 2011 us=153842   real_hash_size = 256
Tue Jun 07 12:17:41 2011 us=153959   virtual_hash_size = 256
Tue Jun 07 12:17:41 2011 us=154066   client_connect_script = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=154163   learn_address_script = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=154250   client_disconnect_script = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=154329   client_config_dir = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=154401   ccd_exclusive = DISABLED
Tue Jun 07 12:17:41 2011 us=154466   tmp_dir = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=154711   push_ifconfig_defined = DISABLED
Tue Jun 07 12:17:41 2011 us=154768   push_ifconfig_local = 0.0.0.0
Tue Jun 07 12:17:41 2011 us=154817   push_ifconfig_remote_netmask = 0.0.0.0
Tue Jun 07 12:17:41 2011 us=154862   enable_c2c = DISABLED
Tue Jun 07 12:17:41 2011 us=154902   duplicate_cn = DISABLED
Tue Jun 07 12:17:41 2011 us=154939   cf_max = 0
Tue Jun 07 12:17:41 2011 us=177375   cf_per = 0
Tue Jun 07 12:17:41 2011 us=177617   max_clients = 1024
Tue Jun 07 12:17:41 2011 us=177820   max_routes_per_client = 256
Tue Jun 07 12:17:41 2011 us=178003   client_cert_not_required = DISABLED
Tue Jun 07 12:17:41 2011 us=178169   username_as_common_name = DISABLED
Tue Jun 07 12:17:41 2011 us=178319   auth_user_pass_verify_script = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=178456   auth_user_pass_verify_script_via_file = DISABLED
Tue Jun 07 12:17:41 2011 us=178578   client = ENABLED
Tue Jun 07 12:17:41 2011 us=178688   pull = ENABLED
Tue Jun 07 12:17:41 2011 us=178788   auth_user_pass_file = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=178882   show_net_up = DISABLED
Tue Jun 07 12:17:41 2011 us=178964   route_method = 0
Tue Jun 07 12:17:41 2011 us=179039   ip_win32_defined = DISABLED
Tue Jun 07 12:17:41 2011 us=179107   ip_win32_type = 3
Tue Jun 07 12:17:41 2011 us=179169   dhcp_masq_offset = 0
Tue Jun 07 12:17:41 2011 us=179225   dhcp_lease_time = 31536000
Tue Jun 07 12:17:41 2011 us=202514   tap_sleep = 0
Tue Jun 07 12:17:41 2011 us=202587   dhcp_options = DISABLED
Tue Jun 07 12:17:41 2011 us=202969   dhcp_renew = DISABLED
Tue Jun 07 12:17:41 2011 us=203314   dhcp_pre_release = DISABLED
Tue Jun 07 12:17:41 2011 us=203624   dhcp_release = DISABLED
Tue Jun 07 12:17:41 2011 us=203904   domain = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=204156   netbios_scope = '[UNDEF]'
Tue Jun 07 12:17:41 2011 us=204383   netbios_node_type = 0
Tue Jun 07 12:17:41 2011 us=204589   disable_nbt = DISABLED
Tue Jun 07 12:17:41 2011 us=204780 OpenVPN 2.0.9 Win32-MinGW [SSL] [LZO] built on Oct  1 2006
Tue Jun 07 12:17:41 2011 us=205014 IMPORTANT: OpenVPN's default port number is now 1194, based on an official port number assignment by IANA.  OpenVPN 2.0-beta16 and earlier used 5000 as the default port.
Tue Jun 07 12:17:41 2011 us=205853 LZO compression initialized
Tue Jun 07 12:17:41 2011 us=206062 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Tue Jun 07 12:17:41 2011 us=290785 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Tue Jun 07 12:17:41 2011 us=290831 Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Tue Jun 07 12:17:41 2011 us=290841 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Tue Jun 07 12:17:41 2011 us=290859 Local Options hash (VER=V4): '41690919'
Tue Jun 07 12:17:41 2011 us=290872 Expected Remote Options hash (VER=V4): '530fdded'
Tue Jun 07 12:17:41 2011 us=290892 Socket Buffers: R=[8192->8192] S=[8192->8192]
Tue Jun 07 12:17:41 2011 us=290906 UDPv4 link local: [undef]
Tue Jun 07 12:17:41 2011 us=290914 UDPv4 link remote: xxx.xxx.xxx.xxx:1194
Tue Jun 07 12:17:43 2011 us=527503 read UDPv4: Connection reset by peer (WSAECONNRESET) (code=10054)
Tue Jun 07 12:17:45 2011 us=710430 read UDPv4: Connection reset by peer (WSAECONNRESET) (code=10054)
Tue Jun 07 12:17:47 2011 us=893505 read UDPv4: Connection reset by peer (WSAECONNRESET) (code=10054)
Tue Jun 07 12:17:50 2011 us=77135 read UDPv4: Connection reset by peer (WSAECONNRESET) (code=10054)
Tue Jun 07 12:17:52 2011 us=262031 TLS: Initial packet from 192.168.0.136:1194, sid=22da01d4 73ae8634
Tue Jun 07 12:17:52 2011 us=314908 VERIFY OK: depth=1, /C=DE/ST=SAX/L=Leipzig/O=FSN/CN=FSN_CA/emailAddress=loeschbar@himbeer.org
Tue Jun 07 12:17:52 2011 us=315455 VERIFY OK: nsCertType=SERVER
Tue Jun 07 12:17:52 2011 us=315469 VERIFY OK: depth=0, /C=DE/ST=SAX/L=Leipzig/O=FSN/CN=server/emailAddress=loeschbar@himbeer.org
Tue Jun 07 12:17:52 2011 us=408151 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jun 07 12:17:52 2011 us=408217 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jun 07 12:17:52 2011 us=408372 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jun 07 12:17:52 2011 us=408404 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jun 07 12:17:52 2011 us=428627 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jun 07 12:17:52 2011 us=428655 [server] Peer Connection Initiated with 192.168.0.136:1194
Tue Jun 07 12:17:53 2011 us=520549 SENT CONTROL [server]: 'PUSH_REQUEST' (status=1)
Tue Jun 07 12:17:53 2011 us=532067 PUSH: Received control message: 'PUSH_REPLY,route 10.8.0.0 255.255.255.0,route 10.8.0.0 255.255.255.0,topology net30,ping 10,ping-restart 120,ifconfig 10.8.0.6 10.8.0.5'
Tue Jun 07 12:17:53 2011 us=532206 Options error: Unrecognized option or missing parameter(s) in [PUSH-OPTIONS]:3: topology (2.0.9)
Tue Jun 07 12:17:53 2011 us=532248 OPTIONS IMPORT: timers and/or timeouts modified
Tue Jun 07 12:17:53 2011 us=532271 OPTIONS IMPORT: --ifconfig/up options modified
Tue Jun 07 12:17:53 2011 us=532326 OPTIONS IMPORT: route options modified
Tue Jun 07 12:17:53 2011 us=549607 TAP-WIN32 device [LAN-Verbindung 5] opened: \\.\Global\{3182F99E-E68F-4DFC-9FF8-468B3BFE038A}.tap
Tue Jun 07 12:17:53 2011 us=550898 TAP-Win32 Driver Version 8.4 
Tue Jun 07 12:17:53 2011 us=552204 TAP-Win32 MTU=1500
Tue Jun 07 12:17:53 2011 us=553498 Notified TAP-Win32 driver to set a DHCP IP/netmask of 10.8.0.6/255.255.255.252 on interface {3182F99E-E68F-4DFC-9FF8-468B3BFE038A} [DHCP-serv: 10.8.0.5, lease-time: 31536000]
Tue Jun 07 12:17:53 2011 us=555878 Successful ARP Flush on interface [2] {3182F99E-E68F-4DFC-9FF8-468B3BFE038A}
Tue Jun 07 12:17:53 2011 us=568175 TEST ROUTES: 0/0 succeeded len=2 ret=0 a=0 u/d=down
Tue Jun 07 12:17:53 2011 us=568204 Route: Waiting for TUN/TAP interface to come up...
Tue Jun 07 12:17:54 2011 us=664142 TEST ROUTES: 0/0 succeeded len=2 ret=0 a=0 u/d=down
Tue Jun 07 12:17:54 2011 us=664223 Route: Waiting for TUN/TAP interface to come up...
Tue Jun 07 12:17:55 2011 us=765653 TEST ROUTES: 0/0 succeeded len=2 ret=0 a=0 u/d=down
Tue Jun 07 12:17:55 2011 us=765733 Route: Waiting for TUN/TAP interface to come up...
Tue Jun 07 12:17:56 2011 us=877403 TEST ROUTES: 3/3 succeeded len=2 ret=1 a=0 u/d=up
Tue Jun 07 12:17:56 2011 us=877496 route ADD 192.168.0.136 MASK 255.255.255.255 192.168.0.1
Tue Jun 07 12:17:56 2011 us=886089 Route addition via IPAPI succeeded
Tue Jun 07 12:17:56 2011 us=886119 route ADD 0.0.0.0 MASK 128.0.0.0 10.8.0.5
Tue Jun 07 12:17:56 2011 us=892949 Route addition via IPAPI succeeded
Tue Jun 07 12:17:56 2011 us=892985 route ADD 128.0.0.0 MASK 128.0.0.0 10.8.0.5
Tue Jun 07 12:17:56 2011 us=898158 Route addition via IPAPI succeeded
Tue Jun 07 12:17:56 2011 us=898186 route ADD 10.8.0.0 MASK 255.255.255.0 10.8.0.5
Tue Jun 07 12:17:56 2011 us=901800 Route addition via IPAPI succeeded
Tue Jun 07 12:17:56 2011 us=901833 route ADD 10.8.0.0 MASK 255.255.255.0 10.8.0.5
Tue Jun 07 12:17:56 2011 us=905235 Route addition via IPAPI succeeded
Tue Jun 07 12:17:56 2011 us=905263 Initialization Sequence Completed

Post by **janjust** » Tue Jun 07, 2011 10:39 am

you're using openvpn 2.0.9 on windows? that's a really old version of openvpn; if you're running Vista or 7 you must upgrade to 2.1.4 or even better, 2.2.0.

during the first connection attempt there seems to be a firewall that's blocking access; do you see the connection attempts on the server also?

scallywag · Post by **scallywag** » Tue Jun 07, 2011 11:26 am

the client is in the serverlog. iptables doesnt have any configurations and i also tried with the server in a dmz.

serverlog

Code: Select all

Jun  7 13:14:16 debian ovpn-server[1978]: MULTI: multi_create_instance called
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 Re-using SSL/TLS context
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 LZO compression initialized
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 Local Options hash (VER=V4): '530fdded'
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 Expected Remote Options hash (VER=V4): '41690919'
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 UDPv4 READ [14] from [AF_INET]xxx.xxx.xxx.x:1036: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 TLS: Initial packet from [AF_INET]xxx.xxx.xxx.x:1036, sid=77219633 2a55e679
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 UDPv4 WRITE [26] to [AF_INET]xxx.xxx.xxx.x:1036: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 UDPv4 READ [22] from [AF_INET]xxx.xxx.xxx.x:1036: P_ACK_V1 kid=0 [ 0 ]
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 UDPv4 READ [102] from [AF_INET]xxx.xxx.xxx.x:1036: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Jun  7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 UDPv4 WRITE [126] to [AF_INET]xxx.xxx.xxx.x:1036: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=100
/*repeated many times */


Jun  7 13:15:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jun  7 13:15:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 TLS Error: TLS handshake failed
Jun  7 13:15:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 SIGUSR1[soft,tls-error] received, client-instance restarting
Jun  7 13:15:18 debian ovpn-server[1978]: MULTI: multi_create_instance called
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 Re-using SSL/TLS context
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 LZO compression initialized
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 Local Options hash (VER=V4): '530fdded'
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 Expected Remote Options hash (VER=V4): '41690919'
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 UDPv4 READ [14] from [AF_INET]xxx.xxx.xxx.x:1037: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 TLS: Initial packet from [AF_INET]xxx.xxx.xxx.x:1037, sid=41604bac 84165628
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 UDPv4 WRITE [26] to [AF_INET]xxx.xxx.xxx.x:1037: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 UDPv4 READ [22] from [AF_INET]xxx.xxx.xxx.x:1037: P_ACK_V1 kid=0 [ 0 ]
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 UDPv4 READ [102] from [AF_INET]xxx.xxx.xxx.x:1037: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=88
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 UDPv4 WRITE [126] to [AF_INET]xxx.xxx.xxx.x:1037: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=100
Jun  7 13:15:18 debian ovpn-server[1978]: xxx.xxx.xxx.x:1037 UDPv4 WRITE [114] to [AF_INET]xxx.xxx.xxx.x:1037: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100

Post by **janjust** » Tue Jun 07, 2011 12:21 pm

this

Jun 7 13:14:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 UDPv4 WRITE [126] to [AF_INET]xxx.xxx.xxx.x:1036: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=100
/*repeated many times */

Jun 7 13:15:16 debian ovpn-server[1978]: xxx.xxx.xxx.x:1036 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)

suggests that the server is trying to reach the client but is failing, after which the connection is reset; check the firewalls between the server and client and whether UDP traffic is allowed.

what OS is the client running?

scallywag · Post by **scallywag** » Tue Jun 07, 2011 4:31 pm

its solved. the problem was, that i always tried to connect to my local server from local client via wan. then i think client and server had same ip or something like that. but janjust, many thanks for your fast help! very nice.

Post by **maikcat** » Fri Jun 24, 2011 1:28 pm

topic closed

Michael.

OpenVPN Support Forum

[solved] connection works only after service -stop -start

[solved] connection works only after service -stop -start

Re: connection works only after service -stop -start

Re: connection works only after service -stop -start

Re: connection works only after service -stop -start

Re: connection works only after service -stop -start

Re: connection works only after service -stop -start

Re: connection works only after service -stop -start

Re: connection works only after service -stop -start

Re: connection works only after service -stop -start

Re: [solved] connection works only after service -stop -sta