o***@keemail.me
2017-06-30 16:20:29 UTC
Hello list,
I've come across an issue with my OpenVPN setup with a single client.
The single client is allowed to connect multiple times (duplicate-cn on the server side).
The server's cipher is configured to AES-256-CBC (cipher AES-256-CBC) and an no ncp-ciphers, so the default of AES-256-GCM and AES-128-GCM is active. This should allow the client to connect with the ciphers AES-256-CBC, AES-256-GCM and AES-128-GCM - as it is intended.
This usually works as it should, but I've notices issues if the client connects multiple times with different ciphers within a short period of time.
The problem has been observed with AES-128-GCM.
If everything goes as intended, the in essence server logs:
<DATETIME> us=270206 <CLIENT-IP:PORT> WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1602', remote='link-mtu 1550'
<DATETIME> us=270273 <CLIENT-IP:PORT> WARNING: 'cipher' is used inconsistently, local='cipher AES-256-CBC', remote='cipher AES-128-GCM'
<DATETIME> us=270336 <CLIENT-IP:PORT> WARNING: 'auth' is used inconsistently, local='auth SHA512', remote='auth [null-digest]'
<DATETIME> us=270435 <CLIENT-IP:PORT> WARNING: 'keysize' is used inconsistently, local='keysize 256', remote='keysize 128'
WR<DATETIME> us=272297 <CLIENT-IP:PORT> Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 4069 bit RSA
<DATETIME> us=272468 <CLIENT-IP:PORT> [<CLIENT-NAME>] Peer Connection Initiated with [AF_INET]<CLIENT-IP:PORT>
<DATETIME> us=272576 <CLIENT-NAME>/<CLIENT-IP:PORT> MULTI_sva: pool returned IPv4=172.16.0.6, IPv6=(Not enabled)
<DATETIME> us=272693 <CLIENT-NAME>/<CLIENT-IP:PORT> MULTI: Learn: 172.16.0.6 -> <CLIENT-NAME>/<CLIENT-IP:PORT>
<DATETIME> us=272770 <CLIENT-NAME>/<CLIENT-IP:PORT> MULTI: primary virtual IP for <CLIENT-NAME>/<CLIENT-IP:PORT> : 172.16.0.6
R<DATETIME> us=511067 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
<DATETIME> us=511735 <CLIENT-NAME>/<CLIENT-IP:PORT> Using peer cipher 'AES-128-GCM'
<DATETIME> us=512401 <CLIENT-NAME>/<CLIENT-IP:PORT> SENT CONTROL [<CLIENT-NAME>]: 'PUSH_REPLY,route 172.16.0.1,topology net30,ifconfig 172.16.0.6 172.16.0.5,peer-id 0' (status=1)
<DATETIME> us=512941 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel MTU parms [ L:1550 D:1450 EF:50 EB:406 ET:0 EL:3 ]
<DATETIME> us=513919 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Encrypt: Cipher 'AES-128-GCM' initialized with 128 bit key
<DATETIME> us=514274 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Decrypt: Cipher 'AES-128-GCM' initialized with 128 bit key
WWRRWRwrWRwrWRwrWRRwrWR
So the client connects, a cipher/auth mismatch exists and the server continues (due to the cipher being on the ncp-ciphers list), with AES-128-GCM (as chosen by the client).
Now, in some cases, when the client connects with different ciphers, the server appears to wrongly choose the peer cipher or data channel enc/dec cipher.
In the server logs this is can be observed as:
<DATETIME> us=416063 <CLIENT-NAME>/<CLIENT-IP:PORT> WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1602', remote='link-mtu 1550'
<DATETIME> us=416125 <CLIENT-NAME>/<CLIENT-IP:PORT> WARNING: 'cipher' is used inconsistently, local='cipher AES-256-CBC', remote='cipher AES-128-GCM'
<DATETIME> us=416182 <CLIENT-NAME>/<CLIENT-IP:PORT> WARNING: 'auth' is used inconsistently, local='auth SHA512', remote='auth [null-digest]'
<DATETIME> us=416317 <CLIENT-NAME>/<CLIENT-IP:PORT> WARNING: 'keysize' is used inconsistently, local='keysize 256', remote='keysize 128'
<DATETIME> us=416538 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Encrypt: Cipher 'AES-256-CBC' initialized with 256 bit key
<DATETIME> us=416614 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Encrypt: Using 512 bit message hash 'SHA512' for HMAC authentication
<DATETIME> us=416672 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Decrypt: Cipher 'AES-256-CBC' initialized with 256 bit key
<DATETIME> us=416730 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Decrypt: Using 512 bit message hash 'SHA512' for HMAC authentication
<DATETIME> us=416803 <CLIENT-NAME>/<CLIENT-IP:PORT> TLS: move_session: dest=TM_ACTIVE src=TM_UNTRUSTED reinit_src=1
<DATETIME> us=417059 <CLIENT-NAME>/<CLIENT-IP:PORT> TLS: tls_multi_process: untrusted session promoted to semi-trusted
WR<DATETIME> us=417997 <CLIENT-NAME>/<CLIENT-IP:PORT> Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 4069 bit RSA
R<DATETIME> us=551112 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
WR<DATETIME> us=690323 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
WR<DATETIME> us=956749 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
WR<DATETIME> us=474589 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
WR<DATETIME> us=993878 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
<DATETIME> us=993980 <CLIENT-NAME>/<CLIENT-IP:PORT> Using peer cipher 'AES-128-GCM'
<DATETIME> us=994041 <CLIENT-NAME>/<CLIENT-IP:PORT> SENT CONTROL [<CLIENT-NAME>]: 'PUSH_REPLY,route 172.16.0.1,topology net30,ifconfig 172.16.0.6 172.16.0.5,peer-id 0' (status=1)
WWRR<DATETIME> us=8832 <CLIENT-NAME>/<CLIENT-IP:PORT> Authenticate/Decrypt packet error: packet HMAC authentication failed
R<DATETIME> us=24179 <CLIENT-NAME>/<CLIENT-IP:PORT> Authenticate/Decrypt packet error: packet HMAC authentication failed
R<DATETIME> us=43303 <CLIENT-NAME>/<CLIENT-IP:PORT> Authenticate/Decrypt packet error: packet HMAC authentication failed
R<DATETIME> us=500081 <CLIENT-NAME>/<CLIENT-IP:PORT> Authenticate/Decrypt packet error: packet HMAC authentication failed
R<DATETIME> us=48185 <CLIENT-NAME>/<CLIENT-IP:PORT> Authenticate/Decrypt packet error: missing authentication info
This time the server logs that the data channel enc/dec cipher AES-256-CBC and SHA512 for HMAC is used. Obviously this results in "Authenticate/Decrypt packet error"s.
Why does this occur and how can I fix this issue?
Thank you and kind regards.
I've come across an issue with my OpenVPN setup with a single client.
The single client is allowed to connect multiple times (duplicate-cn on the server side).
The server's cipher is configured to AES-256-CBC (cipher AES-256-CBC) and an no ncp-ciphers, so the default of AES-256-GCM and AES-128-GCM is active. This should allow the client to connect with the ciphers AES-256-CBC, AES-256-GCM and AES-128-GCM - as it is intended.
This usually works as it should, but I've notices issues if the client connects multiple times with different ciphers within a short period of time.
The problem has been observed with AES-128-GCM.
If everything goes as intended, the in essence server logs:
<DATETIME> us=270206 <CLIENT-IP:PORT> WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1602', remote='link-mtu 1550'
<DATETIME> us=270273 <CLIENT-IP:PORT> WARNING: 'cipher' is used inconsistently, local='cipher AES-256-CBC', remote='cipher AES-128-GCM'
<DATETIME> us=270336 <CLIENT-IP:PORT> WARNING: 'auth' is used inconsistently, local='auth SHA512', remote='auth [null-digest]'
<DATETIME> us=270435 <CLIENT-IP:PORT> WARNING: 'keysize' is used inconsistently, local='keysize 256', remote='keysize 128'
WR<DATETIME> us=272297 <CLIENT-IP:PORT> Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 4069 bit RSA
<DATETIME> us=272468 <CLIENT-IP:PORT> [<CLIENT-NAME>] Peer Connection Initiated with [AF_INET]<CLIENT-IP:PORT>
<DATETIME> us=272576 <CLIENT-NAME>/<CLIENT-IP:PORT> MULTI_sva: pool returned IPv4=172.16.0.6, IPv6=(Not enabled)
<DATETIME> us=272693 <CLIENT-NAME>/<CLIENT-IP:PORT> MULTI: Learn: 172.16.0.6 -> <CLIENT-NAME>/<CLIENT-IP:PORT>
<DATETIME> us=272770 <CLIENT-NAME>/<CLIENT-IP:PORT> MULTI: primary virtual IP for <CLIENT-NAME>/<CLIENT-IP:PORT> : 172.16.0.6
R<DATETIME> us=511067 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
<DATETIME> us=511735 <CLIENT-NAME>/<CLIENT-IP:PORT> Using peer cipher 'AES-128-GCM'
<DATETIME> us=512401 <CLIENT-NAME>/<CLIENT-IP:PORT> SENT CONTROL [<CLIENT-NAME>]: 'PUSH_REPLY,route 172.16.0.1,topology net30,ifconfig 172.16.0.6 172.16.0.5,peer-id 0' (status=1)
<DATETIME> us=512941 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel MTU parms [ L:1550 D:1450 EF:50 EB:406 ET:0 EL:3 ]
<DATETIME> us=513919 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Encrypt: Cipher 'AES-128-GCM' initialized with 128 bit key
<DATETIME> us=514274 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Decrypt: Cipher 'AES-128-GCM' initialized with 128 bit key
WWRRWRwrWRwrWRwrWRRwrWR
So the client connects, a cipher/auth mismatch exists and the server continues (due to the cipher being on the ncp-ciphers list), with AES-128-GCM (as chosen by the client).
Now, in some cases, when the client connects with different ciphers, the server appears to wrongly choose the peer cipher or data channel enc/dec cipher.
In the server logs this is can be observed as:
<DATETIME> us=416063 <CLIENT-NAME>/<CLIENT-IP:PORT> WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1602', remote='link-mtu 1550'
<DATETIME> us=416125 <CLIENT-NAME>/<CLIENT-IP:PORT> WARNING: 'cipher' is used inconsistently, local='cipher AES-256-CBC', remote='cipher AES-128-GCM'
<DATETIME> us=416182 <CLIENT-NAME>/<CLIENT-IP:PORT> WARNING: 'auth' is used inconsistently, local='auth SHA512', remote='auth [null-digest]'
<DATETIME> us=416317 <CLIENT-NAME>/<CLIENT-IP:PORT> WARNING: 'keysize' is used inconsistently, local='keysize 256', remote='keysize 128'
<DATETIME> us=416538 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Encrypt: Cipher 'AES-256-CBC' initialized with 256 bit key
<DATETIME> us=416614 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Encrypt: Using 512 bit message hash 'SHA512' for HMAC authentication
<DATETIME> us=416672 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Decrypt: Cipher 'AES-256-CBC' initialized with 256 bit key
<DATETIME> us=416730 <CLIENT-NAME>/<CLIENT-IP:PORT> Data Channel Decrypt: Using 512 bit message hash 'SHA512' for HMAC authentication
<DATETIME> us=416803 <CLIENT-NAME>/<CLIENT-IP:PORT> TLS: move_session: dest=TM_ACTIVE src=TM_UNTRUSTED reinit_src=1
<DATETIME> us=417059 <CLIENT-NAME>/<CLIENT-IP:PORT> TLS: tls_multi_process: untrusted session promoted to semi-trusted
WR<DATETIME> us=417997 <CLIENT-NAME>/<CLIENT-IP:PORT> Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 4069 bit RSA
R<DATETIME> us=551112 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
WR<DATETIME> us=690323 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
WR<DATETIME> us=956749 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
WR<DATETIME> us=474589 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
WR<DATETIME> us=993878 <CLIENT-NAME>/<CLIENT-IP:PORT> PUSH: Received control message: 'PUSH_REQUEST'
<DATETIME> us=993980 <CLIENT-NAME>/<CLIENT-IP:PORT> Using peer cipher 'AES-128-GCM'
<DATETIME> us=994041 <CLIENT-NAME>/<CLIENT-IP:PORT> SENT CONTROL [<CLIENT-NAME>]: 'PUSH_REPLY,route 172.16.0.1,topology net30,ifconfig 172.16.0.6 172.16.0.5,peer-id 0' (status=1)
WWRR<DATETIME> us=8832 <CLIENT-NAME>/<CLIENT-IP:PORT> Authenticate/Decrypt packet error: packet HMAC authentication failed
R<DATETIME> us=24179 <CLIENT-NAME>/<CLIENT-IP:PORT> Authenticate/Decrypt packet error: packet HMAC authentication failed
R<DATETIME> us=43303 <CLIENT-NAME>/<CLIENT-IP:PORT> Authenticate/Decrypt packet error: packet HMAC authentication failed
R<DATETIME> us=500081 <CLIENT-NAME>/<CLIENT-IP:PORT> Authenticate/Decrypt packet error: packet HMAC authentication failed
R<DATETIME> us=48185 <CLIENT-NAME>/<CLIENT-IP:PORT> Authenticate/Decrypt packet error: missing authentication info
This time the server logs that the data channel enc/dec cipher AES-256-CBC and SHA512 for HMAC is used. Obviously this results in "Authenticate/Decrypt packet error"s.
Why does this occur and how can I fix this issue?
Thank you and kind regards.