[SOLVED] Windows XP sp2 to sp3 upgrade breaks openvpn connec

frankgtl

I have some older windows xp sp2 machines that work fine with OpenVPN but when I upgrade them to SP3 the connection no longer works.
The open vpn client connect to the server
I get an IP
but when I try to access any equipment on thru the vpn no data is being transfered. No connections are made.

If I remove sp3 (rollback) and try the same thing, all works fine.

Any thoughts?

janjust

I'm using OpenVPN 2.1 and 2.2 on Win XP SP3 without any issues; this could be a configuration error that only shows in SP3. Post your server and client config files (esp if you are using client-config-dir files) and we might be able to tell you what is happening. A client log file with 'verb 5' set would also help.

frankgtl

Please excuse my ignorance here but were would I find those log files and how would I set 'verb 5'.
I only have access to the client side at this time.

janjust

add a line

verb 5

to the client .ovpn config file (usually located in c:\program files\openvpn\config).

reconnect the client and post the log file (which you can view directly from the OpenVPN GUI application

frankgtl

Thank you for the info.
I will need to stage a machine and get this info for you.

frankgtl

Here is my client.log file.
Tue Nov 08 10:55:51 2011 us=453000 Current Parameter Settings:
Tue Nov 08 10:55:51 2011 us=453000 config = 'stdin'
Tue Nov 08 10:55:51 2011 us=453000 mode = 0
Tue Nov 08 10:55:51 2011 us=453000 show_ciphers = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 show_digests = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 show_engines = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 genkey = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 key_pass_file = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 show_tls_ciphers = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 Connection profiles [default]:
Tue Nov 08 10:55:51 2011 us=453000 proto = tcp
Tue Nov 08 10:55:51 2011 us=453000 local = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 local_port = 443
Tue Nov 08 10:55:51 2011 us=453000 remote = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 remote_port = 443
Tue Nov 08 10:55:51 2011 us=453000 remote_float = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 bind_defined = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 bind_local = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 connect_retry_seconds = 5
Tue Nov 08 10:55:51 2011 us=453000 connect_timeout = 10
Tue Nov 08 10:55:51 2011 us=453000 connect_retry_max = 0
Tue Nov 08 10:55:51 2011 us=453000 socks_proxy_server = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 socks_proxy_port = 0
Tue Nov 08 10:55:51 2011 us=453000 socks_proxy_retry = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 Connection profiles [0]:
Tue Nov 08 10:55:51 2011 us=453000 proto = tcp-client
Tue Nov 08 10:55:51 2011 us=453000 local = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 local_port = 0
Tue Nov 08 10:55:51 2011 us=453000 remote = 'vpn-serv.XX.com'
Tue Nov 08 10:55:51 2011 us=453000 remote_port = 443
Tue Nov 08 10:55:51 2011 us=453000 remote_float = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 bind_defined = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 bind_local = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 connect_retry_seconds = 5
Tue Nov 08 10:55:51 2011 us=453000 connect_timeout = 10
Tue Nov 08 10:55:51 2011 us=453000 connect_retry_max = 0
Tue Nov 08 10:55:51 2011 us=453000 socks_proxy_server = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 socks_proxy_port = 0
Tue Nov 08 10:55:51 2011 us=453000 socks_proxy_retry = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 Connection profiles [1]:
Tue Nov 08 10:55:51 2011 us=453000 proto = tcp-client
Tue Nov 08 10:55:51 2011 us=453000 local = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 local_port = 0
Tue Nov 08 10:55:51 2011 us=453000 remote = 'vpn-serv.xx.com'
Tue Nov 08 10:55:51 2011 us=453000 remote_port = 443
Tue Nov 08 10:55:51 2011 us=453000 remote_float = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 bind_defined = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 bind_local = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 connect_retry_seconds = 5
Tue Nov 08 10:55:51 2011 us=453000 connect_timeout = 10
Tue Nov 08 10:55:51 2011 us=453000 connect_retry_max = 0
Tue Nov 08 10:55:51 2011 us=453000 socks_proxy_server = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 socks_proxy_port = 0
Tue Nov 08 10:55:51 2011 us=453000 socks_proxy_retry = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 Connection profiles END
Tue Nov 08 10:55:51 2011 us=453000 remote_random = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 ipchange = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 dev = 'tun'
Tue Nov 08 10:55:51 2011 us=453000 dev_type = 'tun'
Tue Nov 08 10:55:51 2011 us=453000 dev_node = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 lladdr = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 topology = 1
Tue Nov 08 10:55:51 2011 us=453000 tun_ipv6 = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 ifconfig_local = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 ifconfig_remote_netmask = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 ifconfig_noexec = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 ifconfig_nowarn = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 shaper = 0
Tue Nov 08 10:55:51 2011 us=453000 tun_mtu = 1500
Tue Nov 08 10:55:51 2011 us=453000 tun_mtu_defined = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 link_mtu = 1500
Tue Nov 08 10:55:51 2011 us=453000 link_mtu_defined = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 tun_mtu_extra = 0
Tue Nov 08 10:55:51 2011 us=453000 tun_mtu_extra_defined = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 fragment = 0
Tue Nov 08 10:55:51 2011 us=453000 mtu_discover_type = -1
Tue Nov 08 10:55:51 2011 us=453000 mtu_test = 0
Tue Nov 08 10:55:51 2011 us=453000 mlock = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 keepalive_ping = 0
Tue Nov 08 10:55:51 2011 us=453000 keepalive_timeout = 0
Tue Nov 08 10:55:51 2011 us=453000 inactivity_timeout = 3600
Tue Nov 08 10:55:51 2011 us=453000 ping_send_timeout = 0
Tue Nov 08 10:55:51 2011 us=453000 ping_rec_timeout = 0
Tue Nov 08 10:55:51 2011 us=453000 ping_rec_timeout_action = 0
Tue Nov 08 10:55:51 2011 us=453000 ping_timer_remote = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 remap_sigusr1 = 0
Tue Nov 08 10:55:51 2011 us=453000 explicit_exit_notification = 0
Tue Nov 08 10:55:51 2011 us=453000 persist_tun = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 persist_local_ip = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 persist_remote_ip = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 persist_key = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 mssfix = 1450
Tue Nov 08 10:55:51 2011 us=453000 resolve_retry_seconds = 1000000000
Tue Nov 08 10:55:51 2011 us=453000 username = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 groupname = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 chroot_dir = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 cd_dir = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 writepid = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 up_script = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 down_script = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 down_pre = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 up_restart = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 up_delay = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 daemon = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 inetd = 0
Tue Nov 08 10:55:51 2011 us=453000 log = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 suppress_timestamps = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 nice = 0
Tue Nov 08 10:55:51 2011 us=453000 verbosity = 5
Tue Nov 08 10:55:51 2011 us=453000 mute = 0
Tue Nov 08 10:55:51 2011 us=453000 gremlin = 0
Tue Nov 08 10:55:51 2011 us=453000 status_file = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 status_file_version = 1
Tue Nov 08 10:55:51 2011 us=453000 status_file_update_freq = 60
Tue Nov 08 10:55:51 2011 us=453000 occ = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 rcvbuf = 100000
Tue Nov 08 10:55:51 2011 us=453000 sndbuf = 100000
Tue Nov 08 10:55:51 2011 us=453000 sockflags = 0
Tue Nov 08 10:55:51 2011 us=453000 fast_io = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 lzo = 1
Tue Nov 08 10:55:51 2011 us=453000 route_script = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 route_default_gateway = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 route_default_metric = 0
Tue Nov 08 10:55:51 2011 us=453000 route_noexec = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 route_delay = 5
Tue Nov 08 10:55:51 2011 us=453000 route_delay_window = 30
Tue Nov 08 10:55:51 2011 us=453000 route_delay_defined = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 route_nopull = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 route_gateway_via_dhcp = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 max_routes = 100
Tue Nov 08 10:55:51 2011 us=453000 allow_pull_fqdn = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 management_addr = '127.0.0.1'
Tue Nov 08 10:55:51 2011 us=453000 management_port = 48110
Tue Nov 08 10:55:51 2011 us=453000 management_user_pass = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 management_log_history_cache = 250
Tue Nov 08 10:55:51 2011 us=453000 management_echo_buffer_size = 100
Tue Nov 08 10:55:51 2011 us=453000 management_write_peer_info_file = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 management_client_user = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 management_client_group = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 management_flags = 38
Tue Nov 08 10:55:51 2011 us=453000 shared_secret_file = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 key_direction = 2
Tue Nov 08 10:55:51 2011 us=453000 ciphername_defined = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 ciphername = 'BF-CBC'
Tue Nov 08 10:55:51 2011 us=453000 authname_defined = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 authname = 'SHA1'
Tue Nov 08 10:55:51 2011 us=453000 prng_hash = 'SHA1'
Tue Nov 08 10:55:51 2011 us=453000 prng_nonce_secret_len = 16
Tue Nov 08 10:55:51 2011 us=453000 keysize = 0
Tue Nov 08 10:55:51 2011 us=453000 engine = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 replay = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 mute_replay_warnings = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 replay_window = 64
Tue Nov 08 10:55:51 2011 us=453000 replay_time = 15
Tue Nov 08 10:55:51 2011 us=453000 packet_id_file = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 use_iv = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 test_crypto = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 tls_server = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 tls_client = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 key_method = 2
Tue Nov 08 10:55:51 2011 us=453000 ca_file = '[[INLINE]]'
Tue Nov 08 10:55:51 2011 us=453000 ca_path = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 dh_file = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 cert_file = '[[INLINE]]'
Tue Nov 08 10:55:51 2011 us=453000 priv_key_file = '[[INLINE]]'
Tue Nov 08 10:55:51 2011 us=453000 pkcs12_file = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 cryptoapi_cert = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 cipher_list = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 tls_verify = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 tls_remote = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 crl_file = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 ns_cert_type = 64
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku[i] = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku[i] = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku[i] = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku[i] = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku[i] = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_ku[i] = 0
Tue Nov 08 10:55:51 2011 us=453000 remote_cert_eku = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 tls_timeout = 2
Tue Nov 08 10:55:51 2011 us=453000 renegotiate_bytes = 0
Tue Nov 08 10:55:51 2011 us=453000 renegotiate_packets = 0
Tue Nov 08 10:55:51 2011 us=453000 renegotiate_seconds = 604800
Tue Nov 08 10:55:51 2011 us=453000 handshake_window = 60
Tue Nov 08 10:55:51 2011 us=453000 transition_window = 3600
Tue Nov 08 10:55:51 2011 us=453000 single_session = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 push_peer_info = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 tls_exit = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 tls_auth_file = '[[INLINE]]'
Tue Nov 08 10:55:51 2011 us=453000 client = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 pull = ENABLED
Tue Nov 08 10:55:51 2011 us=453000 auth_user_pass_file = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 show_net_up = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 route_method = 0
Tue Nov 08 10:55:51 2011 us=453000 ip_win32_defined = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 ip_win32_type = 3
Tue Nov 08 10:55:51 2011 us=453000 dhcp_masq_offset = 0
Tue Nov 08 10:55:51 2011 us=453000 dhcp_lease_time = 31536000
Tue Nov 08 10:55:51 2011 us=453000 tap_sleep = 0
Tue Nov 08 10:55:51 2011 us=453000 dhcp_options = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 dhcp_renew = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 dhcp_pre_release = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 dhcp_release = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 domain = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 netbios_scope = '[UNDEF]'
Tue Nov 08 10:55:51 2011 us=453000 netbios_node_type = 0
Tue Nov 08 10:55:51 2011 us=453000 disable_nbt = DISABLED
Tue Nov 08 10:55:51 2011 us=453000 OpenVPNAS 2.1.1oOAS Win32-MSVC++ [SSL] [LZO2] built on Jul 29 2010
Tue Nov 08 10:55:51 2011 us=453000 MANAGEMENT: Connected to management server at 127.0.0.1:48110
Tue Nov 08 10:55:51 2011 us=453000 MANAGEMENT: CMD 'log on'
Tue Nov 08 10:55:51 2011 us=453000 MANAGEMENT: CMD 'state on'
Tue Nov 08 10:55:51 2011 us=453000 MANAGEMENT: CMD 'echo on'
Tue Nov 08 10:55:51 2011 us=453000 MANAGEMENT: CMD 'bytecount 5'
Tue Nov 08 10:55:51 2011 us=453000 MANAGEMENT: CMD 'hold off'
Tue Nov 08 10:55:51 2011 us=453000 MANAGEMENT: CMD 'hold release'
Tue Nov 08 10:55:51 2011 us=453000 NOTE: OpenVPNAS 2.1 requires '--script-security 2' or higher to call user-defined

scripts or executables
Tue Nov 08 10:55:51 2011 us=546000 Control Channel Authentication: tls-auth using INLINE static key file
Tue Nov 08 10:55:51 2011 us=546000 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for

HMAC authentication
Tue Nov 08 10:55:51 2011 us=546000 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for

HMAC authentication
Tue Nov 08 10:55:51 2011 us=546000 LZO compression initialized
Tue Nov 08 10:55:51 2011 us=546000 Control Channel MTU parms [ L:1544 D:168 EF:68 EB:0 ET:0 EL:0 ]
Tue Nov 08 10:55:51 2011 us=546000 Socket Buffers: R=[8192->100000] S=[8192->100000]
Tue Nov 08 10:55:51 2011 us=546000 MANAGEMENT: >STATE:1320774951,RESOLVE,,,
Tue Nov 08 10:55:51 2011 us=562000 Data Channel MTU parms [ L:1544 D:1450 EF:44 EB:135 ET:0 EL:0 AF:3/1 ]
Tue Nov 08 10:55:51 2011 us=562000 Local Options String: 'V4,dev-type tun,link-mtu 1544,tun-mtu 1500,proto

TCPv4_CLIENT,comp-lzo,keydir 1,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-client'
Tue Nov 08 10:55:51 2011 us=562000 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1544,tun-mtu 1500,proto

TCPv4_SERVER,comp-lzo,keydir 0,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-server'
Tue Nov 08 10:55:51 2011 us=562000 Local Options hash (VER=V4): 'ee93268d'
Tue Nov 08 10:55:51 2011 us=562000 Expected Remote Options hash (VER=V4): 'bd577cd1'
Tue Nov 08 10:55:51 2011 us=562000 Attempting to establish TCP connection with 67.211.x.x:443
Tue Nov 08 10:55:51 2011 us=562000 MANAGEMENT: >STATE:1320774951,TCP_CONNECT,,,
Tue Nov 08 10:55:51 2011 us=640000 TCP connection established with 67.211.x.x:443
Tue Nov 08 10:55:51 2011 us=640000 TCPv4_CLIENT link local: [undef]
Tue Nov 08 10:55:51 2011 us=640000 TCPv4_CLIENT link remote: 67.211.x.x:443
Tue Nov 08 10:55:51 2011 us=640000 MANAGEMENT: >STATE:1320774951,WAIT,,,
Tue Nov 08 10:55:51 2011 us=734000 MANAGEMENT: >STATE:1320774951,AUTH,,,
Tue Nov 08 10:55:51 2011 us=734000 TLS: Initial packet from 67.211.x.x:443, sid=fc905f12 2d2c142e
Tue Nov 08 10:55:52 2011 us=203000 VERIFY OK: depth=1, /CN=OpenVPN_CA
Tue Nov 08 10:55:52 2011 us=203000 VERIFY OK: nsCertType=SERVER
Tue Nov 08 10:55:52 2011 us=203000 VERIFY OK: depth=0, /CN=OpenVPN_Server
Tue Nov 08 10:55:53 2011 us=265000 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Nov 08 10:55:53 2011 us=265000 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Nov 08 10:55:53 2011 us=265000 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Nov 08 10:55:53 2011 us=265000 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Nov 08 10:55:53 2011 us=265000 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Nov 08 10:55:53 2011 us=265000 [OpenVPN_Server] Peer Connection Initiated with 67.211.x.x:443
Tue Nov 08 10:55:54 2011 us=421000 MANAGEMENT: >STATE:1320774954,GET_CONFIG,,,
Tue Nov 08 10:55:55 2011 us=578000 SENT CONTROL [OpenVPN_Server]: 'PUSH_REQUEST' (status=1)
Tue Nov 08 10:55:55 2011 us=765000 PUSH: Received control message: 'PUSH_REPLY,explicit-exit-notify,topology

subnet,route-delay 5 30,dhcp-pre-release,dhcp-renew,dhcp-release,route-metric 101,ping 5,ping-restart

40,socket-flags TCP_NODELAY,redirect-private local,redirect-private bypass-dhcp,redirect-private

bypass-dns,route-gateway 5.5.0.1,route 10.200.x.0 255.255.255.0,route 172.x.x.0 255.255.255.0,comp-lzo yes,ifconfig

5.5.x.x 255.255.240.0'
Tue Nov 08 10:55:55 2011 us=765000 OPTIONS IMPORT: timers and/or timeouts modified
Tue Nov 08 10:55:55 2011 us=765000 OPTIONS IMPORT: --explicit-exit-notify can only be used with --proto udp
Tue Nov 08 10:55:55 2011 us=765000 OPTIONS IMPORT: LZO parms modified
Tue Nov 08 10:55:55 2011 us=765000 OPTIONS IMPORT: --socket-flags option modified
Tue Nov 08 10:55:55 2011 us=765000 Socket flags: TCP_NODELAY=1 succeeded
Tue Nov 08 10:55:55 2011 us=765000 OPTIONS IMPORT: --ifconfig/up options modified
Tue Nov 08 10:55:55 2011 us=765000 OPTIONS IMPORT: route options modified
Tue Nov 08 10:55:55 2011 us=765000 OPTIONS IMPORT: route-related options modified
Tue Nov 08 10:55:55 2011 us=765000 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Tue Nov 08 10:55:55 2011 us=765000 ROUTE default_gateway=132.x.x.254
Tue Nov 08 10:55:55 2011 us=765000 ROUTE: bypass_host_route[0]=132.x.x.251
Tue Nov 08 10:55:55 2011 us=765000 ROUTE: bypass_host_route[1]=132.x.x.2
Tue Nov 08 10:55:55 2011 us=765000 ROUTE: bypass_host_route[2]=132.x.x.4
Tue Nov 08 10:55:55 2011 us=765000 MANAGEMENT: >STATE:1320774955,ASSIGN_IP,,5.5.x.x,
Tue Nov 08 10:55:55 2011 us=765000 TAP-WIN32 device [Open-VPN] opened:

\\.\Global\{37ED3FF9-8190-448C-BF87-837ED0B5D0ED}.tap
Tue Nov 08 10:55:55 2011 us=765000 TAP-Win32 Driver Version 9.7
Tue Nov 08 10:55:55 2011 us=765000 TAP-Win32 MTU=1500
Tue Nov 08 10:55:55 2011 us=765000 Set TAP-Win32 TUN subnet mode network/local/netmask =

5.5.0.0/5.5.6.30/255.255.240.0 [SUCCEEDED]
Tue Nov 08 10:55:55 2011 us=765000 Notified TAP-Win32 driver to set a DHCP IP/netmask of 5.5.x.x/255.255.240.0 on

interface {37ED3FF9-8190-448C-BF87-837ED0B5D0ED} [DHCP-serv: 5.5.x.254, lease-time: 31536000]
Tue Nov 08 10:55:55 2011 us=765000 Successful ARP Flush on interface [3] {37ED3FF9-8190-448C-BF87-837ED0B5D0ED}
Tue Nov 08 10:55:55 2011 us=765000 NOTE: Release of DHCP-assigned IP address lease on TAP-Win32 adapter failed: The

system cannot find the file specified. (code=2)
Tue Nov 08 10:55:55 2011 us=765000 WARNING: Failed to renew DHCP IP address lease on TAP-Win32 adapter: The system

cannot find the file specified. (code=2)
Tue Nov 08 10:56:00 2011 TEST ROUTES: 3/3 succeeded len=2 ret=1 a=0 u/d=up
Tue Nov 08 10:56:00 2011 C:\WINDOWS\system32\route.exe ADD 132.x.x.251 MASK 255.255.255.255 132.x.x.254
Tue Nov 08 10:56:00 2011 Route addition via IPAPI succeeded [adaptive]
Tue Nov 08 10:56:00 2011 C:\WINDOWS\system32\route.exe ADD 132.x.x.2 MASK 255.255.255.255 132.x.x.254
Tue Nov 08 10:56:00 2011 Route addition via IPAPI succeeded [adaptive]
Tue Nov 08 10:56:00 2011 C:\WINDOWS\system32\route.exe ADD 132.x.x.4 MASK 255.255.255.255 132.x.x.254
Tue Nov 08 10:56:00 2011 Route addition via IPAPI succeeded [adaptive]
Tue Nov 08 10:56:00 2011 MANAGEMENT: >STATE:1320774960,ADD_ROUTES,,,
Tue Nov 08 10:56:00 2011 C:\WINDOWS\system32\route.exe ADD 10.200.x.0 MASK 255.255.255.0 5.5.0.1 METRIC 101
Tue Nov 08 10:56:00 2011 Route addition via IPAPI succeeded [adaptive]
Tue Nov 08 10:56:00 2011 C:\WINDOWS\system32\route.exe ADD 172.x.x.0 MASK 255.255.255.0 5.5.0.1 METRIC 101
Tue Nov 08 10:56:00 2011 Route addition via IPAPI succeeded [adaptive]
Tue Nov 08 10:56:00 2011 Initialization Sequence Completed
Tue Nov 08 10:56:00 2011 MANAGEMENT: >STATE:1320774960,CONNECTED,SUCCESS,5.5.x.x,67.211.x.x
Tue Nov 08 11:00:19 2011 us=31000 MANAGEMENT: CMD 'exit'
Tue Nov 08 11:00:19 2011 us=31000 MANAGEMENT: Client disconnected
Tue Nov 08 11:00:19 2011 us=31000 MANAGEMENT: Triggering management exit
Tue Nov 08 11:00:19 2011 us=31000 TCP/UDP: Closing socket
Tue Nov 08 11:00:19 2011 us=31000 C:\WINDOWS\system32\route.exe DELETE 172.x.x.0 MASK 255.255.255.0 5.5.0.1
Tue Nov 08 11:00:19 2011 us=46000 ROUTE: route deletion failed using DeleteIpForwardEntry: The parameter is

incorrect.
Tue Nov 08 11:00:19 2011 us=46000 Route deletion via IPAPI failed [adaptive]
Tue Nov 08 11:00:19 2011 us=46000 Route deletion fallback to route.exe
The route specified was not found.
Tue Nov 08 11:00:19 2011 us=78000 C:\WINDOWS\system32\route.exe DELETE 10.200.x.0 MASK 255.255.255.0 5.5.0.1
Tue Nov 08 11:00:19 2011 us=78000 ROUTE: route deletion failed using DeleteIpForwardEntry: The parameter is

incorrect.
Tue Nov 08 11:00:19 2011 us=78000 Route deletion via IPAPI failed [adaptive]
Tue Nov 08 11:00:19 2011 us=78000 Route deletion fallback to route.exe
The route specified was not found.
Tue Nov 08 11:00:19 2011 us=109000 C:\WINDOWS\system32\route.exe DELETE 132.x.x.251 MASK 255.255.255.255 132.x.x.254
Tue Nov 08 11:00:19 2011 us=109000 Route deletion via IPAPI succeeded [adaptive]
Tue Nov 08 11:00:19 2011 us=109000 C:\WINDOWS\system32\route.exe DELETE 132.x.x.2 MASK 255.255.255.255 132.x.x.254
Tue Nov 08 11:00:19 2011 us=109000 Route deletion via IPAPI succeeded [adaptive]
Tue Nov 08 11:00:19 2011 us=109000 C:\WINDOWS\system32\route.exe DELETE 132.x.x.4 MASK 255.255.255.255 132.x.x.254
Tue Nov 08 11:00:19 2011 us=109000 Route deletion via IPAPI succeeded [adaptive]
Tue Nov 08 11:00:19 2011 us=109000 Closing TUN/TAP interface
Tue Nov 08 11:00:19 2011 us=125000 TAP: DHCP address released
Tue Nov 08 11:00:19 2011 us=125000 SIGTERM[soft,management-exit] received, process exiting
Tue Nov 08 11:00:19 2011 us=125000 MANAGEMENT: >STATE:1320775219,EXITING,management-exit,,
WRWWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWWWWRWRWRWRWRWRWRWRWRWRRRRWRWRWRWRWRWRWWWWRWRRRRRRWWWRRWRWRRWWRWRWRWWRRWWRWRWRWRRWW

RWRRWRWWRRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWRWWRWRWRRWWRWRWRWRWRWRWRWRWRWRWRWRWRWRWR

frankgtl

[Edited by FrankGTL]

janjust

the connection log looks OK but I don't see any traffic after the connection has come up:

Tue Nov 08 10:56:00 2011 Initialization Sequence Completed
[...]
Tue Nov 08 11:00:19 2011 us=31000 MANAGEMENT: CMD 'exit'

did you kill the openvpn connection after 4 minutes?
is there a firewall blocking access to/from the tap-win32 adapter?

frankgtl

That's exactly what happens. The traffic dies as soon as the connection is made and the IP is received.
I've disabled the local firewall and the company firewall allows for the traffic. I have it working on other machines, just not the ones with SP3.

frankgtl

Found what was happening but not Why
Found a temp fix, now looking for a perm solution.

What is happening is; the route to my 10.200.x.x and 172.x.x.x routes with a metric of 101 are being deleted for an unknown reason.

Temp fix: add these routes manually after the client closes them seems to work.

Now we just need to figure out why the routes are closing ... going to change the metric down to 30 to see if that's the issue.

frankgtl

Looks like there is a vendor specific bug in SP3
this article address dhcp and drops
applying this fix fixed my issues
http://support.microsoft.com/kb/953761/en-us

janjust

Sweet! I'm locking this topic and will bookmark it for future reference.
thanks for sharing your solution