OpenVPN routing problem

boginw

Hello forum, I have encountered some problems with my VPN setup. I have a setup with MySQL authentication which works, but whenever a user connects he can't connect anywhere.
OpenVPN log writes this

MULTI: bad source address from client [192.168.2.254], packet dropped

My server.conf looks like this.

port 1194
proto udp
dev tun

ca /etc/openvpn/easy-rsa/keys/ca.crt
cert /etc/openvpn/easy-rsa/keys/server.crt
key /etc/openvpn/easy-rsa/keys/server.key
dh /etc/openvpn/easy-rsa/keys/dh1024.pem

server 10.128.127.0 255.255.255.0
ifconfig-pool-persist ipp.txt

keepalive 10 120
comp-lzo
max-clients 50
persist-key
persist-tun

status openvpn-status.log
log-append /var/log/openvpn.log
verb 6
mute 20

client-cert-not-required
username-as-common-name

plugin /usr/lib/openvpn/openvpn-auth-pam.so openvpn

My iptable rules:

# Generated by iptables-save v1.4.14 on Sat May 10 14:08:16 2014
*mangle
:PREROUTING ACCEPT [0:0]
:INPUT ACCEPT [0:0]
:FORWARD ACCEPT [0:0]
:OUTPUT ACCEPT [0:0]
:POSTROUTING ACCEPT [0:0]
COMMIT
# Completed on Sat May 10 14:08:16 2014
# Generated by iptables-save v1.4.14 on Sat May 10 14:08:16 2014
*nat
:PREROUTING ACCEPT [0:0]
:INPUT ACCEPT [0:0]
:OUTPUT ACCEPT [0:0]
:POSTROUTING ACCEPT [0:0]
COMMIT
# Completed on Sat May 10 14:08:16 2014
# Generated by iptables-save v1.4.14 on Sat May 10 14:08:16 2014
*filter
:INPUT ACCEPT [0:0]
:FORWARD ACCEPT [0:0]
:OUTPUT ACCEPT [0:0]
COMMIT
# Completed on Sat May 10 14:08:16 2014

Any help will be greatly appreciated

maikcat

also post your client configs,

but whenever a user connects he can't connect anywhere.

also explain the above please...
what you test and its not working?

Michael.

numbersinmybrain

i am having the exact the same problem. I'll let you know if I come across the solution or any other alternative. This is my situation:https://forums.openvpn.net/topic15883.html

boginw

What I mean by, can't connect anywhere is that when connected, no traffic is routed through the VPN with the client.ovpn file. When I try the default Ubuntu Network Manager with OpenVPN as VPN and connect to the server, then it seems all traffic is being rejected or something like that.

Here's client.ovpn

client

dev tun

proto udp

remote 188.226.155.48 1194

resolv-retry infinite

nobind

persist-key
persist-tun

ca ca.crt

auth-user-pass

cipher BF-CBC

comp-lzo

verb 4

mute 20

numbersinmybrain

You should also post your log files if you can for the client and server. It will help better to figure out the problem.

boginw

Here's client log for connecting and while i'm loading Google

Mon May 19 17:32:23 2014 us=906572 event_wait : Interrupted system call (code=4)
Mon May 19 17:32:23 2014 us=907155 TCP/UDP: Closing socket
Mon May 19 17:32:23 2014 us=907318 /sbin/ip route del 10.128.127.1/32
Mon May 19 17:32:23 2014 us=910512 Closing TUN/TAP interface
Mon May 19 17:32:23 2014 us=910568 /sbin/ip addr del dev tun0 local 10.128.127.10 peer 10.128.127.9
Mon May 19 17:32:23 2014 us=924885 SIGINT[hard,] received, process exiting
Mon May 19 17:32:26 2014 us=779304 Current Parameter Settings:
Mon May 19 17:32:26 2014 us=779402   config = 'client.conf'
Mon May 19 17:32:26 2014 us=779421   mode = 0
Mon May 19 17:32:26 2014 us=779436   persist_config = DISABLED
Mon May 19 17:32:26 2014 us=779452   persist_mode = 1
Mon May 19 17:32:26 2014 us=779467   show_ciphers = DISABLED
Mon May 19 17:32:26 2014 us=779483   show_digests = DISABLED
Mon May 19 17:32:26 2014 us=779498   show_engines = DISABLED
Mon May 19 17:32:26 2014 us=779514   genkey = DISABLED
Mon May 19 17:32:26 2014 us=779530   key_pass_file = '[UNDEF]'
Mon May 19 17:32:26 2014 us=779545   show_tls_ciphers = DISABLED
Mon May 19 17:32:26 2014 us=779561 Connection profiles [default]:
Mon May 19 17:32:26 2014 us=779576   proto = udp
Mon May 19 17:32:26 2014 us=779592   local = '[UNDEF]'
Mon May 19 17:32:26 2014 us=779607   local_port = 0
Mon May 19 17:32:26 2014 us=779622   remote = '188.226.155.48'
Mon May 19 17:32:26 2014 us=779638   remote_port = 1194
Mon May 19 17:32:26 2014 us=779653   remote_float = DISABLED
Mon May 19 17:32:26 2014 us=779668   bind_defined = DISABLED
Mon May 19 17:32:26 2014 us=779683   bind_local = DISABLED
Mon May 19 17:32:26 2014 us=779698 NOTE: --mute triggered...
Mon May 19 17:32:26 2014 us=779730 255 variation(s) on previous 20 message(s) suppressed by --mute
Mon May 19 17:32:26 2014 us=779747 OpenVPN 2.3.2 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [eurephia] [MH] [IPv6] built on Feb  4 2014
Mon May 19 17:32:30 2014 us=632187 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.
Mon May 19 17:32:30 2014 us=633565 LZO compression initialized
Mon May 19 17:32:30 2014 us=633802 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Mon May 19 17:32:30 2014 us=633943 Socket Buffers: R=[212992->131072] S=[212992->131072]
Mon May 19 17:32:30 2014 us=634039 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Mon May 19 17:32:30 2014 us=634112 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'
Mon May 19 17:32:30 2014 us=634153 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'
Mon May 19 17:32:30 2014 us=634228 Local Options hash (VER=V4): '41690919'
Mon May 19 17:32:30 2014 us=634284 Expected Remote Options hash (VER=V4): '530fdded'
Mon May 19 17:32:30 2014 us=634338 UDPv4 link local: [undef]
Mon May 19 17:32:30 2014 us=634395 UDPv4 link remote: [AF_INET]188.226.155.48:1194
Mon May 19 17:32:30 2014 us=690015 TLS: Initial packet from [AF_INET]188.226.155.48:1194, sid=06bc2702 9ae75d9a
Mon May 19 17:32:30 2014 us=690316 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Mon May 19 17:32:31 2014 us=20936 VERIFY OK: depth=1, C=FO, ST=ST, L=Torshavn, O=Privatnet, OU=changeme, CN=changeme, name=changeme, emailAddress=samband@privatnet.fo
Mon May 19 17:32:31 2014 us=21535 VERIFY OK: depth=0, C=FO, ST=ST, L=Torshavn, O=Privatnet, OU=changeme, CN=changeme, name=changeme, emailAddress=samband@privatnet.fo
Mon May 19 17:32:31 2014 us=204235 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mon May 19 17:32:31 2014 us=204366 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mon May 19 17:32:31 2014 us=204545 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mon May 19 17:32:31 2014 us=204591 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mon May 19 17:32:31 2014 us=204698 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Mon May 19 17:32:31 2014 us=204774 [changeme] Peer Connection Initiated with [AF_INET]188.226.155.48:1194
Mon May 19 17:32:33 2014 us=241356 SENT CONTROL [changeme]: 'PUSH_REQUEST' (status=1)
Mon May 19 17:32:33 2014 us=295721 PUSH: Received control message: 'PUSH_REPLY,route 10.128.127.1,topology net30,ping 10,ping-restart 120,ifconfig 10.128.127.10 10.128.127.9'
Mon May 19 17:32:33 2014 us=295963 OPTIONS IMPORT: timers and/or timeouts modified
Mon May 19 17:32:33 2014 us=296060 OPTIONS IMPORT: --ifconfig/up options modified
Mon May 19 17:32:33 2014 us=296098 OPTIONS IMPORT: route options modified
Mon May 19 17:32:33 2014 us=296519 ROUTE_GATEWAY 192.168.2.1/255.255.255.0 IFACE=wlan0 HWADDR=00:1f:3b:12:a0:4b
Mon May 19 17:32:33 2014 us=297119 TUN/TAP device tun0 opened
Mon May 19 17:32:33 2014 us=297187 TUN/TAP TX queue length set to 100
Mon May 19 17:32:33 2014 us=297254 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Mon May 19 17:32:33 2014 us=297339 /sbin/ip link set dev tun0 up mtu 1500
Mon May 19 17:32:33 2014 us=308257 /sbin/ip addr add dev tun0 local 10.128.127.10 peer 10.128.127.9
Mon May 19 17:32:33 2014 us=310231 /sbin/ip route add 10.128.127.1/32 via 10.128.127.9
Mon May 19 17:32:33 2014 us=313118 Initialization Sequence Completed

And here's the server log

Mon May 19 16:31:25 2014 us=884922 MULTI: multi_create_instance called
Mon May 19 16:31:25 2014 us=885048 88.85.62.90:47388 Re-using SSL/TLS context
Mon May 19 16:31:25 2014 us=885077 88.85.62.90:47388 LZO compression initialized
Mon May 19 16:31:25 2014 us=885199 88.85.62.90:47388 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Mon May 19 16:31:25 2014 us=885214 88.85.62.90:47388 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Mon May 19 16:31:25 2014 us=885255 88.85.62.90:47388 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'
Mon May 19 16:31:25 2014 us=885264 88.85.62.90:47388 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'
Mon May 19 16:31:25 2014 us=885281 88.85.62.90:47388 Local Options hash (VER=V4): '530fdded'
Mon May 19 16:31:25 2014 us=885293 88.85.62.90:47388 Expected Remote Options hash (VER=V4): '41690919'
Mon May 19 16:31:25 2014 us=885351 88.85.62.90:47388 UDPv4 READ [14] from [AF_INET]88.85.62.90:47388: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Mon May 19 16:31:25 2014 us=885367 88.85.62.90:47388 TLS: Initial packet from [AF_INET]88.85.62.90:47388, sid=4448dfd3 fd804d31
Mon May 19 16:31:25 2014 us=885394 88.85.62.90:47388 UDPv4 WRITE [26] to [AF_INET]88.85.62.90:47388: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Mon May 19 16:31:25 2014 us=938554 88.85.62.90:47388 UDPv4 READ [22] from [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 0 ]
Mon May 19 16:31:25 2014 us=939455 88.85.62.90:47388 UDPv4 READ [114] from [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=100
Mon May 19 16:31:25 2014 us=939499 88.85.62.90:47388 UDPv4 WRITE [22] to [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 1 ]
Mon May 19 16:31:25 2014 us=941457 88.85.62.90:47388 UDPv4 READ [114] from [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Mon May 19 16:31:25 2014 us=941518 88.85.62.90:47388 UDPv4 WRITE [22] to [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 2 ]
Mon May 19 16:31:25 2014 us=941835 88.85.62.90:47388 UDPv4 READ [39] from [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=25
Mon May 19 16:31:25 2014 us=943261 88.85.62.90:47388 UDPv4 WRITE [126] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ 3 ] pid=1 DATA len=100
Mon May 19 16:31:25 2014 us=943313 88.85.62.90:47388 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Mon May 19 16:31:25 2014 us=943349 88.85.62.90:47388 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Mon May 19 16:31:25 2014 us=943380 88.85.62.90:47388 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Mon May 19 16:31:25 2014 us=994740 88.85.62.90:47388 UDPv4 READ [22] from [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 1 ]
Mon May 19 16:31:25 2014 us=994877 88.85.62.90:47388 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Mon May 19 16:31:25 2014 us=995602 88.85.62.90:47388 UDPv4 READ [22] from [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 2 ]
Mon May 19 16:31:25 2014 us=995644 88.85.62.90:47388 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Mon May 19 16:31:25 2014 us=997326 88.85.62.90:47388 UDPv4 READ [22] from [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 3 ]
Mon May 19 16:31:25 2014 us=997382 88.85.62.90:47388 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Mon May 19 16:31:25 2014 us=997772 88.85.62.90:47388 UDPv4 READ [22] from [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 4 ]
Mon May 19 16:31:25 2014 us=997806 88.85.62.90:47388 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Mon May 19 16:31:26 2014 us=46157 88.85.62.90:47388 UDPv4 READ [22] from [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 5 ]
Mon May 19 16:31:26 2014 us=46276 88.85.62.90:47388 NOTE: --mute triggered...
AUTH-PAM: BACKGROUND: received command code: 0
AUTH-PAM: BACKGROUND: USER: bogi
AUTH-PAM: BACKGROUND: my_conv[0] query='Password:' style=1
Mon May 19 16:31:26 2014 us=373225 88.85.62.90:47388 53 variation(s) on previous 20 message(s) suppressed by --mute
Mon May 19 16:31:26 2014 us=373256 88.85.62.90:47388 PLUGIN_CALL: POST /usr/lib/openvpn/openvpn-auth-pam.so/PLUGIN_AUTH_USER_PASS_VERIFY status=0
Mon May 19 16:31:26 2014 us=373300 88.85.62.90:47388 TLS: Username/Password authentication succeeded for username 'bogi' [CN SET]
Mon May 19 16:31:26 2014 us=373474 88.85.62.90:47388 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mon May 19 16:31:26 2014 us=373490 88.85.62.90:47388 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mon May 19 16:31:26 2014 us=373539 88.85.62.90:47388 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mon May 19 16:31:26 2014 us=373548 88.85.62.90:47388 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mon May 19 16:31:26 2014 us=373603 88.85.62.90:47388 UDPv4 WRITE [126] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ 9 ] pid=30 DATA len=100
Mon May 19 16:31:26 2014 us=373650 88.85.62.90:47388 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=31 DATA len=100
Mon May 19 16:31:26 2014 us=373679 88.85.62.90:47388 UDPv4 WRITE [80] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=32 DATA len=66
Mon May 19 16:31:26 2014 us=424933 88.85.62.90:47388 UDPv4 READ [22] from [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 30 ]
Mon May 19 16:31:26 2014 us=425536 88.85.62.90:47388 UDPv4 READ [22] from [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 31 ]
Mon May 19 16:31:26 2014 us=426519 88.85.62.90:47388 UDPv4 READ [22] from [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 32 ]
Mon May 19 16:31:26 2014 us=426543 88.85.62.90:47388 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA
Mon May 19 16:31:26 2014 us=426568 88.85.62.90:47388 [bogi] Peer Connection Initiated with [AF_INET]88.85.62.90:47388
Mon May 19 16:31:26 2014 us=426595 bogi/88.85.62.90:47388 MULTI_sva: pool returned IPv4=10.128.127.10, IPv6=1::1600:0:437f:0
Mon May 19 16:31:26 2014 us=426629 bogi/88.85.62.90:47388 MULTI: Learn: 10.128.127.10 -> bogi/88.85.62.90:47388
Mon May 19 16:31:26 2014 us=426638 bogi/88.85.62.90:47388 MULTI: primary virtual IP for bogi/88.85.62.90:47388: 10.128.127.10
Mon May 19 16:31:28 2014 us=591283 bogi/88.85.62.90:47388 UDPv4 READ [104] from [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=90
Mon May 19 16:31:28 2014 us=591431 bogi/88.85.62.90:47388 PUSH: Received control message: 'PUSH_REQUEST'
Mon May 19 16:31:28 2014 us=591445 bogi/88.85.62.90:47388 send_push_reply(): safe_cap=960
Mon May 19 16:31:28 2014 us=591478 bogi/88.85.62.90:47388 SENT CONTROL [bogi]: 'PUSH_REPLY,route 10.128.127.1,topology net30,ping 10,ping-restart 120,ifconfig 10.128.127.10 10.128.127.9' (status=1)
Mon May 19 16:31:28 2014 us=591498 bogi/88.85.62.90:47388 UDPv4 WRITE [22] to [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 10 ]
Mon May 19 16:31:28 2014 us=591554 bogi/88.85.62.90:47388 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=33 DATA len=100
Mon May 19 16:31:28 2014 us=591581 bogi/88.85.62.90:47388 UDPv4 WRITE [84] to [AF_INET]88.85.62.90:47388: P_CONTROL_V1 kid=0 [ ] pid=34 DATA len=70
Mon May 19 16:31:28 2014 us=643298 bogi/88.85.62.90:47388 UDPv4 READ [22] from [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 33 ]
Mon May 19 16:31:28 2014 us=666853 bogi/88.85.62.90:47388 UDPv4 READ [22] from [AF_INET]88.85.62.90:47388: P_ACK_V1 kid=0 [ 34 ]
Mon May 19 16:31:38 2014 us=743035 bogi/88.85.62.90:47388 UDPv4 READ [53] from [AF_INET]88.85.62.90:47388: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:31:38 2014 us=743161 bogi/88.85.62.90:47388 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:47388: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:31:48 2014 us=795576 bogi/88.85.62.90:47388 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:47388: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:31:48 2014 us=847319 bogi/88.85.62.90:47388 UDPv4 READ [53] from [AF_INET]88.85.62.90:47388: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:31:59 2014 us=53965 bogi/88.85.62.90:47388 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:47388: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:31:59 2014 us=116144 bogi/88.85.62.90:47388 UDPv4 READ [53] from [AF_INET]88.85.62.90:47388: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:32:09 2014 us=249763 bogi/88.85.62.90:47388 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:47388: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:32:09 2014 us=296997 bogi/88.85.62.90:47388 UDPv4 READ [53] from [AF_INET]88.85.62.90:47388: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:32:19 2014 us=321410 bogi/88.85.62.90:47388 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:47388: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:32:19 2014 us=372865 bogi/88.85.62.90:47388 UDPv4 READ [53] from [AF_INET]88.85.62.90:47388: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:32:29 2014 us=439695 bogi/88.85.62.90:47388 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:47388: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:32:29 2014 us=489870 read UDPv4 [ECONNREFUSED]: Connection refused (code=111)
Mon May 19 16:32:30 2014 us=655425 MULTI: multi_create_instance called
Mon May 19 16:32:30 2014 us=655541 88.85.62.90:53723 Re-using SSL/TLS context
Mon May 19 16:32:30 2014 us=655572 88.85.62.90:53723 LZO compression initialized
Mon May 19 16:32:30 2014 us=655738 88.85.62.90:53723 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Mon May 19 16:32:30 2014 us=655763 88.85.62.90:53723 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Mon May 19 16:32:30 2014 us=655819 88.85.62.90:53723 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'
Mon May 19 16:32:30 2014 us=655837 88.85.62.90:53723 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'
Mon May 19 16:32:30 2014 us=655865 88.85.62.90:53723 Local Options hash (VER=V4): '530fdded'
Mon May 19 16:32:30 2014 us=655889 88.85.62.90:53723 Expected Remote Options hash (VER=V4): '41690919'
Mon May 19 16:32:30 2014 us=655940 88.85.62.90:53723 UDPv4 READ [14] from [AF_INET]88.85.62.90:53723: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Mon May 19 16:32:30 2014 us=655965 88.85.62.90:53723 TLS: Initial packet from [AF_INET]88.85.62.90:53723, sid=c77c8a5f 84dbee95
Mon May 19 16:32:30 2014 us=656010 88.85.62.90:53723 UDPv4 WRITE [26] to [AF_INET]88.85.62.90:53723: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Mon May 19 16:32:30 2014 us=710478 88.85.62.90:53723 UDPv4 READ [22] from [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 0 ]
Mon May 19 16:32:30 2014 us=712009 88.85.62.90:53723 UDPv4 READ [114] from [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=100
Mon May 19 16:32:30 2014 us=712068 88.85.62.90:53723 UDPv4 WRITE [22] to [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 1 ]
Mon May 19 16:32:30 2014 us=713068 88.85.62.90:53723 UDPv4 READ [114] from [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Mon May 19 16:32:30 2014 us=713121 88.85.62.90:53723 UDPv4 WRITE [22] to [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 2 ]
Mon May 19 16:32:30 2014 us=713929 88.85.62.90:53723 UDPv4 READ [39] from [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=25
Mon May 19 16:32:30 2014 us=716246 88.85.62.90:53723 UDPv4 WRITE [126] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ 3 ] pid=1 DATA len=100
Mon May 19 16:32:30 2014 us=716342 88.85.62.90:53723 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Mon May 19 16:32:30 2014 us=716404 88.85.62.90:53723 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Mon May 19 16:32:30 2014 us=716458 88.85.62.90:53723 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Mon May 19 16:32:30 2014 us=769071 88.85.62.90:53723 UDPv4 READ [22] from [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 1 ]
Mon May 19 16:32:30 2014 us=769228 88.85.62.90:53723 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Mon May 19 16:32:30 2014 us=770743 88.85.62.90:53723 UDPv4 READ [22] from [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 2 ]
Mon May 19 16:32:30 2014 us=770789 88.85.62.90:53723 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Mon May 19 16:32:30 2014 us=771173 88.85.62.90:53723 UDPv4 READ [22] from [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 3 ]
Mon May 19 16:32:30 2014 us=771218 88.85.62.90:53723 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Mon May 19 16:32:30 2014 us=771874 88.85.62.90:53723 UDPv4 READ [22] from [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 4 ]
Mon May 19 16:32:30 2014 us=771919 88.85.62.90:53723 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Mon May 19 16:32:30 2014 us=822002 88.85.62.90:53723 UDPv4 READ [22] from [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 5 ]
Mon May 19 16:32:30 2014 us=822160 88.85.62.90:53723 NOTE: --mute triggered...
AUTH-PAM: BACKGROUND: received command code: 0
AUTH-PAM: BACKGROUND: USER: bogi
AUTH-PAM: BACKGROUND: my_conv[0] query='Password:' style=1
Mon May 19 16:32:31 2014 us=169489 88.85.62.90:53723 53 variation(s) on previous 20 message(s) suppressed by --mute
Mon May 19 16:32:31 2014 us=169514 88.85.62.90:53723 PLUGIN_CALL: POST /usr/lib/openvpn/openvpn-auth-pam.so/PLUGIN_AUTH_USER_PASS_VERIFY status=0
Mon May 19 16:32:31 2014 us=169548 88.85.62.90:53723 TLS: Username/Password authentication succeeded for username 'bogi' [CN SET]
Mon May 19 16:32:31 2014 us=169696 88.85.62.90:53723 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mon May 19 16:32:31 2014 us=169708 88.85.62.90:53723 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mon May 19 16:32:31 2014 us=169757 88.85.62.90:53723 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Mon May 19 16:32:31 2014 us=169766 88.85.62.90:53723 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mon May 19 16:32:31 2014 us=169810 88.85.62.90:53723 UDPv4 WRITE [126] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ 9 ] pid=30 DATA len=100
Mon May 19 16:32:31 2014 us=169865 88.85.62.90:53723 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=31 DATA len=100
Mon May 19 16:32:31 2014 us=169908 88.85.62.90:53723 UDPv4 WRITE [80] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=32 DATA len=66
Mon May 19 16:32:31 2014 us=222704 88.85.62.90:53723 UDPv4 READ [22] from [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 30 ]
Mon May 19 16:32:31 2014 us=223695 88.85.62.90:53723 UDPv4 READ [22] from [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 31 ]
Mon May 19 16:32:31 2014 us=224446 88.85.62.90:53723 UDPv4 READ [22] from [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 32 ]
Mon May 19 16:32:31 2014 us=224475 88.85.62.90:53723 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA
Mon May 19 16:32:31 2014 us=224499 88.85.62.90:53723 [bogi] Peer Connection Initiated with [AF_INET]88.85.62.90:53723
Mon May 19 16:32:31 2014 us=224629 MULTI: new connection by client 'bogi' will cause previous active sessions by this client to be dropped.  Remember to use the --duplicate-cn option if you want multiple clients using the same certificate or username to concurrently connect.
Mon May 19 16:32:31 2014 us=224649 MULTI_sva: pool returned IPv4=10.128.127.10, IPv6=8038:9277:437f:0:f2c7:fb75:437f:0
Mon May 19 16:32:31 2014 us=224681 MULTI: Learn: 10.128.127.10 -> bogi/88.85.62.90:53723
Mon May 19 16:32:31 2014 us=224690 MULTI: primary virtual IP for bogi/88.85.62.90:53723: 10.128.127.10
Mon May 19 16:32:33 2014 us=261709 bogi/88.85.62.90:53723 UDPv4 READ [104] from [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=90
Mon May 19 16:32:33 2014 us=261852 bogi/88.85.62.90:53723 PUSH: Received control message: 'PUSH_REQUEST'
Mon May 19 16:32:33 2014 us=261866 bogi/88.85.62.90:53723 send_push_reply(): safe_cap=960
Mon May 19 16:32:33 2014 us=261898 bogi/88.85.62.90:53723 SENT CONTROL [bogi]: 'PUSH_REPLY,route 10.128.127.1,topology net30,ping 10,ping-restart 120,ifconfig 10.128.127.10 10.128.127.9' (status=1)
Mon May 19 16:32:33 2014 us=261919 bogi/88.85.62.90:53723 UDPv4 WRITE [22] to [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 10 ]
Mon May 19 16:32:33 2014 us=261972 bogi/88.85.62.90:53723 UDPv4 WRITE [114] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=33 DATA len=100
Mon May 19 16:32:33 2014 us=262000 bogi/88.85.62.90:53723 UDPv4 WRITE [84] to [AF_INET]88.85.62.90:53723: P_CONTROL_V1 kid=0 [ ] pid=34 DATA len=70
Mon May 19 16:32:33 2014 us=314937 bogi/88.85.62.90:53723 UDPv4 READ [22] from [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 33 ]
Mon May 19 16:32:33 2014 us=332744 bogi/88.85.62.90:53723 UDPv4 READ [22] from [AF_INET]88.85.62.90:53723: P_ACK_V1 kid=0 [ 34 ]
Mon May 19 16:32:43 2014 us=359922 bogi/88.85.62.90:53723 UDPv4 READ [53] from [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:32:43 2014 us=360047 bogi/88.85.62.90:53723 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:32:53 2014 us=426484 bogi/88.85.62.90:53723 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:32:53 2014 us=479138 bogi/88.85.62.90:53723 UDPv4 READ [53] from [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:03 2014 us=679903 bogi/88.85.62.90:53723 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:03 2014 us=695790 bogi/88.85.62.90:53723 UDPv4 READ [53] from [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:13 2014 us=721263 bogi/88.85.62.90:53723 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:13 2014 us=773724 bogi/88.85.62.90:53723 UDPv4 READ [53] from [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:23 2014 us=988574 bogi/88.85.62.90:53723 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:24 2014 us=41221 bogi/88.85.62.90:53723 UDPv4 READ [53] from [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:33 2014 us=140673 bogi/88.85.62.90:53723 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:34 2014 us=373730 bogi/88.85.62.90:53723 UDPv4 READ [53] from [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:43 2014 us=535262 bogi/88.85.62.90:53723 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:44 2014 us=694411 bogi/88.85.62.90:53723 UDPv4 READ [53] from [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:54 2014 us=126250 bogi/88.85.62.90:53723 UDPv4 WRITE [53] to [AF_INET]88.85.62.90:53723: P_DATA_V1 kid=0 DATA len=52
Mon May 19 16:33:54 2014 us=179137 bogi/88.85.62.90:53723 NOTE: --mute triggered...

Hope this can help