Discussion:
[Openvpn-users] Issue with single user, implicit ncp-ciphers connections
o***@keemail.me
2017-06-30 16:20:29 UTC
Permalink
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.
Gert Doering
2017-06-30 16:56:01 UTC
Permalink
Hi,
Post by o***@keemail.me
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.
<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
If you look closely, you can see that there is no "Connection established"
here, because the server does not see this as a *new* connection, but
thinks it's a TLS renegotiation.

Unless there is a specific reason, always use --nobind on the client, which
ensures that a client restart will use a different port, avoiding this
issue.
Post by o***@keemail.me
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'
Something is funky here anyway, as we shouldn't be receving multiple
PUSH_REQUESTS in short order, but since you mangled the timestamps and
client ports, it's not easy to see what really happened.
Post by o***@keemail.me
<DATETIME> us=993980 <CLIENT-NAME>/<CLIENT-IP:PORT> Using peer cipher 'AES-128-GCM'
... why is the client not using NCP anyway? "using peer cipher" is just
a fallback option for 2.3 clients that cannot be properly upgraded...

[..]
Post by o***@keemail.me
Why does this occur and how can I fix this issue?
- use --nobind on the client
- use 2.4.3 everywhere
- do not use --ncp-disable and varying --cipher settings unless there is
a very specific situation that you need this for

gert
--
USENET is *not* the non-clickable part of WWW!
//www.muc.de/~gert/
Gert Doering - Munich, Germany ***@greenie.muc.de
fax: +49-89-35655025 ***@net.informatik.tu-muenchen.de
o***@keemail.me
2017-07-03 05:53:05 UTC
Permalink
Hello!
Post by Gert Doering
Hi,
Post by o***@keemail.me
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.
<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
If you look closely, you can see that there is no "Connection established"
here, because the server does not see this as a *new* connection, but
thinks it's a TLS renegotiation.
Does the server and/or the client cache TLS connections or in an other way keep track of previous connections?

Is there a way to prevent this behaviour?
Post by Gert Doering
Unless there is a specific reason, always use --nobind on the client, which
ensures that a client restart will use a different port, avoiding this
issue.
Post by o***@keemail.me
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'
Something is funky here anyway, as we shouldn't be receving multiple
PUSH_REQUESTS in short order, but since you mangled the timestamps and
client ports, it's not easy to see what really happened.
Post by o***@keemail.me
<DATETIME> us=993980 <CLIENT-NAME>/<CLIENT-IP:PORT> Using peer cipher 'AES-128-GCM'
The client is connected mutliple times at this moment, I know the mangled IP/Port/Datetimes make that hard to see, but the logs are chronological and only concern with the client connection using AES-128-GCM.
Post by Gert Doering
... why is the client not using NCP anyway? "using peer cipher" is just
a fallback option for 2.3 clients that cannot be properly upgraded...
[..]
Post by o***@keemail.me
Why does this occur and how can I fix this issue?
- use --nobind on the client
- use 2.4.3 everywhere
- do not use --ncp-disable and varying --cipher settings unless there is
a very specific situation that you need this for
You have valid and very helpful comments, but for this specific case I ca not use --nobind.

The client(s) will be updated any day now, but I need to keep --ncp-disable and varying --cipher's as that's a requirement for me.
Post by Gert Doering
gert
--
USENET is *not* the non-clickable part of WWW!
//www.muc.de/~gert/
Thank you 

op
Gert Doering
2017-07-03 07:01:17 UTC
Permalink
Hi,
Post by o***@keemail.me
You have valid and very helpful comments, but for this specific case I ca not use --nobind.
The client(s) will be updated any day now, but I need to keep --ncp-disable and varying --cipher's as that's a requirement for me.
You insist on using a combination of *four* things that need to be all
true at the same time to cause these issues (same username, not using
--nobind, using --ncp-disable, plus varying ciphers).

Depending on how your clients disconnect, --explicit-exit-notify might
help (because that will ensure the server knows "client went away") - but
otherwise, this is turning into a "if I do this, it hurts" - "then don't
do this" thread.

gert
--
USENET is *not* the non-clickable part of WWW!
//www.muc.de/~gert/
Gert Doering - Munich, Germany ***@greenie.muc.de
fax: +49-89-35655025 ***@net.informatik.tu-muenchen.de
o***@keemail.me
2017-07-03 08:00:39 UTC
Permalink
Hi,

I'm already using explicit-exit-notify, which doesn't seem to help in this specific case.

I'm afraid you're right, further discussion seems a bit off - I will conduct further research.

Thank you very much for your assistance!
Post by Gert Doering
Hi,
Post by o***@keemail.me
You have valid and very helpful comments, but for this specific case I ca not use --nobind.
The client(s) will be updated any day now, but I need to keep --ncp-disable and varying --cipher's as that's a requirement for me.
You insist on using a combination of *four* things that need to be all
true at the same time to cause these issues (same username, not using
--nobind, using --ncp-disable, plus varying ciphers).
Depending on how your clients disconnect, --explicit-exit-notify might
help (because that will ensure the server knows "client went away") - but
otherwise, this is turning into a "if I do this, it hurts" - "then don't
do this" thread.
gert
--
USENET is *not* the non-clickable part of WWW!
//www.muc.de/~gert/
Loading...