I am running OpenVPN server 2.4.11 and have many clients connecting from all over the place, using client version 2.4.6. Now I am unsuccesfully trying to connect a client, running 2.5.3.
I ran into some cipher issues so I have the server like this:
#;cipher BF-CBC # Blowfish (default)
#cipher AES-256-CBC
#;cipher AES-128-CBC # AES
#;cipher DES-EDE3-CBC # Triple-DES
and the 2.5.3 client like this:
data-ciphers AES-256-GCM:AES-128-GCM:AES-256-CBC data-ciphers-fallback
AES-256-CBC
My 2.4.6 clients seem to be connecting fine with:
; cipher x
When I turn the client-logging verbosity way up, I get the following:
2021-07-27 11:52:07 us=889575 PID packet_id_init seq_backtrack=64 time_backtrack=15
2021-07-27 11:52:07 us=889575 PID packet_id_init seq_backtrack=64 time_backtrack=15
2021-07-27 11:52:07 us=889575 TLS: tls_session_init: new session object, sid=1cc2ba0d 622efd4c
2021-07-27 11:52:07 us=889575 TLS: tls_session_init: entry
2021-07-27 11:52:07 us=889575 PID packet_id_init seq_backtrack=64 time_backtrack=15
2021-07-27 11:52:07 us=889575 PID packet_id_init seq_backtrack=64 time_backtrack=15
2021-07-27 11:52:07 us=889575 TLS: tls_session_init: new session object, sid=b0797385 f9dd48f4
2021-07-27 11:52:07 us=889575 Control Channel MTU parms [ L:1624 D:1210 EF:40 EB:0 ET:0 EL:3 ]
2021-07-27 11:52:07 us=889575 MTU DYNAMIC mtu=1450, flags=2, 1624 -> 1450
2021-07-27 11:52:07 us=889575 RESOLVE_REMOTE flags=0x0101 phase=1 rrs=0 sig=-1 status=0
2021-07-27 11:52:07 us=889575 Data Channel MTU parms [ L:1624 D:1450 EF:124 EB:406 ET:0 EL:3 ]
2021-07-27 11:52:07 us=889575 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 56 bytes
2021-07-27 11:52:07 us=889575 calc_options_string_link_mtu: link-mtu 1624 -> 1560
2021-07-27 11:52:07 us=889575 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 56 bytes
2021-07-27 11:52:07 us=889575 calc_options_string_link_mtu: link-mtu 1624 -> 1560
2021-07-27 11:52:07 us=889575 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_CLIENT,comp-lzo,cipher AES-256-CBC,auth SHA1,keysize 256,key-method 2,tls-client'
2021-07-27 11:52:07 us=889575 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,cipher AES-256-CBC,auth SHA1,keysize 256,key-method 2,tls-server'
2021-07-27 11:52:07 us=889575 STREAM: RESET
2021-07-27 11:52:07 us=889575 STREAM: INIT maxlen=1627
2021-07-27 11:52:07 us=889575 TCP/UDP: Preserving recently used remote address: [AF_INET]<serverIpHere>:443
2021-07-27 11:52:07 us=889575 Socket Buffers: R=[65536->65536] S=[65536->65536]
2021-07-27 11:52:07 us=889575 Attempting to establish TCP connection with [AF_INET]<serverIpHere>:443 [nonblock]
2021-07-27 11:52:07 us=889575 TCP connection established with [AF_INET]<serverIpHere>:443
2021-07-27 11:52:07 us=889575 TCP_CLIENT link local: (not bound)
2021-07-27 11:52:07 us=889575 TCP_CLIENT link remote: [AF_INET]<serverIpHere>:443
2021-07-27 11:52:07 us=889575 TIMER: coarse timer wakeup 1 seconds
2021-07-27 11:52:07 us=889575 TLS: tls_multi_process: i=0 state=S_INITIAL, mysid=1cc2ba0d 622efd4c, stored-sid=00000000 00000000, stored-ip=[AF_INET]<serverIpHere>:443
2021-07-27 11:52:07 us=889575 TLS: tls_process: chg=0 ks=S_INITIAL lame=S_UNDEF to_link->len=0 wakeup=604800
2021-07-27 11:52:07 us=889575 ACK mark active outgoing ID 0
2021-07-27 11:52:07 us=889575 TLS: Initial Handshake, sid=1cc2ba0d 622efd4c
2021-07-27 11:52:07 us=889575 ACK reliable_can_send active=1 current=1 : [1] 0
2021-07-27 11:52:07 us=889575 ACK reliable_send ID 0 (size=4 to=2)
2021-07-27 11:52:07 us=889575 write_control_auth(): P_CONTROL_HARD_RESET_CLIENT_V2
2021-07-27 11:52:07 us=889575 Reliable -> TCP/UDP
2021-07-27 11:52:07 us=889575 ACK reliable_send_timeout 2 [1] 0
2021-07-27 11:52:07 us=889575 TLS: tls_process: timeout set to 2
2021-07-27 11:52:07 us=889575 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b0797385 f9dd48f4, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=889575 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=889575 RANDOM USEC=228205
2021-07-27 11:52:07 us=889575 WE_CTL n=0 ev=0000000000518D28 rwflags=0x0001 arg=0x4d2088
2021-07-27 11:52:07 us=889575 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
2021-07-27 11:52:07 us=889575 STREAM: GET NEXT len=1627
2021-07-27 11:52:07 us=889575 WIN32 I/O: Socket Receive queued [1627]
2021-07-27 11:52:07 us=889575 WE_CTL n=1 ev=0000000001F29960 rwflags=0x0003 arg=0x50f0a0
2021-07-27 11:52:07 us=889575 I/O WAIT T?|T?|SRQ|SW0 [1/228205]
2021-07-27 11:52:07 us=889575 WE_WAIT enter n=3 to=1228
2021-07-27 11:52:07 us=889575 [0] ev=0000000000000210 rwflags=0x0001 arg=0x4d2088
2021-07-27 11:52:07 us=889575 [1] ev=00000000000002F0 rwflags=0x0002 arg=0x50f0a0
2021-07-27 11:52:07 us=889575 [2] ev=00000000000002EC rwflags=0x0001 arg=0x50f0a0
2021-07-27 11:52:07 us=889575 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x50f0a0
2021-07-27 11:52:07 us=889575 event_wait returned 1
2021-07-27 11:52:07 us=889575 I/O WAIT status=0x0002
2021-07-27 11:52:07 us=889575 TCP_CLIENT WRITE [14] to [AF_INET]<serverIpHere>:443: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 sid=1cc2ba0d 622efd4c [ ] pid=0 DATA
2021-07-27 11:52:07 us=889575 STREAM: WRITE 14 offset=30
2021-07-27 11:52:07 us=889575 WIN32 I/O: Socket Send immediate return [16,16]
2021-07-27 11:52:07 us=889575 TCP_CLIENT write returned 16
2021-07-27 11:52:07 us=889575 TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=1cc2ba0d 622efd4c, stored-sid=00000000 00000000, stored-ip=[AF_INET]<serverIpHere>:443
2021-07-27 11:52:07 us=889575 TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
2021-07-27 11:52:07 us=889575 ACK reliable_can_send active=1 current=0 : [1] 0
2021-07-27 11:52:07 us=889575 SSL state (connect): before SSL initialization
2021-07-27 11:52:07 us=889575 SSL state (connect): SSLv3/TLS write client hello
2021-07-27 11:52:07 us=889575 ACK reliable_send_timeout 2 [1] 0
2021-07-27 11:52:07 us=889575 TLS: tls_process: timeout set to 2
2021-07-27 11:52:07 us=889575 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b0797385 f9dd48f4, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=889575 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=889575 WE_CTL n=0 ev=0000000000518D28 rwflags=0x0001 arg=0x4d2088
2021-07-27 11:52:07 us=889575 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
2021-07-27 11:52:07 us=889575 WE_CTL n=1 ev=0000000001F29960 rwflags=0x0001 arg=0x50f0a0
2021-07-27 11:52:07 us=889575 I/O WAIT T?|T?|SRQ|Sw1 [1/228205]
2021-07-27 11:52:07 us=889575 WE_WAIT enter n=2 to=1228
2021-07-27 11:52:07 us=889575 [0] ev=0000000000000210 rwflags=0x0001 arg=0x4d2088
2021-07-27 11:52:07 us=889575 [1] ev=00000000000002EC rwflags=0x0001 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 WE_WAIT leave rwflags=0x0001 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 event_wait returned 1
2021-07-27 11:52:07 us=996219 I/O WAIT status=0x0001
2021-07-27 11:52:07 us=996219 WIN32 I/O: Socket Completion success [28]
2021-07-27 11:52:07 us=996219 STREAM: ADD length_added=28
2021-07-27 11:52:07 us=996219 STREAM: ADD returned TRUE, buf_len=26, residual_len=0
2021-07-27 11:52:07 us=996219 STREAM: GET FINAL len=26
2021-07-27 11:52:07 us=996219 STREAM: RESET
2021-07-27 11:52:07 us=996219 TCP_CLIENT read returned 26
2021-07-27 11:52:07 us=996219 TCP_CLIENT READ [26] from [AF_INET]<serverIpHere>:443: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 sid=51f687ff 14254798 [ 0 sid=1cc2ba0d 622efd4c ] pid=0 DATA
2021-07-27 11:52:07 us=996219 TLS: control channel, op=P_CONTROL_HARD_RESET_SERVER_V2, IP=[AF_INET]<serverIpHere>:443
2021-07-27 11:52:07 us=996219 TLS: initial packet test, i=0 state=S_PRE_START, mysid=1cc2ba0d 622efd4c, rec-sid=51f687ff 14254798, rec-ip=[AF_INET]<serverIpHere>:443, stored-sid=00000000 00000000, stored-ip=[AF_INET]<serverIpHere>:443
2021-07-27 11:52:07 us=996219 TLS: initial packet test, i=1 state=S_INITIAL, mysid=b0797385 f9dd48f4, rec-sid=51f687ff 14254798, rec-ip=[AF_INET]<serverIpHere>:443, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=996219 TLS: initial packet test, i=2 state=S_UNDEF, mysid=00000000 00000000, rec-sid=51f687ff 14254798, rec-ip=[AF_INET]<serverIpHere>:443, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=996219 TLS: Initial packet from [AF_INET]<serverIpHere>:443, sid=51f687ff 14254798
2021-07-27 11:52:07 us=996219 TLS: received control channel packet s#=0 sid=51f687ff 14254798
2021-07-27 11:52:07 us=996219 ACK reliable_schedule_now
2021-07-27 11:52:07 us=996219 ACK received for pid 0, deleting from send buffer
2021-07-27 11:52:07 us=996219 ACK read ID 0 (buf->len=0)
2021-07-27 11:52:07 us=996219 ACK RWBS rel->size=8 rel->packet_id=00000000 id=00000000 ret=1
2021-07-27 11:52:07 us=996219 ACK mark active incoming ID 0
2021-07-27 11:52:07 us=996219 ACK acknowledge ID 0 (ack->len=1)
2021-07-27 11:52:07 us=996219 TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=1cc2ba0d 622efd4c, stored-sid=51f687ff 14254798, stored-ip=[AF_INET]<serverIpHere>:443
2021-07-27 11:52:07 us=996219 TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
2021-07-27 11:52:07 us=996219 ACK reliable_can_send active=0 current=0 : [1]
2021-07-27 11:52:07 us=996219 Incoming Ciphertext -> TLS
2021-07-27 11:52:07 us=996219 TLS: tls_process: chg=1 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
2021-07-27 11:52:07 us=996219 ACK reliable_can_send active=0 current=0 : [1]
2021-07-27 11:52:07 us=996219 ACK write ID 0 (ack->len=1, n=1)
2021-07-27 11:52:07 us=996219 write_control_auth(): P_ACK_V1
2021-07-27 11:52:07 us=996219 Dedicated ACK -> TCP/UDP
2021-07-27 11:52:07 us=996219 ACK reliable_send_timeout 604800 [1]
2021-07-27 11:52:07 us=996219 TLS: tls_process: timeout set to 60
2021-07-27 11:52:07 us=996219 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b0797385 f9dd48f4, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=996219 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=996219 WE_CTL n=0 ev=0000000000518D28 rwflags=0x0001 arg=0x4d2088
2021-07-27 11:52:07 us=996219 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
2021-07-27 11:52:07 us=996219 STREAM: GET NEXT len=1627
2021-07-27 11:52:07 us=996219 WIN32 I/O: Socket Receive queued [1627]
2021-07-27 11:52:07 us=996219 WE_CTL n=1 ev=0000000001F29960 rwflags=0x0003 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 I/O WAIT T?|T?|SRQ|SW1 [1/228205]
2021-07-27 11:52:07 us=996219 WE_WAIT enter n=3 to=1228
2021-07-27 11:52:07 us=996219 [0] ev=0000000000000210 rwflags=0x0001 arg=0x4d2088
2021-07-27 11:52:07 us=996219 [1] ev=00000000000002F0 rwflags=0x0002 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 [2] ev=00000000000002EC rwflags=0x0001 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 event_wait returned 1
2021-07-27 11:52:07 us=996219 I/O WAIT status=0x0002
2021-07-27 11:52:07 us=996219 TCP_CLIENT WRITE [22] to [AF_INET]<serverIpHere>:443: P_ACK_V1 kid=0 sid=1cc2ba0d 622efd4c [ 0 sid=51f687ff 14254798 ]
2021-07-27 11:52:07 us=996219 STREAM: WRITE 22 offset=35
2021-07-27 11:52:07 us=996219 WIN32 I/O: Socket Completion non-queued success [16]
2021-07-27 11:52:07 us=996219 WIN32 I/O: Socket Send immediate return [24,24]
2021-07-27 11:52:07 us=996219 TCP_CLIENT write returned 24
2021-07-27 11:52:07 us=996219 TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=1cc2ba0d 622efd4c, stored-sid=51f687ff 14254798, stored-ip=[AF_INET]<serverIpHere>:443
2021-07-27 11:52:07 us=996219 TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
2021-07-27 11:52:07 us=996219 STATE S_START
2021-07-27 11:52:07 us=996219 ACK reliable_can_send active=0 current=0 : [1]
2021-07-27 11:52:07 us=996219 STATE S_SENT_KEY
2021-07-27 11:52:07 us=996219 BIO read tls_read_ciphertext 277 bytes
2021-07-27 11:52:07 us=996219 ACK mark active outgoing ID 1
2021-07-27 11:52:07 us=996219 Outgoing Ciphertext -> Reliable
2021-07-27 11:52:07 us=996219 TLS: tls_process: chg=1 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
2021-07-27 11:52:07 us=996219 ACK reliable_can_send active=1 current=1 : [2] 1
2021-07-27 11:52:07 us=996219 ACK reliable_send ID 1 (size=281 to=2)
2021-07-27 11:52:07 us=996219 write_control_auth(): P_CONTROL_V1
2021-07-27 11:52:07 us=996219 Reliable -> TCP/UDP
2021-07-27 11:52:07 us=996219 ACK reliable_send_timeout 2 [2] 1
2021-07-27 11:52:07 us=996219 TLS: tls_process: timeout set to 2
2021-07-27 11:52:07 us=996219 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b0797385 f9dd48f4, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=996219 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=996219 WE_CTL n=0 ev=0000000000518D28 rwflags=0x0001 arg=0x4d2088
2021-07-27 11:52:07 us=996219 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
2021-07-27 11:52:07 us=996219 WE_CTL n=1 ev=0000000001F29960 rwflags=0x0003 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 I/O WAIT T?|T?|SRQ|SW1 [1/228205]
2021-07-27 11:52:07 us=996219 WE_WAIT enter n=3 to=1228
2021-07-27 11:52:07 us=996219 [0] ev=0000000000000210 rwflags=0x0001 arg=0x4d2088
2021-07-27 11:52:07 us=996219 [1] ev=00000000000002F0 rwflags=0x0002 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 [2] ev=00000000000002EC rwflags=0x0001 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 WE_WAIT leave [1,0] rwflags=0x0002 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 WE_WAIT leave [2,1] rwflags=0x0001 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 event_wait returned 2
2021-07-27 11:52:07 us=996219 I/O WAIT status=0x0003
2021-07-27 11:52:07 us=996219 TCP_CLIENT WRITE [291] to [AF_INET]<serverIpHere>:443: P_CONTROL_V1 kid=0 sid=1cc2ba0d 622efd4c [ ] pid=1 DATA 16030101 10010001 0c030355 6182437e 53df30ab e06a3a12 61b99510 adb19f2[more...]
2021-07-27 11:52:07 us=996219 STREAM: WRITE 291 offset=30
2021-07-27 11:52:07 us=996219 WIN32 I/O: Socket Completion non-queued success [24]
2021-07-27 11:52:07 us=996219 WIN32 I/O: Socket Send error [293]: Connection reset by peer (WSAECONNRESET)
2021-07-27 11:52:07 us=996219 TCP_CLIENT write returned 293
2021-07-27 11:52:07 us=996219 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=1cc2ba0d 622efd4c, stored-sid=51f687ff 14254798, stored-ip=[AF_INET]<serverIpHere>:443
2021-07-27 11:52:07 us=996219 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
2021-07-27 11:52:07 us=996219 ACK reliable_can_send active=1 current=0 : [2] 1
2021-07-27 11:52:07 us=996219 ACK reliable_send_timeout 2 [2] 1
2021-07-27 11:52:07 us=996219 TLS: tls_process: timeout set to 2
2021-07-27 11:52:07 us=996219 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b0797385 f9dd48f4, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=996219 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
2021-07-27 11:52:07 us=996219 WE_CTL n=0 ev=0000000000518D28 rwflags=0x0001 arg=0x4d2088
2021-07-27 11:52:07 us=996219 STREAM: SET NEXT, buf=[536,0] next=[536,1627] len=-1 maxlen=1627
2021-07-27 11:52:07 us=996219 WE_CTL n=1 ev=0000000001F29960 rwflags=0x0001 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 I/O WAIT T?|T?|SRQ|Sw1 [1/228205]
2021-07-27 11:52:07 us=996219 WE_WAIT enter n=2 to=1228
2021-07-27 11:52:07 us=996219 [0] ev=0000000000000210 rwflags=0x0001 arg=0x4d2088
2021-07-27 11:52:07 us=996219 [1] ev=00000000000002EC rwflags=0x0001 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 WE_WAIT leave [1,0] rwflags=0x0001 arg=0x50f0a0
2021-07-27 11:52:07 us=996219 event_wait returned 1
2021-07-27 11:52:07 us=996219 I/O WAIT status=0x0001
2021-07-27 11:52:07 us=996219 WIN32 I/O: Socket Completion error: Unknown error (errno=10054)
2021-07-27 11:52:07 us=996219 Connection reset, restarting [-1]
2021-07-27 11:52:07 us=996219 PID packet_id_free
2021-07-27 11:52:07 us=996219 PID packet_id_free
2021-07-27 11:52:07 us=996219 PID packet_id_free
2021-07-27 11:52:07 us=996219 PID packet_id_free
2021-07-27 11:52:07 us=996219 PID packet_id_free
2021-07-27 11:52:07 us=996219 PID packet_id_free
2021-07-27 11:52:07 us=996219 PID packet_id_free
2021-07-27 11:52:07 us=996219 PID packet_id_free
2021-07-27 11:52:07 us=996219 TCP/UDP: Closing socket
2021-07-27 11:52:07 us=996219 PID packet_id_free
2021-07-27 11:52:07 us=996219 SIGUSR1[soft,connection-reset] received, process restarting
2021-07-27 11:52:07 us=996219 Restart pause, 5 second(s)
I verified that I can telnet from the client, to the server on port 443.
Any idea why I'm getting my connection reset?
