OpenVPN Support Forum

Posted: **Mon Oct 16, 2017 9:16 pm**

Hi,

I've been happily running openvpn for a long time without issues until today.
I haven't touched the openvpn config on either the server and the clients.

Somehow, the connection is always reset, and I can't seem to understand from the log what could be causing this.
The clients are providing correct user/pass details.

Here's part of the log (real public IP replaced with 000.000.000.000):

Code: Select all

Mon Oct 16 22:42:20 2017 us=924241 TCP connection established with [AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:20 2017 us=924248 TCP_SERVER link local: (not bound)
Mon Oct 16 22:42:20 2017 us=924254 TCP_SERVER link remote: [AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:20 2017 us=924269 000.000.000.000:33134 SENT PING
Mon Oct 16 22:42:20 2017 us=924275 000.000.000.000:33134 TIMER: coarse timer wakeup 1 seconds
Mon Oct 16 22:42:20 2017 us=924288 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_INITIAL, mysid=8f389425 982b996e, stored-sid=00000000 00000000, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:20 2017 us=924295 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_INITIAL lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:20 2017 us=924300 000.000.000.000:33134 ACK mark active outgoing ID 0
Mon Oct 16 22:42:20 2017 us=924307 000.000.000.000:33134 TLS: Initial Handshake, sid=8f389425 982b996e
Mon Oct 16 22:42:20 2017 us=924313 000.000.000.000:33134 ACK reliable_can_send active=1 current=1 : [1] 0
Mon Oct 16 22:42:20 2017 us=924350 000.000.000.000:33134 SSL state (accept): before/accept initialization
Mon Oct 16 22:42:20 2017 us=924370 000.000.000.000:33134 TLS: tls_process: chg=1 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:20 2017 us=924376 000.000.000.000:33134 ACK reliable_can_send active=1 current=1 : [1] 0
Mon Oct 16 22:42:20 2017 us=924384 000.000.000.000:33134 ACK reliable_send_timeout 0 [1] 0
Mon Oct 16 22:42:20 2017 us=924390 000.000.000.000:33134 TLS: tls_process: timeout set to 1
Mon Oct 16 22:42:20 2017 us=924399 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:20 2017 us=924407 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:20 2017 us=924415 000.000.000.000:33134 RANDOM USEC=61205
Mon Oct 16 22:42:20 2017 us=924423 000.000.000.000:33134 SCHEDULE: schedule_add_modify wakeup=[Mon Oct 16 22:42:21 2017 us=985625] pri=0
Mon Oct 16 22:42:20 2017 us=924432 000.000.000.000:33134 MULTI TCP: instance added: 000.000.000.000:33134
Mon Oct 16 22:42:20 2017 us=924441 000.000.000.000:33134 MULTI TCP: multi_tcp_action a=TA_INITIAL p=0
Mon Oct 16 22:42:20 2017 us=924447 000.000.000.000:33134 MULTI TCP: multi_tcp_dispatch a=TA_INITIAL mi=0x006f2b50
Mon Oct 16 22:42:20 2017 us=924453 000.000.000.000:33134 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:20 2017 us=924459 000.000.000.000:33134 EP_CTL fd=9 rwflags=0x0001 ev=0x00000001 arg=0x006f2b50
Mon Oct 16 22:42:20 2017 us=924471 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=8f389425 982b996e, stored-sid=00000000 00000000, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:20 2017 us=924477 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:20 2017 us=924483 000.000.000.000:33134 ACK reliable_can_send active=1 current=1 : [1] 0
Mon Oct 16 22:42:20 2017 us=924490 000.000.000.000:33134 ACK reliable_send_timeout 0 [1] 0
Mon Oct 16 22:42:20 2017 us=924495 000.000.000.000:33134 TLS: tls_process: timeout set to 1
Mon Oct 16 22:42:20 2017 us=924504 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:20 2017 us=924512 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:20 2017 us=924519 000.000.000.000:33134 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:20 2017 us=924524 000.000.000.000:33134 MULTI TCP: multi_tcp_post TA_INITIAL -> TA_UNDEF
Mon Oct 16 22:42:20 2017 us=924532 000.000.000.000:33134 SCHEDULE: schedule_find_least wakeup=[Mon Oct 16 22:42:21 2017 us=985625] pri=343657858
Mon Oct 16 22:42:21 2017 us=837370 000.000.000.000:33134 EP_WAIT[0] rwflags=0x0001 ev=0x00000001 arg=0x006f2b50
Mon Oct 16 22:42:21 2017 us=837398 000.000.000.000:33134 MULTI: REAP range 176 -> 192
Mon Oct 16 22:42:21 2017 us=837406 000.000.000.000:33134 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Mon Oct 16 22:42:21 2017 us=837412 000.000.000.000:33134 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x006f2b50
Mon Oct 16 22:42:21 2017 us=837419 000.000.000.000:33134 STREAM: GET NEXT len=1627
Mon Oct 16 22:42:21 2017 us=837431 000.000.000.000:33134 STREAM: ADD length_added=44
Mon Oct 16 22:42:21 2017 us=837437 000.000.000.000:33134 STREAM: ADD returned TRUE, buf_len=42, residual_len=0
Mon Oct 16 22:42:21 2017 us=837442 000.000.000.000:33134 STREAM: GET FINAL len=42
Mon Oct 16 22:42:21 2017 us=837447 000.000.000.000:33134 STREAM: RESET
Mon Oct 16 22:42:21 2017 us=837453 000.000.000.000:33134 TCP_SERVER read returned 42
Mon Oct 16 22:42:21 2017 us=837476 000.000.000.000:33134 TCP_SERVER READ [42] from [AF_INET]000.000.000.000:33134: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 sid=d096c4a7 e5b41807 tls_hmac=97396155 eb3defd0 caf8207f 349fd22f 2fda87d6 pid=[ #1 / time = (1508186541) Mon Oct 16 22:42:21 2017 ] [ ] pid=0 DATA
Mon Oct 16 22:42:21 2017 us=837484 000.000.000.000:33134 TLS: control channel, op=P_CONTROL_HARD_RESET_CLIENT_V2, IP=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:21 2017 us=837497 000.000.000.000:33134 TLS: initial packet test, i=0 state=S_PRE_START, mysid=8f389425 982b996e, rec-sid=d096c4a7 e5b41807, rec-ip=[AF_INET]000.000.000.000:33134, stored-sid=00000000 00000000, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:21 2017 us=837512 000.000.000.000:33134 TLS: initial packet test, i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, rec-sid=d096c4a7 e5b41807, rec-ip=[AF_INET]000.000.000.000:33134, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:21 2017 us=837523 000.000.000.000:33134 TLS: initial packet test, i=2 state=S_UNDEF, mysid=00000000 00000000, rec-sid=d096c4a7 e5b41807, rec-ip=[AF_INET]000.000.000.000:33134, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:21 2017 us=837532 000.000.000.000:33134 TLS: Initial packet from [AF_INET]000.000.000.000:33134, sid=d096c4a7 e5b41807
Mon Oct 16 22:42:21 2017 us=837546 000.000.000.000:33134 DECRYPT FROM: 97396155 eb3defd0 caf8207f 349fd22f 2fda87d6 00000001 59e519ad 38d096c[more...]
Mon Oct 16 22:42:21 2017 us=837567 000.000.000.000:33134 PID_TEST [0] [TLS_WRAP-0] [] 0:0 1508186541:1 t=1508186541[0] r=[0,64,15,0,1] sl=[0,0,64,528]
Mon Oct 16 22:42:21 2017 us=837576 000.000.000.000:33134 TLS: received control channel packet s#=0 sid=d096c4a7 e5b41807
Mon Oct 16 22:42:21 2017 us=837581 000.000.000.000:33134 ACK reliable_schedule_now
Mon Oct 16 22:42:21 2017 us=837587 000.000.000.000:33134 ACK read ID 0 (buf->len=0)
Mon Oct 16 22:42:21 2017 us=837593 000.000.000.000:33134 ACK RWBS rel->size=8 rel->packet_id=00000000 id=00000000 ret=1

Mon Oct 16 22:42:21 2017 us=837599 000.000.000.000:33134 ACK mark active incoming ID 0
Mon Oct 16 22:42:21 2017 us=837605 000.000.000.000:33134 ACK acknowledge ID 0 (ack->len=1)
Mon Oct 16 22:42:21 2017 us=837614 000.000.000.000:33134 TIMER: coarse timer wakeup 1 seconds
Mon Oct 16 22:42:21 2017 us=837626 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:21 2017 us=837633 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:21 2017 us=837639 000.000.000.000:33134 ACK reliable_can_send active=1 current=1 : [1] 0
Mon Oct 16 22:42:21 2017 us=837644 000.000.000.000:33134 ACK reliable_send ID 0 (size=4 to=2)
Mon Oct 16 22:42:21 2017 us=837650 000.000.000.000:33134 ACK write ID 0 (ack->len=1, n=1)
Mon Oct 16 22:42:21 2017 us=837660 000.000.000.000:33134 ENCRYPT HMAC: 74200b44 b314fa4b 187c3d11 4a36d13c 73b5f190
Mon Oct 16 22:42:21 2017 us=837674 000.000.000.000:33134 ENCRYPT TO: 74200b44 b314fa4b 187c3d11 4a36d13c 73b5f190 00000001 59e519ad 408f389[more...]
Mon Oct 16 22:42:21 2017 us=837680 000.000.000.000:33134 Reliable -> TCP/UDP
Mon Oct 16 22:42:21 2017 us=837686 000.000.000.000:33134 ACK reliable_send_timeout 2 [1] 0
Mon Oct 16 22:42:21 2017 us=837691 000.000.000.000:33134 TLS: tls_process: timeout set to 2
Mon Oct 16 22:42:21 2017 us=837700 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:21 2017 us=837709 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:21 2017 us=837719 000.000.000.000:33134 SCHEDULE: schedule_add_modify wakeup=[Mon Oct 16 22:42:22 2017 us=985741] pri=343657858
Mon Oct 16 22:42:21 2017 us=837725 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:21 2017 us=837731 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Mon Oct 16 22:42:21 2017 us=837737 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Mon Oct 16 22:42:21 2017 us=837742 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x006f2b50
Mon Oct 16 22:42:21 2017 us=837748 PO_CTL rwflags=0x0002 ev=9 arg=0x006afbc0
Mon Oct 16 22:42:21 2017 us=837754 PO_CTL rwflags=0x0001 ev=6 arg=0x006afac8
Mon Oct 16 22:42:21 2017 us=837761 I/O WAIT TR|Tw|Sr|SW [0/0]
Mon Oct 16 22:42:21 2017 us=837771 PO_WAIT[0,0] fd=9 rev=0x00000004 rwflags=0x0002 arg=0x006afbc0
Mon Oct 16 22:42:21 2017 us=837777  event_wait returned 1
Mon Oct 16 22:42:21 2017 us=837782 I/O WAIT status=0x0002
Mon Oct 16 22:42:21 2017 us=837788 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_WRITE mi=0x006f2b50
Mon Oct 16 22:42:21 2017 us=837806 000.000.000.000:33134 TCP_SERVER WRITE [54] to [AF_INET]000.000.000.000:33134: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 sid=8f389425 982b996e tls_hmac=74200b44 b314fa4b 187c3d11 4a36d13c 73b5f190 pid=[ #1 / time = (1508186541) Mon Oct 16 22:42:21 2017 ] [ 0 sid=d096c4a7 e5b41807 ] pid=0 DATA
Mon Oct 16 22:42:21 2017 us=837812 000.000.000.000:33134 STREAM: WRITE 54 offset=18
Mon Oct 16 22:42:21 2017 us=837827 000.000.000.000:33134 TCP_SERVER write returned 56
Mon Oct 16 22:42:21 2017 us=837838 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:21 2017 us=837844 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:21 2017 us=837853 000.000.000.000:33134 ACK reliable_can_send active=1 current=0 : [1] 0
Mon Oct 16 22:42:21 2017 us=837859 000.000.000.000:33134 Incoming Ciphertext -> TLS
Mon Oct 16 22:42:21 2017 us=837871 000.000.000.000:33134 TLS: tls_process: chg=1 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:21 2017 us=837877 000.000.000.000:33134 ACK reliable_can_send active=1 current=0 : [1] 0
Mon Oct 16 22:42:21 2017 us=837884 000.000.000.000:33134 ACK reliable_send_timeout 2 [1] 0
Mon Oct 16 22:42:21 2017 us=837889 000.000.000.000:33134 TLS: tls_process: timeout set to 2
Mon Oct 16 22:42:21 2017 us=837898 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:21 2017 us=837907 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:21 2017 us=837913 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:21 2017 us=837919 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_UNDEF
Mon Oct 16 22:42:21 2017 us=837927 SCHEDULE: schedule_find_least wakeup=[Mon Oct 16 22:42:22 2017 us=985741] pri=1973038265
Mon Oct 16 22:42:21 2017 us=927874 EP_WAIT[0] rwflags=0x0001 ev=0x00000001 arg=0x006f2b50
Mon Oct 16 22:42:21 2017 us=927896 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Mon Oct 16 22:42:21 2017 us=927903 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x006f2b50
Mon Oct 16 22:42:21 2017 us=927909 000.000.000.000:33134 STREAM: GET NEXT len=1627
Mon Oct 16 22:42:21 2017 us=927917 000.000.000.000:33134 STREAM: ADD length_added=52
Mon Oct 16 22:42:21 2017 us=927923 000.000.000.000:33134 STREAM: ADD returned TRUE, buf_len=50, residual_len=0
Mon Oct 16 22:42:21 2017 us=927928 000.000.000.000:33134 STREAM: GET FINAL len=50
Mon Oct 16 22:42:21 2017 us=927933 000.000.000.000:33134 STREAM: RESET
Mon Oct 16 22:42:21 2017 us=927939 000.000.000.000:33134 TCP_SERVER read returned 50
Mon Oct 16 22:42:21 2017 us=927966 000.000.000.000:33134 TCP_SERVER READ [50] from [AF_INET]000.000.000.000:33134: P_ACK_V1 kid=0 sid=d096c4a7 e5b41807 tls_hmac=c3703e73 70053e15 d1fa77cc 437140fa 87f186b2 pid=[ #2 / time = (1508186541) Mon Oct 16 22:42:21 2017 ] [ 0 sid=8f389425 982b996e ]
Mon Oct 16 22:42:21 2017 us=927974 000.000.000.000:33134 TLS: control channel, op=P_ACK_V1, IP=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:21 2017 us=927987 000.000.000.000:33134 TLS: initial packet test, i=0 state=S_PRE_START, mysid=8f389425 982b996e, rec-sid=d096c4a7 e5b41807, rec-ip=[AF_INET]000.000.000.000:33134, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:21 2017 us=927994 000.000.000.000:33134 TLS: found match, session[0], sid=d096c4a7 e5b41807
Mon Oct 16 22:42:21 2017 us=928010 000.000.000.000:33134 DECRYPT FROM: c3703e73 70053e15 d1fa77cc 437140fa 87f186b2 00000002 59e519ad 28d096c[more...]
Mon Oct 16 22:42:21 2017 us=928022 000.000.000.000:33134 PID_TEST [0] [TLS_WRAP-0] [0] 1508186541:1 1508186541:2 t=1508186541[0] r=[0,64,15,0,1] sl=[63,1,64,528]
Mon Oct 16 22:42:21 2017 us=928034 000.000.000.000:33134 TLS: received control channel packet s#=0 sid=d096c4a7 e5b41807
Mon Oct 16 22:42:21 2017 us=928040 000.000.000.000:33134 ACK received for pid 0, deleting from send buffer
Mon Oct 16 22:42:21 2017 us=928054 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:21 2017 us=928061 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:21 2017 us=928067 000.000.000.000:33134 STATE S_START
Mon Oct 16 22:42:21 2017 us=928074 000.000.000.000:33134 ACK reliable_can_send active=0 current=0 : [1]
Mon Oct 16 22:42:21 2017 us=928086 000.000.000.000:33134 TLS: tls_process: chg=1 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:21 2017 us=928092 000.000.000.000:33134 ACK reliable_can_send active=0 current=0 : [1]
Mon Oct 16 22:42:21 2017 us=928106 000.000.000.000:33134 ACK reliable_send_timeout 604800 [1]
Mon Oct 16 22:42:21 2017 us=928112 000.000.000.000:33134 TLS: tls_process: timeout set to 59
Mon Oct 16 22:42:21 2017 us=928121 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:21 2017 us=928130 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:21 2017 us=928138 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:21 2017 us=928144 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:21 2017 us=928150 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_UNDEF
Mon Oct 16 22:42:22 2017 us=65896 EP_WAIT[0] rwflags=0x0001 ev=0x00000001 arg=0x006f2b50
Mon Oct 16 22:42:22 2017 us=65919 MULTI: REAP range 192 -> 208
Mon Oct 16 22:42:22 2017 us=65927 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Mon Oct 16 22:42:22 2017 us=65933 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=65939 000.000.000.000:33134 STREAM: GET NEXT len=1627
Mon Oct 16 22:42:22 2017 us=65947 000.000.000.000:33134 STREAM: ADD length_added=139
Mon Oct 16 22:42:22 2017 us=65953 000.000.000.000:33134 STREAM: ADD returned TRUE, buf_len=137, residual_len=0
Mon Oct 16 22:42:22 2017 us=65958 000.000.000.000:33134 STREAM: GET FINAL len=137
Mon Oct 16 22:42:22 2017 us=65963 000.000.000.000:33134 STREAM: RESET
Mon Oct 16 22:42:22 2017 us=65969 000.000.000.000:33134 TCP_SERVER read returned 137
Mon Oct 16 22:42:22 2017 us=66007 000.000.000.000:33134 TCP_SERVER READ [137] from [AF_INET]000.000.000.000:33134: P_CONTROL_V1 kid=0 sid=d096c4a7 e5b41807 tls_hmac=d58fd977 e442070a c9628f5a 54a5fb2b fba0b47c pid=[ #3 / time = (1508186541) Mon Oct 16 22:42:21 2017 ] [ ] pid=1 DATA 16030100 5a010000 5603034c 98887bbe ab10885c 11017647 8a54c208 a9d0fbf[more...]
Mon Oct 16 22:42:22 2017 us=66016 000.000.000.000:33134 TLS: control channel, op=P_CONTROL_V1, IP=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=66029 000.000.000.000:33134 TLS: initial packet test, i=0 state=S_START, mysid=8f389425 982b996e, rec-sid=d096c4a7 e5b41807, rec-ip=[AF_INET]000.000.000.000:33134, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=66036 000.000.000.000:33134 TLS: found match, session[0], sid=d096c4a7 e5b41807
Mon Oct 16 22:42:22 2017 us=66076 000.000.000.000:33134 DECRYPT FROM: d58fd977 e442070a c9628f5a 54a5fb2b fba0b47c 00000003 59e519ad 20d096c[more...]
Mon Oct 16 22:42:22 2017 us=66090 000.000.000.000:33134 PID_TEST [0] [TLS_WRAP-0] [11] 1508186541:2 1508186541:3 t=1508186542[0] r=[-1,64,15,0,1] sl=[62,2,64,528]
Mon Oct 16 22:42:22 2017 us=66098 000.000.000.000:33134 TLS: received control channel packet s#=0 sid=d096c4a7 e5b41807
Mon Oct 16 22:42:22 2017 us=66104 000.000.000.000:33134 ACK read ID 1 (buf->len=95)
Mon Oct 16 22:42:22 2017 us=66110 000.000.000.000:33134 ACK RWBS rel->size=8 rel->packet_id=00000001 id=00000001 ret=1

Mon Oct 16 22:42:22 2017 us=66115 000.000.000.000:33134 ACK mark active incoming ID 1
Mon Oct 16 22:42:22 2017 us=66123 000.000.000.000:33134 ACK acknowledge ID 1 (ack->len=1)
Mon Oct 16 22:42:22 2017 us=66132 000.000.000.000:33134 TIMER: coarse timer wakeup 1 seconds
Mon Oct 16 22:42:22 2017 us=66142 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=66149 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=66155 000.000.000.000:33134 ACK reliable_can_send active=0 current=0 : [1]
Mon Oct 16 22:42:22 2017 us=66163 000.000.000.000:33134 BIO write tls_write_ciphertext 95 bytes
Mon Oct 16 22:42:22 2017 us=66169 000.000.000.000:33134 Incoming Ciphertext -> TLS
Mon Oct 16 22:42:22 2017 us=66234 000.000.000.000:33134 SSL state (accept): SSLv3 read client hello A
Mon Oct 16 22:42:22 2017 us=66243 000.000.000.000:33134 SSL state (accept): SSLv3 write server hello A
Mon Oct 16 22:42:22 2017 us=66398 000.000.000.000:33134 SSL state (accept): SSLv3 write certificate A
Mon Oct 16 22:42:22 2017 us=85401 000.000.000.000:33134 SSL state (accept): SSLv3 write key exchange A
Mon Oct 16 22:42:22 2017 us=85413 000.000.000.000:33134 SSL state (accept): SSLv3 write certificate request A
Mon Oct 16 22:42:22 2017 us=85420 000.000.000.000:33134 SSL state (accept): SSLv3 flush data
Mon Oct 16 22:42:22 2017 us=85429 000.000.000.000:33134 BIO read tls_read_ciphertext 1114 bytes
Mon Oct 16 22:42:22 2017 us=85434 000.000.000.000:33134 ACK mark active outgoing ID 1
Mon Oct 16 22:42:22 2017 us=85439 000.000.000.000:33134 Outgoing Ciphertext -> Reliable
Mon Oct 16 22:42:22 2017 us=85445 000.000.000.000:33134 TLS: tls_process: chg=1 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=85451 000.000.000.000:33134 ACK reliable_can_send active=1 current=1 : [2] 1
Mon Oct 16 22:42:22 2017 us=85456 000.000.000.000:33134 ACK reliable_send ID 1 (size=1118 to=2)
Mon Oct 16 22:42:22 2017 us=85462 000.000.000.000:33134 ACK write ID 1 (ack->len=1, n=1)
Mon Oct 16 22:42:22 2017 us=85473 000.000.000.000:33134 ENCRYPT HMAC: 8f23d83d 5a5f72ac d2376fa3 102a8cdb cb32ed0f
Mon Oct 16 22:42:22 2017 us=85655 000.000.000.000:33134 ENCRYPT TO: 8f23d83d 5a5f72ac d2376fa3 102a8cdb cb32ed0f 00000002 59e519ad 208f389[more...]
Mon Oct 16 22:42:22 2017 us=85661 000.000.000.000:33134 Reliable -> TCP/UDP
Mon Oct 16 22:42:22 2017 us=85667 000.000.000.000:33134 ACK reliable_send_timeout 2 [2] 1
Mon Oct 16 22:42:22 2017 us=85672 000.000.000.000:33134 TLS: tls_process: timeout set to 2
Mon Oct 16 22:42:22 2017 us=85680 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=85689 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=85699 000.000.000.000:33134 SCHEDULE: schedule_add_modify wakeup=[Mon Oct 16 22:42:23 2017 us=989360] pri=1973038265
Mon Oct 16 22:42:22 2017 us=85705 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:22 2017 us=85711 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_SOCKET_WRITE
Mon Oct 16 22:42:22 2017 us=85716 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Mon Oct 16 22:42:22 2017 us=85721 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=85727 PO_CTL rwflags=0x0002 ev=9 arg=0x006afbc0
Mon Oct 16 22:42:22 2017 us=85732 PO_CTL rwflags=0x0001 ev=6 arg=0x006afac8
Mon Oct 16 22:42:22 2017 us=85739 I/O WAIT TR|Tw|Sr|SW [0/0]
Mon Oct 16 22:42:22 2017 us=85747 PO_WAIT[0,0] fd=9 rev=0x00000004 rwflags=0x0002 arg=0x006afbc0
Mon Oct 16 22:42:22 2017 us=85752  event_wait returned 1
Mon Oct 16 22:42:22 2017 us=85757 I/O WAIT status=0x0002
Mon Oct 16 22:42:22 2017 us=85763 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_WRITE mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=85946 000.000.000.000:33134 TCP_SERVER WRITE [1168] to [AF_INET]000.000.000.000:33134: P_CONTROL_V1 kid=0 sid=8f389425 982b996e tls_hmac=8f23d83d 5a5f72ac d2376fa3 102a8cdb cb32ed0f pid=[ #2 / time = (1508186541) Mon Oct 16 22:42:21 2017 ] [ 1 sid=d096c4a7 e5b41807 ] pid=1 DATA 16030300 36020000 320303f8 71f85994 e01ce5fb ef2d6198 8a6e6198
Mon Oct 16 22:42:22 2017 us=85951 000.000.000.000:33134 STREAM: WRITE 1168 offset=18
Mon Oct 16 22:42:22 2017 us=85974 000.000.000.000:33134 TCP_SERVER write returned 1170
Mon Oct 16 22:42:22 2017 us=85985 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=85991 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=85996 000.000.000.000:33134 ACK reliable_can_send active=1 current=0 : [2] 1
Mon Oct 16 22:42:22 2017 us=86006 000.000.000.000:33134 BIO read tls_read_ciphertext 1114 bytes
Mon Oct 16 22:42:22 2017 us=86011 000.000.000.000:33134 ACK mark active outgoing ID 2
Mon Oct 16 22:42:22 2017 us=86022 000.000.000.000:33134 Outgoing Ciphertext -> Reliable
Mon Oct 16 22:42:22 2017 us=86028 000.000.000.000:33134 TLS: tls_process: chg=1 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=86033 000.000.000.000:33134 ACK reliable_can_send active=2 current=1 : [3] 1 2
Mon Oct 16 22:42:22 2017 us=86038 000.000.000.000:33134 ACK reliable_send ID 2 (size=1118 to=3)
Mon Oct 16 22:42:22 2017 us=86048 000.000.000.000:33134 ENCRYPT HMAC: d85d3809 275c0120 edac2558 4317f252 e435905c
Mon Oct 16 22:42:22 2017 us=86225 000.000.000.000:33134 ENCRYPT TO: d85d3809 275c0120 edac2558 4317f252 e435905c 00000003 59e519ad 208f389[more...]
Mon Oct 16 22:42:22 2017 us=86230 000.000.000.000:33134 Reliable -> TCP/UDP
Mon Oct 16 22:42:22 2017 us=86235 000.000.000.000:33134 ACK reliable_send_timeout 2 [3] 1 2
Mon Oct 16 22:42:22 2017 us=86240 000.000.000.000:33134 TLS: tls_process: timeout set to 2
Mon Oct 16 22:42:22 2017 us=86248 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=86256 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=86263 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_WRITE
Mon Oct 16 22:42:22 2017 us=86268 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Mon Oct 16 22:42:22 2017 us=86272 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=86278 PO_CTL rwflags=0x0002 ev=9 arg=0x006afbc0
Mon Oct 16 22:42:22 2017 us=86283 PO_CTL rwflags=0x0001 ev=6 arg=0x006afac8
Mon Oct 16 22:42:22 2017 us=86289 I/O WAIT TR|Tw|Sr|SW [0/0]
Mon Oct 16 22:42:22 2017 us=86295 PO_WAIT[0,0] fd=9 rev=0x00000004 rwflags=0x0002 arg=0x006afbc0
Mon Oct 16 22:42:22 2017 us=86300  event_wait returned 1
Mon Oct 16 22:42:22 2017 us=86305 I/O WAIT status=0x0002
Mon Oct 16 22:42:22 2017 us=86310 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_WRITE mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=86489 000.000.000.000:33134 TCP_SERVER WRITE [1156] to [AF_INET]000.000.000.000:33134: P_CONTROL_V1 kid=0 sid=8f389425 982b996e tls_hmac=d85d3809 275c0120 edac2558 4317f252 e435905c pid=[ #3 / time = (1508186541) Mon Oct 16 22:42:21 2017 ] [ ] pid=2 DATA 9b1e677d 0ecefb0b 025daea9 e233ae70 56efab51 30819b06 03551d11 0481933[more...]
Mon Oct 16 22:42:22 2017 us=86495 000.000.000.000:33134 STREAM: WRITE 1156 offset=30
Mon Oct 16 22:42:22 2017 us=86502 000.000.000.000:33134 TCP_SERVER write returned 1158
Mon Oct 16 22:42:22 2017 us=86512 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=86518 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=86523 000.000.000.000:33134 ACK reliable_can_send active=2 current=0 : [3] 1 2
Mon Oct 16 22:42:22 2017 us=86531 000.000.000.000:33134 BIO read tls_read_ciphertext 1114 bytes
Mon Oct 16 22:42:22 2017 us=86537 000.000.000.000:33134 ACK mark active outgoing ID 3
Mon Oct 16 22:42:22 2017 us=86542 000.000.000.000:33134 Outgoing Ciphertext -> Reliable
Mon Oct 16 22:42:22 2017 us=86547 000.000.000.000:33134 TLS: tls_process: chg=1 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=86552 000.000.000.000:33134 ACK reliable_can_send active=3 current=1 : [4] 1 2 3
Mon Oct 16 22:42:22 2017 us=86558 000.000.000.000:33134 ACK reliable_send ID 3 (size=1118 to=4)
Mon Oct 16 22:42:22 2017 us=86568 000.000.000.000:33134 ENCRYPT HMAC: 596f223a b61caf1f 50622c76 ca792dd3 c372a36f
Mon Oct 16 22:42:22 2017 us=86740 000.000.000.000:33134 ENCRYPT TO: 596f223a b61caf1f 50622c76 ca792dd3 c372a36f 00000004 59e519ad 208f389[more...]
Mon Oct 16 22:42:22 2017 us=86745 000.000.000.000:33134 Reliable -> TCP/UDP
Mon Oct 16 22:42:22 2017 us=86751 000.000.000.000:33134 ACK reliable_send_timeout 2 [4] 1 2 3
Mon Oct 16 22:42:22 2017 us=86756 000.000.000.000:33134 TLS: tls_process: timeout set to 2
Mon Oct 16 22:42:22 2017 us=86764 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=86774 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=86781 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_SOCKET_WRITE
Mon Oct 16 22:42:22 2017 us=86786 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Mon Oct 16 22:42:22 2017 us=86791 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=86796 PO_CTL rwflags=0x0002 ev=9 arg=0x006afbc0
Mon Oct 16 22:42:22 2017 us=86801 PO_CTL rwflags=0x0001 ev=6 arg=0x006afac8
Mon Oct 16 22:42:22 2017 us=86808 I/O WAIT TR|Tw|Sr|SW [0/0]
Mon Oct 16 22:42:22 2017 us=86813  event_wait returned 0
Mon Oct 16 22:42:22 2017 us=86818 I/O WAIT status=0x0020
Mon Oct 16 22:42:22 2017 us=86823 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_WRITE_DEFERRED mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=86829 000.000.000.000:33134 MULTI TCP: queuing deferred packet
Mon Oct 16 22:42:22 2017 us=86838 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=86844 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=86850 000.000.000.000:33134 ACK reliable_can_send active=3 current=0 : [4] 1 2 3
Mon Oct 16 22:42:22 2017 us=86857 000.000.000.000:33134 BIO read tls_read_ciphertext 398 bytes
Mon Oct 16 22:42:22 2017 us=86862 000.000.000.000:33134 ACK mark active outgoing ID 4
Mon Oct 16 22:42:22 2017 us=86867 000.000.000.000:33134 Outgoing Ciphertext -> Reliable
Mon Oct 16 22:42:22 2017 us=86872 000.000.000.000:33134 TLS: tls_process: chg=1 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=86877 000.000.000.000:33134 ACK reliable_can_send active=4 current=1 : [5] 1 2 3 4
Mon Oct 16 22:42:22 2017 us=86882 000.000.000.000:33134 ACK reliable_send ID 4 (size=402 to=5)
Mon Oct 16 22:42:22 2017 us=86891 000.000.000.000:33134 ENCRYPT HMAC: 852c2404 f99b2b92 7a2fe757 c02c3ade e3b58dad
Mon Oct 16 22:42:22 2017 us=86963 000.000.000.000:33134 ENCRYPT TO: 852c2404 f99b2b92 7a2fe757 c02c3ade e3b58dad 00000005 59e519ad 208f389[more...]
Mon Oct 16 22:42:22 2017 us=86968 000.000.000.000:33134 Reliable -> TCP/UDP
Mon Oct 16 22:42:22 2017 us=86973 000.000.000.000:33134 ACK reliable_send_timeout 2 [5] 1 2 3 4
Mon Oct 16 22:42:22 2017 us=86978 000.000.000.000:33134 TLS: tls_process: timeout set to 2
Mon Oct 16 22:42:22 2017 us=86986 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=86994 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=87000 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE_DEFERRED -> TA_SOCKET_WRITE
Mon Oct 16 22:42:22 2017 us=87005 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Mon Oct 16 22:42:22 2017 us=87009 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=87014 PO_CTL rwflags=0x0002 ev=9 arg=0x006afbc0
Mon Oct 16 22:42:22 2017 us=87019 PO_CTL rwflags=0x0001 ev=6 arg=0x006afac8
Mon Oct 16 22:42:22 2017 us=87025 I/O WAIT TR|Tw|Sr|SW [0/0]
Mon Oct 16 22:42:22 2017 us=87031  event_wait returned 0
Mon Oct 16 22:42:22 2017 us=87036 I/O WAIT status=0x0020
Mon Oct 16 22:42:22 2017 us=87041 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_WRITE_DEFERRED mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=87046 000.000.000.000:33134 MULTI TCP: queuing deferred packet
Mon Oct 16 22:42:22 2017 us=87054 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=87060 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=87068 000.000.000.000:33134 ACK reliable_can_send active=4 current=0 : [5] 1 2 3 4
Mon Oct 16 22:42:22 2017 us=87076 000.000.000.000:33134 ACK output sequence broken: [5] 1 2 3 4
Mon Oct 16 22:42:22 2017 us=87082 000.000.000.000:33134 ACK reliable_send_timeout 2 [5] 1 2 3 4
Mon Oct 16 22:42:22 2017 us=87087 000.000.000.000:33134 TLS: tls_process: timeout set to 2
Mon Oct 16 22:42:22 2017 us=87095 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=87103 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=87109 EP_CTL fd=9 rwflags=0x0002 ev=0x00000004 arg=0x006f2b50
Mon Oct 16 22:42:22 2017 us=87115 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE_DEFERRED -> TA_UNDEF
Mon Oct 16 22:42:22 2017 us=87123 SCHEDULE: schedule_find_least wakeup=[Mon Oct 16 22:42:23 2017 us=989360] pri=2000107839
Mon Oct 16 22:42:22 2017 us=194997 EP_WAIT[0] rwflags=0x0002 ev=0x00000004 arg=0x006f2b50
Mon Oct 16 22:42:22 2017 us=195021 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE_READY p=0
Mon Oct 16 22:42:22 2017 us=195028 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_WRITE_READY mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=195034 MULTI TCP: transmitting previously deferred packet
Mon Oct 16 22:42:22 2017 us=195233 000.000.000.000:33134 TCP_SERVER WRITE [1156] to [AF_INET]000.000.000.000:33134: P_CONTROL_V1 kid=0 sid=8f389425 982b996e tls_hmac=596f223a b61caf1f 50622c76 ca792dd3 c372a36f pid=[ #4 / time = (1508186541) Mon Oct 16 22:42:21 2017 ] [ ] pid=3 DATA 0603551d 11041c30 1a811869 6e666f72 6d617469 63614068 6d616e61 636f722[more...]
Mon Oct 16 22:42:22 2017 us=195240 000.000.000.000:33134 STREAM: WRITE 1156 offset=30
Mon Oct 16 22:42:22 2017 us=195250 000.000.000.000:33134 TCP_SERVER write returned -1
Mon Oct 16 22:42:22 2017 us=195264 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=195275 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=195283 000.000.000.000:33134 ACK reliable_can_send active=4 current=0 : [5] 1 2 3 4
Mon Oct 16 22:42:22 2017 us=195301 000.000.000.000:33134 ACK output sequence broken: [5] 1 2 3 4
Mon Oct 16 22:42:22 2017 us=195311 000.000.000.000:33134 ACK reliable_send_timeout 2 [5] 1 2 3 4
Mon Oct 16 22:42:22 2017 us=195317 000.000.000.000:33134 TLS: tls_process: timeout set to 2
Mon Oct 16 22:42:22 2017 us=195327 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=195336 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=195344 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE_READY -> TA_UNDEF
Mon Oct 16 22:42:22 2017 us=195352 EP_WAIT[0] rwflags=0x0002 ev=0x00000004 arg=0x006f2b50
Mon Oct 16 22:42:22 2017 us=195357 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE_READY p=0
Mon Oct 16 22:42:22 2017 us=195363 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_WRITE_READY mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=195368 MULTI TCP: transmitting previously deferred packet
Mon Oct 16 22:42:22 2017 us=195447 000.000.000.000:33134 TCP_SERVER WRITE [440] to [AF_INET]000.000.000.000:33134: P_CONTROL_V1 kid=0 sid=8f389425 982b996e tls_hmac=852c2404 f99b2b92 7a2fe757 c02c3ade e3b58dad pid=[ #5 / time = (1508186541) Mon Oct 16 22:42:21 2017 ] [ ] pid=4 DATA 5fce8703 3dbfdcfa 6059e6e3 abeec2e8 bc4bf65d 0a1e0390 4915e441 92c4a21[more...]
Mon Oct 16 22:42:22 2017 us=195453 000.000.000.000:33134 STREAM: WRITE 440 offset=30
Mon Oct 16 22:42:22 2017 us=195460 000.000.000.000:33134 TCP_SERVER write returned -1
Mon Oct 16 22:42:22 2017 us=195470 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=195482 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=195488 000.000.000.000:33134 ACK reliable_can_send active=4 current=0 : [5] 1 2 3 4
Mon Oct 16 22:42:22 2017 us=195497 000.000.000.000:33134 ACK output sequence broken: [5] 1 2 3 4
Mon Oct 16 22:42:22 2017 us=195503 000.000.000.000:33134 ACK reliable_send_timeout 2 [5] 1 2 3 4
Mon Oct 16 22:42:22 2017 us=195508 000.000.000.000:33134 TLS: tls_process: timeout set to 2
Mon Oct 16 22:42:22 2017 us=195517 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=195526 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=195533 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:22 2017 us=195540 EP_CTL fd=9 rwflags=0x0001 ev=0x00000001 arg=0x006f2b50
Mon Oct 16 22:42:22 2017 us=195546 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE_READY -> TA_UNDEF
Mon Oct 16 22:42:22 2017 us=195553 EP_WAIT[0] rwflags=0x0001 ev=0x00000001 arg=0x006f2b50
Mon Oct 16 22:42:22 2017 us=195558 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Mon Oct 16 22:42:22 2017 us=195563 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=195569 000.000.000.000:33134 STREAM: GET NEXT len=1627
Mon Oct 16 22:42:22 2017 us=195576 000.000.000.000:33134 STREAM: ADD length_added=52
Mon Oct 16 22:42:22 2017 us=195582 000.000.000.000:33134 STREAM: ADD returned TRUE, buf_len=50, residual_len=0
Mon Oct 16 22:42:22 2017 us=195587 000.000.000.000:33134 STREAM: GET FINAL len=50
Mon Oct 16 22:42:22 2017 us=195592 000.000.000.000:33134 STREAM: RESET
Mon Oct 16 22:42:22 2017 us=195598 000.000.000.000:33134 TCP_SERVER read returned 50
Mon Oct 16 22:42:22 2017 us=195615 000.000.000.000:33134 TCP_SERVER READ [50] from [AF_INET]000.000.000.000:33134: P_ACK_V1 kid=0 sid=d096c4a7 e5b41807 tls_hmac=5b10b3f4 6efaa365 c6b2794c 5aaa97e1 23e041c3 pid=[ #4 / time = (1508186541) Mon Oct 16 22:42:21 2017 ] [ 1 sid=8f389425 982b996e ]
Mon Oct 16 22:42:22 2017 us=195623 000.000.000.000:33134 TLS: control channel, op=P_ACK_V1, IP=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=195635 000.000.000.000:33134 TLS: initial packet test, i=0 state=S_START, mysid=8f389425 982b996e, rec-sid=d096c4a7 e5b41807, rec-ip=[AF_INET]000.000.000.000:33134, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=195643 000.000.000.000:33134 TLS: found match, session[0], sid=d096c4a7 e5b41807
Mon Oct 16 22:42:22 2017 us=195657 000.000.000.000:33134 DECRYPT FROM: 5b10b3f4 6efaa365 c6b2794c 5aaa97e1 23e041c3 00000004 59e519ad 28d096c[more...]
Mon Oct 16 22:42:22 2017 us=195686 000.000.000.000:33134 PID_TEST [0] [TLS_WRAP-0] [011] 1508186541:3 1508186541:4 t=1508186542[0] r=[-1,64,15,0,1] sl=[61,3,64,528]
Mon Oct 16 22:42:22 2017 us=195695 000.000.000.000:33134 TLS: received control channel packet s#=0 sid=d096c4a7 e5b41807
Mon Oct 16 22:42:22 2017 us=195701 000.000.000.000:33134 ACK received for pid 1, deleting from send buffer
Mon Oct 16 22:42:22 2017 us=195713 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=195719 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=195725 000.000.000.000:33134 ACK reliable_can_send active=3 current=0 : [5] 2 3 4
Mon Oct 16 22:42:22 2017 us=195734 000.000.000.000:33134 ACK reliable_send_timeout 3 [5] 2 3 4
Mon Oct 16 22:42:22 2017 us=195740 000.000.000.000:33134 TLS: tls_process: timeout set to 3
Mon Oct 16 22:42:22 2017 us=195749 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=195758 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=195768 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:22 2017 us=195774 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:22 2017 us=195779 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_UNDEF
Mon Oct 16 22:42:22 2017 us=303681 EP_WAIT[0] rwflags=0x0001 ev=0x00000001 arg=0x006f2b50
Mon Oct 16 22:42:22 2017 us=303701 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Mon Oct 16 22:42:22 2017 us=303708 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x006f2b50
Mon Oct 16 22:42:22 2017 us=303714 000.000.000.000:33134 STREAM: GET NEXT len=1627
Mon Oct 16 22:42:22 2017 us=303722 000.000.000.000:33134 STREAM: ADD length_added=52
Mon Oct 16 22:42:22 2017 us=303728 000.000.000.000:33134 STREAM: ADD returned TRUE, buf_len=50, residual_len=0
Mon Oct 16 22:42:22 2017 us=303733 000.000.000.000:33134 STREAM: GET FINAL len=50
Mon Oct 16 22:42:22 2017 us=303738 000.000.000.000:33134 STREAM: RESET
Mon Oct 16 22:42:22 2017 us=303744 000.000.000.000:33134 TCP_SERVER read returned 50
Mon Oct 16 22:42:22 2017 us=303766 000.000.000.000:33134 TCP_SERVER READ [50] from [AF_INET]000.000.000.000:33134: P_ACK_V1 kid=0 sid=d096c4a7 e5b41807 tls_hmac=67992eed 3f8e0ffa d000e601 8e82d88a e64f9d4c pid=[ #5 / time = (1508186541) Mon Oct 16 22:42:21 2017 ] [ 2 sid=8f389425 982b996e ]
Mon Oct 16 22:42:22 2017 us=303773 000.000.000.000:33134 TLS: control channel, op=P_ACK_V1, IP=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=303786 000.000.000.000:33134 TLS: initial packet test, i=0 state=S_START, mysid=8f389425 982b996e, rec-sid=d096c4a7 e5b41807, rec-ip=[AF_INET]000.000.000.000:33134, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=303793 000.000.000.000:33134 TLS: found match, session[0], sid=d096c4a7 e5b41807
Mon Oct 16 22:42:22 2017 us=303808 000.000.000.000:33134 DECRYPT FROM: 67992eed 3f8e0ffa d000e601 8e82d88a e64f9d4c 00000005 59e519ad 28d096c[more...]
Mon Oct 16 22:42:22 2017 us=303820 000.000.000.000:33134 PID_TEST [0] [TLS_WRAP-0] [0011] 1508186541:4 1508186541:5 t=1508186542[0] r=[-1,64,15,0,1] sl=[60,4,64,528]
Mon Oct 16 22:42:22 2017 us=303828 000.000.000.000:33134 TLS: received control channel packet s#=0 sid=d096c4a7 e5b41807
Mon Oct 16 22:42:22 2017 us=303834 000.000.000.000:33134 ACK received for pid 2, deleting from send buffer
Mon Oct 16 22:42:22 2017 us=303847 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:22 2017 us=303854 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:22 2017 us=303860 000.000.000.000:33134 ACK reliable_can_send active=2 current=0 : [5] 3 4
Mon Oct 16 22:42:22 2017 us=303873 000.000.000.000:33134 ACK reliable_send_timeout 4 [5] 3 4
Mon Oct 16 22:42:22 2017 us=303879 000.000.000.000:33134 TLS: tls_process: timeout set to 4
Mon Oct 16 22:42:22 2017 us=303888 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=303897 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:22 2017 us=303904 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:22 2017 us=303910 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:22 2017 us=303920 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_UNDEF
Mon Oct 16 22:42:23 2017 us=369319 MULTI: REAP range 208 -> 224
Mon Oct 16 22:42:23 2017 us=369426 MULTI TCP: multi_tcp_action a=TA_TIMEOUT p=0
Mon Oct 16 22:42:23 2017 us=369445 MULTI TCP: multi_tcp_dispatch a=TA_TIMEOUT mi=0x00000000
Mon Oct 16 22:42:23 2017 us=369464 000.000.000.000:33134 TIMER: coarse timer wakeup 1 seconds
Mon Oct 16 22:42:23 2017 us=369509 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:23 2017 us=369524 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:23 2017 us=369532 000.000.000.000:33134 ACK reliable_can_send active=2 current=0 : [5] 3 4
Mon Oct 16 22:42:23 2017 us=369548 000.000.000.000:33134 ACK reliable_send_timeout 3 [5] 3 4
Mon Oct 16 22:42:23 2017 us=369554 000.000.000.000:33134 TLS: tls_process: timeout set to 3
Mon Oct 16 22:42:23 2017 us=369564 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:23 2017 us=369573 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:23 2017 us=369583 000.000.000.000:33134 SCHEDULE: schedule_add_modify wakeup=[Mon Oct 16 22:42:24 2017 us=989360] pri=2000107839
Mon Oct 16 22:42:23 2017 us=369589 MULTI TCP: multi_tcp_post TA_TIMEOUT -> TA_UNDEF
Mon Oct 16 22:42:23 2017 us=369597 SCHEDULE: schedule_find_least wakeup=[Mon Oct 16 22:42:24 2017 us=989360] pri=587751257
Mon Oct 16 22:42:24 2017 us=439267 MULTI: REAP range 224 -> 240
Mon Oct 16 22:42:24 2017 us=439305 MULTI TCP: multi_tcp_action a=TA_TIMEOUT p=0
Mon Oct 16 22:42:24 2017 us=439312 MULTI TCP: multi_tcp_dispatch a=TA_TIMEOUT mi=0x00000000
Mon Oct 16 22:42:24 2017 us=439326 000.000.000.000:33134 TIMER: coarse timer wakeup 1 seconds
Mon Oct 16 22:42:24 2017 us=439335 000.000.000.000:33134 SCHEDULE: schedule_add_modify wakeup=[Mon Oct 16 22:42:25 2017 us=989360] pri=587751257
Mon Oct 16 22:42:24 2017 us=439342 MULTI TCP: multi_tcp_post TA_TIMEOUT -> TA_UNDEF
Mon Oct 16 22:42:24 2017 us=439350 SCHEDULE: schedule_find_least wakeup=[Mon Oct 16 22:42:25 2017 us=989360] pri=2038579759
Mon Oct 16 22:42:25 2017 us=509332 MULTI: REAP range 240 -> 256
Mon Oct 16 22:42:25 2017 us=509358 MULTI TCP: multi_tcp_action a=TA_TIMEOUT p=0
Mon Oct 16 22:42:25 2017 us=509365 MULTI TCP: multi_tcp_dispatch a=TA_TIMEOUT mi=0x00000000
Mon Oct 16 22:42:25 2017 us=509373 000.000.000.000:33134 TIMER: coarse timer wakeup 1 seconds
Mon Oct 16 22:42:25 2017 us=509383 000.000.000.000:33134 SCHEDULE: schedule_add_modify wakeup=[Mon Oct 16 22:42:26 2017 us=989360] pri=2038579759
Mon Oct 16 22:42:25 2017 us=509390 MULTI TCP: multi_tcp_post TA_TIMEOUT -> TA_UNDEF
Mon Oct 16 22:42:25 2017 us=509398 SCHEDULE: schedule_find_least wakeup=[Mon Oct 16 22:42:26 2017 us=989360] pri=663686165
Mon Oct 16 22:42:26 2017 us=579280 MULTI: REAP range 0 -> 16
Mon Oct 16 22:42:26 2017 us=579310 MULTI TCP: multi_tcp_action a=TA_TIMEOUT p=0
Mon Oct 16 22:42:26 2017 us=579317 MULTI TCP: multi_tcp_dispatch a=TA_TIMEOUT mi=0x00000000
Mon Oct 16 22:42:26 2017 us=579326 000.000.000.000:33134 TIMER: coarse timer wakeup 1 seconds
Mon Oct 16 22:42:26 2017 us=579343 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:26 2017 us=579351 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:26 2017 us=579358 000.000.000.000:33134 ACK reliable_can_send active=2 current=1 : [5] 3 4
Mon Oct 16 22:42:26 2017 us=579364 000.000.000.000:33134 ACK reliable_send ID 3 (size=1118 to=4)
Mon Oct 16 22:42:26 2017 us=579379 000.000.000.000:33134 ENCRYPT HMAC: 8ad92262 791b3755 334884ba 2eb7011e 03fafd7f
Mon Oct 16 22:42:26 2017 us=579573 000.000.000.000:33134 ENCRYPT TO: 8ad92262 791b3755 334884ba 2eb7011e 03fafd7f 00000006 59e519ad 208f389[more...]
Mon Oct 16 22:42:26 2017 us=579580 000.000.000.000:33134 Reliable -> TCP/UDP
Mon Oct 16 22:42:26 2017 us=579586 000.000.000.000:33134 ACK reliable_send_timeout 1 [5] 3 4
Mon Oct 16 22:42:26 2017 us=579592 000.000.000.000:33134 TLS: tls_process: timeout set to 1
Mon Oct 16 22:42:26 2017 us=579601 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:26 2017 us=579610 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:26 2017 us=579626 000.000.000.000:33134 SCHEDULE: schedule_add_modify wakeup=[Mon Oct 16 22:42:27 2017 us=989360] pri=663686165
Mon Oct 16 22:42:26 2017 us=579633 MULTI TCP: multi_tcp_post TA_TIMEOUT -> TA_SOCKET_WRITE
Mon Oct 16 22:42:26 2017 us=579639 MULTI TCP: multi_tcp_action a=TA_SOCKET_WRITE p=1
Mon Oct 16 22:42:26 2017 us=579644 MULTI TCP: multi_tcp_wait_lite a=TA_SOCKET_WRITE mi=0x006f2b50
Mon Oct 16 22:42:26 2017 us=579650 PO_CTL rwflags=0x0002 ev=9 arg=0x006afbc0
Mon Oct 16 22:42:26 2017 us=579656 PO_CTL rwflags=0x0001 ev=6 arg=0x006afac8
Mon Oct 16 22:42:26 2017 us=579664 I/O WAIT TR|Tw|Sr|SW [0/0]
Mon Oct 16 22:42:26 2017 us=579673 PO_WAIT[0,0] fd=9 rev=0x00000004 rwflags=0x0002 arg=0x006afbc0
Mon Oct 16 22:42:26 2017 us=579678  event_wait returned 1
Mon Oct 16 22:42:26 2017 us=579684 I/O WAIT status=0x0002
Mon Oct 16 22:42:26 2017 us=579689 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_WRITE mi=0x006f2b50
Mon Oct 16 22:42:26 2017 us=579887 000.000.000.000:33134 TCP_SERVER WRITE [1156] to [AF_INET]000.000.000.000:33134: P_CONTROL_V1 kid=0 sid=8f389425 982b996e tls_hmac=8ad92262 791b3755 334884ba 2eb7011e 03fafd7f pid=[ #6 / time = (1508186541) Mon Oct 16 22:42:21 2017 ] [ ] pid=3 DATA 0603551d 11041c30 1a811869 6e666f72 6d617469 63614068 6d616e61 636f722[more...]
Mon Oct 16 22:42:26 2017 us=579893 000.000.000.000:33134 STREAM: WRITE 1156 offset=30
Mon Oct 16 22:42:26 2017 us=579916 000.000.000.000:33134 TCP_SERVER write returned 1158
Mon Oct 16 22:42:26 2017 us=579927 000.000.000.000:33134 TLS: tls_multi_process: i=0 state=S_START, mysid=8f389425 982b996e, stored-sid=d096c4a7 e5b41807, stored-ip=[AF_INET]000.000.000.000:33134
Mon Oct 16 22:42:26 2017 us=579934 000.000.000.000:33134 TLS: tls_process: chg=0 ks=S_START lame=S_UNDEF to_link->len=0 wakeup=604800
Mon Oct 16 22:42:26 2017 us=579940 000.000.000.000:33134 ACK reliable_can_send active=2 current=0 : [5] 3 4
Mon Oct 16 22:42:26 2017 us=579954 000.000.000.000:33134 ACK reliable_send_timeout 1 [5] 3 4
Mon Oct 16 22:42:26 2017 us=579960 000.000.000.000:33134 TLS: tls_process: timeout set to 1
Mon Oct 16 22:42:26 2017 us=579969 000.000.000.000:33134 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=8d43a9f2 9c0744de, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:26 2017 us=579978 000.000.000.000:33134 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
Mon Oct 16 22:42:26 2017 us=579985 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
Mon Oct 16 22:42:26 2017 us=579991 MULTI TCP: multi_tcp_post TA_SOCKET_WRITE -> TA_UNDEF
Mon Oct 16 22:42:26 2017 us=579999 SCHEDULE: schedule_find_least wakeup=[Mon Oct 16 22:42:27 2017 us=989360] pri=811176545
Mon Oct 16 22:42:26 2017 us=688340 EP_WAIT[0] rwflags=0x0001 ev=0x00000001 arg=0x006f2b50
Mon Oct 16 22:42:26 2017 us=688365 MULTI TCP: multi_tcp_action a=TA_SOCKET_READ p=0
Mon Oct 16 22:42:26 2017 us=688372 MULTI TCP: multi_tcp_dispatch a=TA_SOCKET_READ mi=0x006f2b50
Mon Oct 16 22:42:26 2017 us=688379 000.000.000.000:33134 STREAM: GET NEXT len=1627
Mon Oct 16 22:42:26 2017 us=688388 000.000.000.000:33134 Connection reset, restarting [0]
Mon Oct 16 22:42:26 2017 us=688394 000.000.000.000:33134 SIGUSR1[soft,connection-reset] received, client-instance restarting
Mon Oct 16 22:42:26 2017 us=688400 MULTI: multi_close_instance called
Mon Oct 16 22:42:26 2017 us=688409 EP_DEL ev=9
Mon Oct 16 22:42:26 2017 us=688428 PID packet_id_free
Mon Oct 16 22:42:26 2017 us=688471 PID packet_id_free
Mon Oct 16 22:42:26 2017 us=688477 PID packet_id_free
Mon Oct 16 22:42:26 2017 us=688483 PID packet_id_free
Mon Oct 16 22:42:26 2017 us=688493 PID packet_id_free
Mon Oct 16 22:42:26 2017 us=688499 PID packet_id_free
Mon Oct 16 22:42:26 2017 us=688504 PID packet_id_free
Mon Oct 16 22:42:26 2017 us=688509 PID packet_id_free
Mon Oct 16 22:42:26 2017 us=688516 TCP/UDP: Closing socket
Mon Oct 16 22:42:26 2017 us=688541 PID packet_id_free
Mon Oct 16 22:42:26 2017 us=688557 MULTI TCP: multi_tcp_post TA_SOCKET_READ -> TA_UNDEF
Mon Oct 16 22:42:26 2017 us=688564 SCHEDULE: schedule_find_least NULL

Code: Select all

# openvpn --version
OpenVPN 2.4.3 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [MH/PKTINFO] [AEAD] built on Jun 23 2017
library versions: OpenSSL 1.0.2k  26 Jan 2017, LZO 2.09
Originally developed by James Yonan
Copyright (C) 2002-2017 OpenVPN Technologies, Inc. <sales@openvpn.net>
Compile time defines: enable_async_push=no enable_comp_stub=no enable_crypto=yes enable_crypto_ofb_cfb=yes enable_debug=yes enable_def_auth=yes enable_dependency_tracking=no enable_dlopen=unknown enable_dlopen_self=unknown enable_dlopen_self_static=unknown enable_fast_install=needless enable_fragment=yes enable_iproute2=no enable_libtool_lock=yes enable_lz4=no enable_lzo=yes enable_management=yes enable_multi=yes enable_multihome=yes enable_pam_dlopen=no enable_pedantic=no enable_pf=yes enable_pkcs11=no enable_plugin_auth_pam=yes enable_plugin_down_root=no enable_plugins=yes enable_port_share=yes enable_selinux=no enable_server=yes enable_shared=yes enable_shared_with_static_runtimes=no enable_silent_rules=no enable_small=no enable_static=yes enable_strict=no enable_strict_options=no enable_systemd=no enable_tests=no enable_werror=no enable_win32_dll=yes enable_x509_alt_username=no with_aix_soname=aix with_crypto_library=openssl with_gnu_ld=yes with_mem_check=no with_sysroot=no

What can I try?

Thanks

Posted: **Mon Oct 16, 2017 9:33 pm**

Try --verb 4 in the config.

Please see:
HOWTO: Request Help ! {2}

Posted: **Tue Oct 17, 2017 7:31 am**

I found more info in the client's log:

Code: Select all

Tue Oct 17 09:11:30 2017 us=511623 TLS: Initial packet from [AF_INET]Server_IP_Address:61198, sid=24abd13e 9dfc3bf3
Tue Oct 17 09:11:34 2017 us=520823 Authenticate/Decrypt packet error: bad packet ID (may be a replay): [ #6 / time = (1508224290) Tue Oct 17 09:11:30 2017 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Tue Oct 17 09:11:34 2017 us=520823 TLS Error: incoming packet authentication failed from [AF_INET]Server_IP_Address:61198
Tue Oct 17 09:11:34 2017 us=520823 Fatal TLS error (check_tls_errors_co), restarting
Tue Oct 17 09:11:34 2017 us=520823 TCP/UDP: Closing socket

I don't know what can be the cause of the "bad packet ID", or if it's only a warning and not a real issue.

"TLS Error: incoming packet authentication failed" seems to be the real issue, but I don't understand why everything was working fine for the past year, no config changes in openvpn, and just now I'm getting this.

Anyway, I'll try to get all the info you requested and post it here asap.

BTW, if I try to connect from an openvpn client from within the server's LAN, no issues at all! The errors happen only when clients connect from Internet, so I may be having issues on my gateway or firewall.

Posted: **Tue Oct 17, 2017 8:58 am**

I tried disabling my Intrusion Protection System as well as making sure everything was OK on my firewalls. However, I'm still getting the exact same error.

*Server*

Code: Select all

# uname -a
Linux inf-fw2 4.9.34-gentoo #1 SMP Mon Jul 10 11:05:23 CEST 2017 x86_64 AMD FX(tm)-8320 Eight-Core Processor AuthenticAMD GNU/Linux

Network setup:

Code: Select all

# ifconfig
enp10s0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 10.215.144.91  netmask 255.255.255.255  broadcast 0.0.0.0
        inet6 fe80::3285:a9ff:fe8e:b9a0  prefixlen 64  scopeid 0x20<link>
        ether 30:85:a9:8e:b9:a0  txqueuelen 1000  (Ethernet)
        RX packets 9225201998  bytes 2320083019737 (2.1 TiB)
        RX errors 0  dropped 5  overruns 0  frame 0
        TX packets 15132458600  bytes 18991823336597 (17.2 TiB)
        TX errors 3  dropped 0 overruns 0  carrier 0  collisions 0

enp5s0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 192.168.210.1  netmask 255.255.254.0  broadcast 192.168.211.255
        inet6 fe80::6a05:caff:fe11:6430  prefixlen 64  scopeid 0x20<link>
        ether 68:05:ca:11:64:30  txqueuelen 1000  (Ethernet)
        RX packets 2372758097  bytes 1182557612578 (1.0 TiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 2764419709  bytes 2972383805340 (2.7 TiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0
        device interrupt 27  memory 0xfe6c0000-fe6e0000

enp6s0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 172.16.0.1  netmask 255.255.255.240  broadcast 172.16.0.15
        inet6 fe80::6a05:caff:fe10:c3b7  prefixlen 64  scopeid 0x20<link>
        ether 68:05:ca:10:c3:b7  txqueuelen 1000  (Ethernet)
        RX packets 13721330661  bytes 18437968422444 (16.7 TiB)
        RX errors 0  dropped 4171  overruns 0  frame 0
        TX packets 7468688869  bytes 776219544935 (722.9 GiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0
        device interrupt 28  memory 0xfe5c0000-fe5e0000

enp7s0f2: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 172.28.17.105  netmask 255.255.255.248  broadcast 172.28.17.111
        inet6 fe80::eaea:6aff:fe0c:4c1e  prefixlen 64  scopeid 0x20<link>
        ether e8:ea:6a:0c:4c:1e  txqueuelen 1000  (Ethernet)
        RX packets 960584767  bytes 735142169832 (684.6 GiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 840109750  bytes 270384070096 (251.8 GiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0
        device memory 0xfde80000-fdefffff

enp7s0f3: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 172.20.11.62  netmask 255.255.255.240  broadcast 172.20.11.63
        inet6 fe80::eaea:6aff:fe0c:4c1f  prefixlen 64  scopeid 0x20<link>
        ether e8:ea:6a:0c:4c:1f  txqueuelen 1000  (Ethernet)
        RX packets 1043203215  bytes 994120225747 (925.8 GiB)
        RX errors 0  dropped 249  overruns 249  frame 0
        TX packets 901573718  bytes 489267368036 (455.6 GiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0
        device memory 0xfdd80000-fddfffff

lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
        inet 127.0.0.1  netmask 255.0.0.0
        inet6 ::1  prefixlen 128  scopeid 0x10<host>
        loop  txqueuelen 1  (Local Loopback)
        RX packets 564260486  bytes 719434174414 (670.0 GiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 564260486  bytes 719434174414 (670.0 GiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

tun146: flags=4305<UP,POINTOPOINT,RUNNING,NOARP,MULTICAST>  mtu 1500
        inet 192.168.146.1  netmask 255.255.255.0  destination 192.168.146.1
        inet6 fe80::9e03:a6fb:fdb1:c095  prefixlen 64  scopeid 0x20<link>
        unspec 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00  txqueuelen 100  (UNSPEC)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 715  bytes 22880 (22.3 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

tun147: flags=4305<UP,POINTOPOINT,RUNNING,NOARP,MULTICAST>  mtu 1500
        inet 192.168.147.1  netmask 255.255.255.224  destination 192.168.147.1
        inet6 fe80::796c:fb62:fa63:c11  prefixlen 64  scopeid 0x20<link>
        unspec 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00  txqueuelen 100  (UNSPEC)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 75  bytes 2400 (2.3 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

tun148: flags=4305<UP,POINTOPOINT,RUNNING,NOARP,MULTICAST>  mtu 1500
        inet 192.168.148.1  netmask 255.255.252.0  destination 192.168.148.1
        inet6 fe80::eace:865d:18ce:65cf  prefixlen 64  scopeid 0x20<link>
        unspec 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00  txqueuelen 100  (UNSPEC)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 669  bytes 21408 (20.9 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

OpenVPN daemon is listening on enp6s0.

SERVER

local 172.16.0.1
port 61198
proto tcp-server
dev tun147
ca /etc/ssl/CA-HMAN/cacert.pem
dh /etc/ssl/CA-HMAN/dh2048.pem
cert /etc/ssl/openvpn/openvpnservers_INF-FW_cert.pem
key /etc/ssl/openvpn/openvpnservers_INF-FW_key_nopassphrase.pem
tls-auth /etc/ssl/openvpn/ta-ivpn.key 0
cipher AES-256-CBC
tls-cipher TLS-DHE-RSA-WITH-AES-256-CBC-SHA256
mode server
tls-server
topology subnet
push "topology subnet"
ifconfig 192.168.147.1 255.255.255.224
push "route-gateway 192.168.147.1"
route-gateway 192.168.147.2
persist-key
persist-tun
client-config-dir /etc/openvpn/ccd-ivpn
script-security 2
client-connect "/etc/openvpn/client-up.sh ivpn"
client-disconnect "/etc/openvpn/client-down.sh ivpn"
push "route 10.215.0.0 255.255.0.0"
push "dhcp-option DNS 10.215.144.31"
push "dhcp-option DNS 10.215.144.35"
push "dhcp-option DOMAIN mydomain.org"
keepalive 10 120
comp-lzo
user openvpn
group openvpn
status /var/log/openvpn/HMAN-ivpn.status
log /var/log/openvpn/HMAN-ivpn.log
verb 4
username-as-common-name
plugin /usr/lib64/openvpn/plugins/openvpn-plugin-auth-pam.so openvpn-ivpn

Server log:

Code: Select all

Tue Oct 17 10:21:21 2017 us=70685 Current Parameter Settings:
Tue Oct 17 10:21:21 2017 us=70725   config = '/etc/openvpn/HMAN-ivpn.conf'
Tue Oct 17 10:21:21 2017 us=70732   mode = 1
Tue Oct 17 10:21:21 2017 us=70739   persist_config = DISABLED
Tue Oct 17 10:21:21 2017 us=70745   persist_mode = 1
Tue Oct 17 10:21:21 2017 us=70751   show_ciphers = DISABLED
Tue Oct 17 10:21:21 2017 us=70756   show_digests = DISABLED
Tue Oct 17 10:21:21 2017 us=70762   show_engines = DISABLED
Tue Oct 17 10:21:21 2017 us=70767   genkey = DISABLED
Tue Oct 17 10:21:21 2017 us=70779   key_pass_file = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=70784   show_tls_ciphers = DISABLED
Tue Oct 17 10:21:21 2017 us=70790   connect_retry_max = 0
Tue Oct 17 10:21:21 2017 us=70796 Connection profiles [0]:
Tue Oct 17 10:21:21 2017 us=70802   proto = tcp-server
Tue Oct 17 10:21:21 2017 us=70808   local = '172.16.0.1'
Tue Oct 17 10:21:21 2017 us=70813   local_port = '61198'
Tue Oct 17 10:21:21 2017 us=70819   remote = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=70824   remote_port = '61198'
Tue Oct 17 10:21:21 2017 us=70829   remote_float = DISABLED
Tue Oct 17 10:21:21 2017 us=70835   bind_defined = DISABLED
Tue Oct 17 10:21:21 2017 us=70840   bind_local = ENABLED
Tue Oct 17 10:21:21 2017 us=70845   bind_ipv6_only = DISABLED
Tue Oct 17 10:21:21 2017 us=70851   connect_retry_seconds = 5
Tue Oct 17 10:21:21 2017 us=70856   connect_timeout = 120
Tue Oct 17 10:21:21 2017 us=70862   socks_proxy_server = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=70867   socks_proxy_port = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=70873   tun_mtu = 1500
Tue Oct 17 10:21:21 2017 us=70878   tun_mtu_defined = ENABLED
Tue Oct 17 10:21:21 2017 us=70883   link_mtu = 1500
Tue Oct 17 10:21:21 2017 us=70888   link_mtu_defined = DISABLED
Tue Oct 17 10:21:21 2017 us=70894   tun_mtu_extra = 0
Tue Oct 17 10:21:21 2017 us=70899   tun_mtu_extra_defined = DISABLED
Tue Oct 17 10:21:21 2017 us=70905   mtu_discover_type = -1
Tue Oct 17 10:21:21 2017 us=70910   fragment = 0
Tue Oct 17 10:21:21 2017 us=70916   mssfix = 1450
Tue Oct 17 10:21:21 2017 us=70921   explicit_exit_notification = 0
Tue Oct 17 10:21:21 2017 us=70927 Connection profiles END
Tue Oct 17 10:21:21 2017 us=70932   remote_random = DISABLED
Tue Oct 17 10:21:21 2017 us=70937   ipchange = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=70943   dev = 'tun147'
Tue Oct 17 10:21:21 2017 us=70948   dev_type = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=70953   dev_node = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=70958   lladdr = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=70963   topology = 3
Tue Oct 17 10:21:21 2017 us=70969   ifconfig_local = '192.168.147.1'
Tue Oct 17 10:21:21 2017 us=70974   ifconfig_remote_netmask = '255.255.255.224'
Tue Oct 17 10:21:21 2017 us=70980   ifconfig_noexec = DISABLED
Tue Oct 17 10:21:21 2017 us=70985   ifconfig_nowarn = DISABLED
Tue Oct 17 10:21:21 2017 us=70990   ifconfig_ipv6_local = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=70996   ifconfig_ipv6_netbits = 0
Tue Oct 17 10:21:21 2017 us=71010   ifconfig_ipv6_remote = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71016   shaper = 0
Tue Oct 17 10:21:21 2017 us=71021   mtu_test = 0
Tue Oct 17 10:21:21 2017 us=71027   mlock = DISABLED
Tue Oct 17 10:21:21 2017 us=71033   keepalive_ping = 10
Tue Oct 17 10:21:21 2017 us=71038   keepalive_timeout = 120
Tue Oct 17 10:21:21 2017 us=71044   inactivity_timeout = 0
Tue Oct 17 10:21:21 2017 us=71049   ping_send_timeout = 10
Tue Oct 17 10:21:21 2017 us=71054   ping_rec_timeout = 240
Tue Oct 17 10:21:21 2017 us=71060   ping_rec_timeout_action = 2
Tue Oct 17 10:21:21 2017 us=71065   ping_timer_remote = DISABLED
Tue Oct 17 10:21:21 2017 us=71070   remap_sigusr1 = 0
Tue Oct 17 10:21:21 2017 us=71075   persist_tun = ENABLED
Tue Oct 17 10:21:21 2017 us=71081   persist_local_ip = DISABLED
Tue Oct 17 10:21:21 2017 us=71086   persist_remote_ip = DISABLED
Tue Oct 17 10:21:21 2017 us=71091   persist_key = ENABLED
Tue Oct 17 10:21:21 2017 us=71097   passtos = DISABLED
Tue Oct 17 10:21:21 2017 us=71104   resolve_retry_seconds = 1000000000
Tue Oct 17 10:21:21 2017 us=71110   resolve_in_advance = DISABLED
Tue Oct 17 10:21:21 2017 us=71120   username = 'openvpn'
Tue Oct 17 10:21:21 2017 us=71126   groupname = 'openvpn'
Tue Oct 17 10:21:21 2017 us=71132   chroot_dir = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71137   cd_dir = '/etc/openvpn'
Tue Oct 17 10:21:21 2017 us=71142   writepid = '/var/run/openvpn.HMAN-ivpn.pid'
Tue Oct 17 10:21:21 2017 us=71148   up_script = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71153   down_script = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71158   down_pre = DISABLED
Tue Oct 17 10:21:21 2017 us=71163   up_restart = DISABLED
Tue Oct 17 10:21:21 2017 us=71169   up_delay = DISABLED
Tue Oct 17 10:21:21 2017 us=71174   daemon = ENABLED
Tue Oct 17 10:21:21 2017 us=71179   inetd = 0
Tue Oct 17 10:21:21 2017 us=71185   log = ENABLED
Tue Oct 17 10:21:21 2017 us=71190   suppress_timestamps = DISABLED
Tue Oct 17 10:21:21 2017 us=71195   machine_readable_output = DISABLED
Tue Oct 17 10:21:21 2017 us=71201   nice = 0
Tue Oct 17 10:21:21 2017 us=71206   verbosity = 4
Tue Oct 17 10:21:21 2017 us=71211   mute = 0
Tue Oct 17 10:21:21 2017 us=71216   gremlin = 0
Tue Oct 17 10:21:21 2017 us=71222   status_file = '/var/log/openvpn/HMAN-ivpn.status'
Tue Oct 17 10:21:21 2017 us=71227   status_file_version = 1
Tue Oct 17 10:21:21 2017 us=71233   status_file_update_freq = 60
Tue Oct 17 10:21:21 2017 us=71238   occ = ENABLED
Tue Oct 17 10:21:21 2017 us=71243   rcvbuf = 0
Tue Oct 17 10:21:21 2017 us=71249   sndbuf = 0
Tue Oct 17 10:21:21 2017 us=71254   mark = 0
Tue Oct 17 10:21:21 2017 us=71259   sockflags = 0
Tue Oct 17 10:21:21 2017 us=71264   fast_io = DISABLED
Tue Oct 17 10:21:21 2017 us=71270   comp.alg = 2
Tue Oct 17 10:21:21 2017 us=71280   comp.flags = 1
Tue Oct 17 10:21:21 2017 us=71285   route_script = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71291   route_default_gateway = '192.168.147.2'
Tue Oct 17 10:21:21 2017 us=71296   route_default_metric = 0
Tue Oct 17 10:21:21 2017 us=71319   route_noexec = DISABLED
Tue Oct 17 10:21:21 2017 us=71325   route_delay = 0
Tue Oct 17 10:21:21 2017 us=71330   route_delay_window = 30
Tue Oct 17 10:21:21 2017 us=71336   route_delay_defined = DISABLED
Tue Oct 17 10:21:21 2017 us=71342   route_nopull = DISABLED
Tue Oct 17 10:21:21 2017 us=71347   route_gateway_via_dhcp = DISABLED
Tue Oct 17 10:21:21 2017 us=71352   allow_pull_fqdn = DISABLED
Tue Oct 17 10:21:21 2017 us=71358   management_addr = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71364   management_port = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71369   management_user_pass = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71374   management_log_history_cache = 250
Tue Oct 17 10:21:21 2017 us=71380   management_echo_buffer_size = 100
Tue Oct 17 10:21:21 2017 us=71385   management_write_peer_info_file = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71391   management_client_user = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71396   management_client_group = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71402   management_flags = 0
Tue Oct 17 10:21:21 2017 us=71409   plugin[0] /usr/lib64/openvpn/plugins/openvpn-plugin-auth-pam.so '[/usr/lib64/openvpn/plugins/openvpn-plugin-auth-pam.so] [openvpn-ivpn]'
Tue Oct 17 10:21:21 2017 us=71415   shared_secret_file = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71420   key_direction = 1
Tue Oct 17 10:21:21 2017 us=71426   ciphername = 'AES-256-CBC'
Tue Oct 17 10:21:21 2017 us=71431   ncp_enabled = ENABLED
Tue Oct 17 10:21:21 2017 us=71437   ncp_ciphers = 'AES-256-GCM:AES-128-GCM'
Tue Oct 17 10:21:21 2017 us=71442   authname = 'SHA1'
Tue Oct 17 10:21:21 2017 us=71448   prng_hash = 'SHA1'
Tue Oct 17 10:21:21 2017 us=71453   prng_nonce_secret_len = 16
Tue Oct 17 10:21:21 2017 us=71458   keysize = 0
Tue Oct 17 10:21:21 2017 us=71464   engine = DISABLED
Tue Oct 17 10:21:21 2017 us=71469   replay = ENABLED
Tue Oct 17 10:21:21 2017 us=71475   mute_replay_warnings = DISABLED
Tue Oct 17 10:21:21 2017 us=71480   replay_window = 64
Tue Oct 17 10:21:21 2017 us=71485   replay_time = 15
Tue Oct 17 10:21:21 2017 us=71491   packet_id_file = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71496   use_iv = ENABLED
Tue Oct 17 10:21:21 2017 us=71501   test_crypto = DISABLED
Tue Oct 17 10:21:21 2017 us=71509   tls_server = ENABLED
Tue Oct 17 10:21:21 2017 us=71515   tls_client = DISABLED
Tue Oct 17 10:21:21 2017 us=71520   key_method = 2
Tue Oct 17 10:21:21 2017 us=71525   ca_file = '/etc/ssl/CA-HMAN/cacert.pem'
Tue Oct 17 10:21:21 2017 us=71531   ca_path = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71536   dh_file = '/etc/ssl/CA-HMAN/dh2048.pem'
Tue Oct 17 10:21:21 2017 us=71542   cert_file = '/etc/ssl/openvpn/openvpnservers_INF-FW_cert.pem'
Tue Oct 17 10:21:21 2017 us=71548   extra_certs_file = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71554   priv_key_file = '/etc/ssl/openvpn/openvpnservers_INF-FW_key_nopassphrase.pem'
Tue Oct 17 10:21:21 2017 us=71559   pkcs12_file = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71564   cipher_list = 'TLS-DHE-RSA-WITH-AES-256-CBC-SHA256'
Tue Oct 17 10:21:21 2017 us=71570   tls_verify = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71575   tls_export_cert = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71581   verify_x509_type = 0
Tue Oct 17 10:21:21 2017 us=71586   verify_x509_name = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71592   crl_file = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71597   ns_cert_type = 0
Tue Oct 17 10:21:21 2017 us=71602   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71608   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71613   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71644   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71650   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71656   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71661   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71666   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71671   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71677   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71682   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71687   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71692   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71697   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71702   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71707   remote_cert_ku[i] = 0
Tue Oct 17 10:21:21 2017 us=71713   remote_cert_eku = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71718   ssl_flags = 4
Tue Oct 17 10:21:21 2017 us=71723   tls_timeout = 2
Tue Oct 17 10:21:21 2017 us=71729   renegotiate_bytes = -1
Tue Oct 17 10:21:21 2017 us=71734   renegotiate_packets = 0
Tue Oct 17 10:21:21 2017 us=71740   renegotiate_seconds = 3600
Tue Oct 17 10:21:21 2017 us=71745   handshake_window = 60
Tue Oct 17 10:21:21 2017 us=71755   transition_window = 3600
Tue Oct 17 10:21:21 2017 us=71765   single_session = DISABLED
Tue Oct 17 10:21:21 2017 us=71770   push_peer_info = DISABLED
Tue Oct 17 10:21:21 2017 us=71776   tls_exit = DISABLED
Tue Oct 17 10:21:21 2017 us=71781   tls_auth_file = '/etc/ssl/openvpn/ta-ivpn.key'
Tue Oct 17 10:21:21 2017 us=71786   tls_crypt_file = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71794   server_network = 0.0.0.0
Tue Oct 17 10:21:21 2017 us=71800   server_netmask = 0.0.0.0
Tue Oct 17 10:21:21 2017 us=71810   server_network_ipv6 = ::
Tue Oct 17 10:21:21 2017 us=71816   server_netbits_ipv6 = 0
Tue Oct 17 10:21:21 2017 us=71822   server_bridge_ip = 0.0.0.0
Tue Oct 17 10:21:21 2017 us=71828   server_bridge_netmask = 0.0.0.0
Tue Oct 17 10:21:21 2017 us=71834   server_bridge_pool_start = 0.0.0.0
Tue Oct 17 10:21:21 2017 us=71840   server_bridge_pool_end = 0.0.0.0
Tue Oct 17 10:21:21 2017 us=71846   push_entry = 'topology subnet'
Tue Oct 17 10:21:21 2017 us=71851   push_entry = 'route-gateway 192.168.147.1'
Tue Oct 17 10:21:21 2017 us=71856   push_entry = 'route 10.215.0.0 255.255.0.0'
Tue Oct 17 10:21:21 2017 us=71862   push_entry = 'dhcp-option DNS 10.215.144.31'
Tue Oct 17 10:21:21 2017 us=71879   push_entry = 'dhcp-option DNS 10.215.144.35'
Tue Oct 17 10:21:21 2017 us=71886   push_entry = 'dhcp-option DOMAIN mydomain.org'
Tue Oct 17 10:21:21 2017 us=71891   push_entry = 'ping 10'
Tue Oct 17 10:21:21 2017 us=71896   push_entry = 'ping-restart 120'
Tue Oct 17 10:21:21 2017 us=71902   ifconfig_pool_defined = DISABLED
Tue Oct 17 10:21:21 2017 us=71908   ifconfig_pool_start = 0.0.0.0
Tue Oct 17 10:21:21 2017 us=71917   ifconfig_pool_end = 0.0.0.0
Tue Oct 17 10:21:21 2017 us=71923   ifconfig_pool_netmask = 0.0.0.0
Tue Oct 17 10:21:21 2017 us=71928   ifconfig_pool_persist_filename = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71934   ifconfig_pool_persist_refresh_freq = 600
Tue Oct 17 10:21:21 2017 us=71939   ifconfig_ipv6_pool_defined = DISABLED
Tue Oct 17 10:21:21 2017 us=71945   ifconfig_ipv6_pool_base = ::
Tue Oct 17 10:21:21 2017 us=71950   ifconfig_ipv6_pool_netbits = 0
Tue Oct 17 10:21:21 2017 us=71956   n_bcast_buf = 256
Tue Oct 17 10:21:21 2017 us=71961   tcp_queue_limit = 64
Tue Oct 17 10:21:21 2017 us=71966   real_hash_size = 256
Tue Oct 17 10:21:21 2017 us=71971   virtual_hash_size = 256
Tue Oct 17 10:21:21 2017 us=71977   client_connect_script = '/etc/openvpn/client-up.sh ivpn'
Tue Oct 17 10:21:21 2017 us=71982   learn_address_script = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=71988   client_disconnect_script = '/etc/openvpn/client-down.sh ivpn'
Tue Oct 17 10:21:21 2017 us=71993   client_config_dir = '/etc/openvpn/ccd-ivpn'
Tue Oct 17 10:21:21 2017 us=71998   ccd_exclusive = DISABLED
Tue Oct 17 10:21:21 2017 us=72004   tmp_dir = '/tmp'
Tue Oct 17 10:21:21 2017 us=72009   push_ifconfig_defined = DISABLED
Tue Oct 17 10:21:21 2017 us=72017   push_ifconfig_local = 0.0.0.0
Tue Oct 17 10:21:21 2017 us=72023   push_ifconfig_remote_netmask = 0.0.0.0
Tue Oct 17 10:21:21 2017 us=72029   push_ifconfig_ipv6_defined = DISABLED
Tue Oct 17 10:21:21 2017 us=72035   push_ifconfig_ipv6_local = ::/0
Tue Oct 17 10:21:21 2017 us=72043   push_ifconfig_ipv6_remote = ::
Tue Oct 17 10:21:21 2017 us=72051   enable_c2c = DISABLED
Tue Oct 17 10:21:21 2017 us=72059   duplicate_cn = DISABLED
Tue Oct 17 10:21:21 2017 us=72066   cf_max = 0
Tue Oct 17 10:21:21 2017 us=72072   cf_per = 0
Tue Oct 17 10:21:21 2017 us=72077   max_clients = 1024
Tue Oct 17 10:21:21 2017 us=72083   max_routes_per_client = 256
Tue Oct 17 10:21:21 2017 us=72089   auth_user_pass_verify_script = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=72094   auth_user_pass_verify_script_via_file = DISABLED
Tue Oct 17 10:21:21 2017 us=72099   auth_token_generate = DISABLED
Tue Oct 17 10:21:21 2017 us=72105   auth_token_lifetime = 0
Tue Oct 17 10:21:21 2017 us=72110   port_share_host = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=72115   port_share_port = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=72120   client = DISABLED
Tue Oct 17 10:21:21 2017 us=72126   pull = DISABLED
Tue Oct 17 10:21:21 2017 us=72131   auth_user_pass_file = '[UNDEF]'
Tue Oct 17 10:21:21 2017 us=72138 OpenVPN 2.4.3 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [MH/PKTINFO] [AEAD] built on Jun 23 2017
Tue Oct 17 10:21:21 2017 us=72149 library versions: OpenSSL 1.0.2k  26 Jan 2017, LZO 2.09
Tue Oct 17 10:21:21 2017 us=72674 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
AUTH-PAM: BACKGROUND: INIT service='openvpn-ivpn'
Tue Oct 17 10:21:21 2017 us=72969 PLUGIN_INIT: POST /usr/lib64/openvpn/plugins/openvpn-plugin-auth-pam.so '[/usr/lib64/openvpn/plugins/openvpn-plugin-auth-pam.so] [openvpn-ivpn]' intercepted=PLUGIN_AUTH_USER_PASS_VERIFY 
Tue Oct 17 10:21:21 2017 us=73242 Diffie-Hellman initialized with 2048 bit key
Tue Oct 17 10:21:21 2017 us=73583 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Oct 17 10:21:21 2017 us=73593 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Oct 17 10:21:21 2017 us=73603 TLS-Auth MTU parms [ L:1624 D:1182 EF:68 EB:0 ET:0 EL:3 ]
Tue Oct 17 10:21:21 2017 us=73820 TUN/TAP device tun147 opened
Tue Oct 17 10:21:21 2017 us=73839 TUN/TAP TX queue length set to 100
Tue Oct 17 10:21:21 2017 us=73853 do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Tue Oct 17 10:21:21 2017 us=73869 /bin/ifconfig tun147 192.168.147.1 netmask 255.255.255.224 mtu 1500 broadcast 192.168.147.31
Tue Oct 17 10:21:21 2017 us=84476 Data Channel MTU parms [ L:1624 D:1450 EF:124 EB:406 ET:0 EL:3 AF:3/1 ]
Tue Oct 17 10:21:21 2017 us=84807 Could not determine IPv4/IPv6 protocol. Using AF_INET
Tue Oct 17 10:21:21 2017 us=84835 Socket Buffers: R=[87380->87380] S=[16384->16384]
Tue Oct 17 10:21:21 2017 us=84850 Listening for incoming TCP connection on [AF_INET]172.16.0.1:61198
Tue Oct 17 10:21:21 2017 us=84861 TCPv4_SERVER link local (bound): [AF_INET]172.16.0.1:61198
Tue Oct 17 10:21:21 2017 us=84867 TCPv4_SERVER link remote: [AF_UNSPEC]
Tue Oct 17 10:21:21 2017 us=84877 GID set to openvpn
Tue Oct 17 10:21:21 2017 us=84887 UID set to openvpn
Tue Oct 17 10:21:21 2017 us=84897 MULTI: multi_init called, r=256 v=256
Tue Oct 17 10:21:21 2017 us=84928 MULTI: TCP INIT maxclients=1024 maxevents=1028
Tue Oct 17 10:21:21 2017 us=84951 Initialization Sequence Completed
Tue Oct 17 10:21:28 2017 us=177617 IP packet with unknown IP version=15 seen
Tue Oct 17 10:22:29 2017 us=617075 IP packet with unknown IP version=15 seen
Tue Oct 17 10:23:31 2017 us=56606 IP packet with unknown IP version=15 seen
Tue Oct 17 10:24:32 2017 us=496150 IP packet with unknown IP version=15 seen
Tue Oct 17 10:25:33 2017 us=935697 IP packet with unknown IP version=15 seen
Tue Oct 17 10:26:35 2017 us=375291 IP packet with unknown IP version=15 seen
Tue Oct 17 10:27:36 2017 us=814818 IP packet with unknown IP version=15 seen
Tue Oct 17 10:28:38 2017 us=254372 IP packet with unknown IP version=15 seen
Tue Oct 17 10:29:39 2017 us=693959 IP packet with unknown IP version=15 seen
Tue Oct 17 10:30:41 2017 us=133507 IP packet with unknown IP version=15 seen
Tue Oct 17 10:31:36 2017 us=343003 MULTI: multi_create_instance called
Tue Oct 17 10:31:36 2017 us=343057 Re-using SSL/TLS context
Tue Oct 17 10:31:36 2017 us=343077 LZO compression initializing
Tue Oct 17 10:31:36 2017 us=343184 Control Channel MTU parms [ L:1624 D:1182 EF:68 EB:0 ET:0 EL:3 ]
Tue Oct 17 10:31:36 2017 us=343207 Data Channel MTU parms [ L:1624 D:1450 EF:124 EB:406 ET:0 EL:3 AF:3/1 ]
Tue Oct 17 10:31:36 2017 us=343242 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Tue Oct 17 10:31:36 2017 us=343252 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_CLIENT,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Tue Oct 17 10:31:36 2017 us=343275 TCP connection established with [AF_INET]Client_IP_Address:49231
Tue Oct 17 10:31:36 2017 us=343285 TCP_SERVER link local: (not bound)
Tue Oct 17 10:31:36 2017 us=343296 TCP_SERVER link remote: [AF_INET]Client_IP_Address:49231
Tue Oct 17 10:31:37 2017 us=285543 Client_IP_Address:49231 TLS: Initial packet from [AF_INET]Client_IP_Address:49231, sid=5889ddc3 9d8e9ff9
Tue Oct 17 10:31:41 2017 us=854958 Client_IP_Address:49231 Connection reset, restarting [0]
Tue Oct 17 10:31:41 2017 us=854984 Client_IP_Address:49231 SIGUSR1[soft,connection-reset] received, client-instance restarting
Tue Oct 17 10:31:41 2017 us=855056 TCP/UDP: Closing socket
Tue Oct 17 10:31:42 2017 us=573093 IP packet with unknown IP version=15 seen
Tue Oct 17 10:31:46 2017 us=923162 MULTI: multi_create_instance called
Tue Oct 17 10:31:46 2017 us=923207 Re-using SSL/TLS context
Tue Oct 17 10:31:46 2017 us=923217 LZO compression initializing
Tue Oct 17 10:31:46 2017 us=923272 Control Channel MTU parms [ L:1624 D:1182 EF:68 EB:0 ET:0 EL:3 ]
Tue Oct 17 10:31:46 2017 us=923285 Data Channel MTU parms [ L:1624 D:1450 EF:124 EB:406 ET:0 EL:3 AF:3/1 ]
Tue Oct 17 10:31:46 2017 us=923309 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Tue Oct 17 10:31:46 2017 us=923316 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_CLIENT,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Tue Oct 17 10:31:46 2017 us=923332 TCP connection established with [AF_INET]Client_IP_Address:49244
Tue Oct 17 10:31:46 2017 us=923339 TCP_SERVER link local: (not bound)
Tue Oct 17 10:31:46 2017 us=923352 TCP_SERVER link remote: [AF_INET]Client_IP_Address:49244
Tue Oct 17 10:31:47 2017 us=862059 Client_IP_Address:49244 TLS: Initial packet from [AF_INET]Client_IP_Address:49244, sid=06410c9f a4be1623

This seems to be the error:

Code: Select all

Tue Oct 17 10:31:41 2017 us=854958 Client_IP_Address:49231 Connection reset, restarting [0]

*Client*

Operating system:

Code: Select all

C:\Windows\System32>ver
Microsoft Windows [Version 6.1.7601]

Same problem on an Ubuntu Linux client.

CLIENT

dev tun
remote vpn2.mydomain.org 61198
proto tcp
port 61198
client
<ca>
-----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----
</ca>
<tls-auth>
-----BEGIN OpenVPN Static key V1-----
...
-----END OpenVPN Static key V1-----
</tls-auth>
<cert>
-----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----
</cert>
<key>
-----BEGIN RSA PRIVATE KEY-----
...
-----END RSA PRIVATE KEY-----
</key>
key-direction 1
cipher AES-256-CBC
tls-cipher TLS-DHE-RSA-WITH-AES-256-CBC-SHA256
ns-cert-type server
auth-nocache
comp-lzo
ping 15
ping-restart 45
ping-timer-rem
persist-tun
persist-key
verb 4
auth-user-pass

Client log:

Code: Select all

Tue Oct 17 10:31:29 2017 us=715623 Current Parameter Settings:
Tue Oct 17 10:31:29 2017 us=715623   config = 'C:\Program Files\OpenVPN\config\client_vpn2.ovpn'
Tue Oct 17 10:31:29 2017 us=715623   mode = 0
Tue Oct 17 10:31:29 2017 us=715623   show_ciphers = DISABLED
Tue Oct 17 10:31:29 2017 us=715623   show_digests = DISABLED
Tue Oct 17 10:31:29 2017 us=715623   show_engines = DISABLED
Tue Oct 17 10:31:29 2017 us=715623   genkey = DISABLED
Tue Oct 17 10:31:29 2017 us=715623   key_pass_file = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=715623   show_tls_ciphers = DISABLED
Tue Oct 17 10:31:29 2017 us=715623 Connection profiles [default]:
Tue Oct 17 10:31:29 2017 us=715623   proto = tcp-client
Tue Oct 17 10:31:29 2017 us=715623   local = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=715623   local_port = 0
Tue Oct 17 10:31:29 2017 us=715623   remote = 'vpn2.mydomain.org'
Tue Oct 17 10:31:29 2017 us=715623   remote_port = 61198
Tue Oct 17 10:31:29 2017 us=715623   remote_float = DISABLED
Tue Oct 17 10:31:29 2017 us=715623   bind_defined = DISABLED
Tue Oct 17 10:31:29 2017 us=715623   bind_local = DISABLED
Tue Oct 17 10:31:29 2017 us=715623   connect_retry_seconds = 5
Tue Oct 17 10:31:29 2017 us=715623   connect_timeout = 10
Tue Oct 17 10:31:29 2017 us=715623   connect_retry_max = 0
Tue Oct 17 10:31:29 2017 us=715623   socks_proxy_server = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=715623   socks_proxy_port = 0
Tue Oct 17 10:31:29 2017 us=715623   socks_proxy_retry = DISABLED
Tue Oct 17 10:31:29 2017 us=715623   tun_mtu = 1500
Tue Oct 17 10:31:29 2017 us=715623   tun_mtu_defined = ENABLED
Tue Oct 17 10:31:29 2017 us=715623   link_mtu = 1500
Tue Oct 17 10:31:29 2017 us=715623   link_mtu_defined = DISABLED
Tue Oct 17 10:31:29 2017 us=715623   tun_mtu_extra = 0
Tue Oct 17 10:31:29 2017 us=715623   tun_mtu_extra_defined = DISABLED
Tue Oct 17 10:31:29 2017 us=715623   mtu_discover_type = -1
Tue Oct 17 10:31:29 2017 us=715623   fragment = 0
Tue Oct 17 10:31:29 2017 us=715623   mssfix = 1450
Tue Oct 17 10:31:29 2017 us=715623   explicit_exit_notification = 0
Tue Oct 17 10:31:29 2017 us=731223 Connection profiles END
Tue Oct 17 10:31:29 2017 us=731223   remote_random = DISABLED
Tue Oct 17 10:31:29 2017 us=731223   ipchange = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=731223   dev = 'tun'
Tue Oct 17 10:31:29 2017 us=731223   dev_type = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=731223   dev_node = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=731223   lladdr = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=731223   topology = 1
Tue Oct 17 10:31:29 2017 us=731223   tun_ipv6 = DISABLED
Tue Oct 17 10:31:29 2017 us=731223   ifconfig_local = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=731223   ifconfig_remote_netmask = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=731223   ifconfig_noexec = DISABLED
Tue Oct 17 10:31:29 2017 us=731223   ifconfig_nowarn = DISABLED
Tue Oct 17 10:31:29 2017 us=731223   ifconfig_ipv6_local = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=731223   ifconfig_ipv6_netbits = 0
Tue Oct 17 10:31:29 2017 us=731223   ifconfig_ipv6_remote = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=731223   shaper = 0
Tue Oct 17 10:31:29 2017 us=731223   mtu_test = 0
Tue Oct 17 10:31:29 2017 us=731223   mlock = DISABLED
Tue Oct 17 10:31:29 2017 us=731223   keepalive_ping = 0
Tue Oct 17 10:31:29 2017 us=731223   keepalive_timeout = 0
Tue Oct 17 10:31:29 2017 us=731223   inactivity_timeout = 0
Tue Oct 17 10:31:29 2017 us=731223   ping_send_timeout = 15
Tue Oct 17 10:31:29 2017 us=731223   ping_rec_timeout = 45
Tue Oct 17 10:31:29 2017 us=731223   ping_rec_timeout_action = 2
Tue Oct 17 10:31:29 2017 us=731223   ping_timer_remote = ENABLED
Tue Oct 17 10:31:29 2017 us=731223   remap_sigusr1 = 0
Tue Oct 17 10:31:29 2017 us=731223   persist_tun = ENABLED
Tue Oct 17 10:31:29 2017 us=731223   persist_local_ip = DISABLED
Tue Oct 17 10:31:29 2017 us=731223   persist_remote_ip = DISABLED
Tue Oct 17 10:31:29 2017 us=731223   persist_key = ENABLED
Tue Oct 17 10:31:29 2017 us=731223   passtos = DISABLED
Tue Oct 17 10:31:29 2017 us=731223   resolve_retry_seconds = 1000000000
Tue Oct 17 10:31:29 2017 us=731223   username = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=731223   groupname = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=731223   chroot_dir = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=731223   cd_dir = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=746823   writepid = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=746823   up_script = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=746823   down_script = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=746823   down_pre = DISABLED
Tue Oct 17 10:31:29 2017 us=746823   up_restart = DISABLED
Tue Oct 17 10:31:29 2017 us=746823   up_delay = DISABLED
Tue Oct 17 10:31:29 2017 us=746823   daemon = DISABLED
Tue Oct 17 10:31:29 2017 us=746823   inetd = 0
Tue Oct 17 10:31:29 2017 us=746823   log = DISABLED
Tue Oct 17 10:31:29 2017 us=746823   suppress_timestamps = DISABLED
Tue Oct 17 10:31:29 2017 us=746823   nice = 0
Tue Oct 17 10:31:29 2017 us=746823   verbosity = 4
Tue Oct 17 10:31:29 2017 us=746823   mute = 0
Tue Oct 17 10:31:29 2017 us=746823   gremlin = 0
Tue Oct 17 10:31:29 2017 us=746823   status_file = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=746823   status_file_version = 1
Tue Oct 17 10:31:29 2017 us=746823   status_file_update_freq = 60
Tue Oct 17 10:31:29 2017 us=746823   occ = ENABLED
Tue Oct 17 10:31:29 2017 us=746823   rcvbuf = 0
Tue Oct 17 10:31:29 2017 us=746823   sndbuf = 0
Tue Oct 17 10:31:29 2017 us=746823   sockflags = 0
Tue Oct 17 10:31:29 2017 us=746823   fast_io = DISABLED
Tue Oct 17 10:31:29 2017 us=746823   lzo = 7
Tue Oct 17 10:31:29 2017 us=762423   route_script = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=762423   route_default_gateway = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=762423   route_default_metric = 0
Tue Oct 17 10:31:29 2017 us=762423   route_noexec = DISABLED
Tue Oct 17 10:31:29 2017 us=762423   route_delay = 5
Tue Oct 17 10:31:29 2017 us=762423   route_delay_window = 30
Tue Oct 17 10:31:29 2017 us=762423   route_delay_defined = ENABLED
Tue Oct 17 10:31:29 2017 us=762423   route_nopull = DISABLED
Tue Oct 17 10:31:29 2017 us=762423   route_gateway_via_dhcp = DISABLED
Tue Oct 17 10:31:29 2017 us=778023   max_routes = 100
Tue Oct 17 10:31:29 2017 us=778023   allow_pull_fqdn = DISABLED
Tue Oct 17 10:31:29 2017 us=778023   management_addr = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=778023   management_port = 0
Tue Oct 17 10:31:29 2017 us=778023   management_user_pass = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=778023   management_log_history_cache = 250
Tue Oct 17 10:31:29 2017 us=778023   management_echo_buffer_size = 100
Tue Oct 17 10:31:29 2017 us=778023   management_write_peer_info_file = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=778023   management_client_user = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=778023   management_client_group = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=778023   management_flags = 0
Tue Oct 17 10:31:29 2017 us=778023   shared_secret_file = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=778023   key_direction = 2
Tue Oct 17 10:31:29 2017 us=778023   ciphername_defined = ENABLED
Tue Oct 17 10:31:29 2017 us=778023   ciphername = 'AES-256-CBC'
Tue Oct 17 10:31:29 2017 us=778023   authname_defined = ENABLED
Tue Oct 17 10:31:29 2017 us=778023   authname = 'SHA1'
Tue Oct 17 10:31:29 2017 us=778023   prng_hash = 'SHA1'
Tue Oct 17 10:31:29 2017 us=793623   prng_nonce_secret_len = 16
Tue Oct 17 10:31:29 2017 us=793623   keysize = 0
Tue Oct 17 10:31:29 2017 us=793623   engine = DISABLED
Tue Oct 17 10:31:29 2017 us=793623   replay = ENABLED
Tue Oct 17 10:31:29 2017 us=793623   mute_replay_warnings = DISABLED
Tue Oct 17 10:31:29 2017 us=793623   replay_window = 64
Tue Oct 17 10:31:29 2017 us=793623   replay_time = 15
Tue Oct 17 10:31:29 2017 us=793623   packet_id_file = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=793623   use_iv = ENABLED
Tue Oct 17 10:31:29 2017 us=793623   test_crypto = DISABLED
Tue Oct 17 10:31:29 2017 us=793623   tls_server = DISABLED
Tue Oct 17 10:31:29 2017 us=793623   tls_client = ENABLED
Tue Oct 17 10:31:29 2017 us=793623   key_method = 2
Tue Oct 17 10:31:29 2017 us=793623   ca_file = '[[INLINE]]'
Tue Oct 17 10:31:29 2017 us=793623   ca_path = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=809223   dh_file = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=809223   cert_file = '[[INLINE]]'
Tue Oct 17 10:31:29 2017 us=809223   extra_certs_file = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=809223   priv_key_file = '[[INLINE]]'
Tue Oct 17 10:31:29 2017 us=809223   pkcs12_file = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=809223   cryptoapi_cert = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=809223   cipher_list = 'TLS-DHE-RSA-WITH-AES-256-CBC-SHA256'
Tue Oct 17 10:31:29 2017 us=809223   tls_verify = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=809223   tls_export_cert = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=809223   verify_x509_type = 0
Tue Oct 17 10:31:29 2017 us=809223   verify_x509_name = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=809223   crl_file = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=809223   ns_cert_type = 1
Tue Oct 17 10:31:29 2017 us=809223   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=809223   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=809223   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=809223   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=809223   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=809223   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=809223   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=809223   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=824823   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=824823   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=824823   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=824823   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=824823   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=824823   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=824823   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=824823   remote_cert_ku[i] = 0
Tue Oct 17 10:31:29 2017 us=824823   remote_cert_eku = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=824823   ssl_flags = 0
Tue Oct 17 10:31:29 2017 us=824823   tls_timeout = 2
Tue Oct 17 10:31:29 2017 us=824823   renegotiate_bytes = -1
Tue Oct 17 10:31:29 2017 us=824823   renegotiate_packets = 0
Tue Oct 17 10:31:29 2017 us=824823   renegotiate_seconds = 3600
Tue Oct 17 10:31:29 2017 us=824823   handshake_window = 60
Tue Oct 17 10:31:29 2017 us=824823   transition_window = 3600
Tue Oct 17 10:31:29 2017 us=824823   single_session = DISABLED
Tue Oct 17 10:31:29 2017 us=824823   push_peer_info = DISABLED
Tue Oct 17 10:31:29 2017 us=824823   tls_exit = DISABLED
Tue Oct 17 10:31:29 2017 us=824823   tls_auth_file = '[[INLINE]]'
Tue Oct 17 10:31:29 2017 us=824823   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=824823   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_protected_authentication = DISABLED
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=840423   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_private_mode = 00000000
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_cert_private = DISABLED
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_pin_cache_period = -1
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_id = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=856023   pkcs11_id_management = DISABLED
Tue Oct 17 10:31:29 2017 us=871623   server_network = 0.0.0.0
Tue Oct 17 10:31:29 2017 us=871623   server_netmask = 0.0.0.0
Tue Oct 17 10:31:29 2017 us=871623   server_network_ipv6 = ::
Tue Oct 17 10:31:29 2017 us=871623   server_netbits_ipv6 = 0
Tue Oct 17 10:31:29 2017 us=871623   server_bridge_ip = 0.0.0.0
Tue Oct 17 10:31:29 2017 us=871623   server_bridge_netmask = 0.0.0.0
Tue Oct 17 10:31:29 2017 us=871623   server_bridge_pool_start = 0.0.0.0
Tue Oct 17 10:31:29 2017 us=871623   server_bridge_pool_end = 0.0.0.0
Tue Oct 17 10:31:29 2017 us=871623   ifconfig_pool_defined = DISABLED
Tue Oct 17 10:31:29 2017 us=871623   ifconfig_pool_start = 0.0.0.0
Tue Oct 17 10:31:29 2017 us=871623   ifconfig_pool_end = 0.0.0.0
Tue Oct 17 10:31:29 2017 us=871623   ifconfig_pool_netmask = 0.0.0.0
Tue Oct 17 10:31:29 2017 us=871623   ifconfig_pool_persist_filename = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=871623   ifconfig_pool_persist_refresh_freq = 600
Tue Oct 17 10:31:29 2017 us=871623   ifconfig_ipv6_pool_defined = DISABLED
Tue Oct 17 10:31:29 2017 us=871623   ifconfig_ipv6_pool_base = ::
Tue Oct 17 10:31:29 2017 us=871623   ifconfig_ipv6_pool_netbits = 0
Tue Oct 17 10:31:29 2017 us=871623   n_bcast_buf = 256
Tue Oct 17 10:31:29 2017 us=871623   tcp_queue_limit = 64
Tue Oct 17 10:31:29 2017 us=871623   real_hash_size = 256
Tue Oct 17 10:31:29 2017 us=871623   virtual_hash_size = 256
Tue Oct 17 10:31:29 2017 us=871623   client_connect_script = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=871623   learn_address_script = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=871623   client_disconnect_script = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=871623   client_config_dir = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=871623   ccd_exclusive = DISABLED
Tue Oct 17 10:31:29 2017 us=871623   tmp_dir = 'C:\Users\vieri\AppData\Local\Temp\'
Tue Oct 17 10:31:29 2017 us=871623   push_ifconfig_defined = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   push_ifconfig_local = 0.0.0.0
Tue Oct 17 10:31:29 2017 us=887223   push_ifconfig_remote_netmask = 0.0.0.0
Tue Oct 17 10:31:29 2017 us=887223   push_ifconfig_ipv6_defined = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   push_ifconfig_ipv6_local = ::/0
Tue Oct 17 10:31:29 2017 us=887223   push_ifconfig_ipv6_remote = ::
Tue Oct 17 10:31:29 2017 us=887223   enable_c2c = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   duplicate_cn = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   cf_max = 0
Tue Oct 17 10:31:29 2017 us=887223   cf_per = 0
Tue Oct 17 10:31:29 2017 us=887223   max_clients = 1024
Tue Oct 17 10:31:29 2017 us=887223   max_routes_per_client = 256
Tue Oct 17 10:31:29 2017 us=887223   auth_user_pass_verify_script = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=887223   auth_user_pass_verify_script_via_file = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   client = ENABLED
Tue Oct 17 10:31:29 2017 us=887223   pull = ENABLED
Tue Oct 17 10:31:29 2017 us=887223   auth_user_pass_file = 'stdin'
Tue Oct 17 10:31:29 2017 us=887223   show_net_up = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   route_method = 0
Tue Oct 17 10:31:29 2017 us=887223   block_outside_dns = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   ip_win32_defined = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   ip_win32_type = 3
Tue Oct 17 10:31:29 2017 us=887223   dhcp_masq_offset = 0
Tue Oct 17 10:31:29 2017 us=887223   dhcp_lease_time = 31536000
Tue Oct 17 10:31:29 2017 us=887223   tap_sleep = 0
Tue Oct 17 10:31:29 2017 us=887223   dhcp_options = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   dhcp_renew = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   dhcp_pre_release = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   dhcp_release = DISABLED
Tue Oct 17 10:31:29 2017 us=887223   domain = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=887223   netbios_scope = '[UNDEF]'
Tue Oct 17 10:31:29 2017 us=887223   netbios_node_type = 0
Tue Oct 17 10:31:29 2017 us=887223   disable_nbt = DISABLED
Tue Oct 17 10:31:29 2017 us=887223 OpenVPN 2.3.13 i686-w64-mingw32 [SSL (OpenSSL)] [LZO] [PKCS11] [IPv6] built on Nov  3 2016
Tue Oct 17 10:31:29 2017 us=887223 Windows version 6.1 (Windows 7) 32bit
Tue Oct 17 10:31:29 2017 us=887223 library versions: OpenSSL 1.0.1u  22 Sep 2016, LZO 2.09
Enter Auth Username:vieri
Enter Auth Password:
Tue Oct 17 10:31:36 2017 us=236423 Control Channel Authentication: tls-auth using INLINE static key file
Tue Oct 17 10:31:36 2017 us=236423 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Oct 17 10:31:36 2017 us=236423 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Oct 17 10:31:36 2017 us=236423 LZO compression initialized
Tue Oct 17 10:31:36 2017 us=236423 Control Channel MTU parms [ L:1560 D:1182 EF:68 EB:0 ET:0 EL:3 ]
Tue Oct 17 10:31:36 2017 us=236423 Socket Buffers: R=[8192->8192] S=[64512->64512]
Tue Oct 17 10:31:36 2017 us=236423 Data Channel MTU parms [ L:1560 D:1450 EF:60 EB:143 ET:0 EL:3 AF:3/1 ]
Tue Oct 17 10:31:36 2017 us=236423 Local Options String: 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_CLIENT,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Tue Oct 17 10:31:36 2017 us=236423 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Tue Oct 17 10:31:36 2017 us=236423 Local Options hash (VER=V4): '2f2c6498'
Tue Oct 17 10:31:36 2017 us=236423 Expected Remote Options hash (VER=V4): '9915e4a2'
Tue Oct 17 10:31:36 2017 us=236423 Attempting to establish TCP connection with [AF_INET]Server_IP_Address:61198 [nonblock]
Tue Oct 17 10:31:37 2017 us=266023 TCP connection established with [AF_INET]Server_IP_Address:61198
Tue Oct 17 10:31:37 2017 us=266023 TCPv4_CLIENT link local: [undef]
Tue Oct 17 10:31:37 2017 us=266023 TCPv4_CLIENT link remote: [AF_INET]Server_IP_Address:61198
Tue Oct 17 10:31:37 2017 us=500023 TLS: Initial packet from [AF_INET]Server_IP_Address:61198, sid=bb9a0086 83138522
Tue Oct 17 10:31:41 2017 us=821223 Authenticate/Decrypt packet error: bad packet ID (may be a replay): [ #7 / time = (1508229097) Tue Oct 17 10:31:37 2017 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Tue Oct 17 10:31:41 2017 us=821223 TLS Error: incoming packet authentication failed from [AF_INET]Server_IP_Address:61198
Tue Oct 17 10:31:41 2017 us=821223 Fatal TLS error (check_tls_errors_co), restarting
Tue Oct 17 10:31:41 2017 us=821223 TCP/UDP: Closing socket
Tue Oct 17 10:31:41 2017 us=821223 SIGUSR1[soft,tls-error] received, process restarting
Tue Oct 17 10:31:41 2017 us=821223 Restart pause, 5 second(s)
Tue Oct 17 10:31:46 2017 us=828823 Re-using SSL/TLS context
Tue Oct 17 10:31:46 2017 us=828823 LZO compression initialized
Tue Oct 17 10:31:46 2017 us=828823 Control Channel MTU parms [ L:1560 D:1182 EF:68 EB:0 ET:0 EL:3 ]
Tue Oct 17 10:31:46 2017 us=828823 Socket Buffers: R=[8192->8192] S=[64512->64512]
Tue Oct 17 10:31:46 2017 us=828823 Data Channel MTU parms [ L:1560 D:1450 EF:60 EB:143 ET:0 EL:3 AF:3/1 ]
Tue Oct 17 10:31:46 2017 us=828823 Local Options String: 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_CLIENT,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Tue Oct 17 10:31:46 2017 us=828823 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Tue Oct 17 10:31:46 2017 us=828823 Local Options hash (VER=V4): '2f2c6498'
Tue Oct 17 10:31:46 2017 us=828823 Expected Remote Options hash (VER=V4): '9915e4a2'
Tue Oct 17 10:31:46 2017 us=828823 Attempting to establish TCP connection with [AF_INET]Server_IP_Address:61198 [nonblock]
Tue Oct 17 10:31:47 2017 us=842823 TCP connection established with [AF_INET]Server_IP_Address:61198
Tue Oct 17 10:31:47 2017 us=842823 TCPv4_CLIENT link local: [undef]
Tue Oct 17 10:31:47 2017 us=842823 TCPv4_CLIENT link remote: [AF_INET]Server_IP_Address:61198
Tue Oct 17 10:31:47 2017 us=952023 TLS: Initial packet from [AF_INET]Server_IP_Address:61198, sid=bb1467bf ded435de
Enter Auth Username:

The error is around here:

Code: Select all

Tue Oct 17 10:31:41 2017 us=821223 Authenticate/Decrypt packet error: bad packet ID (may be a replay): [ #7 / time = (1508229097) Tue Oct 17 10:31:37 2017 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Tue Oct 17 10:31:41 2017 us=821223 TLS Error: incoming packet authentication failed from [AF_INET]Server_IP_Address:61198
Tue Oct 17 10:31:41 2017 us=821223 Fatal TLS error (check_tls_errors_co), restarting

Any ideas?

Posted: **Tue Oct 17, 2017 10:08 am**

I also used verb 9 on the same client scenario just to see if I could get more info. Here's a log extract right around the same error message as in my previous post:

Code: Select all

Tue Oct 17 11:59:36 2017 us=966823 WE_WAIT leave rwflags=0x0001 arg=0x004af05c
Tue Oct 17 11:59:36 2017 us=966823  event_wait returned 1
Tue Oct 17 11:59:36 2017 us=966823 I/O WAIT status=0x0001
Tue Oct 17 11:59:36 2017 us=966823 WIN32 I/O: Socket Completion success [1158]
Tue Oct 17 11:59:36 2017 us=966823 STREAM: ADD length_added=1158
Tue Oct 17 11:59:36 2017 us=966823 STREAM: ADD returned TRUE, buf_len=1156, residual_len=0
Tue Oct 17 11:59:36 2017 us=966823 STREAM: GET FINAL len=1156
Tue Oct 17 11:59:36 2017 us=966823 STREAM: RESET
Tue Oct 17 11:59:36 2017 us=966823 TCPv4_CLIENT read returned 1156
Tue Oct 17 11:59:36 2017 us=966823 TCPv4_CLIENT READ [1156] from [AF_INET]Server_IP_Address:61198: P_CONTROL_V1 kid=0 sid=f9661d58 f0aee70f tls_hmac=c0f7621a 320baa80 f02b5fd2 0d817762 ceb37b67 pid=[ #6 / time = (1508234372) Tue Oct 17 11:59:32 2017 ] [ ] pid=3 DATA 0603551d 11041c30 1a811869 6e666f72 6d617469 63614068 6d616e61 636f722[more...]
Tue Oct 17 11:59:36 2017 us=966823 TLS: control channel, op=P_CONTROL_V1, IP=[AF_INET]Server_IP_Address:61198
Tue Oct 17 11:59:36 2017 us=982423 TLS: initial packet test, i=0 state=S_SENT_KEY, mysid=5b6582fc f6c85809, rec-sid=f9661d58 f0aee70f, rec-ip=[AF_INET]Server_IP_Address:61198, stored-sid=f9661d58 f0aee70f, stored-ip=[AF_INET]Server_IP_Address:61198
Tue Oct 17 11:59:36 2017 us=982423 TLS: found match, session[0], sid=f9661d58 f0aee70f
Tue Oct 17 11:59:36 2017 us=982423 PID_TEST [0] [TLS_AUTH-0] [] 1508234372:3 1508234372:6 t=1508234376[0] r=[-4,0,0,0,1]

Tue Oct 17 11:59:36 2017 us=982423 Authenticate/Decrypt packet error: bad packet ID (may be a replay): [ #6 / time = (1508234372) Tue Oct 17 11:59:32 2017 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Tue Oct 17 11:59:36 2017 us=982423 TLS Error: incoming packet authentication failed from [AF_INET]Server_IP_Address:61198
Tue Oct 17 11:59:36 2017 us=982423 TIMER: coarse timer wakeup 1 seconds
Tue Oct 17 11:59:36 2017 us=982423 Fatal TLS error (check_tls_errors_co), restarting
Tue Oct 17 11:59:36 2017 us=982423 PID packet_id_free
Tue Oct 17 11:59:36 2017 us=982423 PID packet_id_free
Tue Oct 17 11:59:36 2017 us=982423 PID packet_id_free
Tue Oct 17 11:59:36 2017 us=982423 PID packet_id_free
Tue Oct 17 11:59:36 2017 us=982423 PID packet_id_free
Tue Oct 17 11:59:36 2017 us=982423 PID packet_id_free
Tue Oct 17 11:59:36 2017 us=982423 PID packet_id_free
Tue Oct 17 11:59:36 2017 us=982423 PID packet_id_free
Tue Oct 17 11:59:36 2017 us=982423 TCP/UDP: Closing socket

Posted: **Tue Oct 17, 2017 12:19 pm**

You are using --proto tcp and getting the warning: Authenticate/Decrypt packet error: bad packet ID

This is what the manual has to say:

The Manual wrote:--replay-window
<s>
OpenVPN also adds TCP transport as an option (not offered by IPSec) in which case OpenVPN can adopt a very strict attitude towards message deletion and reordering: Don't allow it. Since TCP guarantees reliability, any packet loss or reordering event can be assumed to be an attack

I would be wondering if your PKI is still safe ..

Posted: **Tue Oct 17, 2017 12:42 pm**

I would be wondering if your PKI is still safe

Why would you say that?

In any case, if I didn't use TCP, OpenVPN would never had noticed as a possible attack anyway, right?

Well, I'll first try to not specify TCP, and see if the connection gets established.

Thanks!

Posted: **Tue Oct 17, 2017 1:01 pm**

vieri wrote: ↑
Tue Oct 17, 2017 12:42 pm
Why would you say that?

Because that is what the manual says ..
If you get errors like bad packet ID over TCP then something is quite wrong !

vieri wrote: ↑
Tue Oct 17, 2017 12:42 pm
if I didn't use TCP, OpenVPN would never had noticed as a possible attack anyway

The same (or similar) error would have occurred but in UDP this is to be somewhat expected.

Try UDP and see the result .. but I would still consider setting up a new PKI.

Posted: **Tue Oct 17, 2017 1:07 pm**

I removed "proto tcp-server" on the server, and "proto tcp" on a client. Then I allowed UDP traffic through the gateway and firewall instead of TCP. This time I'm getting nothing in the server log, as if the client couldn't reach the server somehow.

I will look into this asap and post further findings.

Thanks

Posted: **Tue Oct 17, 2017 3:29 pm**

I now have it working with UDP instead of TCP. I can establish the tunnel, and everything seems to be working again.

In the client's log, I can see the following messages after the tunnel has been up for a while (nothing in the server log):

Code: Select all

Tue Oct 17 16:35:23 2017 us=452883 Initialization Sequence Completed
Tue Oct 17 17:19:37 2017 us=250296 PID_ERR replay-window backtrack occurred [15] [SSL-0] [000_0___________000000000000_00111_1_111111111111111111111111111] 0:4305 0:4290 t=1508253577[0] r=[-3,64,15,15,1] sl=[47,64,64,528]
Tue Oct 17 17:19:37 2017 us=653111 PID_ERR replay-window backtrack occurred [18] [SSL-0] [0000000000000000_0_00000000000000000_0__________0000000000000_00] 0:4338 0:4320 t=1508253577[0] r=[-3,64,15,18,1] sl=[14,64,64,528]
Tue Oct 17 17:19:38 2017 us=357261 PID_ERR replay-window backtrack occurred [28] [SSL-0] [00000000_000000000000____00___0011111111__1111111111111111111111] 0:4404 0:4376 t=1508253578[0] r=[-4,64,15,28,1] sl=[12,64,64,528]

I guess the "PID_ERR replay-window backtrack occurred" message confirms that my provider's line quality may not be optimal, or there's a network congestion on the WAN side of the OpenVPN server.

Thanks

Posted: **Tue Oct 17, 2017 4:23 pm**

See --replay-window in The Manual v24x

Could be line quality or any number of other factors ..

Posted: **Tue Oct 17, 2017 5:03 pm**

you will see the message "Replay-window backtrack occurred [x]" every time the maximum sequence number backtrack seen thus far increases. This can be used to calibrate n.

I have:

Code: Select all

[15] 
[18] 
[28]

I'm not sure how to calculate the value I should add to the default 64.

Posted: **Tue Oct 17, 2017 6:10 pm**

All I can tell you is that if you increase the replay window size or time you are lowering the overall security of your VPN .. provided you don't make the change too large then it is probably safe to do so .. but take it in small steps.

Generally, I don't worry about a few backtrack errors, it is the nature of UDP, so long as the VPN still works.

Posted: **Wed Oct 18, 2017 5:45 am**

Thank you very much.
You've been most helpful.

OpenVPN Support Forum

openvpn client cannot connect to server

openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server

Re: openvpn client cannot connect to server