OK, thanks for the DN tip.. tried that and it seems to have solved one problem. Thing is, now I can't finish the connection. here's my Client Log (abridged a bit):
Mon Nov 06 12:11:25 2006 us=316878 Current Parameter Settings:
Mon Nov 06 12:11:25 2006 us=316922 config = 'VPN.ovpn'
Mon Nov 06 12:11:25 2006 us=316930 mode = 0
Mon Nov 06 12:11:25 2006 us=316938 show_ciphers = DISABLED
Mon Nov 06 12:11:25 2006 us=316945 show_digests = DISABLED
Mon Nov 06 12:11:25 2006 us=316952 show_engines = DISABLED
Mon Nov 06 12:11:25 2006 us=316961 genkey = DISABLED
Mon Nov 06 12:11:25 2006 us=316968 key_pass_file = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=316976 show_tls_ciphers = DISABLED
Mon Nov 06 12:11:25 2006 us=316984 proto = 0
Mon Nov 06 12:11:25 2006 us=316996 local = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317005 remote_list[0] = {'XXX.XXX.XXX.XXX', 1194}
Mon Nov 06 12:11:25 2006 us=317013 remote_random = DISABLED
Mon Nov 06 12:11:25 2006 us=317020 local_port = 1194
Mon Nov 06 12:11:25 2006 us=317028 remote_port = 1194
Mon Nov 06 12:11:25 2006 us=317035 remote_float = DISABLED
Mon Nov 06 12:11:25 2006 us=317042 ipchange = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317049 bind_local = ENABLED
Mon Nov 06 12:11:25 2006 us=317056 dev = 'tap'
Mon Nov 06 12:11:25 2006 us=317064 dev_type = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317071 dev_node = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317079 tun_ipv6 = DISABLED
Mon Nov 06 12:11:25 2006 us=317086 ifconfig_local = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317094 ifconfig_remote_netmask = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317102 ifconfig_noexec = DISABLED
Mon Nov 06 12:11:25 2006 us=317109 ifconfig_nowarn = DISABLED
Mon Nov 06 12:11:25 2006 us=317116 shaper = 0
Mon Nov 06 12:11:25 2006 us=317124 tun_mtu = 1500
Mon Nov 06 12:11:25 2006 us=317132 tun_mtu_defined = ENABLED
Mon Nov 06 12:11:25 2006 us=317139 link_mtu = 1500
Mon Nov 06 12:11:25 2006 us=317146 link_mtu_defined = DISABLED
Mon Nov 06 12:11:25 2006 us=317154 tun_mtu_extra = 32
Mon Nov 06 12:11:25 2006 us=317162 tun_mtu_extra_defined = ENABLED
Mon Nov 06 12:11:25 2006 us=317169 fragment = 1400
Mon Nov 06 12:11:25 2006 us=317176 mtu_discover_type = -1
Mon Nov 06 12:11:25 2006 us=317184 mtu_test = 1
Mon Nov 06 12:11:25 2006 us=317191 mlock = DISABLED
Mon Nov 06 12:11:25 2006 us=317199 keepalive_ping = 0
Mon Nov 06 12:11:25 2006 us=317206 keepalive_timeout = 0
Mon Nov 06 12:11:25 2006 us=317213 inactivity_timeout = 0
Mon Nov 06 12:11:25 2006 us=317221 ping_send_timeout = 0
Mon Nov 06 12:11:25 2006 us=317231 ping_rec_timeout = 120
Mon Nov 06 12:11:25 2006 us=317239 ping_rec_timeout_action = 2
Mon Nov 06 12:11:25 2006 us=317247 ping_timer_remote = DISABLED
Mon Nov 06 12:11:25 2006 us=317254 remap_sigusr1 = 0
Mon Nov 06 12:11:25 2006 us=317262 explicit_exit_notification = 0
Mon Nov 06 12:11:25 2006 us=317269 persist_tun = DISABLED
Mon Nov 06 12:11:25 2006 us=317277 persist_local_ip = DISABLED
Mon Nov 06 12:11:25 2006 us=317285 persist_remote_ip = DISABLED
Mon Nov 06 12:11:25 2006 us=317293 persist_key = DISABLED
Mon Nov 06 12:11:25 2006 us=317300 mssfix = 1450
Mon Nov 06 12:11:25 2006 us=317308 resolve_retry_seconds = 1000000000
Mon Nov 06 12:11:25 2006 us=317316 connect_retry_seconds = 5
Mon Nov 06 12:11:25 2006 us=317323 username = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317331 groupname = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317338 chroot_dir = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317346 cd_dir = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317353 writepid = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317360 up_script = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317368 down_script = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=317375 down_pre = DISABLED
Mon Nov 06 12:11:25 2006 us=317382 up_restart = DISABLED
Mon Nov 06 12:11:25 2006 us=317390 up_delay = DISABLED
Mon Nov 06 12:11:25 2006 us=317397 daemon = DISABLED
Mon Nov 06 12:11:25 2006 us=317404 inetd = 0
Mon Nov 06 12:11:25 2006 us=317411 log = DISABLED
Mon Nov 06 12:11:25 2006 us=317423 suppress_timestamps = DISABLED
Mon Nov 06 12:11:25 2006 us=317430 nice = 0
Mon Nov 06 12:11:25 2006 us=317437 verbosity = 9
Mon Nov 06 12:11:25 2006 us=512640 mute = 0
Mon Nov 06 12:11:25 2006 us=512697 gremlin = 0
Mon Nov 06 12:11:25 2006 us=512706 status_file = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=512715 status_file_version = 1
Mon Nov 06 12:11:25 2006 us=512723 status_file_update_freq = 60
Mon Nov 06 12:11:25 2006 us=512730 occ = ENABLED
Mon Nov 06 12:11:25 2006 us=512738 rcvbuf = 0
Mon Nov 06 12:11:25 2006 us=512746 sndbuf = 0
Mon Nov 06 12:11:25 2006 us=512755 socks_proxy_server = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=512771 socks_proxy_port = 0
Mon Nov 06 12:11:25 2006 us=512779 socks_proxy_retry = DISABLED
Mon Nov 06 12:11:25 2006 us=512787 fast_io = DISABLED
Mon Nov 06 12:11:25 2006 us=512794 comp_lzo = ENABLED
Mon Nov 06 12:11:25 2006 us=512802 comp_lzo_adaptive = ENABLED
Mon Nov 06 12:11:25 2006 us=512809 route_script = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=512818 route_default_gateway = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=512825 route_noexec = DISABLED
Mon Nov 06 12:11:25 2006 us=537079 route_delay = 0
Mon Nov 06 12:11:25 2006 us=537095 route_delay_window = 30
Mon Nov 06 12:11:25 2006 us=537102 route_delay_defined = ENABLED
Mon Nov 06 12:11:25 2006 us=537109 management_addr = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=537117 management_port = 0
Mon Nov 06 12:11:25 2006 us=537125 management_user_pass = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=537132 management_log_history_cache = 250
Mon Nov 06 12:11:25 2006 us=537140 management_echo_buffer_size = 100
Mon Nov 06 12:11:25 2006 us=537147 management_query_passwords = DISABLED
Mon Nov 06 12:11:25 2006 us=537154 management_hold = DISABLED
Mon Nov 06 12:11:25 2006 us=537177 shared_secret_file = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=537202 key_direction = 0
Mon Nov 06 12:11:25 2006 us=537211 ciphername_defined = ENABLED
Mon Nov 06 12:11:25 2006 us=537218 ciphername = 'AES-128-CBC'
Mon Nov 06 12:11:25 2006 us=537226 authname_defined = ENABLED
Mon Nov 06 12:11:25 2006 us=537234 authname = 'SHA1'
Mon Nov 06 12:11:25 2006 us=548984 keysize = 0
Mon Nov 06 12:11:25 2006 us=548994 engine = DISABLED
Mon Nov 06 12:11:25 2006 us=549001 replay = ENABLED
Mon Nov 06 12:11:25 2006 us=549012 mute_replay_warnings = DISABLED
Mon Nov 06 12:11:25 2006 us=549030 replay_window = 64
Mon Nov 06 12:11:25 2006 us=549050 replay_time = 15
Mon Nov 06 12:11:25 2006 us=549058 packet_id_file = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=549065 use_iv = ENABLED
Mon Nov 06 12:11:25 2006 us=549072 test_crypto = DISABLED
Mon Nov 06 12:11:25 2006 us=549079 tls_server = DISABLED
Mon Nov 06 12:11:25 2006 us=549087 tls_client = ENABLED
Mon Nov 06 12:11:25 2006 us=549095 key_method = 2
Mon Nov 06 12:11:25 2006 us=549103 ca_file = 'ca.crt'
Mon Nov 06 12:11:25 2006 us=549111 dh_file = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=549119 cert_file = 'client.crt'
Mon Nov 06 12:11:25 2006 us=549126 priv_key_file = 'client.key'
Mon Nov 06 12:11:25 2006 us=549133 pkcs12_file = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=559686 cryptoapi_cert = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=559697 cipher_list = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=559704 tls_verify = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=559713 tls_remote = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=559731 crl_file = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=559753 ns_cert_type = 0
Mon Nov 06 12:11:25 2006 us=559761 tls_timeout = 2
Mon Nov 06 12:11:25 2006 us=559768 renegotiate_bytes = 0
Mon Nov 06 12:11:25 2006 us=559775 renegotiate_packets = 0
Mon Nov 06 12:11:25 2006 us=559782 renegotiate_seconds = 3600
Mon Nov 06 12:11:25 2006 us=559790 handshake_window = 60
Mon Nov 06 12:11:25 2006 us=559798 transition_window = 3600
Mon Nov 06 12:11:25 2006 us=559806 single_session = DISABLED
Mon Nov 06 12:11:25 2006 us=559813 tls_exit = DISABLED
Mon Nov 06 12:11:25 2006 us=559821 tls_auth_file = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=559845 server_network = 0.0.0.0
Mon Nov 06 12:11:25 2006 us=698033 server_netmask = 0.0.0.0
Mon Nov 06 12:11:25 2006 us=698074 server_bridge_ip = 0.0.0.0
Mon Nov 06 12:11:25 2006 us=698090 server_bridge_netmask = 0.0.0.0
Mon Nov 06 12:11:25 2006 us=698099 server_bridge_pool_start = 0.0.0.0
Mon Nov 06 12:11:25 2006 us=698108 server_bridge_pool_end = 0.0.0.0
Mon Nov 06 12:11:25 2006 us=698117 ifconfig_pool_defined = DISABLED
Mon Nov 06 12:11:25 2006 us=698125 ifconfig_pool_start = 0.0.0.0
Mon Nov 06 12:11:25 2006 us=698133 ifconfig_pool_end = 0.0.0.0
Mon Nov 06 12:11:25 2006 us=698141 ifconfig_pool_netmask = 0.0.0.0
Mon Nov 06 12:11:25 2006 us=698150 ifconfig_pool_persist_filename = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=698160 ifconfig_pool_persist_refresh_freq = 600
Mon Nov 06 12:11:25 2006 us=698169 ifconfig_pool_linear = DISABLED
Mon Nov 06 12:11:25 2006 us=698177 n_bcast_buf = 256
Mon Nov 06 12:11:25 2006 us=698184 tcp_queue_limit = 64
Mon Nov 06 12:11:25 2006 us=698192 real_hash_size = 256
Mon Nov 06 12:11:25 2006 us=709618 virtual_hash_size = 256
Mon Nov 06 12:11:25 2006 us=709631 client_connect_script = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=709659 learn_address_script = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=709681 client_disconnect_script = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=709689 client_config_dir = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=709696 ccd_exclusive = DISABLED
Mon Nov 06 12:11:25 2006 us=709703 tmp_dir = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=709711 push_ifconfig_defined = DISABLED
Mon Nov 06 12:11:25 2006 us=709720 push_ifconfig_local = 0.0.0.0
Mon Nov 06 12:11:25 2006 us=709728 push_ifconfig_remote_netmask = 0.0.0.0
Mon Nov 06 12:11:25 2006 us=709737 enable_c2c = DISABLED
Mon Nov 06 12:11:25 2006 us=709744 duplicate_cn = DISABLED
Mon Nov 06 12:11:25 2006 us=709752 cf_max = 0
Mon Nov 06 12:11:25 2006 us=709759 cf_per = 0
Mon Nov 06 12:11:25 2006 us=709766 max_clients = 1024
Mon Nov 06 12:11:25 2006 us=726545 max_routes_per_client = 256
Mon Nov 06 12:11:25 2006 us=726580 client_cert_not_required = DISABLED
Mon Nov 06 12:11:25 2006 us=726602 username_as_common_name = DISABLED
Mon Nov 06 12:11:25 2006 us=726611 auth_user_pass_verify_script = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=726620 auth_user_pass_verify_script_via_file = DISABLED
Mon Nov 06 12:11:25 2006 us=726628 client = DISABLED
Mon Nov 06 12:11:25 2006 us=726635 pull = ENABLED
Mon Nov 06 12:11:25 2006 us=726642 auth_user_pass_file = 'stdin'
Mon Nov 06 12:11:25 2006 us=726652 show_net_up = DISABLED
Mon Nov 06 12:11:25 2006 us=726659 route_method = 0
Mon Nov 06 12:11:25 2006 us=726668 ip_win32_defined = DISABLED
Mon Nov 06 12:11:25 2006 us=726676 ip_win32_type = 3
Mon Nov 06 12:11:25 2006 us=726684 dhcp_masq_offset = 0
Mon Nov 06 12:11:25 2006 us=726692 dhcp_lease_time = 31536000
Mon Nov 06 12:11:25 2006 us=726700 tap_sleep = 0
Mon Nov 06 12:11:25 2006 us=726707 dhcp_options = DISABLED
Mon Nov 06 12:11:25 2006 us=738175 dhcp_renew = DISABLED
Mon Nov 06 12:11:25 2006 us=738185 dhcp_pre_release = DISABLED
Mon Nov 06 12:11:25 2006 us=738192 dhcp_release = DISABLED
Mon Nov 06 12:11:25 2006 us=738202 domain = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=738220 netbios_scope = '[UNDEF]'
Mon Nov 06 12:11:25 2006 us=738240 netbios_node_type = 0
Mon Nov 06 12:11:25 2006 us=738247 disable_nbt = DISABLED
Mon Nov 06 12:11:25 2006 us=738267 OpenVPN 2.0.9 Win32-MinGW [SSL] [LZO] built on Oct 1 2006
Mon Nov 06 12:11:30 2006 us=765261 WARNING: No server certificate verification method has been enabled. See
http://openvpn.net/howto.html#mitm for more info.
Mon Nov 06 12:11:30 2006 us=765444 WE_INIT maxevents=4 flags=0x00000002
Mon Nov 06 12:11:30 2006 us=765487 WE_INIT maxevents=4 capacity=8
Mon Nov 06 12:11:30 2006 us=778038 LZO compression initialized
Mon Nov 06 12:11:30 2006 us=778067 WARNING: using --fragment and --mtu-test together may produce an inaccurate MTU test result
Mon Nov 06 12:11:30 2006 us=778084 MTU DYNAMIC mtu=0, flags=1, 0 -> 138
Mon Nov 06 12:11:30 2006 us=778100 TLS: tls_session_init: entry
Mon Nov 06 12:11:30 2006 us=778117 PID packet_id_init seq_backtrack=64 time_backtrack=15
Mon Nov 06 12:11:30 2006 us=778184 PID packet_id_init seq_backtrack=64 time_backtrack=15
Mon Nov 06 12:11:30 2006 us=778216 TLS: tls_session_init: new session object, sid=57644ade 82ff8e36
Mon Nov 06 12:11:30 2006 us=778232 TLS: tls_session_init: entry
Mon Nov 06 12:11:30 2006 us=778241 PID packet_id_init seq_backtrack=64 time_backtrack=15
Mon Nov 06 12:11:30 2006 us=778275 PID packet_id_init seq_backtrack=64 time_backtrack=15
Mon Nov 06 12:11:30 2006 us=778286 TLS: tls_session_init: new session object, sid=99080840 4f2f4ac6
Mon Nov 06 12:11:30 2006 us=778299 Control Channel MTU parms [ L:1594 D:138 EF:38 EB:0 ET:0 EL:0 ]
Mon Nov 06 12:11:30 2006 us=778317 MTU DYNAMIC mtu=1400, flags=2, 1594 -> 1400
Mon Nov 06 12:11:30 2006 us=778361 MTU DYNAMIC mtu=1450, flags=2, 1594 -> 1450
Mon Nov 06 12:11:30 2006 us=778372 REMOTE_LIST len=1 current=0
Mon Nov 06 12:11:30 2006 us=778379
Mon Nov 06 12:11:30 2006 us=782977 RESOLVE_REMOTE flags=0x0001 phase=1 rrs=0 sig=-1 status=1
Mon Nov 06 12:11:30 2006 us=783005 Data Channel MTU parms [ L:1594 D:1450 EF:62 EB:135 ET:32 EL:0 AF:3/1 ]
Mon Nov 06 12:11:30 2006 us=783016 Fragmentation MTU parms [ L:1594 D:1400 EF:61 EB:135 ET:33 EL:0 AF:3/1 ]
Mon Nov 06 12:11:30 2006 us=783074 Local Options String: 'V4,dev-type tap,link-mtu 1594,tun-mtu 1532,proto UDPv4,comp-lzo,mtu-dynamic,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Mon Nov 06 12:11:30 2006 us=783095 Expected Remote Options String: 'V4,dev-type tap,link-mtu 1594,tun-mtu 1532,proto UDPv4,comp-lzo,mtu-dynamic,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Mon Nov 06 12:11:30 2006 us=783120 Local Options hash (VER=V4): '78bea45a'
Mon Nov 06 12:11:30 2006 us=783135 Expected Remote Options hash (VER=V4): '1374d8b5'
Mon Nov 06 12:11:30 2006 us=783169 Socket Buffers: R=[8192->8192] S=[8192->8192]
Mon Nov 06 12:11:30 2006 us=783186 UDPv4 link local (bound): [undef]:1194
Mon Nov 06 12:11:30 2006 us=783196 UDPv4 link remote: XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:30 2006 us=783210 TIMER: coarse timer wakeup 1 seconds
Mon Nov 06 12:11:30 2006 us=783241 TLS: tls_multi_process: i=0 state=S_INITIAL, mysid=57644ade 82ff8e36, stored-sid=00000000 00000000, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:30 2006 us=783252 TLS: tls_process: chg=0 ks=S_INITIAL lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:30 2006 us=783263 ACK mark active outgoing ID 0
Mon Nov 06 12:11:30 2006 us=783275 TLS: Initial Handshake, sid=57644ade 82ff8e36
Mon Nov 06 12:11:30 2006 us=783285 ACK reliable_can_send active=1 current=1 : [1] 0
Mon Nov 06 12:11:30 2006 us=783293 ACK reliable_send ID 0 (size=4 to=2)
Mon Nov 06 12:11:30 2006 us=783303 Reliable -> TCP/UDP
Mon Nov 06 12:11:30 2006 us=783311 ACK reliable_send_timeout 2 [1] 0
Mon Nov 06 12:11:30 2006 us=783319 TLS: tls_process: timeout set to 2
Mon Nov 06 12:11:30 2006 us=783333 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:30 2006 us=783349 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:30 2006 us=783370 RANDOM USEC=179611
Mon Nov 06 12:11:30 2006 us=783379 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:30 2006 us=783444 WIN32 I/O: Socket Receive queued [1594]
Mon Nov 06 12:11:30 2006 us=783453 WE_CTL n=1 ev=0x00a25264 rwflags=0x0003 arg=0x00453558
Mon Nov 06 12:11:30 2006 us=783466 I/O WAIT T?|T?|SRQ|SW0 [1/179611]
Mon Nov 06 12:11:30 2006 us=783488 WE_WAIT enter n=3 to=1180
Mon Nov 06 12:11:30 2006 us=783507
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:30 2006 us=783517 [1] ev=0x0000073c rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:30 2006 us=783525 [2] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:30 2006 us=783537 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:30 2006 us=783546 event_wait returned 1
Mon Nov 06 12:11:30 2006 us=783553 I/O WAIT status=0x0002
Mon Nov 06 12:11:30 2006 us=783575 UDPv4 WRITE [14] to XXX.XXX.XXX.XXX:1194: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 sid=57644ade 82ff8e36 [ ] pid=0 DATA
Mon Nov 06 12:11:30 2006 us=783641 WIN32 I/O: Socket Send immediate return [14,14]
Mon Nov 06 12:11:30 2006 us=783649 UDPv4 write returned 14
Mon Nov 06 12:11:30 2006 us=783666 TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=57644ade 82ff8e36, stored-sid=00000000 00000000, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:30 2006 us=783676 TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:30 2006 us=783685 ACK reliable_can_send active=1 current=0 : [1] 0
Mon Nov 06 12:11:30 2006 us=783775 SSL state (connect): before/connect initialization
Mon Nov 06 12:11:30 2006 us=789283 SSL state (connect): SSLv3 write client hello A
Mon Nov 06 12:11:30 2006 us=789313 ACK reliable_send_timeout 2 [1] 0
Mon Nov 06 12:11:30 2006 us=789321 TLS: tls_process: timeout set to 2
Mon Nov 06 12:11:30 2006 us=789339 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:30 2006 us=789354 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:30 2006 us=789369 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:30 2006 us=789378 WE_CTL n=1 ev=0x00a25264 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:30 2006 us=789390 I/O WAIT T?|T?|SRQ|Sw1 [1/179611]
Mon Nov 06 12:11:30 2006 us=789399 WE_WAIT enter n=2 to=1180
Mon Nov 06 12:11:30 2006 us=789407
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:30 2006 us=795619 [1] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=230066 WE_WAIT leave rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=230093 event_wait returned 1
Mon Nov 06 12:11:31 2006 us=230102 I/O WAIT status=0x0001
Mon Nov 06 12:11:31 2006 us=230132 WIN32 I/O: Socket Completion success [26]
Mon Nov 06 12:11:31 2006 us=230141 UDPv4 read returned 26
Mon Nov 06 12:11:31 2006 us=230167 UDPv4 READ [26] from XXX.XXX.XXX.XXX:1194: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 sid=859e87dd 3e16709c [ 0 sid=57644ade 82ff8e36 ] pid=0 DATA
Mon Nov 06 12:11:31 2006 us=230185 TLS: control channel, op=P_CONTROL_HARD_RESET_SERVER_V2, IP=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=230208 TLS: initial packet test, i=0 state=S_PRE_START, mysid=57644ade 82ff8e36, rec-sid=859e87dd 3e16709c, rec-ip=XXX.XXX.XXX.XXX:1194, stored-sid=00000000 00000000, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=230229 TLS: initial packet test, i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, rec-sid=859e87dd 3e16709c, rec-ip=XXX.XXX.XXX.XXX:1194, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=230268 TLS: initial packet test, i=2 state=S_UNDEF, mysid=00000000 00000000, rec-sid=859e87dd 3e16709c, rec-ip=XXX.XXX.XXX.XXX:1194, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=230306 TLS: Initial packet from XXX.XXX.XXX.XXX:1194, sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=230319 TLS: received control channel packet s#=0 sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=230326 ACK reliable_schedule_now
Mon Nov 06 12:11:31 2006 us=230334 ACK received for pid 0, deleting from send buffer
Mon Nov 06 12:11:31 2006 us=230341 ACK read ID 0 (buf->len=0)
Mon Nov 06 12:11:31 2006 us=230349 ACK mark active incoming ID 0
Mon Nov 06 12:11:31 2006 us=230356 ACK acknowledge ID 0 (ack->len=1)
Mon Nov 06 12:11:31 2006 us=230386 TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=230397 TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=230406 ACK reliable_can_send active=0 current=0 : [1]
Mon Nov 06 12:11:31 2006 us=230414 Incoming Ciphertext -> TLS
Mon Nov 06 12:11:31 2006 us=230450 TLS: tls_process: chg=1 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=230459 ACK reliable_can_send active=0 current=0 : [1]
Mon Nov 06 12:11:31 2006 us=230471 ACK write ID 0 (ack->len=1, n=1)
Mon Nov 06 12:11:31 2006 us=230478 Dedicated ACK -> TCP/UDP
Mon Nov 06 12:11:31 2006 us=230486 ACK reliable_send_timeout 604800 [1]
Mon Nov 06 12:11:31 2006 us=230493 TLS: tls_process: timeout set to 60
Mon Nov 06 12:11:31 2006 us=230507 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=230520 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=230532 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=230557 WIN32 I/O: Socket Receive queued [1594]
Mon Nov 06 12:11:31 2006 us=230565 WE_CTL n=1 ev=0x00a25264 rwflags=0x0003 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=230577 I/O WAIT T?|T?|SRQ|SW1 [1/179611]
Mon Nov 06 12:11:31 2006 us=230586 WE_WAIT enter n=3 to=1180
Mon Nov 06 12:11:31 2006 us=230594
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=230602 [1] ev=0x0000073c rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=230609 [2] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=230621 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=230629 event_wait returned 1
Mon Nov 06 12:11:31 2006 us=230635 I/O WAIT status=0x0002
Mon Nov 06 12:11:31 2006 us=230653 UDPv4 WRITE [22] to XXX.XXX.XXX.XXX:1194: P_ACK_V1 kid=0 sid=57644ade 82ff8e36 [ 0 sid=859e87dd 3e16709c ]
Mon Nov 06 12:11:31 2006 us=230663 WIN32 I/O: Socket Completion non-queued success [14]
Mon Nov 06 12:11:31 2006 us=230726 WIN32 I/O: Socket Send immediate return [22,22]
Mon Nov 06 12:11:31 2006 us=231168 UDPv4 write returned 22
Mon Nov 06 12:11:31 2006 us=231188 TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=231201 TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=231219 STATE S_START
Mon Nov 06 12:11:31 2006 us=231241 ACK reliable_can_send active=0 current=0 : [1]
Mon Nov 06 12:11:31 2006 us=231276 STATE S_SENT_KEY
Mon Nov 06 12:11:31 2006 us=231291 BIO read tls_read_ciphertext 88 bytes
Mon Nov 06 12:11:31 2006 us=231298 ACK mark active outgoing ID 1
Mon Nov 06 12:11:31 2006 us=231303 Outgoing Ciphertext -> Reliable
Mon Nov 06 12:11:31 2006 us=231311 TLS: tls_process: chg=1 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=231320 ACK reliable_can_send active=1 current=1 : [2] 1
Mon Nov 06 12:11:31 2006 us=231329 ACK reliable_send ID 1 (size=92 to=2)
Mon Nov 06 12:11:31 2006 us=237286 Reliable -> TCP/UDP
Mon Nov 06 12:11:31 2006 us=237295 ACK reliable_send_timeout 2 [2] 1
Mon Nov 06 12:11:31 2006 us=237301 TLS: tls_process: timeout set to 2
Mon Nov 06 12:11:31 2006 us=237328 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=237355 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=237368 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=237376 WE_CTL n=1 ev=0x00a25264 rwflags=0x0003 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=237387 I/O WAIT T?|T?|SRQ|SW1 [1/179611]
Mon Nov 06 12:11:31 2006 us=237395 WE_WAIT enter n=3 to=1180
Mon Nov 06 12:11:31 2006 us=237402
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=237410 [1] ev=0x0000073c rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=243761 [2] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=243773 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=243780 event_wait returned 1
Mon Nov 06 12:11:31 2006 us=243787 I/O WAIT status=0x0002
Mon Nov 06 12:11:31 2006 us=243854 UDPv4 WRITE [102] to XXX.XXX.XXX.XXX:1194: P_CONTROL_V1 kid=0 sid=57644ade 82ff8e36 [ ] pid=1 DATA 16030100 53010000 4f030145 4f88e350 2acd7077 43bed7de 0f563acb 74eb4f7[more...]
Mon Nov 06 12:11:31 2006 us=243865 WIN32 I/O: Socket Completion non-queued success [22]
Mon Nov 06 12:11:31 2006 us=243892 WIN32 I/O: Socket Send immediate return [102,102]
Mon Nov 06 12:11:31 2006 us=243901 UDPv4 write returned 102
Mon Nov 06 12:11:31 2006 us=243916 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=243926 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=251458 ACK reliable_can_send active=1 current=0 : [2] 1
Mon Nov 06 12:11:31 2006 us=251571 ACK reliable_send_timeout 2 [2] 1
Mon Nov 06 12:11:31 2006 us=251581 TLS: tls_process: timeout set to 2
Mon Nov 06 12:11:31 2006 us=251598 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=251614 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=251630 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=251641 WE_CTL n=1 ev=0x00a25264 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=251656 I/O WAIT T?|T?|SRQ|Sw1 [1/179611]
Mon Nov 06 12:11:31 2006 us=251664 WE_WAIT enter n=2 to=1180
Mon Nov 06 12:11:31 2006 us=260851
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=260861 [1] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=348346 WE_WAIT leave rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=348381 event_wait returned 1
Mon Nov 06 12:11:31 2006 us=348389 I/O WAIT status=0x0001
Mon Nov 06 12:11:31 2006 us=348408 WIN32 I/O: Socket Completion success [126]
Mon Nov 06 12:11:31 2006 us=348416 UDPv4 read returned 126
Mon Nov 06 12:11:31 2006 us=348476 UDPv4 READ [126] from XXX.XXX.XXX.XXX:1194: P_CONTROL_V1 kid=0 sid=859e87dd 3e16709c [ 1 sid=57644ade 82ff8e36 ] pid=1 DATA 16030100 2a020000 26030145 4f88fd2d 30a322fd bd693ac4 56a15cbe 593e87e[more...]
Mon Nov 06 12:11:31 2006 us=348489 TLS: control channel, op=P_CONTROL_V1, IP=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=348511 TLS: initial packet test, i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, rec-sid=859e87dd 3e16709c, rec-ip=XXX.XXX.XXX.XXX:1194, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=348524 TLS: found match, session[0], sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=348536 TLS: received control channel packet s#=0 sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=348544 ACK received for pid 1, deleting from send buffer
Mon Nov 06 12:11:31 2006 us=348552 ACK read ID 1 (buf->len=100)
Mon Nov 06 12:11:31 2006 us=348561 ACK mark active incoming ID 1
Mon Nov 06 12:11:31 2006 us=348569 ACK acknowledge ID 1 (ack->len=1)
Mon Nov 06 12:11:31 2006 us=348600 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=348613 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=348622 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=348635 BIO write tls_write_ciphertext 100 bytes
Mon Nov 06 12:11:31 2006 us=348643 Incoming Ciphertext -> TLS
Mon Nov 06 12:11:31 2006 us=348720 SSL state (connect): SSLv3 read server hello A
Mon Nov 06 12:11:31 2006 us=348740 TLS: tls_process: chg=1 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=348750 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=348765 ACK write ID 1 (ack->len=1, n=1)
Mon Nov 06 12:11:31 2006 us=348773 Dedicated ACK -> TCP/UDP
Mon Nov 06 12:11:31 2006 us=348781 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:31 2006 us=348800 TLS: tls_process: timeout set to 60
Mon Nov 06 12:11:31 2006 us=348816 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=348830 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=351607 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=351644 WIN32 I/O: Socket Receive immediate return [1594,114]
Mon Nov 06 12:11:31 2006 us=351666 WE_CTL n=1 ev=0x00a25264 rwflags=0x0003 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=351680 I/O WAIT T?|T?|SR1|SW1 [1/179611]
Mon Nov 06 12:11:31 2006 us=351688 WE_WAIT enter n=3 to=1180
Mon Nov 06 12:11:31 2006 us=351696
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=351704 [1] ev=0x0000073c rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=351711 [2] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=351725 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=351734 WE_WAIT leave [2,1] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=351741 event_wait returned 2
Mon Nov 06 12:11:31 2006 us=351747 I/O WAIT status=0x0003
Mon Nov 06 12:11:31 2006 us=358330 UDPv4 WRITE [22] to XXX.XXX.XXX.XXX:1194: P_ACK_V1 kid=0 sid=57644ade 82ff8e36 [ 1 sid=859e87dd 3e16709c ]
Mon Nov 06 12:11:31 2006 us=358340 WIN32 I/O: Socket Completion non-queued success [102]
Mon Nov 06 12:11:31 2006 us=358424 WIN32 I/O: Socket Send immediate return [22,22]
Mon Nov 06 12:11:31 2006 us=358433 UDPv4 write returned 22
Mon Nov 06 12:11:31 2006 us=358450 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=358460 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=358468 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=358484 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:31 2006 us=358491 TLS: tls_process: timeout set to 60
Mon Nov 06 12:11:31 2006 us=358504 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=366377 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=366391 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=366412 WE_CTL n=1 ev=0x00a25264 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=366436 I/O WAIT T?|T?|SR1|Sw1 [1/179611]
Mon Nov 06 12:11:31 2006 us=366445 WE_WAIT enter n=2 to=1180
Mon Nov 06 12:11:31 2006 us=366452
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=366460 [1] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=366470 WE_WAIT leave [1,0] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=366477 event_wait returned 1
Mon Nov 06 12:11:31 2006 us=413372 I/O WAIT status=0x0001
Mon Nov 06 12:11:31 2006 us=413391 WIN32 I/O: Socket Completion non-queued success [114]
Mon Nov 06 12:11:31 2006 us=413411 UDPv4 read returned 114
Mon Nov 06 12:11:31 2006 us=413477 UDPv4 READ [114] from XXX.XXX.XXX.XXX:1194: P_CONTROL_V1 kid=0 sid=859e87dd 3e16709c [ ] pid=2 DATA 06035504 06130243 41311030 0e060355 04081307 416c6265 72746131 11300f0[more...]
Mon Nov 06 12:11:31 2006 us=413489 TLS: control channel, op=P_CONTROL_V1, IP=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=413509 TLS: initial packet test, i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, rec-sid=859e87dd 3e16709c, rec-ip=XXX.XXX.XXX.XXX:1194, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=413523 TLS: found match, session[0], sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=413534 TLS: received control channel packet s#=0 sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=421583 ACK read ID 2 (buf->len=100)
Mon Nov 06 12:11:31 2006 us=421594 ACK mark active incoming ID 2
Mon Nov 06 12:11:31 2006 us=421600 ACK acknowledge ID 2 (ack->len=1)
Mon Nov 06 12:11:31 2006 us=421628 TIMER: coarse timer wakeup 1 seconds
Mon Nov 06 12:11:31 2006 us=421662 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=421674 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=421682 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=421692 BIO write tls_write_ciphertext 100 bytes
Mon Nov 06 12:11:31 2006 us=421699 Incoming Ciphertext -> TLS
Mon Nov 06 12:11:31 2006 us=421734 TLS: tls_process: chg=1 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=421742 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=429781 ACK write ID 2 (ack->len=1, n=1)
Mon Nov 06 12:11:31 2006 us=429790 Dedicated ACK -> TCP/UDP
Mon Nov 06 12:11:31 2006 us=429810 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:31 2006 us=429819 TLS: tls_process: timeout set to 59
Mon Nov 06 12:11:31 2006 us=429846 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=429860 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=429873 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=429899 WIN32 I/O: Socket Receive immediate return [1594,114]
Mon Nov 06 12:11:31 2006 us=429907 WE_CTL n=1 ev=0x00a25264 rwflags=0x0003 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=429918 I/O WAIT T?|T?|SR1|SW1 [1/179611]
Mon Nov 06 12:11:31 2006 us=429926 WE_WAIT enter n=3 to=1180
Mon Nov 06 12:11:31 2006 us=429933
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=437112 [1] ev=0x0000073c rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=437122 [2] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=437135 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=437154 WE_WAIT leave [2,1] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=437162 event_wait returned 2
Mon Nov 06 12:11:31 2006 us=437168 I/O WAIT status=0x0003
Mon Nov 06 12:11:31 2006 us=437201 UDPv4 WRITE [22] to XXX.XXX.XXX.XXX:1194: P_ACK_V1 kid=0 sid=57644ade 82ff8e36 [ 2 sid=859e87dd 3e16709c ]
Mon Nov 06 12:11:31 2006 us=437224 WIN32 I/O: Socket Completion non-queued success [22]
Mon Nov 06 12:11:31 2006 us=437288 WIN32 I/O: Socket Send immediate return [22,22]
Mon Nov 06 12:11:31 2006 us=437297 UDPv4 write returned 22
Mon Nov 06 12:11:31 2006 us=437314 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=489655 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=489700 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=489749 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:31 2006 us=489759 TLS: tls_process: timeout set to 59
Mon Nov 06 12:11:31 2006 us=489775 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=489790 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=489805 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=489814 WE_CTL n=1 ev=0x00a25264 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=496150 I/O WAIT T?|T?|SR1|Sw1 [1/179611]
Mon Nov 06 12:11:31 2006 us=496159 WE_WAIT enter n=2 to=1180
Mon Nov 06 12:11:31 2006 us=496166
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=496210 [1] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=496237 WE_WAIT leave [1,0] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=496245 event_wait returned 1
Mon Nov 06 12:11:31 2006 us=496251 I/O WAIT status=0x0001
Mon Nov 06 12:11:31 2006 us=496261 WIN32 I/O: Socket Completion non-queued success [114]
Mon Nov 06 12:11:31 2006 us=496269 UDPv4 read returned 114
Mon Nov 06 12:11:31 2006 us=496317 UDPv4 READ [114] from XXX.XXX.XXX.XXX:1194: P_CONTROL_V1 kid=0 sid=859e87dd 3e16709c [ ] pid=3 DATA 30150603 55040313 0e6f7065 6e76706e 2e65636c 2e636131 1d301b06 092a864[more...]
Mon Nov 06 12:11:31 2006 us=503025 TLS: control channel, op=P_CONTROL_V1, IP=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=503062 TLS: initial packet test, i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, rec-sid=859e87dd 3e16709c, rec-ip=XXX.XXX.XXX.XXX:1194, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=503088 TLS: found match, session[0], sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=503100 TLS: received control channel packet s#=0 sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=503109 ACK read ID 3 (buf->len=100)
Mon Nov 06 12:11:31 2006 us=503117 ACK mark active incoming ID 3
Mon Nov 06 12:11:31 2006 us=503123 ACK acknowledge ID 3 (ack->len=1)
Mon Nov 06 12:11:31 2006 us=503143 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=503152 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=551095 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=551110 BIO write tls_write_ciphertext 100 bytes
Mon Nov 06 12:11:31 2006 us=551133 Incoming Ciphertext -> TLS
Mon Nov 06 12:11:31 2006 us=551186 TLS: tls_process: chg=1 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=551195 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=551212 ACK write ID 3 (ack->len=1, n=1)
Mon Nov 06 12:11:31 2006 us=551219 Dedicated ACK -> TCP/UDP
Mon Nov 06 12:11:31 2006 us=551226 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:31 2006 us=551233 TLS: tls_process: timeout set to 59
Mon Nov 06 12:11:31 2006 us=551247 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=551261 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=559975 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=560014 WIN32 I/O: Socket Receive immediate return [1594,114]
Mon Nov 06 12:11:31 2006 us=560036 WE_CTL n=1 ev=0x00a25264 rwflags=0x0003 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=560048 I/O WAIT T?|T?|SR1|SW1 [1/179611]
Mon Nov 06 12:11:31 2006 us=560056 WE_WAIT enter n=3 to=1180
Mon Nov 06 12:11:31 2006 us=560064
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=560071 [1] ev=0x0000073c rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=560079 [2] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=560094 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=560104 WE_WAIT leave [2,1] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=560112 event_wait returned 2
Mon Nov 06 12:11:31 2006 us=567326 I/O WAIT status=0x0003
Mon Nov 06 12:11:31 2006 us=567390 UDPv4 WRITE [22] to XXX.XXX.XXX.XXX:1194: P_ACK_V1 kid=0 sid=57644ade 82ff8e36 [ 3 sid=859e87dd 3e16709c ]
Mon Nov 06 12:11:31 2006 us=567402 WIN32 I/O: Socket Completion non-queued success [22]
Mon Nov 06 12:11:31 2006 us=567466 WIN32 I/O: Socket Send immediate return [22,22]
Mon Nov 06 12:11:31 2006 us=567474 UDPv4 write returned 22
Mon Nov 06 12:11:31 2006 us=567496 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=567508 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=567517 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=567555 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:31 2006 us=567562 TLS: tls_process: timeout set to 59
Mon Nov 06 12:11:31 2006 us=617316 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=617362 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=617380 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=617390 WE_CTL n=1 ev=0x00a25264 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=617405 I/O WAIT T?|T?|SR1|Sw1 [1/179611]
Mon Nov 06 12:11:31 2006 us=617414 WE_WAIT enter n=2 to=1180
Mon Nov 06 12:11:31 2006 us=617423
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=617430 [1] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=617445 WE_WAIT leave [1,0] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=617455 event_wait returned 1
Mon Nov 06 12:11:31 2006 us=624243 I/O WAIT status=0x0001
Mon Nov 06 12:11:31 2006 us=624254 WIN32 I/O: Socket Completion non-queued success [114]
Mon Nov 06 12:11:31 2006 us=624261 UDPv4 read returned 114
Mon Nov 06 12:11:31 2006 us=624338 UDPv4 READ [114] from XXX.XXX.XXX.XXX:1194: P_CONTROL_V1 kid=0 sid=859e87dd 3e16709c [ ] pid=4 DATA 43413110 300e0603 55040813 07416c62 65727461 31243022 06035504 0a131b4[more...]
Mon Nov 06 12:11:31 2006 us=624350 TLS: control channel, op=P_CONTROL_V1, IP=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=624370 TLS: initial packet test, i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, rec-sid=859e87dd 3e16709c, rec-ip=XXX.XXX.XXX.XXX:1194, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=624382 TLS: found match, session[0], sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=624392 TLS: received control channel packet s#=0 sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=624401 ACK read ID 4 (buf->len=100)
Mon Nov 06 12:11:31 2006 us=624408 ACK mark active incoming ID 4
Mon Nov 06 12:11:31 2006 us=633889 ACK acknowledge ID 4 (ack->len=1)
Mon Nov 06 12:11:31 2006 us=633954 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=633967 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=633976 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=633988 BIO write tls_write_ciphertext 100 bytes
Mon Nov 06 12:11:31 2006 us=633996 Incoming Ciphertext -> TLS
Mon Nov 06 12:11:31 2006 us=634037 TLS: tls_process: chg=1 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=634045 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=634060 ACK write ID 4 (ack->len=1, n=1)
Mon Nov 06 12:11:31 2006 us=634067 Dedicated ACK -> TCP/UDP
Mon Nov 06 12:11:31 2006 us=634074 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:31 2006 us=685803 TLS: tls_process: timeout set to 59
Mon Nov 06 12:11:31 2006 us=685832 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=685852 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=685894 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=685928 WIN32 I/O: Socket Receive immediate return [1594,114]
Mon Nov 06 12:11:31 2006 us=685937 WE_CTL n=1 ev=0x00a25264 rwflags=0x0003 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=685949 I/O WAIT T?|T?|SR1|SW1 [1/179611]
Mon Nov 06 12:11:31 2006 us=685957 WE_WAIT enter n=3 to=1180
Mon Nov 06 12:11:31 2006 us=685965
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=685972 [1] ev=0x0000073c rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=696307 [2] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=696355 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=696366 WE_WAIT leave [2,1] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=696373 event_wait returned 2
Mon Nov 06 12:11:31 2006 us=696381 I/O WAIT status=0x0003
Mon Nov 06 12:11:31 2006 us=696406 UDPv4 WRITE [22] to XXX.XXX.XXX.XXX:1194: P_ACK_V1 kid=0 sid=57644ade 82ff8e36 [ 4 sid=859e87dd 3e16709c ]
Mon Nov 06 12:11:31 2006 us=696416 WIN32 I/O: Socket Completion non-queued success [22]
Mon Nov 06 12:11:31 2006 us=696472 WIN32 I/O: Socket Send immediate return [22,22]
Mon Nov 06 12:11:31 2006 us=696480 UDPv4 write returned 22
Mon Nov 06 12:11:31 2006 us=696501 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=705804 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=705815 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=705886 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:31 2006 us=705894 TLS: tls_process: timeout set to 59
Mon Nov 06 12:11:31 2006 us=705907 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=705922 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=705935 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=705944 WE_CTL n=1 ev=0x00a25264 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=705955 I/O WAIT T?|T?|SR1|Sw1 [1/179611]
Mon Nov 06 12:11:31 2006 us=705962 WE_WAIT enter n=2 to=1180
Mon Nov 06 12:11:31 2006 us=766092
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=766113 [1] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=766140 WE_WAIT leave [1,0] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=766163 event_wait returned 1
Mon Nov 06 12:11:31 2006 us=766174 I/O WAIT status=0x0001
Mon Nov 06 12:11:31 2006 us=766184 WIN32 I/O: Socket Completion non-queued success [114]
Mon Nov 06 12:11:31 2006 us=766192 UDPv4 read returned 114
Mon Nov 06 12:11:31 2006 us=766244 UDPv4 READ [114] from XXX.XXX.XXX.XXX:1194: P_CONTROL_V1 kid=0 sid=859e87dd 3e16709c [ ] pid=5 DATA 1b06092a 864886f7 0d010901 160e616e 64726577 72406563 6c2e6361 3082012[more...]
Mon Nov 06 12:11:31 2006 us=766257 TLS: control channel, op=P_CONTROL_V1, IP=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=775395 TLS: initial packet test, i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, rec-sid=859e87dd 3e16709c, rec-ip=XXX.XXX.XXX.XXX:1194, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=775423 TLS: found match, session[0], sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=775448 TLS: received control channel packet s#=0 sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=775458 ACK read ID 5 (buf->len=100)
Mon Nov 06 12:11:31 2006 us=775467 ACK mark active incoming ID 5
Mon Nov 06 12:11:31 2006 us=775474 ACK acknowledge ID 5 (ack->len=1)
Mon Nov 06 12:11:31 2006 us=775499 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=775511 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=775520 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=786095 BIO write tls_write_ciphertext 100 bytes
Mon Nov 06 12:11:31 2006 us=786126 Incoming Ciphertext -> TLS
Mon Nov 06 12:11:31 2006 us=786185 TLS: tls_process: chg=1 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=786197 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=786212 ACK write ID 5 (ack->len=1, n=1)
Mon Nov 06 12:11:31 2006 us=786219 Dedicated ACK -> TCP/UDP
Mon Nov 06 12:11:31 2006 us=786226 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:31 2006 us=786233 TLS: tls_process: timeout set to 59
Mon Nov 06 12:11:31 2006 us=786250 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=786265 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=786279 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=845774 WIN32 I/O: Socket Receive immediate return [1594,114]
Mon Nov 06 12:11:31 2006 us=845805 WE_CTL n=1 ev=0x00a25264 rwflags=0x0003 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=845820 I/O WAIT T?|T?|SR1|SW1 [1/179611]
Mon Nov 06 12:11:31 2006 us=845827 WE_WAIT enter n=3 to=1180
Mon Nov 06 12:11:31 2006 us=845835
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=845843 [1] ev=0x0000073c rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=845850 [2] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=845862 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=845870 WE_WAIT leave [2,1] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=845878 event_wait returned 2
Mon Nov 06 12:11:31 2006 us=845885 I/O WAIT status=0x0003
Mon Nov 06 12:11:31 2006 us=845909 UDPv4 WRITE [22] to XXX.XXX.XXX.XXX:1194: P_ACK_V1 kid=0 sid=57644ade 82ff8e36 [ 5 sid=859e87dd 3e16709c ]
Mon Nov 06 12:11:31 2006 us=856664 WIN32 I/O: Socket Completion non-queued success [22]
Mon Nov 06 12:11:31 2006 us=856737 WIN32 I/O: Socket Send immediate return [22,22]
Mon Nov 06 12:11:31 2006 us=856745 UDPv4 write returned 22
Mon Nov 06 12:11:31 2006 us=856768 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=856779 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=856788 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=856829 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:31 2006 us=856836 TLS: tls_process: timeout set to 59
Mon Nov 06 12:11:31 2006 us=856849 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=913263 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=913278 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=913301 WE_CTL n=1 ev=0x00a25264 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=913327 I/O WAIT T?|T?|SR1|Sw1 [1/179611]
Mon Nov 06 12:11:31 2006 us=913334 WE_WAIT enter n=2 to=1180
Mon Nov 06 12:11:31 2006 us=913342
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=913349 [1] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=913359 WE_WAIT leave [1,0] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=913366 event_wait returned 1
Mon Nov 06 12:11:31 2006 us=913373 I/O WAIT status=0x0001
Mon Nov 06 12:11:31 2006 us=913381 WIN32 I/O: Socket Completion non-queued success [114]
Mon Nov 06 12:11:31 2006 us=913389 UDPv4 read returned 114
Mon Nov 06 12:11:31 2006 us=921862 UDPv4 READ [114] from XXX.XXX.XXX.XXX:1194: P_CONTROL_V1 kid=0 sid=859e87dd 3e16709c [ ] pid=6 DATA 4fbf90f6 7e166d85 7b7678cb cd577ee2 32e19162 304a8bec a0e56545 2ed2a5c[more...]
Mon Nov 06 12:11:31 2006 us=921874 TLS: control channel, op=P_CONTROL_V1, IP=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=921894 TLS: initial packet test, i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, rec-sid=859e87dd 3e16709c, rec-ip=XXX.XXX.XXX.XXX:1194, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=921906 TLS: found match, session[0], sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=921918 TLS: received control channel packet s#=0 sid=859e87dd 3e16709c
Mon Nov 06 12:11:31 2006 us=921926 ACK read ID 6 (buf->len=100)
Mon Nov 06 12:11:31 2006 us=921934 ACK mark active incoming ID 6
Mon Nov 06 12:11:31 2006 us=921940 ACK acknowledge ID 6 (ack->len=1)
Mon Nov 06 12:11:31 2006 us=932062 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=932077 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=932097 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=932120 BIO write tls_write_ciphertext 100 bytes
Mon Nov 06 12:11:31 2006 us=932128 Incoming Ciphertext -> TLS
Mon Nov 06 12:11:31 2006 us=932151 TLS: tls_process: chg=1 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:31 2006 us=932159 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:31 2006 us=932174 ACK write ID 6 (ack->len=1, n=1)
Mon Nov 06 12:11:31 2006 us=932181 Dedicated ACK -> TCP/UDP
Mon Nov 06 12:11:31 2006 us=932188 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:31 2006 us=932195 TLS: tls_process: timeout set to 59
Mon Nov 06 12:11:31 2006 us=988619 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=988652 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:31 2006 us=988669 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=988696 WIN32 I/O: Socket Receive immediate return [1594,114]
Mon Nov 06 12:11:31 2006 us=988704 WE_CTL n=1 ev=0x00a25264 rwflags=0x0003 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=988717 I/O WAIT T?|T?|SR1|SW1 [1/179611]
Mon Nov 06 12:11:31 2006 us=988724 WE_WAIT enter n=3 to=1180
Mon Nov 06 12:11:31 2006 us=988732
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:31 2006 us=988739 [1] ev=0x0000073c rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=988747 [2] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=998114 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=998124 WE_WAIT leave [2,1] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:31 2006 us=998131 event_wait returned 2
Mon Nov 06 12:11:31 2006 us=998140 I/O WAIT status=0x0003
Mon Nov 06 12:11:31 2006 us=998186 UDPv4 WRITE [22] to XXX.XXX.XXX.XXX:1194: P_ACK_V1 kid=0 sid=57644ade 82ff8e36 [ 6 sid=859e87dd 3e16709c ]
Mon Nov 06 12:11:31 2006 us=998196 WIN32 I/O: Socket Completion non-queued success [22]
Mon Nov 06 12:11:31 2006 us=998246 WIN32 I/O: Socket Send immediate return [22,22]
Mon Nov 06 12:11:31 2006 us=998253 UDPv4 write returned 22
Mon Nov 06 12:11:31 2006 us=998273 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=57644ade 82ff8e36, stored-sid=859e87dd 3e16709c, stored-ip=XXX.XXX.XXX.XXX:1194
Mon Nov 06 12:11:31 2006 us=998283 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Nov 06 12:11:32 2006 us=53839 ACK reliable_can_send active=0 current=0 : [2]
Mon Nov 06 12:11:32 2006 us=53914 ACK reliable_send_timeout 604800 [2]
Mon Nov 06 12:11:32 2006 us=53923 TLS: tls_process: timeout set to 59
Mon Nov 06 12:11:32 2006 us=53937 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=99080840 4f2f4ac6, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:32 2006 us=53951 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[undef]
Mon Nov 06 12:11:32 2006 us=53962 WE_CTL n=0 ev=0x00469984 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:32 2006 us=53970 WE_CTL n=1 ev=0x00a25264 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:32 2006 us=53981 I/O WAIT T?|T?|SR1|Sw1 [1/179611]
Mon Nov 06 12:11:32 2006 us=53988 WE_WAIT enter n=2 to=1180
Mon Nov 06 12:11:32 2006 us=53995
- ev=0x00000750 rwflags=0x0001 arg=0x00453560
Mon Nov 06 12:11:32 2006 us=54002 [1] ev=0x00000748 rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:32 2006 us=62839 WE_WAIT leave [1,0] rwflags=0x0001 arg=0x00453558
Mon Nov 06 12:11:32 2006 us=62849 event_wait returned 1
Server Log:
Mon Nov 6 12:11:57 2006 MULTI: multi_create_instance called
Mon Nov 6 12:11:57 2006 HOST:33477 Re-using SSL/TLS context
Mon Nov 6 12:11:57 2006 HOST:33477 LZO compression initialized
Mon Nov 6 12:11:57 2006 HOST:33477 Control Channel MTU parms [ L:1594 D:138 EF:38 EB:0 ET:0 EL:0 ]
Mon Nov 6 12:11:57 2006 HOST:33477 Data Channel MTU parms [ L:1594 D:1400 EF:62 EB:135 ET:32 EL:0 AF:3/1 ]
Mon Nov 6 12:11:57 2006 HOST:33477 Fragmentation MTU parms [ L:1594 D:1400 EF:61 EB:135 ET:33 EL:0 AF:3/1 ]
Mon Nov 6 12:11:57 2006 HOST:33477 Local Options hash (VER=V4): '1374d8b5'
Mon Nov 6 12:11:57 2006 HOST:33477 Expected Remote Options hash (VER=V4): '78bea45a'
Mon Nov 6 12:11:57 2006 HOST:33477 TLS: Initial packet from 68.148.4.247:33477, sid=57644ade 82ff8e36
Mon Nov 6 12:12:04 2006 HOST:33477 TLS: new session incoming connection from HOST:33477
Mon Nov 6 12:12:11 2006 6HOST:33477 TLS: new session incoming connection from HOST:33477
Mon Nov 6 12:12:57 2006 HOST:33477 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Mon Nov 6 12:12:57 2006 HOST:33477 TLS Error: TLS handshake failed
Mon Nov 6 12:12:57 2006 HOST:33477 SIGUSR1[soft,tls-error] received, client-instance restarting
So.. If I compare the two logs.. it looks like a TLS problem, no? Great.. any idea how I fix that?