connection is reset immediatly even though credential check

goryvamp

Hi Forum,

I'm trying to connect from W7-64bit to a zeroshell machine and I get immediately disconnected even though certificate check is OK. Can you pls help?
Thanks,

Induni
===================================

SERVER CONFIG
---------------
openvpn --dev-type tap --dev VPN99 --mode server --tls-server --proto tcp-server --port 1195 --dh /etc/ssl/dh.pem --ca /var/register/system/openvpn/Auth/X509/CAFile --cert /var/register/system/openvpn/TLS/cert.pem --key /var/register/system/openvpn/TLS/key.pem --daemon VPN99_H2L --comp-lzo --ifconfig-pool 192.168.250.1 192.168.250.253 255.255.255.0 --push route-gateway 192.168.250.254 --push redirect-gateway --push dhcp-option DNS 192.168.250.254 --push --client-connect /root/kerbynet.cgi/scripts/ov_connect --client-disconnect /root/kerbynet.cgi/scripts/ov_disconnect --mute 3 --management 127.0.0.1 34099 --keepalive 5 60 --duplicate-cn --script-security 3

WINDOW CONFIG
----------------
remote 192.168.2.3 1195
proto tcp
ca "--FILE 1--"
cert "-- FILE 2--"
key "--FILE 3--"
comp-lzo
verb 5
mute 20
resolv-retry infinite
nobind
client
dev tap
persist-key
persist-tun

LOG
----

Wed Feb 23 19:28:53 2011 us=992000 Current Parameter Settings:
Wed Feb 23 19:28:53 2011 us=992000 config = 'zeroshell.ovpn'
Wed Feb 23 19:28:53 2011 us=992000 mode = 0
Wed Feb 23 19:28:53 2011 us=992000 show_ciphers = DISABLED
Wed Feb 23 19:28:53 2011 us=992000 show_digests = DISABLED
Wed Feb 23 19:28:53 2011 us=992000 show_engines = DISABLED
Wed Feb 23 19:28:53 2011 us=992000 genkey = DISABLED
Wed Feb 23 19:28:53 2011 us=992000 key_pass_file = '[UNDEF]'
Wed Feb 23 19:28:53 2011 us=992000 show_tls_ciphers = DISABLED
Wed Feb 23 19:28:53 2011 us=992000 Connection profiles [default]:
Wed Feb 23 19:28:53 2011 us=992000 proto = tcp-client
Wed Feb 23 19:28:53 2011 us=992000 local = '[UNDEF]'
Wed Feb 23 19:28:53 2011 us=992000 local_port = 0
Wed Feb 23 19:28:53 2011 us=992000 remote = '192.168.2.3'
Wed Feb 23 19:28:53 2011 us=992000 remote_port = 1195
Wed Feb 23 19:28:53 2011 us=992000 remote_float = DISABLED
Wed Feb 23 19:28:53 2011 us=992000 bind_defined = DISABLED
Wed Feb 23 19:28:53 2011 us=992000 bind_local = DISABLED
Wed Feb 23 19:28:53 2011 us=992000 connect_retry_seconds = 5
Wed Feb 23 19:28:53 2011 us=992000 connect_timeout = 10
Wed Feb 23 19:28:53 2011 us=992000 NOTE: --mute triggered...
Wed Feb 23 19:28:53 2011 us=992000 252 variation(s) on previous 20 message(s) suppressed by --mute
Wed Feb 23 19:28:53 2011 us=992000 OpenVPN 2.1.4 i686-pc-mingw32 [SSL] [LZO2] [PKCS11] built on Nov 8 2010
Wed Feb 23 19:28:53 2011 us=992000 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
Wed Feb 23 19:28:53 2011 us=992000 NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Wed Feb 23 19:28:54 2011 us=881000 LZO compression initialized
Wed Feb 23 19:28:54 2011 us=881000 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Wed Feb 23 19:28:54 2011 us=881000 Socket Buffers: R=[128000->128000] S=[49152->49152]
Wed Feb 23 19:28:54 2011 us=881000 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Wed Feb 23 19:28:54 2011 us=881000 Local Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Wed Feb 23 19:28:54 2011 us=881000 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Wed Feb 23 19:28:54 2011 us=881000 Local Options hash (VER=V4): '31fdf004'
Wed Feb 23 19:28:54 2011 us=881000 Expected Remote Options hash (VER=V4): '3e6d1056'
Wed Feb 23 19:28:54 2011 us=881000 Attempting to establish TCP connection with 192.168.2.3:1195
Wed Feb 23 19:28:54 2011 us=881000 TCP connection established with 192.168.2.3:1195
Wed Feb 23 19:28:54 2011 us=881000 TCPv4_CLIENT link local: [undef]
Wed Feb 23 19:28:54 2011 us=881000 TCPv4_CLIENT link remote: 192.168.2.3:1195
Wed Feb 23 19:28:54 2011 us=897000 TLS: Initial packet from 192.168.2.3:1195, sid=9f9f9e6c 392c7404
Wed Feb 23 19:28:55 2011 us=22000 VERIFY OK: depth=1, /C=FR/O=clonater.com/OU=Tokyo/CN=Tokyo_CA/emailAddress=info@clonater.com
Wed Feb 23 19:28:55 2011 us=22000 VERIFY OK: depth=0, /OU=Hosts/CN=camomille.clonater.com
Wed Feb 23 19:28:55 2011 us=84000 Connection reset, restarting [-1]
Wed Feb 23 19:28:55 2011 us=84000 TCP/UDP: Closing socket
Wed Feb 23 19:28:55 2011 us=84000 SIGUSR1[soft,connection-reset] received, process restarting
Wed Feb 23 19:28:55 2011 us=84000 Restart pause, 5 second(s)
Wed Feb 23 19:29:00 2011 us=92000 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
Wed Feb 23 19:29:00 2011 us=92000 NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Wed Feb 23 19:29:00 2011 us=92000 Re-using SSL/TLS context
Wed Feb 23 19:29:00 2011 us=92000 LZO compression initialized
Wed Feb 23 19:29:00 2011 us=92000 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Wed Feb 23 19:29:00 2011 us=92000 Socket Buffers: R=[128000->128000] S=[49152->49152]
Wed Feb 23 19:29:00 2011 us=92000 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Wed Feb 23 19:29:00 2011 us=92000 Local Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Wed Feb 23 19:29:00 2011 us=92000 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Wed Feb 23 19:29:00 2011 us=92000 Local Options hash (VER=V4): '31fdf004'
Wed Feb 23 19:29:00 2011 us=92000 Expected Remote Options hash (VER=V4): '3e6d1056'
Wed Feb 23 19:29:00 2011 us=92000 Attempting to establish TCP connection with 192.168.2.3:1195
Wed Feb 23 19:29:00 2011 us=92000 TCP/UDP: Closing socket
Wed Feb 23 19:29:00 2011 us=92000 SIGTERM[hard,init_instance] received, process exiting

janjust

You're using quite a complicated setup; for example, if the script

/root/kerbynet.cgi/scripts/ov_connect

returns a non-zero exit status the connection is dropped immediately. Try running the server with

verb 7

and connect the client - the server log file will (usually) contain some hint why the connection was dropped immediately.

goryvamp

Unfortunately I don't have much control on the complicated setup - ZeroShell comes pre-setup.

For instance I would prefer to use the tun driver instead of tap but I'm not sure if there is an easy way of changing that.

Here is the log @ verb 7. Thanks for your help that's very much appreciated,

Induni
---------------------------------------------------

Thu Feb 24 10:03:40 2011 us=934000 Current Parameter Settings:
Thu Feb 24 10:03:40 2011 us=950000 config = 'zeroshell.ovpn'
Thu Feb 24 10:03:40 2011 us=950000 mode = 0
Thu Feb 24 10:03:40 2011 us=950000 show_ciphers = DISABLED
Thu Feb 24 10:03:40 2011 us=950000 show_digests = DISABLED
Thu Feb 24 10:03:40 2011 us=950000 show_engines = DISABLED
Thu Feb 24 10:03:40 2011 us=950000 genkey = DISABLED
Thu Feb 24 10:03:40 2011 us=950000 key_pass_file = '[UNDEF]'
Thu Feb 24 10:03:40 2011 us=950000 show_tls_ciphers = DISABLED
Thu Feb 24 10:03:40 2011 us=950000 Connection profiles [default]:
Thu Feb 24 10:03:40 2011 us=950000 proto = tcp-client
Thu Feb 24 10:03:40 2011 us=950000 local = '[UNDEF]'
Thu Feb 24 10:03:40 2011 us=950000 local_port = 0
Thu Feb 24 10:03:40 2011 us=950000 remote = '192.168.2.3'
Thu Feb 24 10:03:40 2011 us=950000 remote_port = 1195
Thu Feb 24 10:03:40 2011 us=950000 remote_float = DISABLED
Thu Feb 24 10:03:40 2011 us=950000 bind_defined = DISABLED
Thu Feb 24 10:03:40 2011 us=950000 bind_local = DISABLED
Thu Feb 24 10:03:40 2011 us=950000 connect_retry_seconds = 5
Thu Feb 24 10:03:40 2011 us=950000 connect_timeout = 10
Thu Feb 24 10:03:40 2011 us=950000 NOTE: --mute triggered...
Thu Feb 24 10:03:40 2011 us=950000 252 variation(s) on previous 20 message(s) suppressed by --mute
Thu Feb 24 10:03:40 2011 us=950000 OpenVPN 2.1.4 i686-pc-mingw32 [SSL] [LZO2] [PKCS11] built on Nov 8 2010
Thu Feb 24 10:03:40 2011 us=950000 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
Thu Feb 24 10:03:40 2011 us=950000 NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Thu Feb 24 10:03:41 2011 us=855000 PRNG init md=SHA1 size=36
Thu Feb 24 10:03:41 2011 us=855000 LZO compression initialized
Thu Feb 24 10:03:41 2011 us=855000 MTU DYNAMIC mtu=0, flags=1, 0 -> 140
Thu Feb 24 10:03:41 2011 us=855000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:41 2011 us=855000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:41 2011 us=855000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:41 2011 us=855000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:41 2011 us=855000 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu Feb 24 10:03:41 2011 us=855000 MTU DYNAMIC mtu=1450, flags=2, 1576 -> 1450
Thu Feb 24 10:03:41 2011 us=870000 Socket Buffers: R=[128000->128000] S=[49152->49152]
Thu Feb 24 10:03:41 2011 us=870000 RESOLVE_REMOTE flags=0x0101 phase=1 rrs=0 sig=-1 status=1
Thu Feb 24 10:03:41 2011 us=870000 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu Feb 24 10:03:41 2011 us=870000 Local Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Thu Feb 24 10:03:41 2011 us=870000 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Thu Feb 24 10:03:41 2011 us=870000 Local Options hash (VER=V4): '31fdf004'
Thu Feb 24 10:03:41 2011 us=870000 Expected Remote Options hash (VER=V4): '3e6d1056'
Thu Feb 24 10:03:41 2011 us=870000 Attempting to establish TCP connection with 192.168.2.3:1195
Thu Feb 24 10:03:41 2011 us=870000 TCP connection established with 192.168.2.3:1195
Thu Feb 24 10:03:41 2011 us=870000 TCPv4_CLIENT link local: [undef]
Thu Feb 24 10:03:41 2011 us=870000 TCPv4_CLIENT link remote: 192.168.2.3:1195
Thu Feb 24 10:03:41 2011 us=870000 TCPv4_CLIENT WRITE [14] to 192.168.2.3:1195: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Thu Feb 24 10:03:42 2011 us=120000 TCPv4_CLIENT READ [26] from 192.168.2.3:1195: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Thu Feb 24 10:03:42 2011 us=120000 TLS: Initial packet from 192.168.2.3:1195, sid=3d6023de 3c1b13c7
Thu Feb 24 10:03:42 2011 us=120000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 0 ]
Thu Feb 24 10:03:42 2011 us=120000 TCPv4_CLIENT WRITE [108] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=94
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT READ [126] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=100
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 1 ]
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 2 ]
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT WRITE [26] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 3 4 ]
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 5 ]
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 6 ]
Thu Feb 24 10:03:42 2011 us=229000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Thu Feb 24 10:03:42 2011 us=229000 VERIFY OK: depth=1, /C=FR/O=clonater.com/OU=Tokyo/CN=Tokyo_CA/emailAddress=info@clonater.com
Thu Feb 24 10:03:42 2011 us=245000 VERIFY OK: depth=0, /OU=Hosts/CN=camomille.clonater.com
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 7 ]
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 8 ]
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=100
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 9 ]
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=100
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 10 ]
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=100
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=12 DATA len=100
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 11 ]
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 12 ]
Thu Feb 24 10:03:42 2011 us=245000 TCPv4_CLIENT READ [85] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=13 DATA len=71
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [126] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ 13 ] pid=2 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [6] 2 3 4 5
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 2 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [7] 6 3 4 5
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 3 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [8] 6 7 4 5
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 4 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [9] 6 7 8 5
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 5 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [10] 6 7 8 9
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 6 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [11] 10 7 8 9
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 7 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 8 ]
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [13] 10 11 12 9
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=12 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [13] 10 11 12 9
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 9 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=13 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [14] 10 11 12 13
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 10 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=14 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [15] 14 11 12 13
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 11 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=15 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [16] 14 15 12 13
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 12 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=16 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [17] 14 15 16 13
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 13 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=17 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [18] 14 15 16 17
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 14 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=18 DATA len=100
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [19] 18 15 16 17
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 15 ]
Thu Feb 24 10:03:42 2011 us=291000 TCPv4_CLIENT WRITE [73] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=19 DATA len=59
Thu Feb 24 10:03:42 2011 us=291000 ACK output sequence broken: [20] 18 19 16 17
Thu Feb 24 10:03:42 2011 us=291000 Connection reset, restarting [-1]
Thu Feb 24 10:03:42 2011 us=291000 PID packet_id_free
Thu Feb 24 10:03:42 2011 us=291000 PID packet_id_free
Thu Feb 24 10:03:42 2011 us=291000 PID packet_id_free
Thu Feb 24 10:03:42 2011 us=291000 PID packet_id_free
Thu Feb 24 10:03:42 2011 us=291000 PID packet_id_free
Thu Feb 24 10:03:42 2011 us=291000 PID packet_id_free
Thu Feb 24 10:03:42 2011 us=291000 PID packet_id_free
Thu Feb 24 10:03:42 2011 us=291000 PID packet_id_free
Thu Feb 24 10:03:42 2011 us=307000 TCP/UDP: Closing socket
Thu Feb 24 10:03:42 2011 us=307000 PID packet_id_free
Thu Feb 24 10:03:42 2011 us=307000 SIGUSR1[soft,connection-reset] received, process restarting
Thu Feb 24 10:03:42 2011 us=307000 Restart pause, 5 second(s)
Thu Feb 24 10:03:47 2011 us=315000 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
Thu Feb 24 10:03:47 2011 us=315000 NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Thu Feb 24 10:03:47 2011 us=315000 Re-using SSL/TLS context
Thu Feb 24 10:03:47 2011 us=315000 LZO compression initialized
Thu Feb 24 10:03:47 2011 us=315000 MTU DYNAMIC mtu=0, flags=1, 0 -> 140
Thu Feb 24 10:03:47 2011 us=315000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:47 2011 us=315000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:47 2011 us=315000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:47 2011 us=315000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:47 2011 us=315000 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu Feb 24 10:03:47 2011 us=315000 MTU DYNAMIC mtu=1450, flags=2, 1576 -> 1450
Thu Feb 24 10:03:47 2011 us=315000 Socket Buffers: R=[128000->128000] S=[49152->49152]
Thu Feb 24 10:03:47 2011 us=315000 RESOLVE_REMOTE flags=0x0101 phase=1 rrs=0 sig=-1 status=1
Thu Feb 24 10:03:47 2011 us=315000 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu Feb 24 10:03:47 2011 us=315000 Local Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Thu Feb 24 10:03:47 2011 us=315000 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Thu Feb 24 10:03:47 2011 us=315000 Local Options hash (VER=V4): '31fdf004'
Thu Feb 24 10:03:47 2011 us=315000 Expected Remote Options hash (VER=V4): '3e6d1056'
Thu Feb 24 10:03:47 2011 us=315000 Attempting to establish TCP connection with 192.168.2.3:1195
Thu Feb 24 10:03:47 2011 us=315000 TCP connection established with 192.168.2.3:1195
Thu Feb 24 10:03:47 2011 us=315000 TCPv4_CLIENT link local: [undef]
Thu Feb 24 10:03:47 2011 us=315000 TCPv4_CLIENT link remote: 192.168.2.3:1195
Thu Feb 24 10:03:47 2011 us=315000 TCPv4_CLIENT WRITE [14] to 192.168.2.3:1195: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Thu Feb 24 10:03:47 2011 us=315000 TCPv4_CLIENT READ [26] from 192.168.2.3:1195: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Thu Feb 24 10:03:47 2011 us=315000 TLS: Initial packet from 192.168.2.3:1195, sid=eab6b89f bbda0292
Thu Feb 24 10:03:47 2011 us=315000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 0 ]
Thu Feb 24 10:03:47 2011 us=315000 TCPv4_CLIENT WRITE [108] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=94
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT READ [126] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=100
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 1 ]
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 2 ]
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT WRITE [26] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 3 4 ]
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 5 ]
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 6 ]
Thu Feb 24 10:03:47 2011 us=439000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Thu Feb 24 10:03:47 2011 us=439000 VERIFY OK: depth=1, /C=FR/O=clonater.com/OU=Tokyo/CN=Tokyo_CA/emailAddress=info@clonater.com
Thu Feb 24 10:03:47 2011 us=455000 VERIFY OK: depth=0, /OU=Hosts/CN=camomille.clonater.com
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 7 ]
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 8 ]
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=100
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 9 ]
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=100
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=100
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 10 ]
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 11 ]
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT READ [114] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=12 DATA len=100
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT WRITE [22] to 192.168.2.3:1195: P_ACK_V1 kid=0 [ 12 ]
Thu Feb 24 10:03:47 2011 us=455000 TCPv4_CLIENT READ [85] from 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=13 DATA len=71
Thu Feb 24 10:03:47 2011 us=502000 TCPv4_CLIENT WRITE [126] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ 13 ] pid=2 DATA len=100
Thu Feb 24 10:03:47 2011 us=502000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Thu Feb 24 10:03:47 2011 us=502000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Thu Feb 24 10:03:47 2011 us=502000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Thu Feb 24 10:03:47 2011 us=502000 ACK output sequence broken: [6] 2 3 4 5
Thu Feb 24 10:03:47 2011 us=502000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 2 ]
Thu Feb 24 10:03:47 2011 us=502000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Thu Feb 24 10:03:47 2011 us=502000 ACK output sequence broken: [7] 6 3 4 5
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 3 ]
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 4 ]
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [9] 6 7 8 5
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 5 ]
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [10] 6 7 8 9
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [10] 6 7 8 9
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 6 ]
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [11] 10 7 8 9
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 7 ]
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [12] 10 11 8 9
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 8 ]
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 9 ]
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [14] 10 11 12 13
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=12 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=13 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [14] 10 11 12 13
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 10 ]
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=14 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [15] 14 11 12 13
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 11 ]
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=15 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [16] 14 15 12 13
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 12 ]
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 13 ]
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [18] 14 15 16 17
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=16 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=17 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [18] 14 15 16 17
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 14 ]
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [114] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=18 DATA len=100
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [19] 18 15 16 17
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT READ [22] from 192.168.2.3:1195: P_ACK_V1 kid=0 [ 15 ]
Thu Feb 24 10:03:47 2011 us=549000 TCPv4_CLIENT WRITE [73] to 192.168.2.3:1195: P_CONTROL_V1 kid=0 [ ] pid=19 DATA len=59
Thu Feb 24 10:03:47 2011 us=549000 ACK output sequence broken: [20] 18 19 16 17
Thu Feb 24 10:03:47 2011 us=564000 Connection reset, restarting [-1]
Thu Feb 24 10:03:47 2011 us=564000 PID packet_id_free
Thu Feb 24 10:03:47 2011 us=564000 PID packet_id_free
Thu Feb 24 10:03:47 2011 us=564000 PID packet_id_free
Thu Feb 24 10:03:47 2011 us=564000 PID packet_id_free
Thu Feb 24 10:03:47 2011 us=564000 PID packet_id_free
Thu Feb 24 10:03:47 2011 us=564000 PID packet_id_free
Thu Feb 24 10:03:47 2011 us=564000 PID packet_id_free
Thu Feb 24 10:03:47 2011 us=564000 PID packet_id_free
Thu Feb 24 10:03:47 2011 us=564000 TCP/UDP: Closing socket
Thu Feb 24 10:03:47 2011 us=564000 PID packet_id_free
Thu Feb 24 10:03:47 2011 us=564000 SIGUSR1[soft,connection-reset] received, process restarting
Thu Feb 24 10:03:47 2011 us=564000 Restart pause, 5 second(s)
Thu Feb 24 10:03:52 2011 us=572000 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
Thu Feb 24 10:03:52 2011 us=572000 NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Thu Feb 24 10:03:52 2011 us=572000 Re-using SSL/TLS context
Thu Feb 24 10:03:52 2011 us=572000 LZO compression initialized
Thu Feb 24 10:03:52 2011 us=572000 MTU DYNAMIC mtu=0, flags=1, 0 -> 140
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 10:03:52 2011 us=572000 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu Feb 24 10:03:52 2011 us=572000 MTU DYNAMIC mtu=1450, flags=2, 1576 -> 1450
Thu Feb 24 10:03:52 2011 us=572000 Socket Buffers: R=[128000->128000] S=[49152->49152]
Thu Feb 24 10:03:52 2011 us=572000 RESOLVE_REMOTE flags=0x0101 phase=1 rrs=0 sig=-1 status=1
Thu Feb 24 10:03:52 2011 us=572000 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu Feb 24 10:03:52 2011 us=572000 Local Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Thu Feb 24 10:03:52 2011 us=572000 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Thu Feb 24 10:03:52 2011 us=572000 Local Options hash (VER=V4): '31fdf004'
Thu Feb 24 10:03:52 2011 us=572000 Expected Remote Options hash (VER=V4): '3e6d1056'
Thu Feb 24 10:03:52 2011 us=572000 Attempting to establish TCP connection with 192.168.2.3:1195
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_free
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_free
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_free
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_free
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_free
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_free
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_free
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_free
Thu Feb 24 10:03:52 2011 us=572000 TCP/UDP: Closing socket
Thu Feb 24 10:03:52 2011 us=572000 PID packet_id_free
Thu Feb 24 10:03:52 2011 us=572000 SIGTERM[hard,init_instance] received, process exiting
Thu Feb 24 10:03:52 2011 us=572000 PKCS#11: Removing providers
Thu Feb 24 10:03:52 2011 us=572000 PKCS#11: Releasing sessions
Thu Feb 24 10:03:52 2011 us=572000 PKCS#11: Terminating slotevent
Thu Feb 24 10:03:52 2011 us=572000 PKCS#11: Marking as uninitialized
Thu Feb 24 10:03:52 2011 us=572000 Closing Win32 semaphore 'openvpn_netcmd'

janjust

this looks like the client log, not the server log; also , what's in the client-connect script on the server side? can you disable it, to see if it has an effect?

maikcat

hi there,

if you want my opinion

setup openvpn somewhere else and keep zeroshell only for its loadbalance feature...

cheers,

michael.

goryvamp

Disabling the --client-connect param still makes it to reset

=====================================================
SERVER LOG
------------

Thu Feb 24 15:04:30 2011 us=52685 Current Parameter Settings:
Thu Feb 24 15:04:30 2011 us=53296 config = '[UNDEF]'
Thu Feb 24 15:04:30 2011 us=53370 mode = 1
Thu Feb 24 15:04:30 2011 us=53421 NOTE: --mute triggered...
Thu Feb 24 15:04:30 2011 us=53548 213 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:04:30 2011 us=53607 OpenVPN 2.1.4 i586-pc-linux-gnu [SSL] [LZO2] [EPOLL] built on Dec 30 2010
Thu Feb 24 15:04:30 2011 us=53990 MANAGEMENT: TCP Socket listening on 127.0.0.1:34099
Thu Feb 24 15:04:30 2011 us=54588 GDG: route[1] 192.168.5.0/255.255.255.0/0.0.0.0 m=0
Thu Feb 24 15:04:30 2011 us=54706 GDG: route[2] 192.168.2.0/255.255.255.0/0.0.0.0 m=0
Thu Feb 24 15:04:30 2011 us=54785 GDG: route[3] 192.168.250.0/255.255.255.0/0.0.0.0 m=0
Thu Feb 24 15:04:30 2011 us=54846 NOTE: --mute triggered...
Thu Feb 24 15:04:30 2011 us=54968 2 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:04:30 2011 us=55021 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Thu Feb 24 15:04:30 2011 us=139315 Diffie-Hellman initialized with 1024 bit key
Thu Feb 24 15:04:30 2011 us=155244 PRNG init md=SHA1 size=36
Thu Feb 24 15:04:30 2011 us=155545 MTU DYNAMIC mtu=0, flags=1, 0 -> 140
Thu Feb 24 15:04:30 2011 us=155616 TLS-Auth MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu Feb 24 15:04:30 2011 us=155672 MTU DYNAMIC mtu=1450, flags=2, 1576 -> 1450
Thu Feb 24 15:04:30 2011 us=155822 Socket Buffers: R=[87380->131072] S=[16384->131072]
Thu Feb 24 15:04:30 2011 us=155966 TUN/TAP device VPN99 opened
Thu Feb 24 15:04:30 2011 us=156046 TUN/TAP TX queue length set to 100
Thu Feb 24 15:04:30 2011 us=156197 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu Feb 24 15:04:30 2011 us=157242 Listening for incoming TCP connection on [undef]:1195
Thu Feb 24 15:04:30 2011 us=157652 TCPv4_SERVER link local (bound): [undef]:1195
Thu Feb 24 15:04:30 2011 us=157716 TCPv4_SERVER link remote: [undef]
Thu Feb 24 15:04:30 2011 us=157793 MULTI: multi_init called, r=256 v=256
Thu Feb 24 15:04:30 2011 us=158247 IFCONFIG POOL: base=192.168.250.1 size=253
Thu Feb 24 15:04:30 2011 us=158481 MULTI: TCP INIT maxclients=1024 maxevents=1028
Thu Feb 24 15:04:30 2011 us=158680 Initialization Sequence Completed
Thu Feb 24 15:04:30 2011 us=449217 MANAGEMENT: Client connected from 127.0.0.1:34099
Thu Feb 24 15:04:30 2011 us=450565 MANAGEMENT: CMD 'status 2'
Thu Feb 24 15:04:30 2011 us=451573 MANAGEMENT: Client disconnected
Thu Feb 24 15:04:40 2011 us=445753 MULTI: REAP range 0 -> 16
Thu Feb 24 15:04:40 2011 us=446023 MULTI TCP: multi_tcp_action a=TA_TIMEOUT p=0
Thu Feb 24 15:04:40 2011 us=446085 MULTI TCP: multi_tcp_dispatch a=TA_TIMEOUT mi=0x00000000
Thu Feb 24 15:04:40 2011 us=446156 NOTE: --mute triggered...
Thu Feb 24 15:05:33 2011 us=831966 22 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:33 2011 us=832181 MULTI: multi_create_instance called
Thu Feb 24 15:05:33 2011 us=832407 Re-using SSL/TLS context
Thu Feb 24 15:05:33 2011 us=832562 LZO compression initialized
Thu Feb 24 15:05:33 2011 us=832627 MTU DYNAMIC mtu=0, flags=1, 0 -> 140
Thu Feb 24 15:05:33 2011 us=832748 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 15:05:33 2011 us=833294 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 15:05:33 2011 us=833403 NOTE: --mute triggered...
Thu Feb 24 15:05:33 2011 us=833657 2 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:33 2011 us=833730 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu Feb 24 15:05:33 2011 us=833854 MTU DYNAMIC mtu=1450, flags=2, 1576 -> 1450
Thu Feb 24 15:05:33 2011 us=833995 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu Feb 24 15:05:33 2011 us=834145 Local Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Thu Feb 24 15:05:33 2011 us=834202 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Thu Feb 24 15:05:33 2011 us=834516 Local Options hash (VER=V4): '3e6d1056'
Thu Feb 24 15:05:33 2011 us=834606 Expected Remote Options hash (VER=V4): '31fdf004'
Thu Feb 24 15:05:33 2011 us=834766 TCP connection established with 192.168.0.88:60199
Thu Feb 24 15:05:33 2011 us=834852 TCPv4_SERVER link local: [undef]
Thu Feb 24 15:05:33 2011 us=834914 TCPv4_SERVER link remote: 192.168.0.88:60199
Thu Feb 24 15:05:33 2011 us=835046 192.168.0.88:60199 SENT PING
Thu Feb 24 15:05:33 2011 us=835773 192.168.0.88:60199 MULTI TCP: instance added: 192.168.0.88:60199
Thu Feb 24 15:05:33 2011 us=835929 192.168.0.88:60199 MULTI TCP: multi_tcp_action a=TA_INITIAL p=0
Thu Feb 24 15:05:33 2011 us=835983 192.168.0.88:60199 NOTE: --mute triggered...
Thu Feb 24 15:05:33 2011 us=841416 192.168.0.88:60199 4 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:33 2011 us=841630 192.168.0.88:60199 TCPv4_SERVER READ [14] from 192.168.0.88:60199: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Thu Feb 24 15:05:33 2011 us=841726 192.168.0.88:60199 TLS: Initial packet from 192.168.0.88:60199, sid=93c9995c faef3a1a
Thu Feb 24 15:05:33 2011 us=841936 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Thu Feb 24 15:05:33 2011 us=841997 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:33 2011 us=842052 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:33 2011 us=842168 NOTE: --mute triggered...
Thu Feb 24 15:05:33 2011 us=842229 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:33 2011 us=842333 192.168.0.88:60199 TCPv4_SERVER WRITE [26] to 192.168.0.88:60199: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Thu Feb 24 15:05:33 2011 us=842782 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_UNDEF
Thu Feb 24 15:05:33 2011 us=843988 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Thu Feb 24 15:05:33 2011 us=844111 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x09371ee8
Thu Feb 24 15:05:33 2011 us=844227 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 0 ]
Thu Feb 24 15:05:33 2011 us=844464 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_UNDEF
Thu Feb 24 15:05:33 2011 us=882937 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Thu Feb 24 15:05:33 2011 us=883123 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x09371ee8
Thu Feb 24 15:05:33 2011 us=883256 192.168.0.88:60199 TCPv4_SERVER READ [108] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=94
Thu Feb 24 15:05:33 2011 us=979261 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Thu Feb 24 15:05:33 2011 us=979512 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:33 2011 us=979571 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:33 2011 us=979653 NOTE: --mute triggered...
Thu Feb 24 15:05:33 2011 us=979714 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:33 2011 us=979799 192.168.0.88:60199 TCPv4_SERVER WRITE [126] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=100
Thu Feb 24 15:05:33 2011 us=982923 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_WRITE
Thu Feb 24 15:05:33 2011 us=983098 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:33 2011 us=983158 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:33 2011 us=983237 NOTE: --mute triggered...
Thu Feb 24 15:05:33 2011 us=983297 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:33 2011 us=983383 192.168.0.88:60199 TCPv4_SERVER WRITE [114] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=100
Thu Feb 24 15:05:33 2011 us=993204 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_WRITE
Thu Feb 24 15:05:33 2011 us=993497 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:33 2011 us=993558 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:33 2011 us=993771 NOTE: --mute triggered...
Thu Feb 24 15:05:33 2011 us=993897 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:33 2011 us=993986 192.168.0.88:60199 TCPv4_SERVER WRITE [114] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Thu Feb 24 15:05:34 2011 us=1622 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=1753 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=1874 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=1956 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=2017 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=2104 192.168.0.88:60199 TCPv4_SERVER WRITE [114] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Thu Feb 24 15:05:34 2011 us=2562 192.168.0.88:60199 ACK output sequence broken: [5] 1 2 3 4
Thu Feb 24 15:05:34 2011 us=2665 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_UNDEF
Thu Feb 24 15:05:34 2011 us=2743 MULTI: REAP range 112 -> 128
Thu Feb 24 15:05:34 2011 us=2802 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=2894 192.168.0.88:60199 2 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=2971 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 1 ]
Thu Feb 24 15:05:34 2011 us=4264 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=4372 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=4429 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=4505 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=4565 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=4649 192.168.0.88:60199 TCPv4_SERVER WRITE [114] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Thu Feb 24 15:05:34 2011 us=5056 192.168.0.88:60199 ACK output sequence broken: [6] 5 2 3 4
Thu Feb 24 15:05:34 2011 us=5153 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=5208 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=5259 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=5320 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=5395 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 2 ]
Thu Feb 24 15:05:34 2011 us=5516 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=5576 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=5631 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=5697 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=5752 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=6939 192.168.0.88:60199 TCPv4_SERVER WRITE [114] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Thu Feb 24 15:05:34 2011 us=7434 192.168.0.88:60199 ACK output sequence broken: [7] 5 6 3 4
Thu Feb 24 15:05:34 2011 us=7542 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=7598 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=7650 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=7712 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=7793 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 3 ]
Thu Feb 24 15:05:34 2011 us=9000 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=9093 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=9149 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=9225 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=9366 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=9451 192.168.0.88:60199 TCPv4_SERVER WRITE [114] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Thu Feb 24 15:05:34 2011 us=13634 192.168.0.88:60199 ACK output sequence broken: [8] 5 6 7 4
Thu Feb 24 15:05:34 2011 us=13842 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_UNDEF
Thu Feb 24 15:05:34 2011 us=13926 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Thu Feb 24 15:05:34 2011 us=13978 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=14079 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=14165 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 4 ]
Thu Feb 24 15:05:34 2011 us=14308 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=14366 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=14421 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=14491 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=14547 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=14622 192.168.0.88:60199 TCPv4_SERVER WRITE [114] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Thu Feb 24 15:05:34 2011 us=15069 192.168.0.88:60199 ACK output sequence broken: [9] 5 6 7 8
Thu Feb 24 15:05:34 2011 us=15167 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=15221 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=15272 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=15329 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=15404 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 5 ]
Thu Feb 24 15:05:34 2011 us=15514 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=15572 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=15627 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=15692 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=15747 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=15822 192.168.0.88:60199 TCPv4_SERVER WRITE [114] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=100
Thu Feb 24 15:05:34 2011 us=23027 192.168.0.88:60199 ACK output sequence broken: [10] 9 6 7 8
Thu Feb 24 15:05:34 2011 us=23344 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=23403 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=23454 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=23519 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=23607 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 6 ]
Thu Feb 24 15:05:34 2011 us=23861 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=23923 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=23979 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=24061 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=24119 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=24195 192.168.0.88:60199 TCPv4_SERVER WRITE [114] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=100
Thu Feb 24 15:05:34 2011 us=24800 192.168.0.88:60199 ACK output sequence broken: [11] 9 10 7 8
Thu Feb 24 15:05:34 2011 us=24907 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=24962 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=26348 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=26451 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=26546 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 7 ]
Thu Feb 24 15:05:34 2011 us=26788 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=26849 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=26906 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=26982 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=27041 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=27116 192.168.0.88:60199 TCPv4_SERVER WRITE [114] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=100
Thu Feb 24 15:05:34 2011 us=27550 192.168.0.88:60199 ACK output sequence broken: [12] 9 10 11 8
Thu Feb 24 15:05:34 2011 us=27653 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_UNDEF
Thu Feb 24 15:05:34 2011 us=27730 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Thu Feb 24 15:05:34 2011 us=27782 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=27866 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=27942 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 8 ]
Thu Feb 24 15:05:34 2011 us=28059 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=28117 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=28171 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=28235 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=28291 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=28645 192.168.0.88:60199 TCPv4_SERVER WRITE [114] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=12 DATA len=100
Thu Feb 24 15:05:34 2011 us=28951 192.168.0.88:60199 ACK output sequence broken: [13] 9 10 11 12
Thu Feb 24 15:05:34 2011 us=29047 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=29100 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=29151 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=29209 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=29470 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 9 ]
Thu Feb 24 15:05:34 2011 us=29617 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=29675 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=29729 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=29841 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=29898 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=29972 192.168.0.88:60199 TCPv4_SERVER WRITE [85] to 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=13 DATA len=71
Thu Feb 24 15:05:34 2011 us=30290 192.168.0.88:60199 ACK output sequence broken: [14] 13 10 11 12
Thu Feb 24 15:05:34 2011 us=30385 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=30440 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=30490 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=30549 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=30623 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 10 ]
Thu Feb 24 15:05:34 2011 us=30722 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_UNDEF
Thu Feb 24 15:05:34 2011 us=30795 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Thu Feb 24 15:05:34 2011 us=30850 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=31037 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 11 ]
Thu Feb 24 15:05:34 2011 us=31143 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=31200 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=31253 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ_RESIDUAL mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=31324 192.168.0.88:60199 TCPv4_SERVER READ [22] from 192.168.0.88:60199: P_ACK_V1 kid=0 [ 12 ]
Thu Feb 24 15:05:34 2011 us=31412 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_UNDEF
Thu Feb 24 15:05:34 2011 us=66477 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Thu Feb 24 15:05:34 2011 us=66741 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=66872 192.168.0.88:60199 TCPv4_SERVER READ [126] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ 13 ] pid=2 DATA len=100
Thu Feb 24 15:05:34 2011 us=67184 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=67248 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=67301 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=67379 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=67439 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=67541 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 2 ]
Thu Feb 24 15:05:34 2011 us=67988 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_UNDEF
Thu Feb 24 15:05:34 2011 us=68298 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Thu Feb 24 15:05:34 2011 us=68374 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=68480 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=100
Thu Feb 24 15:05:34 2011 us=68654 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=68715 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=68769 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=68836 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=68892 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=68966 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 3 ]
Thu Feb 24 15:05:34 2011 us=69278 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=69532 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=69589 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ_RESIDUAL mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=69669 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=100
Thu Feb 24 15:05:34 2011 us=69884 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=69949 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=70002 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=70070 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=70127 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=70201 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 4 ]
Thu Feb 24 15:05:34 2011 us=70512 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=70758 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=70815 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ_RESIDUAL mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=70898 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=100
Thu Feb 24 15:05:34 2011 us=71057 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=71220 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=71277 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=71345 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=71403 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=71476 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 5 ]
Thu Feb 24 15:05:34 2011 us=71812 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_UNDEF
Thu Feb 24 15:05:34 2011 us=72078 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Thu Feb 24 15:05:34 2011 us=72134 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=72241 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=100
Thu Feb 24 15:05:34 2011 us=72413 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=72474 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=72528 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=72594 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=72650 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=72723 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 6 ]
Thu Feb 24 15:05:34 2011 us=73008 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=73249 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=73310 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ_RESIDUAL mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=73392 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=100
Thu Feb 24 15:05:34 2011 us=73554 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=73617 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=73671 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=73771 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=73829 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=73902 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 7 ]
Thu Feb 24 15:05:34 2011 us=74205 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=74449 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=74507 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ_RESIDUAL mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=74616 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=100
Thu Feb 24 15:05:34 2011 us=74785 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=74845 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=74899 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=74970 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=75027 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=75101 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 8 ]
Thu Feb 24 15:05:34 2011 us=75400 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_UNDEF
Thu Feb 24 15:05:34 2011 us=75658 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Thu Feb 24 15:05:34 2011 us=75716 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=75820 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=100
Thu Feb 24 15:05:34 2011 us=75983 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=76045 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=76186 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=76255 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=76311 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=76386 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 9 ]
Thu Feb 24 15:05:34 2011 us=76715 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=76955 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=77014 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ_RESIDUAL mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=77099 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=100
Thu Feb 24 15:05:34 2011 us=77261 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=77322 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=77376 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=77443 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=77500 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=77574 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 10 ]
Thu Feb 24 15:05:34 2011 us=78050 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=78155 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=78210 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ_RESIDUAL mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=78292 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=100
Thu Feb 24 15:05:34 2011 us=78449 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=78509 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=78562 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=78630 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=78685 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=78759 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 11 ]
Thu Feb 24 15:05:34 2011 us=79048 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_UNDEF
Thu Feb 24 15:05:34 2011 us=79297 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Thu Feb 24 15:05:34 2011 us=79356 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=79460 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=12 DATA len=100
Thu Feb 24 15:05:34 2011 us=79618 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=79678 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=79732 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=79797 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=79853 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=79926 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 12 ]
Thu Feb 24 15:05:34 2011 us=80204 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=80432 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=80492 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ_RESIDUAL mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=80576 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=13 DATA len=100
Thu Feb 24 15:05:34 2011 us=80732 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=80794 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=80847 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=81011 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=81069 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=81142 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 13 ]
Thu Feb 24 15:05:34 2011 us=81467 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=81701 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=81788 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ_RESIDUAL mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=81872 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=14 DATA len=100
Thu Feb 24 15:05:34 2011 us=82039 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=82099 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=82154 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=82222 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=82278 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=82350 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 14 ]
Thu Feb 24 15:05:34 2011 us=82636 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_UNDEF
Thu Feb 24 15:05:34 2011 us=82889 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Thu Feb 24 15:05:34 2011 us=82950 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=83049 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=15 DATA len=100
Thu Feb 24 15:05:34 2011 us=83209 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Thu Feb 24 15:05:34 2011 us=83269 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Thu Feb 24 15:05:34 2011 us=83322 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=83387 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=83442 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=83514 192.168.0.88:60199 TCPv4_SERVER WRITE [22] to 192.168.0.88:60199: P_ACK_V1 kid=0 [ 15 ]
Thu Feb 24 15:05:34 2011 us=83791 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_READ_RESIDUAL
Thu Feb 24 15:05:34 2011 us=84024 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ_RESIDUAL p=1
Thu Feb 24 15:05:34 2011 us=84083 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ_RESIDUAL mi=0x09371ee8
Thu Feb 24 15:05:34 2011 us=84165 192.168.0.88:60199 TCPv4_SERVER READ [114] from 192.168.0.88:60199: P_CONTROL_V1 kid=0 [ ] pid=16 DATA len=100
Thu Feb 24 15:05:34 2011 us=85510 192.168.0.88:60199 VERIFY ERROR: depth=1, error=self signed certificate in certificate chain: /C=FR/O=clonater.com/OU=Tokyo/CN=Tokyo_CA/emailAddress=info@clonater.com
Thu Feb 24 15:05:34 2011 us=114763 192.168.0.88:60199 TLS_ERROR: BIO read tls_read_plaintext error: error:140890B2:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:no certificate returned
Thu Feb 24 15:05:34 2011 us=115079 192.168.0.88:60199 TLS Error: TLS object -> incoming plaintext read error
Thu Feb 24 15:05:34 2011 us=115140 192.168.0.88:60199 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=115198 192.168.0.88:60199 1 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=115249 192.168.0.88:60199 PID packet_id_free
Thu Feb 24 15:05:34 2011 us=115613 192.168.0.88:60199 PID packet_id_free
Thu Feb 24 15:05:34 2011 us=115685 192.168.0.88:60199 PID packet_id_free
Thu Feb 24 15:05:34 2011 us=115807 192.168.0.88:60199 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=116080 192.168.0.88:60199 2 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=116145 192.168.0.88:60199 Fatal TLS error (check_tls_errors_co), restarting
Thu Feb 24 15:05:34 2011 us=116213 192.168.0.88:60199 SIGUSR1[soft,tls-error] received, client-instance restarting
Thu Feb 24 15:05:34 2011 us=116387 MULTI: multi_close_instance called
Thu Feb 24 15:05:34 2011 us=116563 PID packet_id_free
Thu Feb 24 15:05:34 2011 us=116671 PID packet_id_free
Thu Feb 24 15:05:34 2011 us=116726 NOTE: --mute triggered...
Thu Feb 24 15:05:34 2011 us=116838 6 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:34 2011 us=116891 TCP/UDP: Closing socket
Thu Feb 24 15:05:34 2011 us=117517 PID packet_id_free
Thu Feb 24 15:05:34 2011 us=117639 MULTI TCP: multi_tcp_post TA_SOCKET_READ_RESIDUAL -> TA_UNDEF
Thu Feb 24 15:05:39 2011 us=120421 MULTI: REAP range 128 -> 144
Thu Feb 24 15:05:39 2011 us=120674 MULTI: multi_create_instance called
Thu Feb 24 15:05:39 2011 us=120817 Re-using SSL/TLS context
Thu Feb 24 15:05:39 2011 us=120955 LZO compression initialized
Thu Feb 24 15:05:39 2011 us=121019 MTU DYNAMIC mtu=0, flags=1, 0 -> 140
Thu Feb 24 15:05:39 2011 us=121129 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 15:05:39 2011 us=121377 PID packet_id_init seq_backtrack=0 time_backtrack=0
Thu Feb 24 15:05:39 2011 us=121446 NOTE: --mute triggered...
Thu Feb 24 15:05:39 2011 us=121582 2 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:39 2011 us=121637 Control Channel MTU parms [ L:1576 D:140 EF:40 EB:0 ET:0 EL:0 ]
Thu Feb 24 15:05:39 2011 us=121700 MTU DYNAMIC mtu=1450, flags=2, 1576 -> 1450
Thu Feb 24 15:05:39 2011 us=121773 Data Channel MTU parms [ L:1576 D:1450 EF:44 EB:135 ET:32 EL:0 AF:3/1 ]
Thu Feb 24 15:05:39 2011 us=121888 Local Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_SERVER,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Thu Feb 24 15:05:39 2011 us=121943 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1576,tun-mtu 1532,proto TCPv4_CLIENT,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Thu Feb 24 15:05:39 2011 us=122046 Local Options hash (VER=V4): '3e6d1056'
Thu Feb 24 15:05:39 2011 us=122130 Expected Remote Options hash (VER=V4): '31fdf004'
Thu Feb 24 15:05:39 2011 us=122258 TCP connection established with 192.168.0.88:60200
Thu Feb 24 15:05:39 2011 us=122500 TCPv4_SERVER link local: [undef]
Thu Feb 24 15:05:39 2011 us=122567 TCPv4_SERVER link remote: 192.168.0.88:60200
Thu Feb 24 15:05:39 2011 us=122678 192.168.0.88:60200 SENT PING
Thu Feb 24 15:05:39 2011 us=122996 192.168.0.88:60200 MULTI TCP: instance added: 192.168.0.88:60200
Thu Feb 24 15:05:39 2011 us=123068 192.168.0.88:60200 MULTI TCP: multi_tcp_action a=TA_INITIAL p=0
Thu Feb 24 15:05:39 2011 us=123324 192.168.0.88:60200 NOTE: --mute triggered...
Thu Feb 24 15:05:39 2011 us=123512 192.168.0.88:60200 4 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:39 2011 us=123573 192.168.0.88:60200 Connection reset, restarting [0]
Thu Feb 24 15:05:39 2011 us=123632 192.168.0.88:60200 SIGUSR1[soft,connection-reset] received, client-instance restarting
Thu Feb 24 15:05:39 2011 us=123684 MULTI: multi_close_instance called
Thu Feb 24 15:05:39 2011 us=123772 PID packet_id_free
Thu Feb 24 15:05:39 2011 us=123947 PID packet_id_free
Thu Feb 24 15:05:39 2011 us=124004 NOTE: --mute triggered...
Thu Feb 24 15:05:39 2011 us=124107 6 variation(s) on previous 3 message(s) suppressed by --mute
Thu Feb 24 15:05:39 2011 us=124160 TCP/UDP: Closing socket
Thu Feb 24 15:05:39 2011 us=124394 PID packet_id_free
Thu Feb 24 15:05:39 2011 us=124485 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_UNDEF
Thu Feb 24 15:05:49 2011 us=118023 MULTI: REAP range 144 -> 160
Thu Feb 24 15:05:49 2011 us=118292 NOTE: --mute triggered...

janjust

I did not see this

Thu Feb 24 15:05:34 2011 us=85510 192.168.0.88:60199 VERIFY ERROR: depth=1, error=self signed certificate in certificate chain: /C=FR/O=clonater.com/OU=Tokyo/CN=Tokyo_ ... onater.com
Thu Feb 24 15:05:34 2011 us=114763 192.168.0.88:60199 TLS_ERROR: BIO read tls_read_plaintext error: error:140890B2:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:no certificate returned
Thu Feb 24 15:05:34 2011 us=115079 192.168.0.88:60199 TLS Error: TLS object -> incoming plaintext read error

before. You need to solve this error before the connection will work...

goryvamp

I'm confused. So why does the client says that certificates checking is OK?
What am I missing here?

janjust

it means the client can verify the server cert, but the server cannot verify the client certificate. Only if both can be certified the connection is started.
What is in

ca "--FILE 1--"
cert "-- FILE 2--"
key "--FILE 3--"

in your client config?

goryvamp

I've checked on on the server I use to connect to when I'm out of the office (a setup that have been working for years):
Server as well as Client must have the same CA cert + [each one its own cert + key signed by the same CA]

On the zeroshell machine I thought I had the same setup but evidently that's not the case.
I haven't yet perfectly mastered it's certificate functions..
So, back to the drawing board.

Thanks for now.

shchour

Check system TIME on SEVER and client.
System time may be outside the keys validity period.