TLS Error: local/remote TLS keys are out of sync
-
Hi,
I'm getting the follow error in the OpenVPN process logs on my pfSense router after connecting to it via an OpenVPN tunnel:
Dec 16 17:52:53 openvpn 25336 <PUBLIC_IPV4>:38367 peer info: IV_VER=3.git::58b92569 Dec 16 17:52:53 openvpn 25336 <PUBLIC_IPV4>:38367 peer info: IV_PLAT=ios Dec 16 17:52:53 openvpn 25336 <PUBLIC_IPV4>:38367 peer info: IV_NCP=2 Dec 16 17:52:53 openvpn 25336 <PUBLIC_IPV4>:38367 peer info: IV_TCPNL=1 Dec 16 17:52:53 openvpn 25336 <PUBLIC_IPV4>:38367 peer info: IV_PROTO=2 Dec 16 17:52:53 openvpn 25336 <PUBLIC_IPV4>:38367 peer info: IV_GUI_VER=net.openvpn.connect.ios_3.2.3-3760 Dec 16 17:52:53 openvpn 25336 <PUBLIC_IPV4>:38367 peer info: IV_SSO=openurl Dec 16 17:52:53 openvpn 25336 <PUBLIC_IPV4>:38367 peer info: IV_BS64DL=1 Dec 16 17:52:53 openvpn 25336 <PUBLIC_IPV4>:38367 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1557', remote='link-mtu 1541' Dec 16 17:52:53 openvpn 25336 <PUBLIC_IPV4>:38367 [james.pedersen] Peer Connection Initiated with [AF_INET]<PUBLIC_IPV4>:38367 Dec 16 17:52:53 openvpn 37435 user 'james.pedersen' authenticated Dec 16 17:52:53 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 MULTI_sva: pool returned IPv4=172.<REDACTED>, IPv6=(Not enabled) Dec 16 17:54:33 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_VER=3.git::58b92569 Dec 16 17:54:33 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_PLAT=ios Dec 16 17:54:33 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_NCP=2 Dec 16 17:54:33 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_TCPNL=1 Dec 16 17:54:33 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_PROTO=2 Dec 16 17:54:33 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_GUI_VER=net.openvpn.connect.ios_3.2.3-3760 Dec 16 17:54:33 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_SSO=openurl Dec 16 17:54:33 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1557', remote='link-mtu 1541' Dec 16 17:54:34 openvpn 92659 user 'james.pedersen' could not authenticate. Dec 16 17:55:25 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 TLS Error: local/remote TLS keys are out of sync: [AF_INET]<PUBLIC_IPV4>38367 [1] Dec 16 17:55:36 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 TLS Error: local/remote TLS keys are out of sync: [AF_INET]<PUBLIC_IPV4>:38367 [1] Dec 16 17:55:46 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 TLS Error: local/remote TLS keys are out of sync: [AF_INET]<PUBLIC_IPV4>:38367 [1] Dec 16 17:55:57 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 TLS Error: local/remote TLS keys are out of sync: [AF_INET]<PUBLIC_IPV4>:38367 [1] Dec 16 17:56:07 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 TLS Error: local/remote TLS keys are out of sync: [AF_INET]<PUBLIC_IPV4>:38367 [1] Dec 16 17:56:13 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_VER=3.git::58b92569 Dec 16 17:56:13 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_PLAT=ios Dec 16 17:56:13 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_NCP=2 Dec 16 17:56:13 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_TCPNL=1 Dec 16 17:56:13 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_PROTO=2 Dec 16 17:56:13 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_GUI_VER=net.openvpn.connect.ios_3.2.3-3760 Dec 16 17:56:13 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 peer info: IV_SSO=openurl Dec 16 17:56:13 openvpn 25336 james.pedersen/<PUBLIC_IPV4>:38367 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1557', remote='link-mtu 1541' Dec 16 17:56:15 openvpn 15853 user 'james.pedersen' could not authenticate. Dec 16 17:57:16 openvpn 25336 <PUBLIC_IPV4>:28203 peer info: IV_VER=3.git::58b92569 Dec 16 17:57:16 openvpn 25336 <PUBLIC_IPV4>:28203 peer info: IV_PLAT=ios Dec 16 17:57:16 openvpn 25336 <PUBLIC_IPV4>:28203 peer info: IV_NCP=2 Dec 16 17:57:16 openvpn 25336 <PUBLIC_IPV4>:28203 peer info: IV_TCPNL=1 Dec 16 17:57:16 openvpn 25336 <PUBLIC_IPV4>:28203 peer info: IV_PROTO=2 Dec 16 17:57:16 openvpn 25336 <PUBLIC_IPV4>:28203 peer info: IV_GUI_VER=net.openvpn.connect.ios_3.2.3-3760 Dec 16 17:57:16 openvpn 25336 <PUBLIC_IPV4>:28203 peer info: IV_SSO=openurl Dec 16 17:57:16 openvpn 25336 <PUBLIC_IPV4>:28203 peer info: IV_BS64DL=1 Dec 16 17:57:16 openvpn 25336 <PUBLIC_IPV4>:28203 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1557', remote='link-mtu 1541' Dec 16 17:57:16 openvpn 25336 <PUBLIC_IPV4>:28203 [james.pedersen] Peer Connection Initiated with [AF_INET]<PUBLIC_IPV4>:28203 Dec 16 17:57:18 openvpn 17457 user 'james.pedersen' could not authenticate.
My OpenVPN client has been configured to use
reneg-sec 100
. I am able to successfully authenticate into and connect to the router via an OpenVPN tunnel. But after around 100 seconds, I start getting the error messages in the OpenVPN logs, and shortly after that I get a "User authentication failed" message in the client and am disconnected from the VPN.Here's my full client configuration:
persist-tun persist-key data-ciphers AES-256-GCM:AES-128-GCM:AES-128-CBC data-ciphers-fallback AES-128-CBC auth SHA1 tls-client client remote <PUBLIC_IPV4_REDACTED> 1194 udp4 verify-x509-name "router.acme.com" name auth-user-pass remote-cert-tls server explicit-exit-notify pull-filter ignore "NTP 10.1.0.1" pull-filter ignore "dhcp-option NTP 10.1.0.1" pull-filter ignore "DNS 10.1.0.1" pull-filter ignore "dhcp-option DNS 10.1.0.1" DNS 8.8.8.8 NTP 0.pfsense.pool.ntp.org NTP 1.pfsense.pool.ntp.org reneg-sec 100 tls-cipher "TLS_DH_RSA_WITH_AES_256_CBC_SHA" <ca> -----BEGIN CERTIFICATE----- REDACTED -----END CERTIFICATE----- </ca> <cert> -----BEGIN CERTIFICATE----- REDACTED -----END CERTIFICATE----- </cert> <key> -----BEGIN PRIVATE KEY----- REDACTED -----END PRIVATE KEY----- </key> key-direction 1 <tls-auth> # # 2048 bit OpenVPN static key # -----BEGIN OpenVPN Static key V1----- REDACTED -----END OpenVPN Static key V1----- </tls-auth>
Here's my OpenVPN server configuration:
dev ovpns1 verb 1 dev-type tun dev-node /dev/tun1 writepid /var/run/openvpn_server1.pid #user nobody #group nobody script-security 3 daemon keepalive 10 60 ping-timer-rem persist-tun persist-key proto udp4 auth SHA1 up /usr/local/sbin/ovpn-linkup down /usr/local/sbin/ovpn-linkdown client-connect /usr/local/sbin/openvpn.attributes.sh client-disconnect /usr/local/sbin/openvpn.attributes.sh learn-address "/usr/local/sbin/openvpn.learn-address.sh acme.com" local <PUBLIC_IPV4_REDACTED> tls-server server 172.<REDACTED> 255.255.255.0 client-config-dir /var/etc/openvpn/server1/csc username-as-common-name plugin /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so /usr/local/sbin/ovpn_auth_verify_async user <REDACTED> false server1 1194 tls-verify "/usr/local/sbin/ovpn_auth_verify tls 'router.acme.com' 1" lport 1194 management /var/etc/openvpn/server1/sock unix push "route 10.0.0.0 255.255.0.0" <REDACTED_PUSH_ROUTE_DIRECTIVES> push "dhcp-option DOMAIN acme.com" push "dhcp-option DNS 10.1.0.1" push "dhcp-option NTP 10.1.0.1" duplicate-cn capath /var/etc/openvpn/server1/ca cert /var/etc/openvpn/server1/cert key /var/etc/openvpn/server1/key dh /etc/dh-parameters.1024 tls-auth /var/etc/openvpn/server1/tls-auth 0 data-ciphers AES-256-GCM:AES-128-GCM:AES-128-CBC:AES-256-CBC data-ciphers-fallback AES-128-CBC allow-compression asym persist-remote-ip float topology net30
Here are the logs from my OpenVPN client:
021-12-16 17:52:52 1 2021-12-16 17:52:52 ----- OpenVPN Start ----- OpenVPN core 3.git::58b92569 ios arm64 64-bit 2021-12-16 17:52:52 OpenVPN core 3.git::58b92569 ios arm64 64-bit 2021-12-16 17:52:52 Frame=512/2048/512 mssfix-ctrl=1250 2021-12-16 17:52:52 UNUSED OPTIONS 0 [persist-tun] 1 [persist-key] 2 [data-ciphers] [AES-256-GCM:AES-128-GCM:AES-128-CBC] 3 [data-ciphers-fallback] [AES-128-CBC] 5 [tls-client] 8 [verify-x509-name] [router.acme.com] [name] 11 [explicit-exit-notify] 12 [pull-filter] [ignore] [NTP 10.1.0.1] 13 [pull-filter] [ignore] [dhcp-option NTP 10.1.0.1] 14 [pull-filter] [ignore] [DNS 10.1.0.1] 15 [pull-filter] [ignore] [dhcp-option DNS 10.1.0.1] 16 [DNS] [8.8.8.8] 17 [NTP] [0.pfsense.pool.ntp.org] 18 [NTP] [1.pfsense.pool.ntp.org] 20 [tls-cipher] [TLS_DH_RSA_WITH_AES_256_CBC_SHA] 2021-12-16 17:52:52 EVENT: RESOLVE 2021-12-16 17:52:52 Contacting [<REDACTED_IPV6>]:1194/UDP via UDP 2021-12-16 17:52:52 EVENT: WAIT 2021-12-16 17:52:52 Connecting to [<REDACTED_IPV4>]:1194 (<REDACTED_IPV6>) via UDPv6 2021-12-16 17:52:52 EVENT: CONNECTING 2021-12-16 17:52:52 Tunnel Options:V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,keydir 1,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-client 2021-12-16 17:52:52 Creds: Username/Password 2021-12-16 17:52:52 Peer Info: IV_VER=3.git::58b92569 IV_PLAT=ios IV_NCP=2 IV_TCPNL=1 IV_PROTO=2 IV_GUI_VER=net.openvpn.connect.ios_3.2.3-3760 IV_SSO=openurl IV_BS64DL=1 2021-12-16 17:52:52 VERIFY OK: depth=1, /C=US/ST=California/L=San Bruno/O=Acme, Inc/emailAddress=<REDACTED>@acme.com/CN=internal-ca 2021-12-16 17:52:52 VERIFY OK: depth=0, /C=US/ST=California/L=San Bruno/O=Acme\, Inc/emailAddress=<REDACTED>@acme.com/CN=router.acme.com 2021-12-16 17:52:53 SSL Handshake: CN=router.acme.com, TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA 2021-12-16 17:52:53 Session is ACTIVE 2021-12-16 17:52:53 EVENT: GET_CONFIG 2021-12-16 17:52:53 Sending PUSH_REQUEST to server... 2021-12-16 17:52:53 OPTIONS: 0 [route] [10.0.0.0] [255.255.0.0] <REDACTED_INFO_ABOUT_ROUTES> 15 [dhcp-option] [DOMAIN] [acme.com] 16 [dhcp-option] [DNS] [10.1.0.1] 17 [dhcp-option] [NTP] [10.1.0.1] 18 [<REDACTED_ROUTE_INFO>] 19 [topology] [net30] 20 [ping] [10] 21 [ping-restart] [60] 22 [<REDACTED_IFCONFIG_INFO>] 23 [peer-id] [0] 24 [cipher] [AES-256-GCM] 2021-12-16 17:52:53 PROTOCOL OPTIONS: cipher: AES-256-GCM digest: NONE compress: NONE peer ID: 0 2021-12-16 17:52:53 EVENT: ASSIGN_IP 2021-12-16 17:52:53 NIP: preparing TUN network settings 2021-12-16 17:52:53 NIP: init TUN network settings with endpoint: <REDACTED_IPV6> <REDACTED_ROUTE_INFO> 2021-12-16 17:52:53 NIP: adding (included) IPv4 route 10.0.0.0/16 <REDACTED_INFO_ABOUT_ROUTES> 2021-12-16 17:52:53 NIP: adding match domain acme.com 2021-12-16 17:52:53 NIP: adding DNS 10.1.0.1 2021-12-16 17:52:53 NIP: adding DNS specific routes: <REDACTED_ROUTE_INFO> 2021-12-16 17:52:53 Connected via NetworkExtensionTUN 2021-12-16 17:52:53 EVENT: CONNECTED james.pedersen@<REDACTED_IPV4>:1194 (<REDACTED_IPV6>) via /UDPv6 on NetworkExtensionTUN/<REDACTED_IP_ADDR>/ gw=[/] 2021-12-16 17:54:33 Tunnel Options:V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,keydir 1,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-client 2021-12-16 17:54:33 Creds: Username/Password 2021-12-16 17:54:33 Peer Info: IV_VER=3.git::58b92569 IV_PLAT=ios IV_NCP=2 IV_TCPNL=1 IV_PROTO=2 IV_GUI_VER=net.openvpn.connect.ios_3.2.3-3760 IV_SSO=openurl 2021-12-16 17:54:33 VERIFY OK: depth=1, /C=US/ST=California/L=San Bruno/O=Acme, Inc/emailAddress=<REDACTED>@acme.com/CN=internal-ca 2021-12-16 17:54:33 VERIFY OK: depth=0, /C=US/ST=California/L=San Bruno/O=Acme\, Inc/emailAddress=<REDACTED>@acme.com/CN=router.acme.com 2021-12-16 17:54:33 SSL Handshake: CN=router.acme.com, TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA 2021-12-16 17:56:13 Tunnel Options:V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,keydir 1,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-client 2021-12-16 17:56:13 Creds: Username/Password 2021-12-16 17:56:13 Peer Info: IV_VER=3.git::58b92569 IV_PLAT=ios IV_NCP=2 IV_TCPNL=1 IV_PROTO=2 IV_GUI_VER=net.openvpn.connect.ios_3.2.3-3760 IV_SSO=openurl 2021-12-16 17:56:13 VERIFY OK: depth=1, /C=US/ST=California/L=San Bruno/O=Acme, Inc/emailAddress=<REDACTED>@acme.com/CN=internal-ca 2021-12-16 17:56:13 VERIFY OK: depth=0, /C=US/ST=California/L=San Bruno/O=Acme\, Inc/emailAddress=<REDACTED>@acme.com/CN=router.acme.com 2021-12-16 17:56:13 SSL Handshake: CN=router.acme.com, TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA 2021-12-16 17:57:14 Session invalidated: KEEPALIVE_TIMEOUT 2021-12-16 17:57:14 Client terminated, restarting in 2000 ms... 2021-12-16 17:57:16 EVENT: RECONNECTING 2021-12-16 17:57:16 EVENT: RESOLVE 2021-12-16 17:57:16 Contacting [<REDACTED_IPV6_ADDR>]:1194/UDP via UDP 2021-12-16 17:57:16 EVENT: WAIT 2021-12-16 17:57:16 Connecting to [<REDACTED_IP_ADDR>]:1194 (<REDACTED_IPV6_ADDR>:7232) via UDPv6 2021-12-16 17:57:16 EVENT: CONNECTING 2021-12-16 17:57:16 Tunnel Options:V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,keydir 1,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-client 2021-12-16 17:57:16 Creds: Username/Password 2021-12-16 17:57:16 Peer Info: IV_VER=3.git::58b92569 IV_PLAT=ios IV_NCP=2 IV_TCPNL=1 IV_PROTO=2 IV_GUI_VER=net.openvpn.connect.ios_3.2.3-3760 IV_SSO=openurl IV_BS64DL=1 2021-12-16 17:57:16 VERIFY OK: depth=1, /C=US/ST=California/L=San Bruno/O=Acme, Inc/emailAddress=<REDACTED>@acme.com/CN=internal-ca 2021-12-16 17:57:16 VERIFY OK: depth=0, /C=US/ST=California/L=San Bruno/O=Acme\, Inc/emailAddress=<REDACTED>@acme.com/CN=router.acme.com 2021-12-16 17:57:16 SSL Handshake: CN=router.acme.com, TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA 2021-12-16 17:57:16 Session is ACTIVE 2021-12-16 17:57:16 EVENT: GET_CONFIG 2021-12-16 17:57:16 Sending PUSH_REQUEST to server... 2021-12-16 17:57:17 Sending PUSH_REQUEST to server... 2021-12-16 17:57:19 Sending PUSH_REQUEST to server... 2021-12-16 17:57:20 AUTH_FAILED 2021-12-16 17:57:20 EVENT: AUTH_FAILED [ERR] 2021-12-16 17:57:20 Raw stats on disconnect: BYTES_IN : 18114 BYTES_OUT : 17531 PACKETS_IN : 61 PACKETS_OUT : 65 TUN_BYTES_IN : 77 TUN_BYTES_OUT : 161 TUN_PACKETS_IN : 1 TUN_PACKETS_OUT : 1 KEEPALIVE_TIMEOUT : 1 N_RECONNECT : 1 2021-12-16 17:57:20 Performance stats on disconnect: CPU usage (microseconds): 169653 Tunnel compression ratio (uplink): 227.675 Tunnel compression ratio (downlink): 112.509 Network bytes per CPU second: 210105 Tunnel bytes per CPU second: 1402 2021-12-16 17:57:20 EVENT: DISCONNECTED 2021-12-16 17:57:20 Raw stats on disconnect: BYTES_IN : 18114 BYTES_OUT : 17531 PACKETS_IN : 61 PACKETS_OUT : 65 TUN_BYTES_IN : 77 TUN_BYTES_OUT : 161 TUN_PACKETS_IN : 1 TUN_PACKETS_OUT : 1 KEEPALIVE_TIMEOUT : 1 AUTH_FAILED : 1 N_RECONNECT : 1 2021-12-16 17:57:20 Performance stats on disconnect: CPU usage (microseconds): 174710 Tunnel compression ratio (uplink): 227.675 Tunnel compression ratio (downlink): 112.509 Network bytes per CPU second: 204023 Tunnel bytes per CPU second: 1362
Any ideas as to what could be causing the local and remote TLS keys to go out of sync?
Thank you,
James Pedersen -
-
@jamespedersen-brightpattern-com how did you resolve this issue?
-
In my case I suspect that the issue was with expiring TOTP codes from the two factor authenticator (Google Authenticator) that we have been using. TOTP codes only last a short time, and our the OpenVPN clients were trying to reauthenticate using expired TOTP codes (they had initially authenticated with PIN+TOTP in the password prompt).
So far my workaround for this has been the following: First, increase the reneg-sec parameter on the server to something larger, which will cause the reauthentication to occur less frequently, and set reneg-sec 0 on the client so that the server setting for this is used. Second, configure the server with the auth-gen-token <LIFETIME> directive. This way, the server will use session tokens instead of passwords when renegotiation occurs. This bypasses the issue of reauthenticating with expired TOTP codes, as long as the session token itself hasn’t expired.
Thank you,
James Pedersen -
@jamespedersen-brightpattern-com
Thanks! Will test your recommendation:VPN > OpenVPN > Servers > Edit > Advanced Configuration > Custom options
push "route 192.168.1.0 255.255.255.0";
push "route 10.0.100.0 255.255.255.0";
reneg-sec 28800
auth-gen-token 43200