Clients 2.4.5 and ..6 do have Connection Problems with 2.4.0 Server

TorroLoco

Dear Community,

I have Problems with clients, that will not connect to our server after updating them from 2.4.4 to 2.4.5 or 2.4.6
The Server is a Debian Stretch machine, running 2.4.0 and the Clients are Win7 machines.

Here are the related Errors :

Sep 5 10:11:17 vpn openvpn[21656]: xxx.xxx.xxx.xxx:18934 TLS error: The server has no TLS ciphersuites in common with the client. Your --tls-cipher setting might be too restrictive.
Sep 5 10:11:17 vpn openvpn[21656]: xxx.xxx.xxx.xxx:18934 OpenSSL: error:1408A0C1:SSL routines:ssl3_get_client_hello:no shared cipher
Sep 5 10:11:17 vpn openvpn[21656]: xxx.xxx.xxx.xxx:18934 TLS_ERROR: BIO read tls_read_plaintext error
Sep 5 10:11:17 vpn openvpn[21656]: xxx.xxx.xxx.xxx:18934 TLS Error: TLS object -> incoming plaintext read error
Sep 5 10:11:17 vpn openvpn[21656]: xxx.xxx.xxx.xxx:18934 TLS Error: TLS handshake failed
Sep 5 10:11:17 vpn openvpn[21656]: xxx.xxx.xxx.xxx:18934 SIGUSR1[soft,tls-error] received, client-instance restarting

I checked if the server and the client made the same ciphers available (show-ciphers and show-tls)
Then, i explicitly specified these on server and client (cipher and tls-cipher) in the conf, without success, and there was no change in the error message. (AES-256-CBC and GCM; ECDHE curves with AES 256 [we use elliptic Keys])
I had also renewed persistent objects, without success
In a dump of the connection attempt are only encrypted UDP packets. We can see that the Client sends a package and the Server answers, then the Client sends a short packet and then a longer (which is is resent then) , referring to the client logs, this is the Client_Hello

What works:

Connect to port and initialize server and client. Server sends a message that client accepts and client then sends the client Hello. Since all UDP packets are encrypted, decryption SHOULD work.
However, the client repeats the client Hello packet several times until the timeout. The server does not answer (-> does this match the protocol or does the server actually have to answer that ciphers do not fit for client to suggest next sentence?)

Does anyone have a hint where to search next ?

Kind Regards,
Sebastian

TinCanTech

The problem is due to different versions of the SSL library in use.

What you have described essentially means that you have specified a less than ideal TLS cipher.
Openvpn will always select the strongest (by known standards) TLS cipher available between peers.
It is not recommended to specify a TLS cipher unless you understand the risks you are taking.

(cypher: variant spelling of cipher)

TorroLoco

Hello !

Thank you for your answer.
I am testing in a Mirrored Test-Enviroment, so i should not break something (i hope 😃 )
What would you recommend ? NCP ?
Is it Possible/common to update the SSL Library on the server, or wil OpenVPN just work with a specified version ?

Sebastian

TinCanTech

TorroLoco wrote What would you recommend ? NCP ?

NCP is for the data channle not the TLS (control) channel.

Simply remove your --tls-cipher spec from the configs and let openvpn decide.

TorroLoco

So this becomes interesting now..
I did not have the --tls-cipher in the config files when getting this error first, and added it later on both sides, to be sure that they use the same set.
After this test gave no new results, i removed it. The 2.4.4 Clients can connect to the server without --tls-cipher.

Regards !

TorroLoco

Available TLS Ciphers on SERVER (2.4.0),
listed in order of preference:

TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
TLS-ECDHE-ECDSA-WITH-AES-256-GCM-SHA384
TLS-ECDHE-RSA-WITH-AES-256-CBC-SHA384
TLS-ECDHE-ECDSA-WITH-AES-256-CBC-SHA384
TLS-ECDHE-RSA-WITH-AES-256-CBC-SHA
TLS-ECDHE-ECDSA-WITH-AES-256-CBC-SHA
TLS-DHE-RSA-WITH-AES-256-GCM-SHA384
TLS-DHE-RSA-WITH-AES-256-CBC-SHA256
TLS-DHE-RSA-WITH-AES-256-CBC-SHA
TLS-DHE-RSA-WITH-CAMELLIA-256-CBC-SHA
TLS-ECDHE-RSA-WITH-AES-128-GCM-SHA256
TLS-ECDHE-ECDSA-WITH-AES-128-GCM-SHA256
TLS-ECDHE-RSA-WITH-AES-128-CBC-SHA256
TLS-ECDHE-ECDSA-WITH-AES-128-CBC-SHA256
TLS-ECDHE-RSA-WITH-AES-128-CBC-SHA
TLS-ECDHE-ECDSA-WITH-AES-128-CBC-SHA
TLS-DHE-RSA-WITH-AES-128-GCM-SHA256
TLS-DHE-RSA-WITH-AES-128-CBC-SHA256
TLS-DHE-RSA-WITH-AES-128-CBC-SHA
TLS-DHE-RSA-WITH-CAMELLIA-128-CBC-SHA

Available TLS Ciphers on CLIENT (2.4.4 - WORKING VERSION)
listed in order of preference:

TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
TLS-ECDHE-ECDSA-WITH-AES-256-GCM-SHA384
TLS-ECDHE-RSA-WITH-AES-256-CBC-SHA384
TLS-ECDHE-ECDSA-WITH-AES-256-CBC-SHA384
TLS-ECDHE-RSA-WITH-AES-256-CBC-SHA
TLS-ECDHE-ECDSA-WITH-AES-256-CBC-SHA
TLS-DHE-RSA-WITH-AES-256-GCM-SHA384
TLS-DHE-RSA-WITH-AES-256-CBC-SHA256
TLS-DHE-RSA-WITH-AES-256-CBC-SHA
TLS-DHE-RSA-WITH-CAMELLIA-256-CBC-SHA
TLS-ECDHE-RSA-WITH-AES-128-GCM-SHA256
TLS-ECDHE-ECDSA-WITH-AES-128-GCM-SHA256
TLS-ECDHE-RSA-WITH-AES-128-CBC-SHA256
TLS-ECDHE-ECDSA-WITH-AES-128-CBC-SHA256
TLS-ECDHE-RSA-WITH-AES-128-CBC-SHA
TLS-ECDHE-ECDSA-WITH-AES-128-CBC-SHA
TLS-DHE-RSA-WITH-AES-128-GCM-SHA256
TLS-DHE-RSA-WITH-AES-128-CBC-SHA256
TLS-DHE-RSA-WITH-AES-128-CBC-SHA
TLS-DHE-RSA-WITH-CAMELLIA-128-CBC-SHA

Available TLS Ciphers on CLIENT (2.4.6 - NOT WORKING VERSION ),
listed in order of preference:

TLS-ECDHE-ECDSA-WITH-AES-256-GCM-SHA384
TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
TLS-DHE-RSA-WITH-AES-256-GCM-SHA384
TLS-ECDHE-ECDSA-WITH-CHACHA20-POLY1305-SHA256
TLS-ECDHE-RSA-WITH-CHACHA20-POLY1305-SHA256
TLS-DHE-RSA-WITH-CHACHA20-POLY1305-SHA256
TLS-ECDHE-ECDSA-WITH-AES-128-GCM-SHA256
TLS-ECDHE-RSA-WITH-AES-128-GCM-SHA256
TLS-DHE-RSA-WITH-AES-128-GCM-SHA256
TLS-ECDHE-ECDSA-WITH-AES-256-CBC-SHA384
TLS-ECDHE-RSA-WITH-AES-256-CBC-SHA384
TLS-DHE-RSA-WITH-AES-256-CBC-SHA256
TLS-ECDHE-ECDSA-WITH-AES-128-CBC-SHA256
TLS-ECDHE-RSA-WITH-AES-128-CBC-SHA256
TLS-DHE-RSA-WITH-AES-128-CBC-SHA256
TLS-ECDHE-ECDSA-WITH-AES-256-CBC-SHA
TLS-ECDHE-RSA-WITH-AES-256-CBC-SHA
TLS-DHE-RSA-WITH-AES-256-CBC-SHA
TLS-ECDHE-ECDSA-WITH-AES-128-CBC-SHA
TLS-ECDHE-RSA-WITH-AES-128-CBC-SHA
TLS-DHE-RSA-WITH-AES-128-CBC-SHA

As you can see, both clients have common ciphers with the Server for automatic choosing.
I am wondering, why the 2.4.6 can not connect with the Server.

TinCanTech

Please see:
HOWTO: Request Help ! {2}

TorroLoco

Hello !

here are the config files

# Server config (2.4.0)
port xxxx #Connection port
proto udp
dev tun
ca xxx.crt
cert xxx.crt
key xxx.key
dh xxxxx.pem #4096 bit dh parameters
topology subnet
server xxx.xxx.xxx.xxx xxx.xxx.xxx.xxxx # ip and netmask
ifconfig-pool-persist xxx.txt # list of ip <-> clients
push "route xx.xxx.xxx.xxx xxx.xxx.xxxx.xxx" # Push route(s) to clients
learn-address ./xxxxx #firewall script
script-security 2
keepalive 10 120
tls-auth xxx.key 0
cipher AES-256-GCM
compress lz4-v2 #compression on network
push "compress lz4-v2"
user xxx
group xxx
persist-key
persist-tun
status xxx.xx # openVPN status file
verb 6
explicit-exit-notify 1

And the Client

# Client config - connects/works with 2.4.4 but not with 2.4.5. and up
client
dev tun
proto udp
remote xxx.xxx.xxx.xxx xxxx
resolv-retry infinite
nobind
persist-key
persist-tun
ca xxx.crt
cert xxx.crt
key xxx.key
remote-cert-ku xxxx
tls-auth xxx.key 1
cipher AES-256-GCM
comp-lzo
verb 6
script-security 2

I hope this helps to find the error..

best regards,
Sebastian

TorroLoco

Client-2.4.6-failedAttemptLog

Wed Sep 12 11:47:38 2018 NOTE: --user option is not implemented on Windows
Wed Sep 12 11:47:38 2018 NOTE: --group option is not implemented on Windows
Wed Sep 12 11:47:38 2018 us=270001 Current Parameter Settings:
Wed Sep 12 11:47:38 2018 us=270001   config = 'client.ovpn'
Wed Sep 12 11:47:38 2018 us=270001   mode = 0
Wed Sep 12 11:47:38 2018 us=270001   show_ciphers = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   show_digests = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   show_engines = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   genkey = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   key_pass_file = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   show_tls_ciphers = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   connect_retry_max = 0
Wed Sep 12 11:47:38 2018 us=270001 Connection profiles [0]:
Wed Sep 12 11:47:38 2018 us=270001   proto = udp
Wed Sep 12 11:47:38 2018 us=270001   local = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   local_port = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   remote = 'xxx.xxx.xxx.xxx'
Wed Sep 12 11:47:38 2018 us=270001   remote_port = 'xxxx'
Wed Sep 12 11:47:38 2018 us=270001   remote_float = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   bind_defined = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   bind_local = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   bind_ipv6_only = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   connect_retry_seconds = 5
Wed Sep 12 11:47:38 2018 us=270001   connect_timeout = 120
Wed Sep 12 11:47:38 2018 us=270001   socks_proxy_server = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   socks_proxy_port = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   tun_mtu = 1500
Wed Sep 12 11:47:38 2018 us=270001   tun_mtu_defined = ENABLED
Wed Sep 12 11:47:38 2018 us=270001   link_mtu = 1500
Wed Sep 12 11:47:38 2018 us=270001   link_mtu_defined = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   tun_mtu_extra = 0
Wed Sep 12 11:47:38 2018 us=270001   tun_mtu_extra_defined = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   mtu_discover_type = -1
Wed Sep 12 11:47:38 2018 us=270001   fragment = 0
Wed Sep 12 11:47:38 2018 us=270001   mssfix = 1450
Wed Sep 12 11:47:38 2018 us=270001   explicit_exit_notification = 0
Wed Sep 12 11:47:38 2018 us=270001 Connection profiles END
Wed Sep 12 11:47:38 2018 us=270001   remote_random = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   ipchange = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   dev = 'tun'
Wed Sep 12 11:47:38 2018 us=270001   dev_type = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   dev_node = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   lladdr = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   topology = 1
Wed Sep 12 11:47:38 2018 us=270001   ifconfig_local = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   ifconfig_remote_netmask = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   ifconfig_noexec = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   ifconfig_nowarn = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   ifconfig_ipv6_local = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   ifconfig_ipv6_netbits = 0
Wed Sep 12 11:47:38 2018 us=270001   ifconfig_ipv6_remote = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=270001   shaper = 0
Wed Sep 12 11:47:38 2018 us=270001   mtu_test = 0
Wed Sep 12 11:47:38 2018 us=270001   mlock = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   keepalive_ping = 0
Wed Sep 12 11:47:38 2018 us=270001   keepalive_timeout = 0
Wed Sep 12 11:47:38 2018 us=270001   inactivity_timeout = 0
Wed Sep 12 11:47:38 2018 us=270001   ping_send_timeout = 0
Wed Sep 12 11:47:38 2018 us=270001   ping_rec_timeout = 0
Wed Sep 12 11:47:38 2018 us=270001   ping_rec_timeout_action = 0
Wed Sep 12 11:47:38 2018 us=270001   ping_timer_remote = DISABLED
Wed Sep 12 11:47:38 2018 us=270001   remap_sigusr1 = 0
Wed Sep 12 11:47:38 2018 us=270001   persist_tun = ENABLED
Wed Sep 12 11:47:38 2018 us=285601   persist_local_ip = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   persist_remote_ip = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   persist_key = ENABLED
Wed Sep 12 11:47:38 2018 us=285601   passtos = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   resolve_retry_seconds = 1000000000
Wed Sep 12 11:47:38 2018 us=285601   resolve_in_advance = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   username = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   groupname = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   chroot_dir = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   cd_dir = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   writepid = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   up_script = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   down_script = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   down_pre = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   up_restart = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   up_delay = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   daemon = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   inetd = 0
Wed Sep 12 11:47:38 2018 us=285601   log = ENABLED
Wed Sep 12 11:47:38 2018 us=285601   suppress_timestamps = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   machine_readable_output = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   nice = 0
Wed Sep 12 11:47:38 2018 us=285601   verbosity = 6
Wed Sep 12 11:47:38 2018 us=285601   mute = 0
Wed Sep 12 11:47:38 2018 us=285601   gremlin = 0
Wed Sep 12 11:47:38 2018 us=285601   status_file = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   status_file_version = 1
Wed Sep 12 11:47:38 2018 us=285601   status_file_update_freq = 60
Wed Sep 12 11:47:38 2018 us=285601   occ = ENABLED
Wed Sep 12 11:47:38 2018 us=285601   rcvbuf = 0
Wed Sep 12 11:47:38 2018 us=285601   sndbuf = 0
Wed Sep 12 11:47:38 2018 us=285601   sockflags = 0
Wed Sep 12 11:47:38 2018 us=285601   fast_io = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   comp.alg = 2
Wed Sep 12 11:47:38 2018 us=285601   comp.flags = 1
Wed Sep 12 11:47:38 2018 us=285601   route_script = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   route_default_gateway = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   route_default_metric = 0
Wed Sep 12 11:47:38 2018 us=285601   route_noexec = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   route_delay = 5
Wed Sep 12 11:47:38 2018 us=285601   route_delay_window = 30
Wed Sep 12 11:47:38 2018 us=285601   route_delay_defined = ENABLED
Wed Sep 12 11:47:38 2018 us=285601   route_nopull = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   route_gateway_via_dhcp = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   allow_pull_fqdn = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   management_addr = '127.0.0.1'
Wed Sep 12 11:47:38 2018 us=285601   management_port = '25340'
Wed Sep 12 11:47:38 2018 us=285601   management_user_pass = 'stdin'
Wed Sep 12 11:47:38 2018 us=285601   management_log_history_cache = 250
Wed Sep 12 11:47:38 2018 us=285601   management_echo_buffer_size = 100
Wed Sep 12 11:47:38 2018 us=285601   management_write_peer_info_file = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   management_client_user = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   management_client_group = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   management_flags = 6
Wed Sep 12 11:47:38 2018 us=285601   shared_secret_file = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   key_direction = 1
Wed Sep 12 11:47:38 2018 us=285601   ciphername = 'AES-256-GCM'
Wed Sep 12 11:47:38 2018 us=285601   ncp_enabled = ENABLED
Wed Sep 12 11:47:38 2018 us=285601   ncp_ciphers = 'AES-256-GCM:AES-128-GCM'
Wed Sep 12 11:47:38 2018 us=285601   authname = 'SHA1'
Wed Sep 12 11:47:38 2018 us=285601   prng_hash = 'SHA1'
Wed Sep 12 11:47:38 2018 us=285601   prng_nonce_secret_len = 16
Wed Sep 12 11:47:38 2018 us=285601   keysize = 0
Wed Sep 12 11:47:38 2018 us=285601   engine = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   replay = ENABLED
Wed Sep 12 11:47:38 2018 us=285601   mute_replay_warnings = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   replay_window = 64
Wed Sep 12 11:47:38 2018 us=285601   replay_time = 15
Wed Sep 12 11:47:38 2018 us=285601   packet_id_file = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   use_iv = ENABLED
Wed Sep 12 11:47:38 2018 us=285601   test_crypto = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   tls_server = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   tls_client = ENABLED
Wed Sep 12 11:47:38 2018 us=285601   key_method = 2
Wed Sep 12 11:47:38 2018 us=285601   ca_file = 'Path/xxxx.crt'
Wed Sep 12 11:47:38 2018 us=285601   ca_path = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   dh_file = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   cert_file = 'Path/xxxx.crt'
Wed Sep 12 11:47:38 2018 us=285601   extra_certs_file = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   priv_key_file = 'Path/xxxx.key'
Wed Sep 12 11:47:38 2018 us=285601   pkcs12_file = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   cryptoapi_cert = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   cipher_list = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   tls_cert_profile = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   tls_verify = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   tls_export_cert = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   verify_x509_type = 0
Wed Sep 12 11:47:38 2018 us=285601   verify_x509_name = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   crl_file = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   ns_cert_type = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = XXX
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_ku[i] = 0
Wed Sep 12 11:47:38 2018 us=285601   remote_cert_eku = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   ssl_flags = 0
Wed Sep 12 11:47:38 2018 us=285601   tls_timeout = 2
Wed Sep 12 11:47:38 2018 us=285601   renegotiate_bytes = -1
Wed Sep 12 11:47:38 2018 us=285601   renegotiate_packets = 0
Wed Sep 12 11:47:38 2018 us=285601   renegotiate_seconds = 3600
Wed Sep 12 11:47:38 2018 us=285601   handshake_window = 60
Wed Sep 12 11:47:38 2018 us=285601   transition_window = 3600
Wed Sep 12 11:47:38 2018 us=285601   single_session = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   push_peer_info = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   tls_exit = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   tls_auth_file = 'Path/xxxx.key'
Wed Sep 12 11:47:38 2018 us=285601   tls_crypt_file = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_protected_authentication = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_private_mode = 00000000
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_cert_private = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_pin_cache_period = -1
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_id = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   pkcs11_id_management = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   server_network = 0.0.0.0
Wed Sep 12 11:47:38 2018 us=285601   server_netmask = 0.0.0.0
Wed Sep 12 11:47:38 2018 us=285601   server_network_ipv6 = ::
Wed Sep 12 11:47:38 2018 us=285601   server_netbits_ipv6 = 0
Wed Sep 12 11:47:38 2018 us=285601   server_bridge_ip = 0.0.0.0
Wed Sep 12 11:47:38 2018 us=285601   server_bridge_netmask = 0.0.0.0
Wed Sep 12 11:47:38 2018 us=285601   server_bridge_pool_start = 0.0.0.0
Wed Sep 12 11:47:38 2018 us=285601   server_bridge_pool_end = 0.0.0.0
Wed Sep 12 11:47:38 2018 us=285601   ifconfig_pool_defined = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   ifconfig_pool_start = 0.0.0.0
Wed Sep 12 11:47:38 2018 us=285601   ifconfig_pool_end = 0.0.0.0
Wed Sep 12 11:47:38 2018 us=285601   ifconfig_pool_netmask = 0.0.0.0
Wed Sep 12 11:47:38 2018 us=285601   ifconfig_pool_persist_filename = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   ifconfig_pool_persist_refresh_freq = 600
Wed Sep 12 11:47:38 2018 us=285601   ifconfig_ipv6_pool_defined = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   ifconfig_ipv6_pool_base = ::
Wed Sep 12 11:47:38 2018 us=285601   ifconfig_ipv6_pool_netbits = 0
Wed Sep 12 11:47:38 2018 us=285601   n_bcast_buf = 256
Wed Sep 12 11:47:38 2018 us=285601   tcp_queue_limit = 64
Wed Sep 12 11:47:38 2018 us=285601   real_hash_size = 256
Wed Sep 12 11:47:38 2018 us=285601   virtual_hash_size = 256
Wed Sep 12 11:47:38 2018 us=285601   client_connect_script = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   learn_address_script = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   client_disconnect_script = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   client_config_dir = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   ccd_exclusive = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   tmp_dir = 'Drive:/Path'
Wed Sep 12 11:47:38 2018 us=285601   push_ifconfig_defined = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   push_ifconfig_local = 0.0.0.0
Wed Sep 12 11:47:38 2018 us=285601   push_ifconfig_remote_netmask = 0.0.0.0
Wed Sep 12 11:47:38 2018 us=285601   push_ifconfig_ipv6_defined = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   push_ifconfig_ipv6_local = ::/0
Wed Sep 12 11:47:38 2018 us=285601   push_ifconfig_ipv6_remote = ::
Wed Sep 12 11:47:38 2018 us=285601   enable_c2c = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   duplicate_cn = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   cf_max = 0
Wed Sep 12 11:47:38 2018 us=285601   cf_per = 0
Wed Sep 12 11:47:38 2018 us=285601   max_clients = 1024
Wed Sep 12 11:47:38 2018 us=285601   max_routes_per_client = 256
Wed Sep 12 11:47:38 2018 us=285601   auth_user_pass_verify_script = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   auth_user_pass_verify_script_via_file = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   auth_token_generate = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   auth_token_lifetime = 0
Wed Sep 12 11:47:38 2018 us=285601   client = ENABLED
Wed Sep 12 11:47:38 2018 us=285601   pull = ENABLED
Wed Sep 12 11:47:38 2018 us=285601   auth_user_pass_file = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   show_net_up = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   route_method = 3
Wed Sep 12 11:47:38 2018 us=285601   block_outside_dns = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   ip_win32_defined = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   ip_win32_type = 3
Wed Sep 12 11:47:38 2018 us=285601   dhcp_masq_offset = 0
Wed Sep 12 11:47:38 2018 us=285601   dhcp_lease_time = 31536000
Wed Sep 12 11:47:38 2018 us=285601   tap_sleep = 0
Wed Sep 12 11:47:38 2018 us=285601   dhcp_options = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   dhcp_renew = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   dhcp_pre_release = DISABLED
Wed Sep 12 11:47:38 2018 us=285601   domain = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   netbios_scope = '[UNDEF]'
Wed Sep 12 11:47:38 2018 us=285601   netbios_node_type = 0
Wed Sep 12 11:47:38 2018 us=285601   disable_nbt = DISABLED
Wed Sep 12 11:47:38 2018 us=285601 OpenVPN 2.4.6 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Apr 26 2018
Wed Sep 12 11:47:38 2018 us=285601 Windows version 6.1 (Windows 7) 64bit
Wed Sep 12 11:47:38 2018 us=285601 library versions: OpenSSL 1.1.0h  27 Mar 2018, LZO 2.10
Enter Management Password:
Wed Sep 12 11:47:38 2018 us=285601 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25340
Wed Sep 12 11:47:38 2018 us=285601 Need hold release from management interface, waiting...
Wed Sep 12 11:47:38 2018 us=722401 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25340
Wed Sep 12 11:47:38 2018 us=831601 MANAGEMENT: CMD 'state on'
Wed Sep 12 11:47:38 2018 us=831601 MANAGEMENT: CMD 'log all on'
Wed Sep 12 11:47:39 2018 us=3201 MANAGEMENT: CMD 'echo all on'
Wed Sep 12 11:47:39 2018 us=3201 MANAGEMENT: CMD 'bytecount 5'
Wed Sep 12 11:47:39 2018 us=3201 MANAGEMENT: CMD 'hold off'
Wed Sep 12 11:47:39 2018 us=3201 MANAGEMENT: CMD 'hold release'
Wed Sep 12 11:47:39 2018 us=3201 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.
Wed Sep 12 11:47:39 2018 us=3201 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed Sep 12 11:47:39 2018 us=3201 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed Sep 12 11:47:39 2018 us=3201 LZO compression initializing
Wed Sep 12 11:47:39 2018 us=3201 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Wed Sep 12 11:47:39 2018 us=3201 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Wed Sep 12 11:47:39 2018 us=3201 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1550,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-client'
Wed Sep 12 11:47:39 2018 us=3201 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1550,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-server'
Wed Sep 12 11:47:39 2018 us=3201 TCP/UDP: Preserving recently used remote address: [AF_INET]xxx.xxx.xxx.xxx:xxxx
Wed Sep 12 11:47:39 2018 us=3201 Socket Buffers: R=[8192->8192] S=[8192->8192]
Wed Sep 12 11:47:39 2018 us=3201 UDP link local: (not bound)
Wed Sep 12 11:47:39 2018 us=3201 UDP link remote: [AF_INET]xxx.xxx.xxx.xxx:xxxx
Wed Sep 12 11:47:39 2018 us=3201 MANAGEMENT: >STATE:1536745659,WAIT,,,,,,
Wed Sep 12 11:47:39 2018 us=3201 UDP WRITE [42] to [AF_INET]xxx.xxx.xxx.xxx:xxxx: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ 932823425 2821582887 310636839 2521871998 154597888 347 2564864768 0 ]
Wed Sep 12 11:47:39 2018 us=3201 UDP READ [0] from [AF_UNSPEC]: DATA UNDEF len=-1
Wed Sep 12 11:47:39 2018 us=18801 UDP READ [54] from [AF_INET]xxx.xxx.xxx.xxx:xxxx: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 275606471 764010330 51650250 3539928077 1081231872 347 2564985345 0 3775067993 2508388136 0 ]
Wed Sep 12 11:47:39 2018 us=18801 MANAGEMENT: >STATE:1536745659,AUTH,,,,,,
Wed Sep 12 11:47:39 2018 us=18801 TLS: Initial packet from [AF_INET]xxx.xxx.xxx.xxx:xxxx, sid=006f3e00 45414898
Wed Sep 12 11:47:39 2018 us=18801 UDP WRITE [50] to [AF_INET]xxx.xxx.xxx.xxx:xxxx: P_ACK_V1 kid=0 [ 1004372934 2879745489 2006448963 1598397478 942872064 603 2564864769 ]
Wed Sep 12 11:47:39 2018 us=18801 UDP WRITE [202] to [AF_INET]xxx.xxx.xxx.xxx:xxxx: P_CONTROL_V1 kid=0 [ 4085465467 1520527345 4024948871 1621627138 197071360 859 2564864768 1 369295616 2600534016 2533557137 2843427629 930904732 1678322428 1891960024 888822914 3765733175 4049150797 1331992832 2932780 3224371359 3433680040 3433742379 3224
Wed Sep 12 11:47:41 2018 us=483601 UDP WRITE [202] to [AF_INET]xxx.xxx.xxx.xxx:xxxx: P_CONTROL_V1 kid=0 [ 3899602752 2725682834 3129690151 904916592 1989460480 1115 2564864768 1 369295616 2600534016 2533557137 2843427629 930904732 1678322428 1891960024 888822914 3765733175 4049150797 1331992832 2932780 3224371359 3433680040 3433742379 322
Wed Sep 12 11:47:45 2018 us=180801 UDP WRITE [202] to [AF_INET]xxx.xxx.xxx.xxx:xxxx: P_CONTROL_V1 kid=0 [ 3870572614 1942696468 1280006936 3365998376 3260086528 1371 2564864768 1 369295616 2600534016 2533557137 2843427629 930904732 1678322428 1891960024 888822914 3765733175 4049150797 1331992832 2932780 3224371359 3433680040 3433742379 32
Wed Sep 12 11:47:53 2018 us=152401 UDP WRITE [202] to [AF_INET]xxx.xxx.xxx.xxx:xxxx: P_CONTROL_V1 kid=0 [ 2087080039 2024031522 2172434516 2841681481 2488613888 1627 2564864768 1 369295616 2600534016 2533557137 2843427629 930904732 1678322428 1891960024 888822914 3765733175 4049150797 1331992832 2932780 3224371359 3433680040 3433742379 32
Wed Sep 12 11:48:09 2018 us=111201 UDP WRITE [202] to [AF_INET]xxx.xxx.xxx.xxx:xxxx: P_CONTROL_V1 kid=0 [ 3418892781 376241726 1779728896 2839769160 2025801216 1883 2564864768 1 369295616 2600534016 2533557137 2843427629 930904732 1678322428 1891960024 888822914 3765733175 4049150797 1331992832 2932780 3224371359 3433680040 3433742379 322
Wed Sep 12 11:48:39 2018 us=905602 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Wed Sep 12 11:48:39 2018 us=905602 TLS Error: TLS handshake failed
Wed Sep 12 11:48:39 2018 us=905602 TCP/UDP: Closing socket
Wed Sep 12 11:48:39 2018 us=905602 SIGUSR1[soft,tls-error] received, process restarting
Wed Sep 12 11:48:39 2018 us=905602 MANAGEMENT: >STATE:1536745719,RECONNECTING,tls-error,,,,,
Wed Sep 12 11:48:39 2018 us=905602 Restart pause, 5 second(s)
Wed Sep 12 11:48:44 2018 us=975602 SIGTERM[hard,init_instance] received, process exiting
Wed Sep 12 11:48:44 2018 us=975602 MANAGEMENT: >STATE:1536745724,EXITING,init_instance,,,,,

[/oconf]

TinCanTech

TorroLoco wrote Wed Sep 12 11:48:39 2018 us=905602 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)

TorroLoco

Hello TinCanTech ,

thank your for your help.

I think there must be another problem, because the same config file on the same machine works for 2.4.4, tested this already.
When you look at the UDP Traffic, around line 322 to 326, then you can see, that there is "confirmed" traffic between server and client.
My guess is, that the server did not accept/drops the UDP Packages from the client for some reason and then runs into this timeout, which can be misunderstood as connection error. Maybe Decryption or protocol errors ? i also did a dump on the UDP port and did see that the packages arrive on the server.

Regards !

TinCanTech

Server log at --verb 4 ..

TorroLoco

oconf=server log

Sep 17 09:34:01 vpn openvpn[675]: MULTI: multi_create_instance called
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 Re-using SSL/TLS context
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 LZ4v2 compression initializing
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1550,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-server'
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1550,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-client'
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 UDPv4 READ [42] from [AF_INET]xxx.xxx.xxx.xxx:29671: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ 1222946453 3970330228 594863753 3166341892 1519293184 347 2673406720 0 ]
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 TLS: Initial packet from [AF_INET]xxx.xxx.xxx.xxx:29671, sid=88598c70 6907c779
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 UDPv4 WRITE [54] to [AF_INET]xxx.xxx.xxx.xxx:29671: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 1745191688 4001677533 1930797341 1248180336 2988339968 347 2673525249 0 2287570032 1762117497 0 ]
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 UDPv4 READ [50] from [AF_INET]xxx.xxx.xxx.xxx:29671: P_ACK_V1 kid=0 [ 2462866984 3781809729 856877485 832217861 3316435712 603 2673406721 0 82222991 1071937410 ]
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 UDPv4 READ [202] from [AF_INET]xxx.xxx.xxx.xxx:29671: P_CONTROL_V1 kid=0 [ 1819136359 129756688 2317080548 529625332 100978432 859 2673406720 1 369295616 2600534016 2533557065 843495839 2460184269 702682229 3933545853 2504758001 3819003489 1347555070 4246203904 2932780 3224371359 3433680040 ] pid=3223633960
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 TLS error: The server has no TLS ciphersuites in common with the client. Your --tls-cipher setting might be too restrictive.
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 OpenSSL: error:1408A0C1:SSL routines:ssl3_get_client_hello:no shared cipher
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 TLS_ERROR: BIO read tls_read_plaintext error
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 TLS Error: TLS object -> incoming plaintext read error
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 TLS Error: TLS handshake failed
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 SIGUSR1[soft,tls-error] received, client-instance restarting
Sep 17 09:35:06 vpn openvpn[675]: MULTI: multi_create_instance called
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 Re-using SSL/TLS context
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 LZ4v2 compression initializing
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1550,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-server'
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1550,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-client'
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 UDPv4 READ [42] from [AF_INET]xxx.xxx.xxx.xxx:19486: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ 2061901455 2523786667 1076017242 3972702342 621972224 347 2673423360 0 ]
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 TLS: Initial packet from [AF_INET]xxx.xxx.xxx.xxx:19486, sid=8b7c0a21 c0b63d40
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 UDPv4 WRITE [54] to [AF_INET]xxx.xxx.xxx.xxx:19486: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 2503792974 744295339 2362207133 3932417275 1175066368 347 2673541889 0 2340162081 3233168704 0 ]
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 UDPv4 READ [50] from [AF_INET]xxx.xxx.xxx.xxx:19486: P_ACK_V1 kid=0 [ 2439222657 3947174177 3607643043 2932935924 453944832 603 2673423361 0 190982566 4008998444 ]
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 UDPv4 READ [202] from [AF_INET]xxx.xxx.xxx.xxx:19486: P_CONTROL_V1 kid=0 [ 3404903771 3086373890 2344889732 2533085915 3943456512 859 2673423360 1 369295616 2600534016 2533557131 3558546013 3814040631 2559149966 313261958 3759443051 1217632795 2511323043 4269485568 2932780 3224371359 3433680040 3433742379 32
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 TLS error: The server has no TLS ciphersuites in common with the client. Your --tls-cipher setting might be too restrictive.
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 OpenSSL: error:1408A0C1:SSL routines:ssl3_get_client_hello:no shared cipher
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 TLS_ERROR: BIO read tls_read_plaintext error
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 TLS Error: TLS object -> incoming plaintext read error
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 TLS Error: TLS handshake failed
Sep 17 09:35:06 vpn openvpn[675]: xxx.xxx.xxx.xxx:19486 SIGUSR1[soft,tls-error] received, client-instance restarting

[/oconf]

Hello !

Here is the Server log of two connection attempts.
As you can see, the Server receives the UDP-Packets.

Best regards,
Sebastian

TinCanTech

Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 TLS error: The server has no TLS ciphersuites in common with the client. Your --tls-cipher setting might be too restrictive.
Sep 17 09:34:01 vpn openvpn[675]: xxx.xxx.xxx.xxx:29671 OpenSSL: error:1408A0C1:SSL routines:ssl3_get_client_hello:no shared cipher

Are you still specifying --tls-cipher ?

TorroLoco

Hello !

No, the config files used for the attempt are specified in Post #8

Sebastian

TinCanTech

Did you restart server and client after changing the configs ?

I have noticed this behavior on rare occasions but it has generally been my mistake.
On very rare occasions (twice in fact) I have seen this and simply not been able to either explain it
or find a solution .. I resorted to restarting both server and client and the problem was resolved.

Unfortunately, I have not found a way to reliably reproduce the problem so I have attributed it
to be a mistake of my own ... :oops:

It could be that you are mixing versions of openvpn but I cannot give you a definitive answer to that either.

TorroLoco

Hi !

Both client and Server have been restarted after changing the config.
The mix is 2.4.0 on the Server and 2.4.6 on the Clients.
2.4.4 Clients do work with these configs with an 2.4.0 Server .

Is it a bug for the Support ?

Sebastian

TinCanTech

I think it is probably better to upgrade your server and client(s) to 2.4.6 (see the date)

There has been much development on 2.4 and many different SSL libraries have been used.

However, a well researched bug report is always welcome. :geek:

TorroLoco

This was exactly the first thing i wanted to do, but i am advised to just use the standard Debian 9 distro stable repos on the Server, there is just 2.4.0 avaiable (actual).
How would a well researched Bug report look like 🙂

TinCanTech

https://community.openvpn.net/openvpn/wiki/OpenvpnSoftwareRepos