TLS Error: local/remote TLS keys are out of sync

jamespedersen-brightpattern.com · Dec 17, 2021, 2:31 AM

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

viragomann · Dec 17, 2021, 1:31 PM

@jamespedersen-brightpattern-com
Try to add a

compress

line to the clients config.

mrpfsense · Jan 21, 2022, 7:29 PM

@jamespedersen-brightpattern-com how did you resolve this issue?

jamespedersen-brightpattern.com · Jan 21, 2022, 7:44 PM

@mrpfsense

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

mrpfsense · Jan 21, 2022, 8:35 PM

@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