Strange drop out issues

thomasw

Hi,

Firstly thanks in advance for any help, this has been driving me crazy for months and becoming a big problem for me.

As background I have a number of clients with Windows 2008/2008 R2/2012 servers with OpenVPN server installed with a pretty standard config we use, pretty typical setup I think. We also run a external script to authenticate against AD but I don't think that is relevant. We also have OpenVPN User Manager from Mertech installed on the servers though again I don't think it is relevant (it isn't always open on the servers either). All other servers we run with OpenVPN have the same basic setup and are running fine and have for some time.

But with one particular client we recently have a latency/packet loss issue. It isn't constant, and it is only when certain users connect.
So for example we have some 20 or more users using the VPN during the working day and it is fine, no issues at all.
But we first noticed it when a different person kept trying to work from home after hours (they don't use it during hours). I can be connected fine from my own home and pinging through the VPN with no issues, but when that user connects it starts a cyclic process where every 3 minutes and 20 seconds (approximately but consistent) we will see a high ping or two (as in 1000-2000ms) then a few dropped pings, then it comes back again within 10-20 seconds, and then is perfect for another another 3 minutes and 20 seconds and does it again. I'm not certain if all PCs have the same interval - i have seen it far more frequently but I think it was when multiple problem users were connected. There is nothing different showing in the VPN status window. The big problem is that it doesn't just affect pinging through his VPN, it affects everyone using it on that server, so me pinging from my PC drops out as well as the problem user and any other users connected at the time. It isn't just pings either - they access a terminal server which drops out so it is all traffic.
I have tried pinging our OpenVPN IP for the server (192.168.216.1) as well as the normal IP of the server (10.8.1.7) and anything else on the network and get the same result.

We mostly use the EnableIPRouting registry change on servers to do the routing and I have that setup on this server, though we also have some servers using routing and remote access to do the routing. Anyway the issue does not seem to be with routing traffic on the server but that it delays traffic/drops traffic for short periods of time at specific intervals.

Note that this whole time I am pinging through to their internet connection and it is fine, and PRTG shows no congestion, etc. I also am leaving a ping going out from their server to the internet with no issues and rarely over 20ms, and they do have a high grade SHDSL line so I am sure there is no issue there. It also doesn't make sense given it only happens when certain users connect and it does it on a timed cycle.

I saw last night when a second problem user connected the traffic would drop far more frequently, maybe every 30-60 seconds. I'm not sure if that was the combination of both users causing a problem, or because that second user causes the issue more frequently than every 3:20, as I was not able to test with just that second user connected.

Is there something that happens with OpenVPN every few minutes? or could it somehow be something external?
But it seems like it is something slowing it down which sometimes is to the extent that it drops packets.

I have removed the antivirus (Kaspersky) from the PC and there isn't any on the server. I have also installed OpenVPN on another server there, copied across the OpenVPN config, etc and had users connect to that with the same effect. Some of the users laptops have been around for a while and some are quite new, all with Windows 7 64bit.

I'd really appreciate any help

This is my server config:

management 10.8.1.7 5423 pass.txt
proto udp
dev tun
ca ca.crt
cert server.crt
key server.key  # This file should be kept secret
dh dh1024.pem
server 192.168.216.0 255.255.255.0
ifconfig-pool-persist ipp.txt
push "route 10.8.1.0 255.255.255.0"
push "dhcp-option DNS 10.8.1.6"
push "dhcp-option DOMAIN client.local"
duplicate-cn
keepalive 10 60
comp-lzo
persist-key
persist-tun
status openvpn-status.log
verb 3
mute 20
--script-security 3
auth-user-pass-verify "C:/Windows/System32/cscript.exe ovpn-auth-ldap.vbs" via-env

Client Config:

	
client
    dev tun
    proto udp
    remote clientdomain.com 80 
    resolv-retry infinite
    nobind
    persist-key
    persist-tun
    ca ca.crt
    cert xxxx.crt
    key xxxx.key
    ns-cert-type server
    comp-lzo
    verb 1
    explicit-exit-notify 2
    ping 10
   ping-restart 60
route-method exe
route-delay 2
auth-user-pass
auth-retry interact

Traffic

Can you post server and client logs at the time of the problem .. (verb 4)

thomasw

No problem. I restarted the OpenVPN service on the server, and connected a client which seems to be making it drop more often than it is up, gave it a few minutes where it worked for a bit and failed for a bit and the logs are below.
FYI this user/PC will do maybe 10-15 pings fine in a row then drop for at least 30, maybe 60 seconds and come back, etc. So it is off more than it works.

I tried disabling compression just now too but it didn't help.
Also I realised when posting these logs that clients version was a little old, so I updated it and the TAP driver to the latest but it hasn't changed the problem.

Also I found if I login to this users laptop as a local administrator it works fine. Note that the user is a local admin anyway, on a domain account, so the point may be more that it is a different profile. But I've disabled everything I can find in user specific startup locations, removed their network drives, and it doesn't help either.
I then created a new local user and it also does not have the problem.
I can try recreating the users profile but I don't have time right now. But I'd really like to know what the problem is anyway rather than working around it as I have a few users with the problem, and I need to know it won't reoccur again.

I do seem to get a single "MULTI: bad source address from client [::], packet dropped" after connecting but that's it. It happens when this user connects or I connect from my PC, which doesn't have the problem so I'm not sure if it is relevant or not.

Server log:

Sun May 17 20:57:46 2015 us=853600 Current Parameter Settings:
Sun May 17 20:57:46 2015 us=854600   config = 'server.ovpn'
Sun May 17 20:57:46 2015 us=854600   mode = 1
Sun May 17 20:57:46 2015 us=854600   show_ciphers = DISABLED
Sun May 17 20:57:46 2015 us=854600   show_digests = DISABLED
Sun May 17 20:57:46 2015 us=854600   show_engines = DISABLED
Sun May 17 20:57:46 2015 us=854600   genkey = DISABLED
Sun May 17 20:57:46 2015 us=854600   key_pass_file = '[UNDEF]'
Sun May 17 20:57:46 2015 us=854600   show_tls_ciphers = DISABLED
Sun May 17 20:57:46 2015 us=854600 Connection profiles [default]:
Sun May 17 20:57:46 2015 us=854600   proto = udp
Sun May 17 20:57:46 2015 us=854600   local = '[UNDEF]'
Sun May 17 20:57:46 2015 us=854600   local_port = 11955
Sun May 17 20:57:46 2015 us=854600   remote = '[UNDEF]'
Sun May 17 20:57:46 2015 us=854600   remote_port = 11955
Sun May 17 20:57:46 2015 us=854600   remote_float = DISABLED
Sun May 17 20:57:46 2015 us=854600   bind_defined = DISABLED
Sun May 17 20:57:46 2015 us=854600   bind_local = ENABLED
Sun May 17 20:57:46 2015 us=854600   connect_retry_seconds = 5
Sun May 17 20:57:46 2015 us=854600   connect_timeout = 10
Sun May 17 20:57:46 2015 us=854600 NOTE: --mute triggered...
Sun May 17 20:57:46 2015 us=854600 273 variation(s) on previous 20 message(s) suppressed by --mute
Sun May 17 20:57:46 2015 us=854600 OpenVPN 2.3.6 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [PKCS11] [IPv6] built on Mar 19 2015
Sun May 17 20:57:46 2015 us=854600 library versions: OpenSSL 1.0.1m 19 Mar 2015, LZO 2.08
Sun May 17 20:57:46 2015 us=855600 MANAGEMENT: TCP Socket listening on [AF_INET]10.8.1.6:6423
Sun May 17 20:57:46 2015 us=855600 WARNING: --ifconfig-pool-persist will not work with --duplicate-cn
Sun May 17 20:57:46 2015 us=856600 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Sun May 17 20:57:46 2015 us=989600 Diffie-Hellman initialized with 1024 bit key
Sun May 17 20:57:46 2015 us=989600 TLS-Auth MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Sun May 17 20:57:46 2015 us=989600 Socket Buffers: R=[8192->8192] S=[8192->8192]
Sun May 17 20:57:46 2015 us=991600 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Sun May 17 20:57:46 2015 us=991600 open_tun, tt->ipv6=0
Sun May 17 20:57:46 2015 us=991600 TAP-WIN32 device [Local Area Connection 3] opened: \\.\Global\{5FB3B95E-46B8-482F-9CCD-66EA020DA306}.tap
Sun May 17 20:57:46 2015 us=991600 TAP-Windows Driver Version 9.21 
Sun May 17 20:57:46 2015 us=991600 TAP-Windows MTU=1500
Sun May 17 20:57:46 2015 us=992600 Notified TAP-Windows driver to set a DHCP IP/netmask of 192.168.217.1/255.255.255.252 on interface {5FB3B95E-46B8-482F-9CCD-66EA020DA306} [DHCP-serv: 192.168.217.2, lease-time: 31536000]
Sun May 17 20:57:46 2015 us=992600 Sleeping for 10 seconds...
Sun May 17 20:57:56 2015 us=992600 Successful ARP Flush on interface [14] {5FB3B95E-46B8-482F-9CCD-66EA020DA306}
Sun May 17 20:57:56 2015 us=993600 C:\Windows\system32\route.exe ADD 192.168.217.0 MASK 255.255.255.0 192.168.217.2
Sun May 17 20:57:56 2015 us=994600 ROUTE: CreateIpForwardEntry succeeded with dwForwardMetric1=20 and dwForwardType=4
Sun May 17 20:57:56 2015 us=994600 Route addition via IPAPI succeeded [adaptive]
Sun May 17 20:57:56 2015 us=994600 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Sun May 17 20:57:56 2015 us=994600 UDPv4 link local (bound): [undef]
Sun May 17 20:57:56 2015 us=994600 UDPv4 link remote: [undef]
Sun May 17 20:57:56 2015 us=994600 MULTI: multi_init called, r=256 v=256
Sun May 17 20:57:56 2015 us=994600 IFCONFIG POOL: base=192.168.217.4 size=62, ipv6=0
Sun May 17 20:57:56 2015 us=994600 IFCONFIG POOL LIST
Sun May 17 20:57:56 2015 us=994600 Initialization Sequence Completed
Sun May 17 20:58:17 2015 us=763600 MULTI: multi_create_instance called
Sun May 17 20:58:17 2015 us=763600 101.185.19.253:65507 Re-using SSL/TLS context
Sun May 17 20:58:17 2015 us=763600 101.185.19.253:65507 LZO compression initialized
Sun May 17 20:58:17 2015 us=763600 101.185.19.253:65507 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Sun May 17 20:58:17 2015 us=763600 101.185.19.253:65507 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Sun May 17 20:58:17 2015 us=763600 101.185.19.253:65507 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'
Sun May 17 20:58:17 2015 us=763600 101.185.19.253:65507 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'
Sun May 17 20:58:17 2015 us=763600 101.185.19.253:65507 Local Options hash (VER=V4): '530fdded'
Sun May 17 20:58:17 2015 us=763600 101.185.19.253:65507 Expected Remote Options hash (VER=V4): '41690919'
Sun May 17 20:58:17 2015 us=763600 101.185.19.253:65507 TLS: Initial packet from [AF_INET]101.185.19.253:65507, sid=73f2b926 4239ae8e
Sun May 17 20:58:19 2015 us=4600 101.185.19.253:65507 VERIFY OK: depth=1, C=AU, ST=SA, L=Adelaide, O=WSP, OU=office, CN=server, name=server, emailAddress=thomas@weknowit.com.au
Sun May 17 20:58:19 2015 us=4600 101.185.19.253:65507 VERIFY OK: depth=0, C=AU, ST=SA, L=Adelaide, O=WSP, OU=office, CN=pralston, name=pralston, emailAddress=thomas@weknowit.com.au
Sun May 17 20:58:19 2015 us=69600 101.185.19.253:65507 env_block: add PATH=C:\Windows\System32;C:\WINDOWS;C:\WINDOWS\System32\Wbem
Sun May 17 20:58:19 2015 us=649600 101.185.19.253:65507 TLS: Username/Password authentication succeeded for username 'wkit' 
Sun May 17 20:58:19 2015 us=649600 101.185.19.253:65507 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Sun May 17 20:58:19 2015 us=649600 101.185.19.253:65507 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Sun May 17 20:58:19 2015 us=649600 101.185.19.253:65507 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Sun May 17 20:58:19 2015 us=649600 101.185.19.253:65507 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Sun May 17 20:58:19 2015 us=854600 101.185.19.253:65507 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Sun May 17 20:58:19 2015 us=854600 101.185.19.253:65507 [pralston] Peer Connection Initiated with [AF_INET]101.185.19.253:65507
Sun May 17 20:58:19 2015 us=854600 pralston/101.185.19.253:65507 MULTI_sva: pool returned IPv4=192.168.217.6, IPv6=(Not enabled)
Sun May 17 20:58:19 2015 us=854600 pralston/101.185.19.253:65507 MULTI: Learn: 192.168.217.6 -> pralston/101.185.19.253:65507
Sun May 17 20:58:19 2015 us=854600 pralston/101.185.19.253:65507 MULTI: primary virtual IP for pralston/101.185.19.253:65507: 192.168.217.6
Sun May 17 20:58:22 2015 us=379600 pralston/101.185.19.253:65507 PUSH: Received control message: 'PUSH_REQUEST'
Sun May 17 20:58:22 2015 us=379600 pralston/101.185.19.253:65507 send_push_reply(): safe_cap=940
Sun May 17 20:58:22 2015 us=379600 pralston/101.185.19.253:65507 SENT CONTROL [pralston]: 'PUSH_REPLY,route 10.8.1.0 255.255.255.0,dhcp-option DNS 10.8.1.6,dhcp-option DOMAIN workspace.local,route 192.168.217.1,topology net30,ping 10,ping-restart 60,ifconfig 192.168.217.6 192.168.217.5' (status=1)
Sun May 17 20:58:22 2015 us=658600 pralston/101.185.19.253:65507 MULTI: bad source address from client [::], packet dropped

Client Log

Sun May 17 20:58:06 2015 us=645324 Current Parameter Settings:
Sun May 17 20:58:06 2015 us=646325   config = 'WSP VPN.ovpn'
Sun May 17 20:58:06 2015 us=646325   mode = 0
Sun May 17 20:58:06 2015 us=646325   show_ciphers = DISABLED
Sun May 17 20:58:06 2015 us=646325   show_digests = DISABLED
Sun May 17 20:58:06 2015 us=646325   show_engines = DISABLED
Sun May 17 20:58:06 2015 us=646325   genkey = DISABLED
Sun May 17 20:58:06 2015 us=646325   key_pass_file = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   show_tls_ciphers = DISABLED
Sun May 17 20:58:06 2015 us=646325 Connection profiles [default]:
Sun May 17 20:58:06 2015 us=646325   proto = udp
Sun May 17 20:58:06 2015 us=646325   local = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   local_port = 0
Sun May 17 20:58:06 2015 us=646325   remote = 'remote.workspace.com.au'
Sun May 17 20:58:06 2015 us=646325   remote_port = 11955
Sun May 17 20:58:06 2015 us=646325   remote_float = DISABLED
Sun May 17 20:58:06 2015 us=646325   bind_defined = DISABLED
Sun May 17 20:58:06 2015 us=646325   bind_local = DISABLED
Sun May 17 20:58:06 2015 us=646325   connect_retry_seconds = 5
Sun May 17 20:58:06 2015 us=646325   connect_timeout = 10
Sun May 17 20:58:06 2015 us=646325   connect_retry_max = 0
Sun May 17 20:58:06 2015 us=646325   socks_proxy_server = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   socks_proxy_port = 0
Sun May 17 20:58:06 2015 us=646325   socks_proxy_retry = DISABLED
Sun May 17 20:58:06 2015 us=646325   tun_mtu = 1500
Sun May 17 20:58:06 2015 us=646325   tun_mtu_defined = ENABLED
Sun May 17 20:58:06 2015 us=646325   link_mtu = 1500
Sun May 17 20:58:06 2015 us=646325   link_mtu_defined = DISABLED
Sun May 17 20:58:06 2015 us=646325   tun_mtu_extra = 0
Sun May 17 20:58:06 2015 us=646325   tun_mtu_extra_defined = DISABLED
Sun May 17 20:58:06 2015 us=646325   mtu_discover_type = -1
Sun May 17 20:58:06 2015 us=646325   fragment = 0
Sun May 17 20:58:06 2015 us=646325   mssfix = 1450
Sun May 17 20:58:06 2015 us=646325   explicit_exit_notification = 2
Sun May 17 20:58:06 2015 us=646325 Connection profiles END
Sun May 17 20:58:06 2015 us=646325   remote_random = DISABLED
Sun May 17 20:58:06 2015 us=646325   ipchange = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   dev = 'tun'
Sun May 17 20:58:06 2015 us=646325   dev_type = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   dev_node = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   lladdr = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   topology = 1
Sun May 17 20:58:06 2015 us=646325   tun_ipv6 = DISABLED
Sun May 17 20:58:06 2015 us=646325   ifconfig_local = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   ifconfig_remote_netmask = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   ifconfig_noexec = DISABLED
Sun May 17 20:58:06 2015 us=646325   ifconfig_nowarn = DISABLED
Sun May 17 20:58:06 2015 us=646325   ifconfig_ipv6_local = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   ifconfig_ipv6_netbits = 0
Sun May 17 20:58:06 2015 us=646325   ifconfig_ipv6_remote = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   shaper = 0
Sun May 17 20:58:06 2015 us=646325   mtu_test = 0
Sun May 17 20:58:06 2015 us=646325   mlock = DISABLED
Sun May 17 20:58:06 2015 us=646325   keepalive_ping = 0
Sun May 17 20:58:06 2015 us=646325   keepalive_timeout = 0
Sun May 17 20:58:06 2015 us=646325   inactivity_timeout = 0
Sun May 17 20:58:06 2015 us=646325   ping_send_timeout = 10
Sun May 17 20:58:06 2015 us=646325   ping_rec_timeout = 60
Sun May 17 20:58:06 2015 us=646325   ping_rec_timeout_action = 2
Sun May 17 20:58:06 2015 us=646325   ping_timer_remote = DISABLED
Sun May 17 20:58:06 2015 us=646325   remap_sigusr1 = 0
Sun May 17 20:58:06 2015 us=646325   persist_tun = ENABLED
Sun May 17 20:58:06 2015 us=646325   persist_local_ip = DISABLED
Sun May 17 20:58:06 2015 us=646325   persist_remote_ip = DISABLED
Sun May 17 20:58:06 2015 us=646325   persist_key = ENABLED
Sun May 17 20:58:06 2015 us=646325   passtos = DISABLED
Sun May 17 20:58:06 2015 us=646325   resolve_retry_seconds = 1000000000
Sun May 17 20:58:06 2015 us=646325   username = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   groupname = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   chroot_dir = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   cd_dir = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   writepid = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   up_script = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   down_script = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   down_pre = DISABLED
Sun May 17 20:58:06 2015 us=646325   up_restart = DISABLED
Sun May 17 20:58:06 2015 us=646325   up_delay = DISABLED
Sun May 17 20:58:06 2015 us=646325   daemon = DISABLED
Sun May 17 20:58:06 2015 us=646325   inetd = 0
Sun May 17 20:58:06 2015 us=646325   log = ENABLED
Sun May 17 20:58:06 2015 us=646325   suppress_timestamps = DISABLED
Sun May 17 20:58:06 2015 us=646325   nice = 0
Sun May 17 20:58:06 2015 us=646325   verbosity = 4
Sun May 17 20:58:06 2015 us=646325   mute = 0
Sun May 17 20:58:06 2015 us=646325   status_file = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   status_file_version = 1
Sun May 17 20:58:06 2015 us=646325   status_file_update_freq = 60
Sun May 17 20:58:06 2015 us=646325   occ = ENABLED
Sun May 17 20:58:06 2015 us=646325   rcvbuf = 0
Sun May 17 20:58:06 2015 us=646325   sndbuf = 0
Sun May 17 20:58:06 2015 us=646325   sockflags = 0
Sun May 17 20:58:06 2015 us=646325   fast_io = DISABLED
Sun May 17 20:58:06 2015 us=646325   lzo = 7
Sun May 17 20:58:06 2015 us=646325   route_script = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   route_default_gateway = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   route_default_metric = 0
Sun May 17 20:58:06 2015 us=646325   route_noexec = DISABLED
Sun May 17 20:58:06 2015 us=646325   route_delay = 2
Sun May 17 20:58:06 2015 us=646325   route_delay_window = 30
Sun May 17 20:58:06 2015 us=646325   route_delay_defined = ENABLED
Sun May 17 20:58:06 2015 us=646325   route_nopull = DISABLED
Sun May 17 20:58:06 2015 us=646325   route_gateway_via_dhcp = DISABLED
Sun May 17 20:58:06 2015 us=646325   max_routes = 100
Sun May 17 20:58:06 2015 us=646325   allow_pull_fqdn = DISABLED
Sun May 17 20:58:06 2015 us=646325   management_addr = '127.0.0.1'
Sun May 17 20:58:06 2015 us=646325   management_port = 25340
Sun May 17 20:58:06 2015 us=646325   management_user_pass = 'stdin'
Sun May 17 20:58:06 2015 us=646325   management_log_history_cache = 250
Sun May 17 20:58:06 2015 us=646325   management_echo_buffer_size = 100
Sun May 17 20:58:06 2015 us=646325   management_write_peer_info_file = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   management_client_user = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   management_client_group = '[UNDEF]'
Sun May 17 20:58:06 2015 us=646325   management_flags = 6
Sun May 17 20:58:06 2015 us=646325   shared_secret_file = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   key_direction = 0
Sun May 17 20:58:06 2015 us=647325   ciphername_defined = ENABLED
Sun May 17 20:58:06 2015 us=647325   ciphername = 'BF-CBC'
Sun May 17 20:58:06 2015 us=647325   authname_defined = ENABLED
Sun May 17 20:58:06 2015 us=647325   authname = 'SHA1'
Sun May 17 20:58:06 2015 us=647325   prng_hash = 'SHA1'
Sun May 17 20:58:06 2015 us=647325   prng_nonce_secret_len = 16
Sun May 17 20:58:06 2015 us=647325   keysize = 0
Sun May 17 20:58:06 2015 us=647325   engine = DISABLED
Sun May 17 20:58:06 2015 us=647325   replay = ENABLED
Sun May 17 20:58:06 2015 us=647325   mute_replay_warnings = DISABLED
Sun May 17 20:58:06 2015 us=647325   replay_window = 64
Sun May 17 20:58:06 2015 us=647325   replay_time = 15
Sun May 17 20:58:06 2015 us=647325   packet_id_file = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   use_iv = ENABLED
Sun May 17 20:58:06 2015 us=647325   test_crypto = DISABLED
Sun May 17 20:58:06 2015 us=647325   tls_server = DISABLED
Sun May 17 20:58:06 2015 us=647325   tls_client = ENABLED
Sun May 17 20:58:06 2015 us=647325   key_method = 2
Sun May 17 20:58:06 2015 us=647325   ca_file = 'ca.crt'
Sun May 17 20:58:06 2015 us=647325   ca_path = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   dh_file = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   cert_file = 'pralston.crt'
Sun May 17 20:58:06 2015 us=647325   priv_key_file = 'pralston.key'
Sun May 17 20:58:06 2015 us=647325   pkcs12_file = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   cryptoapi_cert = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   cipher_list = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   tls_verify = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   tls_export_cert = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   verify_x509_type = 0
Sun May 17 20:58:06 2015 us=647325   verify_x509_name = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   crl_file = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   ns_cert_type = 1
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_ku[i] = 0
Sun May 17 20:58:06 2015 us=647325   remote_cert_eku = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   ssl_flags = 0
Sun May 17 20:58:06 2015 us=647325   tls_timeout = 2
Sun May 17 20:58:06 2015 us=647325   renegotiate_bytes = 0
Sun May 17 20:58:06 2015 us=647325   renegotiate_packets = 0
Sun May 17 20:58:06 2015 us=647325   renegotiate_seconds = 3600
Sun May 17 20:58:06 2015 us=647325   handshake_window = 60
Sun May 17 20:58:06 2015 us=647325   transition_window = 3600
Sun May 17 20:58:06 2015 us=647325   single_session = DISABLED
Sun May 17 20:58:06 2015 us=647325   push_peer_info = DISABLED
Sun May 17 20:58:06 2015 us=647325   tls_exit = DISABLED
Sun May 17 20:58:06 2015 us=647325   tls_auth_file = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_protected_authentication = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_private_mode = 00000000
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_cert_private = DISABLED
Sun May 17 20:58:06 2015 us=647325   pkcs11_pin_cache_period = -1
Sun May 17 20:58:06 2015 us=647325   pkcs11_id = '[UNDEF]'
Sun May 17 20:58:06 2015 us=647325   pkcs11_id_management = DISABLED
Sun May 17 20:58:06 2015 us=647325   server_network = 0.0.0.0
Sun May 17 20:58:06 2015 us=647325   server_netmask = 0.0.0.0
Sun May 17 20:58:06 2015 us=648325   server_network_ipv6 = ::
Sun May 17 20:58:06 2015 us=648325   server_netbits_ipv6 = 0
Sun May 17 20:58:06 2015 us=648325   server_bridge_ip = 0.0.0.0
Sun May 17 20:58:06 2015 us=648325   server_bridge_netmask = 0.0.0.0
Sun May 17 20:58:06 2015 us=648325   server_bridge_pool_start = 0.0.0.0
Sun May 17 20:58:06 2015 us=648325   server_bridge_pool_end = 0.0.0.0
Sun May 17 20:58:06 2015 us=648325   ifconfig_pool_defined = DISABLED
Sun May 17 20:58:06 2015 us=648325   ifconfig_pool_start = 0.0.0.0
Sun May 17 20:58:06 2015 us=648325   ifconfig_pool_end = 0.0.0.0
Sun May 17 20:58:06 2015 us=648325   ifconfig_pool_netmask = 0.0.0.0
Sun May 17 20:58:06 2015 us=648325   ifconfig_pool_persist_filename = '[UNDEF]'
Sun May 17 20:58:06 2015 us=648325   ifconfig_pool_persist_refresh_freq = 600
Sun May 17 20:58:06 2015 us=648325   ifconfig_ipv6_pool_defined = DISABLED
Sun May 17 20:58:06 2015 us=648325   ifconfig_ipv6_pool_base = ::
Sun May 17 20:58:06 2015 us=648325   ifconfig_ipv6_pool_netbits = 0
Sun May 17 20:58:06 2015 us=648325   n_bcast_buf = 256
Sun May 17 20:58:06 2015 us=648325   tcp_queue_limit = 64
Sun May 17 20:58:06 2015 us=648325   real_hash_size = 256
Sun May 17 20:58:06 2015 us=648325   virtual_hash_size = 256
Sun May 17 20:58:06 2015 us=648325   client_connect_script = '[UNDEF]'
Sun May 17 20:58:06 2015 us=648325   learn_address_script = '[UNDEF]'
Sun May 17 20:58:06 2015 us=648325   client_disconnect_script = '[UNDEF]'
Sun May 17 20:58:06 2015 us=648325   client_config_dir = '[UNDEF]'
Sun May 17 20:58:06 2015 us=648325   ccd_exclusive = DISABLED
Sun May 17 20:58:06 2015 us=648325   tmp_dir = 'C:\Users\pralston\AppData\Local\Temp\'
Sun May 17 20:58:06 2015 us=648325   push_ifconfig_defined = DISABLED
Sun May 17 20:58:06 2015 us=648325   push_ifconfig_local = 0.0.0.0
Sun May 17 20:58:06 2015 us=648325   push_ifconfig_remote_netmask = 0.0.0.0
Sun May 17 20:58:06 2015 us=648325   push_ifconfig_ipv6_defined = DISABLED
Sun May 17 20:58:06 2015 us=648325   push_ifconfig_ipv6_local = ::/0
Sun May 17 20:58:06 2015 us=648325   push_ifconfig_ipv6_remote = ::
Sun May 17 20:58:06 2015 us=649326   enable_c2c = DISABLED
Sun May 17 20:58:06 2015 us=649326   duplicate_cn = DISABLED
Sun May 17 20:58:06 2015 us=649326   cf_max = 0
Sun May 17 20:58:06 2015 us=649326   cf_per = 0
Sun May 17 20:58:06 2015 us=649326   max_clients = 1024
Sun May 17 20:58:06 2015 us=649326   max_routes_per_client = 256
Sun May 17 20:58:06 2015 us=649326   auth_user_pass_verify_script = '[UNDEF]'
Sun May 17 20:58:06 2015 us=649326   auth_user_pass_verify_script_via_file = DISABLED
Sun May 17 20:58:06 2015 us=649326   client = ENABLED
Sun May 17 20:58:06 2015 us=649326   pull = ENABLED
Sun May 17 20:58:06 2015 us=649326   auth_user_pass_file = 'stdin'
Sun May 17 20:58:06 2015 us=649326   show_net_up = DISABLED
Sun May 17 20:58:06 2015 us=649326   route_method = 2
Sun May 17 20:58:06 2015 us=649326   ip_win32_defined = DISABLED
Sun May 17 20:58:06 2015 us=649326   ip_win32_type = 3
Sun May 17 20:58:06 2015 us=649326   dhcp_masq_offset = 0
Sun May 17 20:58:06 2015 us=649326   dhcp_lease_time = 31536000
Sun May 17 20:58:06 2015 us=649326   tap_sleep = 0
Sun May 17 20:58:06 2015 us=649326   dhcp_options = DISABLED
Sun May 17 20:58:06 2015 us=649326   dhcp_renew = DISABLED
Sun May 17 20:58:06 2015 us=649326   dhcp_pre_release = DISABLED
Sun May 17 20:58:06 2015 us=649326   dhcp_release = DISABLED
Sun May 17 20:58:06 2015 us=649326   domain = '[UNDEF]'
Sun May 17 20:58:06 2015 us=649326   netbios_scope = '[UNDEF]'
Sun May 17 20:58:06 2015 us=649326   netbios_node_type = 0
Sun May 17 20:58:06 2015 us=649326   disable_nbt = DISABLED
Sun May 17 20:58:06 2015 us=649326 OpenVPN 2.3.2 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [PKCS11] [eurephia] [IPv6] built on Aug 22 2013
Enter Management Password:
Sun May 17 20:58:06 2015 us=650326 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25340
Sun May 17 20:58:06 2015 us=650326 Need hold release from management interface, waiting...
Sun May 17 20:58:06 2015 us=847385 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25340
Sun May 17 20:58:06 2015 us=947415 MANAGEMENT: CMD 'state on'
Sun May 17 20:58:06 2015 us=947415 MANAGEMENT: CMD 'log all on'
Sun May 17 20:58:07 2015 us=21437 MANAGEMENT: CMD 'hold off'
Sun May 17 20:58:07 2015 us=23438 MANAGEMENT: CMD 'hold release'
Sun May 17 20:58:17 2015 us=503581 MANAGEMENT: CMD 'username "Auth" "wkit"'
Sun May 17 20:58:17 2015 us=507582 MANAGEMENT: CMD 'password [...]'
Sun May 17 20:58:17 2015 us=655626 LZO compression initialized
Sun May 17 20:58:17 2015 us=655626 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Sun May 17 20:58:17 2015 us=655626 Socket Buffers: R=[8192->8192] S=[8192->8192]
Sun May 17 20:58:17 2015 us=655626 MANAGEMENT: >STATE:1431862097,RESOLVE,,,
Sun May 17 20:58:17 2015 us=691637 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Sun May 17 20:58:17 2015 us=691637 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'
Sun May 17 20:58:17 2015 us=691637 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'
Sun May 17 20:58:17 2015 us=691637 Local Options hash (VER=V4): '41690919'
Sun May 17 20:58:17 2015 us=691637 Expected Remote Options hash (VER=V4): '530fdded'
Sun May 17 20:58:17 2015 us=691637 UDPv4 link local: [undef]
Sun May 17 20:58:17 2015 us=691637 UDPv4 link remote: [AF_INET]59.167.85.137:11955
Sun May 17 20:58:17 2015 us=691637 MANAGEMENT: >STATE:1431862097,WAIT,,,
Sun May 17 20:58:17 2015 us=724647 MANAGEMENT: >STATE:1431862097,AUTH,,,
Sun May 17 20:58:17 2015 us=724647 TLS: Initial packet from [AF_INET]59.167.85.137:11955, sid=1335580a b0173ffc
Sun May 17 20:58:17 2015 us=724647 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Sun May 17 20:58:18 2015 us=307822 VERIFY OK: depth=1, C=AU, ST=SA, L=Adelaide, O=WSP, OU=office, CN=server, name=server, emailAddress=thomas@weknowit.com.au
Sun May 17 20:58:18 2015 us=307822 VERIFY OK: nsCertType=SERVER
Sun May 17 20:58:18 2015 us=307822 VERIFY OK: depth=0, C=AU, ST=SA, L=Adelaide, O=WSP, OU=office, CN=server, name=server, emailAddress=thomas@weknowit.com.au
Sun May 17 20:58:19 2015 us=789266 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Sun May 17 20:58:19 2015 us=789266 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Sun May 17 20:58:19 2015 us=789266 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Sun May 17 20:58:19 2015 us=789266 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Sun May 17 20:58:19 2015 us=789266 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Sun May 17 20:58:19 2015 us=789266 [server] Peer Connection Initiated with [AF_INET]59.167.85.137:11955
Sun May 17 20:58:20 2015 us=979623 MANAGEMENT: >STATE:1431862100,GET_CONFIG,,,
Sun May 17 20:58:22 2015 us=169980 SENT CONTROL [server]: 'PUSH_REQUEST' (status=1)
Sun May 17 20:58:22 2015 us=345033 PUSH: Received control message: 'PUSH_REPLY,route 10.8.1.0 255.255.255.0,dhcp-option DNS 10.8.1.6,dhcp-option DOMAIN workspace.local,route 192.168.217.1,topology net30,ping 10,ping-restart 60,ifconfig 192.168.217.6 192.168.217.5'
Sun May 17 20:58:22 2015 us=345033 OPTIONS IMPORT: timers and/or timeouts modified
Sun May 17 20:58:22 2015 us=345033 OPTIONS IMPORT: --ifconfig/up options modified
Sun May 17 20:58:22 2015 us=345033 OPTIONS IMPORT: route options modified
Sun May 17 20:58:22 2015 us=345033 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Sun May 17 20:58:22 2015 us=349034 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Sun May 17 20:58:22 2015 us=349034 MANAGEMENT: >STATE:1431862102,ASSIGN_IP,,192.168.217.6,
Sun May 17 20:58:22 2015 us=349034 open_tun, tt->ipv6=0
Sun May 17 20:58:22 2015 us=350034 TAP-WIN32 device [Local Area Connection 2] opened: \\.\Global\{F45AB895-211E-452D-A501-A513575099E2}.tap
Sun May 17 20:58:22 2015 us=350034 TAP-Windows Driver Version 9.9 
Sun May 17 20:58:22 2015 us=350034 TAP-Windows MTU=1500
Sun May 17 20:58:22 2015 us=352035 Notified TAP-Windows driver to set a DHCP IP/netmask of 192.168.217.6/255.255.255.252 on interface {F45AB895-211E-452D-A501-A513575099E2} [DHCP-serv: 192.168.217.5, lease-time: 31536000]
Sun May 17 20:58:22 2015 us=352035 DHCP option string: 0f0f776f 726b7370 6163652e 6c6f6361 6c06040a 080106
Sun May 17 20:58:22 2015 us=352035 Successful ARP Flush on interface [20] {F45AB895-211E-452D-A501-A513575099E2}
Sun May 17 20:58:24 2015 us=36540 TEST ROUTES: 0/0 succeeded len=2 ret=0 a=0 u/d=down
Sun May 17 20:58:24 2015 us=36540 Route: Waiting for TUN/TAP interface to come up...
Sun May 17 20:58:26 2015 us=37140 TEST ROUTES: 0/0 succeeded len=2 ret=0 a=0 u/d=down
Sun May 17 20:58:26 2015 us=37140 Route: Waiting for TUN/TAP interface to come up...
Sun May 17 20:58:27 2015 us=37440 TEST ROUTES: 0/0 succeeded len=2 ret=0 a=0 u/d=down
Sun May 17 20:58:27 2015 us=37440 Route: Waiting for TUN/TAP interface to come up...
Sun May 17 20:58:28 2015 us=42742 TEST ROUTES: 0/0 succeeded len=2 ret=0 a=0 u/d=down
Sun May 17 20:58:28 2015 us=42742 Route: Waiting for TUN/TAP interface to come up...
Sun May 17 20:58:29 2015 us=410152 TEST ROUTES: 0/0 succeeded len=2 ret=0 a=0 u/d=down
Sun May 17 20:58:29 2015 us=410152 Route: Waiting for TUN/TAP interface to come up...
Sun May 17 20:58:30 2015 us=438460 TEST ROUTES: 2/2 succeeded len=2 ret=1 a=0 u/d=up
Sun May 17 20:58:30 2015 us=438460 MANAGEMENT: >STATE:1431862110,ADD_ROUTES,,,
Sun May 17 20:58:30 2015 us=438460 C:\Windows\system32\route.exe ADD 10.8.1.0 MASK 255.255.255.0 192.168.217.5
Sun May 17 20:58:30 2015 us=438460 env_block: add PATH=C:\Windows\System32;C:\WINDOWS;C:\WINDOWS\System32\Wbem
Sun May 17 20:58:30 2015 us=593507 C:\Windows\system32\route.exe ADD 192.168.217.1 MASK 255.255.255.255 192.168.217.5
Sun May 17 20:58:30 2015 us=593507 env_block: add PATH=C:\Windows\System32;C:\WINDOWS;C:\WINDOWS\System32\Wbem
Sun May 17 20:58:30 2015 us=662527 Initialization Sequence Completed
Sun May 17 20:58:30 2015 us=662527 MANAGEMENT: >STATE:1431862110,CONNECTED,SUCCESS,192.168.217.6,59.167.85.137

Traffic

You mean this right:

thomasw wroteSun May 17 20:58:22 2015 us=658600 pralston/101.185.19.253:65507 MULTI: bad source address from client [::], packet dropped

You can either ignore it or solve it.

Either way, it is of little consequence ..