Hello everyone,
I'm having issues with a VPN server I've deployed, but first, some context.
I'm running two OpenVPN servers on a single machine (on different ports obviously), their traffic are filtered according to some rules and redirected to each other.
The goal is to make a program running on a windows machine communicate with a small embedded linux device.
Embedded Linux device <--> OpenVPN Server 1 <--> Filtering <--> OpenVPN Server 2 <--> Windows Machine
Filtering between the two interfaces is a must have for security purposes, if one of the VPN profiles were to be compromised it should not have the ability to send unaunthorized traffic to the other end.
When connecting both clients to their respective servers, everything works like expected at first. But then, after a random amount of time, the connection is lost.
When looking into the logs on the server, I see this log printed over and over, starting at a time corresponding to the loss of connection:
2021-11-09 10:07:38 my-vpn-profile/XX.XXX.XXX.XXX:38622 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
2021-11-09 10:07:38 my-vpn-profile/XX.XXX.XXX.XXX:38622 TLS Error: TLS handshake failed
2021-11-09 10:08:53 my-vpn-profile/XX.XXX.XXX.XXX:38622 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
2021-11-09 10:08:53 my-vpn-profile/XX.XXX.XXX.XXX:38622 TLS Error: TLS handshake failed
...
I do not understand why the key negotiation fails when it was working before. I know that by default it is renegotiated every 3600 seconds, and I see in the logs that the key is renegotiate successfully before that.
This issue can happen with both instances of the VPN Server.
Here are the OpenVPN versions I am running:
- OpenVPN Servers: OpenVPN 2.5.1 x86_64-pc-linux-gnu
- Windows Client: OpenVPN Gui 11.14.0 with OpenVPN 2.5_git x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Jan 20 2020
- Embedded device client: OpenVPN 2.4.4 arm-buildroot-linux-gnueabihf [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Oct 19 2021
Here are my configuration files:
mode server
tls-server
local XXX.XXX.XXX.XXX
port XXXX
proto udp
dev tun0
askpass "/etc/openvpn/stdin-bve.txt"
# keys configuration, use generated keys
ca "/etc/openvpn/certs-bve/ca.crt"
cert "/etc/openvpn/certs-bve/bve.crt"
key "/etc/openvpn/certs-bve/bve.key"
dh "/etc/openvpn/certs-bve/dh.pem"
crl-verify "/etc/openvpn/easy-rsa-bve/pki/crl.pem"
tls-auth "/etc/openvpn/certs-bve/ta.key" 0
server 192.168.45.0 255.255.255.0
ifconfig-pool-persist ipp-bve.txt
push "route 192.168.45.0 255.255.255.0"
push "route 192.168.63.0 255.255.255.0"
client-to-client
keepalive 1800 4000
cipher CAMELLIA-256-CBC
comp-lzo yes
user nobody
group nobody
persist-key
persist-tun
status openvpn-status-bve.log
log-append /var/log/openvpn-bve.log
verb 5
mode server
tls-server
local XXX.XXX.XXX.XXX
port 14110
proto udp
dev tun1
askpass "/etc/openvpn/stdin-vp.txt"
# keys configuration, use generated keys
ca "/etc/openvpn/certs-vp/ca.crt"
cert "/etc/openvpn/certs-vp/vp.crt"
key "/etc/openvpn/certs-vp/vp.key"
dh "/etc/openvpn/certs-vp/dh.pem"
tls-auth "/etc/openvpn/certs-vp/ta.key" 0
crl-verify "/etc/openvpn/easy-rsa-vp/pki/crl.pem"
server 192.168.63.0 255.255.255.0
ifconfig-pool-persist ipp-vp.txt
client-to-client
keepalive 1800 4000
cipher DES-EDE3-CBC
comp-lzo yes
user nobody
group nobody
persist-key
persist-tun
status openvpn-status-vp.log
log-append /var/log/openvpn-vp.log
verb 5
Here are the associated VPN profiles:
client
auth-nocache
#remote-cert-tls server
#crl-verify /etc/openvpn/easy-rsa-bve/pki/crl.pem
dev tun0
proto udp
comp-lzo
resolv-retry infinite
windows-driver wintun
persist-key
persist-tun
remote XXX.XXX.XXX.XXX XXXX
<ca>
...
</ca>
<cert>
...
</cert>
<key>
...
</key>
<tls-auth>
...
</tls-auth>
key-direction 1
cipher CAMELLIA-256-CBC
route 192.168.45.0 255.255.255.0
route 192.168.63.0 255.255.255.0
# Set log file verbosity.
status openvpn-status.bve.log
log /var/log/openvpn.bve.log
log-append /var/log/openvpn.bve.log
verb 5
float
client
auth-nocache
#remote-cert-tls server
#crl-verify /etc/openvpn/easy-rsa-vp/pki/crl.pem
dev tun0
proto udp
comp-lzo
resolv-retry infinite
persist-key
persist-tun
remote XXX.XXX.XXX.XXX XXX
<ca>
...
</ca>
<cert>
...
</cert>
<key>
...
</key>
<tls-auth>
...
</tls-auth>
key-direction 1
cipher DES-EDE3-CBC
route 192.168.63.0 255.255.255.0
# Set log file verbosity.
status openvpn-status.vp.log
log /var/log/openvpn.vp.log
log-append /var/log/openvpn.vp.log
verb 5
float
Here are the logs of my windows client:
Tue Nov 09 18:14:06 2021 us=337172 Current Parameter Settings:
Tue Nov 09 18:14:06 2021 us=337172 config = 'BVE.ovpn'
Tue Nov 09 18:14:06 2021 us=337172 mode = 0
Tue Nov 09 18:14:06 2021 us=337172 show_ciphers = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 show_digests = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 show_engines = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 genkey = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 genkey_filename = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 key_pass_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 show_tls_ciphers = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 connect_retry_max = 0
Tue Nov 09 18:14:06 2021 us=337172 Connection profiles [0]:
Tue Nov 09 18:14:06 2021 us=337172 proto = udp
Tue Nov 09 18:14:06 2021 us=337172 local = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 local_port = '1194'
Tue Nov 09 18:14:06 2021 us=337172 remote = 'XXX.XXX.XXX.XXX'
Tue Nov 09 18:14:06 2021 us=337172 remote_port = 'XXXX'
Tue Nov 09 18:14:06 2021 us=337172 remote_float = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 bind_defined = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 bind_local = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 bind_ipv6_only = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 connect_retry_seconds = 5
Tue Nov 09 18:14:06 2021 us=337172 connect_timeout = 120
Tue Nov 09 18:14:06 2021 us=337172 socks_proxy_server = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 socks_proxy_port = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 tun_mtu = 1500
Tue Nov 09 18:14:06 2021 us=337172 tun_mtu_defined = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 link_mtu = 1500
Tue Nov 09 18:14:06 2021 us=337172 link_mtu_defined = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 tun_mtu_extra = 0
Tue Nov 09 18:14:06 2021 us=337172 tun_mtu_extra_defined = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 mtu_discover_type = -1
Tue Nov 09 18:14:06 2021 us=337172 fragment = 0
Tue Nov 09 18:14:06 2021 us=337172 mssfix = 1450
Tue Nov 09 18:14:06 2021 us=337172 explicit_exit_notification = 0
Tue Nov 09 18:14:06 2021 us=337172 tls_auth_file = '[[INLINE]]'
Tue Nov 09 18:14:06 2021 us=337172 key_direction = 1
Tue Nov 09 18:14:06 2021 us=337172 tls_crypt_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 tls_crypt_v2_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 Connection profiles END
Tue Nov 09 18:14:06 2021 us=337172 remote_random = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 ipchange = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 dev = 'tun0'
Tue Nov 09 18:14:06 2021 us=337172 dev_type = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 dev_node = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 lladdr = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 topology = 1
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_local = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_remote_netmask = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_noexec = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_nowarn = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_ipv6_local = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_ipv6_netbits = 0
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_ipv6_remote = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 shaper = 0
Tue Nov 09 18:14:06 2021 us=337172 mtu_test = 0
Tue Nov 09 18:14:06 2021 us=337172 mlock = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 keepalive_ping = 0
Tue Nov 09 18:14:06 2021 us=337172 keepalive_timeout = 0
Tue Nov 09 18:14:06 2021 us=337172 inactivity_timeout = 0
Tue Nov 09 18:14:06 2021 us=337172 ping_send_timeout = 0
Tue Nov 09 18:14:06 2021 us=337172 ping_rec_timeout = 0
Tue Nov 09 18:14:06 2021 us=337172 ping_rec_timeout_action = 0
Tue Nov 09 18:14:06 2021 us=337172 ping_timer_remote = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 remap_sigusr1 = 0
Tue Nov 09 18:14:06 2021 us=337172 persist_tun = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 persist_local_ip = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 persist_remote_ip = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 persist_key = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 passtos = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 resolve_retry_seconds = 1000000000
Tue Nov 09 18:14:06 2021 us=337172 resolve_in_advance = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 username = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 groupname = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 chroot_dir = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 cd_dir = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 writepid = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 up_script = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 down_script = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 down_pre = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 up_restart = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 up_delay = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 daemon = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 inetd = 0
Tue Nov 09 18:14:06 2021 us=337172 log = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 suppress_timestamps = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 machine_readable_output = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 nice = 0
Tue Nov 09 18:14:06 2021 us=337172 verbosity = 5
Tue Nov 09 18:14:06 2021 us=337172 mute = 0
Tue Nov 09 18:14:06 2021 us=337172 gremlin = 0
Tue Nov 09 18:14:06 2021 us=337172 status_file = 'openvpn-status.bve.log'
Tue Nov 09 18:14:06 2021 us=337172 status_file_version = 1
Tue Nov 09 18:14:06 2021 us=337172 status_file_update_freq = 60
Tue Nov 09 18:14:06 2021 us=337172 occ = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 rcvbuf = 0
Tue Nov 09 18:14:06 2021 us=337172 sndbuf = 0
Tue Nov 09 18:14:06 2021 us=337172 sockflags = 0
Tue Nov 09 18:14:06 2021 us=337172 fast_io = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 comp.alg = 2
Tue Nov 09 18:14:06 2021 us=337172 comp.flags = 1
Tue Nov 09 18:14:06 2021 us=337172 route_script = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 route_default_gateway = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 route_default_metric = 0
Tue Nov 09 18:14:06 2021 us=337172 route_noexec = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 route_delay = 0
Tue Nov 09 18:14:06 2021 us=337172 route_delay_window = 30
Tue Nov 09 18:14:06 2021 us=337172 route_delay_defined = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 route_nopull = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 route_gateway_via_dhcp = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 allow_pull_fqdn = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 Pull filters:
Tue Nov 09 18:14:06 2021 us=337172 ignore "route-method"
Tue Nov 09 18:14:06 2021 us=337172 route 192.168.63.0/255.255.255.0/default (not set)/default (not set)
Tue Nov 09 18:14:06 2021 us=337172 route 192.168.45.0/255.255.255.0/default (not set)/default (not set)
Tue Nov 09 18:14:06 2021 us=337172 management_addr = '127.0.0.1'
Tue Nov 09 18:14:06 2021 us=337172 management_port = '25341'
Tue Nov 09 18:14:06 2021 us=337172 management_user_pass = 'stdin'
Tue Nov 09 18:14:06 2021 us=337172 management_log_history_cache = 250
Tue Nov 09 18:14:06 2021 us=337172 management_echo_buffer_size = 100
Tue Nov 09 18:14:06 2021 us=337172 management_write_peer_info_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 management_client_user = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 management_client_group = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 management_flags = 6
Tue Nov 09 18:14:06 2021 us=337172 shared_secret_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 key_direction = 1
Tue Nov 09 18:14:06 2021 us=337172 ciphername = 'CAMELLIA-256-CBC'
Tue Nov 09 18:14:06 2021 us=337172 ncp_enabled = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 ncp_ciphers = 'AES-256-GCM:AES-128-GCM'
Tue Nov 09 18:14:06 2021 us=337172 authname = 'SHA1'
Tue Nov 09 18:14:06 2021 us=337172 prng_hash = 'SHA1'
Tue Nov 09 18:14:06 2021 us=337172 prng_nonce_secret_len = 16
Tue Nov 09 18:14:06 2021 us=337172 keysize = 0
Tue Nov 09 18:14:06 2021 us=337172 engine = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 replay = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 mute_replay_warnings = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 replay_window = 64
Tue Nov 09 18:14:06 2021 us=337172 replay_time = 15
Tue Nov 09 18:14:06 2021 us=337172 packet_id_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 test_crypto = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 tls_server = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 tls_client = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 key_method = 2
Tue Nov 09 18:14:06 2021 us=337172 ca_file = '[[INLINE]]'
Tue Nov 09 18:14:06 2021 us=337172 ca_path = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 dh_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 cert_file = '[[INLINE]]'
Tue Nov 09 18:14:06 2021 us=337172 extra_certs_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 priv_key_file = '[[INLINE]]'
Tue Nov 09 18:14:06 2021 us=337172 pkcs12_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 cryptoapi_cert = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 cipher_list = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 cipher_list_tls13 = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 tls_cert_profile = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 tls_verify = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 tls_export_cert = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 verify_x509_type = 0
Tue Nov 09 18:14:06 2021 us=337172 verify_x509_name = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 crl_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 ns_cert_type = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_ku[i] = 0
Tue Nov 09 18:14:06 2021 us=337172 remote_cert_eku = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 ssl_flags = 0
Tue Nov 09 18:14:06 2021 us=337172 tls_timeout = 2
Tue Nov 09 18:14:06 2021 us=337172 renegotiate_bytes = -1
Tue Nov 09 18:14:06 2021 us=337172 renegotiate_packets = 0
Tue Nov 09 18:14:06 2021 us=337172 renegotiate_seconds = 3600
Tue Nov 09 18:14:06 2021 us=337172 handshake_window = 60
Tue Nov 09 18:14:06 2021 us=337172 transition_window = 3600
Tue Nov 09 18:14:06 2021 us=337172 single_session = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 push_peer_info = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 tls_exit = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 tls_crypt_v2_metadata = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_protected_authentication = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_private_mode = 00000000
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_cert_private = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_pin_cache_period = -1
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_id = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 pkcs11_id_management = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 server_network = 0.0.0.0
Tue Nov 09 18:14:06 2021 us=337172 server_netmask = 0.0.0.0
Tue Nov 09 18:14:06 2021 us=337172 server_network_ipv6 = ::
Tue Nov 09 18:14:06 2021 us=337172 server_netbits_ipv6 = 0
Tue Nov 09 18:14:06 2021 us=337172 server_bridge_ip = 0.0.0.0
Tue Nov 09 18:14:06 2021 us=337172 server_bridge_netmask = 0.0.0.0
Tue Nov 09 18:14:06 2021 us=337172 server_bridge_pool_start = 0.0.0.0
Tue Nov 09 18:14:06 2021 us=337172 server_bridge_pool_end = 0.0.0.0
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_pool_defined = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_pool_start = 0.0.0.0
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_pool_end = 0.0.0.0
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_pool_netmask = 0.0.0.0
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_pool_persist_filename = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_pool_persist_refresh_freq = 600
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_ipv6_pool_defined = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_ipv6_pool_base = ::
Tue Nov 09 18:14:06 2021 us=337172 ifconfig_ipv6_pool_netbits = 0
Tue Nov 09 18:14:06 2021 us=337172 n_bcast_buf = 256
Tue Nov 09 18:14:06 2021 us=337172 tcp_queue_limit = 64
Tue Nov 09 18:14:06 2021 us=337172 real_hash_size = 256
Tue Nov 09 18:14:06 2021 us=337172 virtual_hash_size = 256
Tue Nov 09 18:14:06 2021 us=337172 client_connect_script = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 learn_address_script = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 client_disconnect_script = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 client_config_dir = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 ccd_exclusive = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 tmp_dir = 'C:\Users\aelkaim\AppData\Local\Temp\'
Tue Nov 09 18:14:06 2021 us=337172 push_ifconfig_defined = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 push_ifconfig_local = 0.0.0.0
Tue Nov 09 18:14:06 2021 us=337172 push_ifconfig_remote_netmask = 0.0.0.0
Tue Nov 09 18:14:06 2021 us=337172 push_ifconfig_ipv6_defined = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 push_ifconfig_ipv6_local = ::/0
Tue Nov 09 18:14:06 2021 us=337172 push_ifconfig_ipv6_remote = ::
Tue Nov 09 18:14:06 2021 us=337172 enable_c2c = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 duplicate_cn = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 cf_max = 0
Tue Nov 09 18:14:06 2021 us=337172 cf_per = 0
Tue Nov 09 18:14:06 2021 us=337172 max_clients = 1024
Tue Nov 09 18:14:06 2021 us=337172 max_routes_per_client = 256
Tue Nov 09 18:14:06 2021 us=337172 auth_user_pass_verify_script = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 auth_user_pass_verify_script_via_file = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 auth_token_generate = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 auth_token_lifetime = 0
Tue Nov 09 18:14:06 2021 us=337172 auth_token_secret_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 vlan_tagging = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 vlan_accept = all
Tue Nov 09 18:14:06 2021 us=337172 vlan_pvid = 1
Tue Nov 09 18:14:06 2021 us=337172 client = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 pull = ENABLED
Tue Nov 09 18:14:06 2021 us=337172 auth_user_pass_file = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 show_net_up = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 route_method = 3
Tue Nov 09 18:14:06 2021 us=337172 block_outside_dns = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 ip_win32_defined = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 ip_win32_type = 1
Tue Nov 09 18:14:06 2021 us=337172 dhcp_masq_offset = 0
Tue Nov 09 18:14:06 2021 us=337172 dhcp_lease_time = 31536000
Tue Nov 09 18:14:06 2021 us=337172 tap_sleep = 0
Tue Nov 09 18:14:06 2021 us=337172 dhcp_options = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 dhcp_renew = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 dhcp_pre_release = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 domain = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 netbios_scope = '[UNDEF]'
Tue Nov 09 18:14:06 2021 us=337172 netbios_node_type = 0
Tue Nov 09 18:14:06 2021 us=337172 disable_nbt = DISABLED
Tue Nov 09 18:14:06 2021 us=337172 OpenVPN 2.5_git x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Jan 20 2020
Tue Nov 09 18:14:06 2021 us=337172 Windows version 6.2 (Windows 8 or greater) 64bit
Tue Nov 09 18:14:06 2021 us=337172 library versions: OpenSSL 1.1.0l 10 Sep 2019, LZO 2.10
Enter Management Password:
Tue Nov 09 18:14:06 2021 us=337172 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25341
Tue Nov 09 18:14:06 2021 us=337172 Need hold release from management interface, waiting...
Tue Nov 09 18:14:06 2021 us=337172 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25341
Tue Nov 09 18:14:06 2021 us=468463 MANAGEMENT: CMD 'state on'
Tue Nov 09 18:14:06 2021 us=468463 MANAGEMENT: CMD 'log all on'
Tue Nov 09 18:14:06 2021 us=785049 MANAGEMENT: CMD 'echo all on'
Tue Nov 09 18:14:06 2021 us=800729 MANAGEMENT: CMD 'bytecount 5'
Tue Nov 09 18:14:06 2021 us=800729 MANAGEMENT: CMD 'hold off'
Tue Nov 09 18:14:06 2021 us=816317 MANAGEMENT: CMD 'hold release'
Tue Nov 09 18:14:06 2021 us=816317 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
Tue Nov 09 18:14:06 2021 us=838619 MANAGEMENT: CMD 'password [...]'
Tue Nov 09 18:14:06 2021 us=838619 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Nov 09 18:14:06 2021 us=838619 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Nov 09 18:14:06 2021 us=838619 LZO compression initializing
Tue Nov 09 18:14:06 2021 us=838619 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Tue Nov 09 18:14:06 2021 us=838619 MANAGEMENT: >STATE:1636478046,RESOLVE,,,,,,
Tue Nov 09 18:14:06 2021 us=854246 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Tue Nov 09 18:14:06 2021 us=854246 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher CAMELLIA-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Tue Nov 09 18:14:06 2021 us=854246 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher CAMELLIA-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Tue Nov 09 18:14:06 2021 us=854246 TCP/UDP: Preserving recently used remote address: [AF_INET]XX.XX.XXX.XX:XXXXX
Tue Nov 09 18:14:06 2021 us=854246 Socket Buffers: R=[65536->65536] S=[65536->65536]
Tue Nov 09 18:14:06 2021 us=854246 UDP link local (bound): [AF_INET][undef]:1194
Tue Nov 09 18:14:06 2021 us=854246 UDP link remote: [AF_INET]XX.XX.XXX.XX:XXXXX
Tue Nov 09 18:14:06 2021 us=854246 MANAGEMENT: >STATE:1636478046,WAIT,,,,,,
Tue Nov 09 18:14:06 2021 us=854246 MANAGEMENT: >STATE:1636478046,AUTH,,,,,,
Tue Nov 09 18:14:06 2021 us=854246 TLS: Initial packet from [AF_INET]XX.XX.XXX.XX:XXXXX, sid=436ebc70 94f3fc73
Tue Nov 09 18:14:06 2021 us=869838 VERIFY OK: depth=1, CN=ChangeMe
Tue Nov 09 18:14:06 2021 us=869838 VERIFY OK: depth=0, CN=my.domain.name
Tue Nov 09 18:14:06 2021 us=901119 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Tue Nov 09 18:14:06 2021 us=901119 [my.domain.name] Peer Connection Initiated with [AF_INET]XX.XX.XXX.XX:XXXXX
Tue Nov 09 18:14:07 2021 us=920355 MANAGEMENT: >STATE:1636478047,GET_CONFIG,,,,,,
Tue Nov 09 18:14:07 2021 us=920355 SENT CONTROL [my.domain.name]: 'PUSH_REQUEST' (status=1)
Tue Nov 09 18:14:07 2021 us=926928 PUSH: Received control message: 'PUSH_REPLY,route 192.168.45.0 255.255.255.0,route 192.168.63.0 255.255.255.0,route 192.168.45.0 255.255.255.0,topology net30,ping 1800,ping-restart 4000,ifconfig 192.168.45.10 192.168.45.9,peer-id 0,cipher AES-256-GCM'
Tue Nov 09 18:14:07 2021 us=926928 OPTIONS IMPORT: timers and/or timeouts modified
Tue Nov 09 18:14:07 2021 us=926928 OPTIONS IMPORT: --ifconfig/up options modified
Tue Nov 09 18:14:07 2021 us=926928 OPTIONS IMPORT: route options modified
Tue Nov 09 18:14:07 2021 us=926928 OPTIONS IMPORT: peer-id set
Tue Nov 09 18:14:07 2021 us=926928 OPTIONS IMPORT: adjusting link_mtu to 1625
Tue Nov 09 18:14:07 2021 us=926928 OPTIONS IMPORT: data channel crypto options modified
Tue Nov 09 18:14:07 2021 us=926928 Data Channel: using negotiated cipher 'AES-256-GCM'
Tue Nov 09 18:14:07 2021 us=926928 Data Channel MTU parms [ L:1553 D:1450 EF:53 EB:406 ET:0 EL:3 ]
Tue Nov 09 18:14:07 2021 us=926928 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 18:14:07 2021 us=926928 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 18:14:07 2021 us=926928 interactive service msg_channel=460
Tue Nov 09 18:14:07 2021 us=926928 ROUTE_GATEWAY 192.168.204.2/255.255.255.0 I=4 HWADDR=00:0c:29:e8:4b:ce
Tue Nov 09 18:14:07 2021 us=926928 open_tun
Tue Nov 09 18:14:07 2021 us=926928 Ring buffers registered via service
Tue Nov 09 18:14:07 2021 us=926928 wintun device [Connexion au réseau local 2] opened
Tue Nov 09 18:14:07 2021 us=926928 do_ifconfig, ipv4=1, ipv6=0
Tue Nov 09 18:14:07 2021 us=926928 MANAGEMENT: >STATE:1636478047,ASSIGN_IP,,192.168.45.10,,,,
Tue Nov 09 18:14:07 2021 us=926928 MANAGEMENT: >STATE:1636478047,ADD_ROUTES,,,,,,
Tue Nov 09 18:14:07 2021 us=926928 C:\Windows\system32\route.exe ADD 192.168.45.0 MASK 255.255.255.0 192.168.45.9
Tue Nov 09 18:14:07 2021 us=942584 Route addition via service succeeded
Tue Nov 09 18:14:07 2021 us=942584 C:\Windows\system32\route.exe ADD 192.168.63.0 MASK 255.255.255.0 192.168.45.9
Tue Nov 09 18:14:07 2021 us=958211 Route addition via service succeeded
Tue Nov 09 18:14:07 2021 us=958211 C:\Windows\system32\route.exe ADD 192.168.45.0 MASK 255.255.255.0 192.168.45.9
Tue Nov 09 18:14:07 2021 us=958211 ROUTE: route addition failed using service: L�objet existe d�j�. [status=5010 if_index=12]
Tue Nov 09 18:14:07 2021 us=958211 Route addition via service failed
Tue Nov 09 18:14:07 2021 us=958211 C:\Windows\system32\route.exe ADD 192.168.63.0 MASK 255.255.255.0 192.168.45.9
Tue Nov 09 18:14:07 2021 us=958211 ROUTE: route addition failed using service: L�objet existe d�j�. [status=5010 if_index=12]
Tue Nov 09 18:14:07 2021 us=958211 Route addition via service failed
Tue Nov 09 18:14:07 2021 us=958211 C:\Windows\system32\route.exe ADD 192.168.45.0 MASK 255.255.255.0 192.168.45.9
Tue Nov 09 18:14:07 2021 us=958211 ROUTE: route addition failed using service: L�objet existe d�j�. [status=5010 if_index=12]
Tue Nov 09 18:14:07 2021 us=958211 Route addition via service failed
Tue Nov 09 18:14:07 2021 us=958211 Initialization Sequence Completed
Tue Nov 09 18:14:07 2021 us=958211 MANAGEMENT: >STATE:1636478047,CONNECTED,SUCCESS,192.168.45.10,XX.XX.XXX.XX,XXXXX,,
Tue Nov 09 19:08:55 2021 us=44367 VERIFY OK: depth=1, CN=ChangeMe
Tue Nov 09 19:08:55 2021 us=44367 VERIFY OK: depth=0, CN=my.domain.name
Tue Nov 09 19:08:55 2021 us=91492 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 19:08:55 2021 us=91492 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 19:08:55 2021 us=91492 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Tue Nov 09 20:03:57 2021 us=445104 VERIFY OK: depth=1, CN=ChangeMe
Tue Nov 09 20:03:57 2021 us=445104 VERIFY OK: depth=0, CN=my.domain.name
Tue Nov 09 20:03:57 2021 us=491970 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 20:03:57 2021 us=491970 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 20:03:57 2021 us=491970 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Tue Nov 09 20:58:58 2021 us=38810 VERIFY OK: depth=1, CN=ChangeMe
Tue Nov 09 20:58:58 2021 us=38810 VERIFY OK: depth=0, CN=my.domain.name
Tue Nov 09 20:58:58 2021 us=65616 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 20:58:58 2021 us=65616 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 20:58:58 2021 us=65616 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Tue Nov 09 21:54:00 2021 us=248263 VERIFY OK: depth=1, CN=ChangeMe
Tue Nov 09 21:54:00 2021 us=248263 VERIFY OK: depth=0, CN=my.domain.name
Tue Nov 09 21:54:00 2021 us=279574 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 21:54:00 2021 us=279574 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 21:54:00 2021 us=279574 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Tue Nov 09 22:49:02 2021 us=48022 VERIFY OK: depth=1, CN=ChangeMe
Tue Nov 09 22:49:02 2021 us=48022 VERIFY OK: depth=0, CN=my.domain.name
Tue Nov 09 22:49:02 2021 us=66307 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 22:49:02 2021 us=66307 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 22:49:02 2021 us=66307 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Tue Nov 09 23:43:56 2021 us=164211 VERIFY OK: depth=1, CN=ChangeMe
Tue Nov 09 23:43:56 2021 us=164211 VERIFY OK: depth=0, CN=my.domain.name
Tue Nov 09 23:43:56 2021 us=208088 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 23:43:56 2021 us=208088 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Nov 09 23:43:56 2021 us=208088 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed Nov 10 00:38:58 2021 us=43412 VERIFY OK: depth=1, CN=ChangeMe
Wed Nov 10 00:38:58 2021 us=43412 VERIFY OK: depth=0, CN=my.domain.name
Wed Nov 10 00:38:58 2021 us=74403 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Nov 10 00:38:58 2021 us=74403 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Nov 10 00:38:58 2021 us=74403 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed Nov 10 01:35:00 2021 us=172484 TLS: new session incoming connection from [AF_INET]XX.XX.XXX.XX:XXXXX
Wed Nov 10 01:35:00 2021 us=172484 MANAGEMENT: >STATE:1636504500,WAIT,,,,,,
Wed Nov 10 01:35:00 2021 us=203714 VERIFY OK: depth=1, CN=ChangeMe
Wed Nov 10 01:35:00 2021 us=203714 VERIFY OK: depth=0, CN=my.domain.name
Wed Nov 10 01:35:00 2021 us=226197 TLS: move_session: dest=TM_ACTIVE src=TM_UNTRUSTED reinit_src=1
Wed Nov 10 01:35:00 2021 us=226197 TLS: tls_multi_process: untrusted session promoted to semi-trusted
Wed Nov 10 01:35:00 2021 us=226197 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed Nov 10 02:35:00 2021 us=511133 TLS: soft reset sec=3600/3600 bytes=0/-1 pkts=0/0
Wed Nov 10 02:36:00 2021 us=286952 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Wed Nov 10 02:36:00 2021 us=286952 TLS Error: TLS handshake failed
Wed Nov 10 02:36:00 2021 us=286952 TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Wed Nov 10 02:36:15 2021 us=467552 MANAGEMENT: >STATE:1636508175,WAIT,,,,,,
Wed Nov 10 02:36:15 2021 us=474315 MANAGEMENT: >STATE:1636508175,AUTH,,,,,,
Wed Nov 10 02:36:15 2021 us=474315 TLS: Initial packet from [AF_INET]XX.XX.XXX.XX:XXXXX, sid=d1ea249a 6d12bc40
Wed Nov 10 02:36:15 2021 us=505700 VERIFY OK: depth=1, CN=ChangeMe
Wed Nov 10 02:36:15 2021 us=505700 VERIFY OK: depth=0, CN=my.domain.name
Wed Nov 10 02:36:15 2021 us=536970 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed Nov 10 03:35:00 2021 us=211602 TLS: tls_multi_process: killed expiring key
Wed Nov 10 03:36:15 2021 us=711825 TLS: soft reset sec=3600/3600 bytes=0/-1 pkts=0/0
Wed Nov 10 03:37:16 2021 us=119431 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Wed Nov 10 03:37:16 2021 us=119431 TLS Error: TLS handshake failed
Wed Nov 10 03:37:16 2021 us=119431 TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Wed Nov 10 03:37:31 2021 us=275299 MANAGEMENT: >STATE:1636511851,WAIT,,,,,,
Wed Nov 10 03:37:31 2021 us=275299 MANAGEMENT: >STATE:1636511851,AUTH,,,,,,
Wed Nov 10 03:37:31 2021 us=275299 TLS: Initial packet from [AF_INET]XX.XX.XXX.XX:XXXXX, sid=552e2831 388bfcb4
Wed Nov 10 03:37:31 2021 us=321819 VERIFY OK: depth=1, CN=ChangeMe
Wed Nov 10 03:37:31 2021 us=321819 VERIFY OK: depth=0, CN=my.domain.name
Wed Nov 10 03:37:31 2021 us=344045 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed Nov 10 04:36:15 2021 us=653577 TLS: tls_multi_process: killed expiring key
Wed Nov 10 04:37:31 2021 us=681046 TLS: soft reset sec=3600/3600 bytes=0/-1 pkts=0/0
Wed Nov 10 04:38:02 2021 us=776961 read UDP: Unknown error (code=10054)
Wed Nov 10 04:38:31 2021 us=330876 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Wed Nov 10 04:38:31 2021 us=330876 TLS Error: TLS handshake failed
Wed Nov 10 04:38:31 2021 us=330876 TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Wed Nov 10 04:38:46 2021 us=419685 MANAGEMENT: >STATE:1636515526,WAIT,,,,,,
Wed Nov 10 04:38:46 2021 us=425903 read UDP: Unknown error (code=10054)
Wed Nov 10 04:38:48 2021 us=450446 MANAGEMENT: >STATE:1636515528,AUTH,,,,,,
Wed Nov 10 04:38:48 2021 us=450446 TLS: Initial packet from [AF_INET]XX.XX.XXX.XX:XXXXX, sid=428579da 50e36d1e
Wed Nov 10 04:38:48 2021 us=466078 VERIFY OK: depth=1, CN=ChangeMe
Wed Nov 10 04:38:48 2021 us=466078 VERIFY OK: depth=0, CN=my.domain.name
Wed Nov 10 04:38:48 2021 us=528350 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed Nov 10 05:37:31 2021 us=632245 TLS: tls_multi_process: killed expiring key
Wed Nov 10 05:38:48 2021 us=692027 TLS: soft reset sec=3600/3600 bytes=0/-1 pkts=0/0
Wed Nov 10 05:39:48 2021 us=633177 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Wed Nov 10 05:39:48 2021 us=633177 TLS Error: TLS handshake failed
Wed Nov 10 05:39:48 2021 us=633177 TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Wed Nov 10 05:40:03 2021 us=861131 MANAGEMENT: >STATE:1636519203,WAIT,,,,,,
Wed Nov 10 05:40:03 2021 us=867319 MANAGEMENT: >STATE:1636519203,AUTH,,,,,,
Wed Nov 10 05:40:03 2021 us=867319 TLS: Initial packet from [AF_INET]XX.XX.XXX.XX:XXXXX, sid=8e668cb1 907d9e07
Wed Nov 10 05:40:03 2021 us=883290 VERIFY OK: depth=1, CN=ChangeMe
Wed Nov 10 05:40:03 2021 us=883290 VERIFY OK: depth=0, CN=my.domain.name
Wed Nov 10 05:40:03 2021 us=898703 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed Nov 10 06:38:48 2021 us=909772 TLS: tls_multi_process: killed expiring key
Wed Nov 10 06:40:03 2021 us=908984 TLS: soft reset sec=3600/3600 bytes=0/-1 pkts=0/0
Wed Nov 10 06:41:03 2021 us=648839 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Wed Nov 10 06:41:03 2021 us=648839 TLS Error: TLS handshake failed
Wed Nov 10 06:41:03 2021 us=648839 TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Wed Nov 10 06:41:18 2021 us=561453 MANAGEMENT: >STATE:1636522878,WAIT,,,,,,
Wed Nov 10 06:41:18 2021 us=561453 read UDP: Unknown error (code=10054)
Wed Nov 10 06:41:20 2021 us=639502 read UDP: Unknown error (code=10054)
Wed Nov 10 06:41:24 2021 us=723886 read UDP: Unknown error (code=10054)
Wed Nov 10 06:41:32 2021 us=802122 read UDP: Unknown error (code=10054)
Wed Nov 10 06:41:48 2021 us=868590 read UDP: Unknown error (code=10054)
Wed Nov 10 06:42:18 2021 us=114319 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Wed Nov 10 06:42:18 2021 us=114319 TLS Error: TLS handshake failed
Wed Nov 10 06:42:33 2021 us=309636 MANAGEMENT: >STATE:1636522953,WAIT,,,,,,
Wed Nov 10 06:42:33 2021 us=320261 MANAGEMENT: >STATE:1636522953,AUTH,,,,,,
Wed Nov 10 06:42:33 2021 us=320261 TLS: Initial packet from [AF_INET]XX.XX.XXX.XX:XXXXX, sid=76e0e8f6 2073b1d1
Wed Nov 10 06:42:33 2021 us=330452 VERIFY OK: depth=1, CN=ChangeMe
Wed Nov 10 06:42:33 2021 us=330452 VERIFY OK: depth=0, CN=my.domain.name
Wed Nov 10 06:42:33 2021 us=377128 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed Nov 10 07:40:03 2021 us=103915 TLS: tls_multi_process: killed expiring key
Wed Nov 10 07:42:33 2021 us=486915 TLS: soft reset sec=3600/3600 bytes=0/-1 pkts=0/0
Wed Nov 10 07:43:33 2021 us=469555 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Wed Nov 10 07:43:33 2021 us=469555 TLS Error: TLS handshake failed
Wed Nov 10 07:43:33 2021 us=469555 TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Wed Nov 10 07:43:48 2021 us=928100 MANAGEMENT: >STATE:1636526628,WAIT,,,,,,
Wed Nov 10 07:43:48 2021 us=928100 MANAGEMENT: >STATE:1636526628,AUTH,,,,,,
Wed Nov 10 07:43:48 2021 us=928100 TLS: Initial packet from [AF_INET]XX.XX.XXX.XX:XXXXX, sid=eccc596f b1730150
Wed Nov 10 07:43:48 2021 us=943894 VERIFY OK: depth=1, CN=ChangeMe
Wed Nov 10 07:43:48 2021 us=943894 VERIFY OK: depth=0, CN=my.domain.name
Wed Nov 10 07:43:48 2021 us=959566 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed Nov 10 08:42:34 2021 us=14236 TLS: tls_multi_process: killed expiring key
Wed Nov 10 08:43:48 2021 us=269905 TLS: soft reset sec=3600/3600 bytes=0/-1 pkts=0/0
Wed Nov 10 08:44:48 2021 us=467434 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Wed Nov 10 08:44:48 2021 us=467434 TLS Error: TLS handshake failed
Wed Nov 10 08:44:48 2021 us=467434 TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Wed Nov 10 08:45:03 2021 us=652642 MANAGEMENT: >STATE:1636530303,WAIT,,,,,,
Wed Nov 10 08:45:03 2021 us=652642 MANAGEMENT: >STATE:1636530303,AUTH,,,,,,
Wed Nov 10 08:45:03 2021 us=652642 TLS: Initial packet from [AF_INET]XX.XX.XXX.XX:XXXXX, sid=02526e09 2b15713b
Wed Nov 10 08:45:03 2021 us=683788 VERIFY OK: depth=1, CN=ChangeMe
Wed Nov 10 08:45:03 2021 us=683788 VERIFY OK: depth=0, CN=my.domain.name
Wed Nov 10 08:45:03 2021 us=699403 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed Nov 10 08:45:21 2021 us=196374 Key [AF_INET]XX.XX.XXX.XX:XXXXX [0] not initialized (yet), dropping packet.
Wed Nov 10 08:45:21 2021 us=211528 Key [AF_INET]XX.XX.XXX.XX:XXXXX [0] not initialized (yet), dropping packet.
Wed Nov 10 08:45:21 2021 us=211528 Key [AF_INET]XX.XX.XXX.XX:XXXXX [0] not initialized (yet), dropping packet.
Wed Nov 10 08:45:21 2021 us=610297 Key [AF_INET]XX.XX.XXX.XX:XXXXX [0] not initialized (yet), dropping packet.
Wed Nov 10 08:45:22 2021 us=200436 Key [AF_INET]XX.XX.XXX.XX:XXXXX [0] not initialized (yet), dropping packet.
Wed Nov 10 08:45:22 2021 us=211973 Key [AF_INET]XX.XX.XXX.XX:XXXXX [0] not initialized (yet), dropping packet.
Wed Nov 10 09:43:48 2021 us=177475 TLS: tls_multi_process: killed expiring key
Wed Nov 10 09:45:03 2021 us=416137 TLS: soft reset sec=3600/3600 bytes=0/-1 pkts=0/0
Wed Nov 10 09:46:03 2021 us=515238 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Wed Nov 10 09:46:03 2021 us=515238 TLS Error: TLS handshake failed
Wed Nov 10 09:46:03 2021 us=515238 TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Wed Nov 10 09:46:18 2021 us=486819 MANAGEMENT: >STATE:1636533978,WAIT,,,,,,
Wed Nov 10 09:46:18 2021 us=486819 MANAGEMENT: >STATE:1636533978,AUTH,,,,,,
Wed Nov 10 09:46:18 2021 us=486819 TLS: Initial packet from [AF_INET]XX.XX.XXX.XX:XXXXX, sid=c192b6ab 9aff4c3c
Wed Nov 10 09:46:18 2021 us=502394 VERIFY OK: depth=1, CN=ChangeMe
Wed Nov 10 09:46:18 2021 us=502394 VERIFY OK: depth=0, CN=my.domain.name
Wed Nov 10 09:46:18 2021 us=533663 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
For the server logs, I tried setting the verbosity to the max so I cannot post it here, but here is a log file with the exact same issue, just not taken at the same time as the other log (see next post)
What even weirder, is that this issue sometimes happen even though the client has disconnected, it seems like the server is trying to validate the TLS key even with the client being disconnected.
I really don't know where to look to solve this issue and would appreciate any help.
Thank you very much for your answers.
