Opened 7 years ago

Closed 3 years ago

#897 closed Bug / Defect (invalid)

OpenVPN not working (tls-auth) on Apollo Lake?

Reported by: mgcrea Owned by:
Priority: critical Milestone:
Component: Generic / unclassified Version: OpenVPN 2.3.10 (Community Ed)
Severity: Not set (select this one, unless your'e a OpenVPN developer) Keywords: tls
Cc: Steffan Karger

Description

Not sure why but two newly acquired NUC6CAYS (Apollo Lake) devices won't connect properly to our VPN server. Looks like a tls-auth issue

  • Both devices run an up-to-date Ubuntu 16.04.2 LTS installation
  • Reproduced on two separate devices
  • Error log loop:
    Tue May 30 15:12:26 2017 us=594155 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.
    Tue May 30 15:12:26 2017 us=594394 Re-using SSL/TLS context
    Tue May 30 15:12:26 2017 us=594482 LZO compression initialized
    Tue May 30 15:12:26 2017 us=594983 Control Channel MTU parms [ L:1560 D:1182 EF:68 EB:0 ET:0 EL:3 ]
    Tue May 30 15:12:26 2017 us=595207 Socket Buffers: R=[87380->87380] S=[16384->16384]
    Tue May 30 15:12:26 2017 us=597360 Data Channel MTU parms [ L:1560 D:1450 EF:60 EB:143 ET:0 EL:3 AF:3/1 ]
    Tue May 30 15:12:26 2017 us=597537 Local Options String: 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_CLIENT,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
    Tue May 30 15:12:26 2017 us=597766 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
    Tue May 30 15:12:26 2017 us=597878 Local Options hash (VER=V4): '2f2c6498'
    Tue May 30 15:12:26 2017 us=598134 Expected Remote Options hash (VER=V4): '9915e4a2'
    Tue May 30 15:12:26 2017 us=598391 Attempting to establish TCP connection with [AF_INET]5.135.198.245:443 [nonblock]
    Tue May 30 15:12:26 2017 us=816276 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.
    Tue May 30 15:12:26 2017 us=816431 Re-using SSL/TLS context
    Tue May 30 15:12:26 2017 us=816510 LZO compression initialized
    Tue May 30 15:12:26 2017 us=816643 Control Channel MTU parms [ L:1560 D:1182 EF:68 EB:0 ET:0 EL:3 ]
    Tue May 30 15:12:26 2017 us=816748 Socket Buffers: R=[87380->87380] S=[16384->16384]
    Tue May 30 15:12:26 2017 us=818746 Data Channel MTU parms [ L:1560 D:1450 EF:60 EB:143 ET:0 EL:3 AF:3/1 ]
    Tue May 30 15:12:26 2017 us=818914 Local Options String: 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_CLIENT,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
    Tue May 30 15:12:26 2017 us=818947 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
    Tue May 30 15:12:26 2017 us=819005 Local Options hash (VER=V4): '2f2c6498'
    Tue May 30 15:12:26 2017 us=819103 Expected Remote Options hash (VER=V4): '9915e4a2'
    Tue May 30 15:12:26 2017 us=819274 Attempting to establish TCP connection with [AF_INET]5.135.198.245:443 [nonblock]
    Tue May 30 15:12:27 2017 us=598869 TCP connection established with [AF_INET]5.135.198.245:443
    Tue May 30 15:12:27 2017 us=599006 TCPv4_CLIENT link local: [undef]
    Tue May 30 15:12:27 2017 us=599081 TCPv4_CLIENT link remote: [AF_INET]5.135.198.245:443
    WRTue May 30 15:12:27 2017 us=606105 TLS: Initial packet from [AF_INET]5.135.198.245:443, sid=43675bcc 81d6c724
    WWRWRRRWWRWRWRRWWRWRWRRWWRWRWRRWWRWRWRRWWRWRWRRWWRWRTue May 30 15:12:27 2017 us=782665 VERIFY OK: depth=1, C=FR, ST=Ile-de-France, L=Paris, O=Carlipa, OU=carlipa-online.com, CN=ca@prod, emailAddress=admin@carlipa-online.com
    Tue May 30 15:12:27 2017 us=783248 VERIFY OK: depth=0, C=FR, ST=Ile-de-France, L=Paris, O=Carlipa, OU=carlipa-online.com, CN=server@prod, emailAddress=admin@carlipa-online.com
    WRRWWRWRWRRWWRWTue May 30 15:12:27 2017 us=819777 TCP connection established with [AF_INET]5.135.198.245:443
    Tue May 30 15:12:27 2017 us=819916 TCPv4_CLIENT link local: [undef]
    Tue May 30 15:12:27 2017 us=819998 TCPv4_CLIENT link remote: [AF_INET]5.135.198.245:443
    WRWRRRTue May 30 15:12:27 2017 us=826903 TLS: Initial packet from [AF_INET]5.135.198.245:443, sid=5c7fa685 65c623d9
    WWWWWWRRWRRRWWRWRRWRWTue May 30 15:12:27 2017 us=919144 Connection reset, restarting [0]
    Tue May 30 15:12:27 2017 us=919557 TCP/UDP: Closing socket
    Tue May 30 15:12:27 2017 us=919727 SIGUSR1[soft,connection-reset] received, process restarting
    Tue May 30 15:12:27 2017 us=919821 Restart pause, 5 second(s)
    RRWWRWRWRRWWRWRWRRWWRWRWRRWWRWRWRRWWRWRTue May 30 15:12:28 2017 us=13548 VERIFY OK: depth=1, C=FR, ST=Ile-de-France, L=Paris, O=Carlipa, OU=carlipa-online.com, CN=ca@prod, emailAddress=admin@carlipa-online.com
    Tue May 30 15:12:28 2017 us=13836 VERIFY OK: depth=0, C=FR, ST=Ile-de-France, L=Paris, O=Carlipa, OU=carlipa-online.com, CN=server@prod, emailAddress=admin@carlipa-online.com
    WRRWWRWRWRRWWRWRWRRWWWWRRRWTue May 30 15:12:28 2017 us=150963 Connection reset, restarting [0]
    Tue May 30 15:12:28 2017 us=151311 TCP/UDP: Closing socket
    Tue May 30 15:12:28 2017 us=151472 SIGUSR1[soft,connection-reset] received, process restarting
    Tue May 30 15:12:28 2017 us=151536 Restart pause, 5 second(s)
    


  • Device info:
root@player-ef15:~# uname -a
Linux player-ef15 4.10.0-21-generic #23~16.04.1-Ubuntu SMP Tue May 2 12:57:17 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
root@player-ef15:~# lsb_release -a
No LSB modules are available.
Distributor ID:	Ubuntu
Description:	Ubuntu 16.04.2 LTS
Release:	16.04
Codename:	xenial
root@player-ef15:~# openvpn --version
OpenVPN 2.3.10 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Feb  2 2016
library versions: OpenSSL 1.0.2g  1 Mar 2016, LZO 2.08
Originally developed by James Yonan
Copyright (C) 2002-2010 OpenVPN Technologies, Inc. <sales@openvpn.net>
Compile time defines: enable_crypto=yes enable_crypto_ofb_cfb=yes enable_debug=yes enable_def_auth=yes enable_dependency_tracking=no enable_dlopen=unknown enable_dlopen_self=unknown enable_dlopen_self_static=unknown enable_fast_install=yes enable_fragment=yes enable_http_proxy=yes enable_iproute2=yes enable_libtool_lock=yes enable_lzo=yes enable_lzo_stub=no enable_maintainer_mode=no enable_management=yes enable_multi=yes enable_multihome=yes enable_pam_dlopen=no enable_password_save=yes enable_pedantic=no enable_pf=yes enable_pkcs11=yes enable_plugin_auth_pam=yes enable_plugin_down_root=yes enable_plugins=yes enable_port_share=yes enable_selinux=no enable_server=yes enable_shared=yes enable_shared_with_static_runtimes=no enable_silent_rules=no enable_small=no enable_socks=yes enable_ssl=yes enable_static=yes enable_strict=no enable_strict_options=no enable_systemd=yes enable_win32_dll=yes enable_x509_alt_username=yes with_crypto_library=openssl with_gnu_ld=yes with_mem_check=no with_plugindir='${prefix}/lib/openvpn' with_sysroot=no

Change History (16)

comment:1 Changed 7 years ago by mgcrea

  • Server logs:
Tue May 30 15:07:27 2017 us=549738 LZO compression initialized
Tue May 30 15:07:27 2017 us=549852 Control Channel MTU parms [ L:1560 D:168 EF:68 EB:0 ET:0 EL:0 ]
Tue May 30 15:07:27 2017 us=549882 Data Channel MTU parms [ L:1560 D:1450 EF:60 EB:135 ET:0 EL:0 AF:3/1 ]
Tue May 30 15:07:27 2017 us=549931 Local Options String: 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Tue May 30 15:07:27 2017 us=549978 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1560,tun-mtu 1500,proto TCPv4_CLIENT,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Tue May 30 15:07:27 2017 us=550014 Local Options hash (VER=V4): '9915e4a2'
Tue May 30 15:07:27 2017 us=550056 Expected Remote Options hash (VER=V4): '2f2c6498'
Tue May 30 15:07:27 2017 us=550170 TCP connection established with [AF_INET]90.63.221.168:49046
Tue May 30 15:07:27 2017 us=550198 TCPv4_SERVER link local: [undef]
Tue May 30 15:07:27 2017 us=550232 TCPv4_SERVER link remote: [AF_INET]90.63.221.168:49046
Tue May 30 15:07:28 2017 us=543273 90.63.221.168:49046 TLS: Initial packet from [AF_INET]90.63.221.168:49046, sid=d1ed148e db63a0bc
Tue May 30 15:07:28 2017 us=811762 90.63.221.168:49046 VERIFY OK: depth=1, /C=FR/ST=Ile-de-France/L=Paris/O=Carlipa/OU=carlipa-online.com/CN=ca@prod/emailAddress=admin@carlipa-online.com
Tue May 30 15:07:28 2017 us=812002 90.63.221.168:49046 VERIFY OK: depth=0, /C=FR/ST=Ile-de-France/L=Paris/O=Carlipa/OU=carlipa-online.com/CN=player@prod/emailAddress=admin@carlipa-online.com
Tue May 30 15:07:28 2017 us=861403 90.63.221.168:49046 TLS_ERROR: BIO read tls_read_plaintext error: error:1408F119:SSL routines:SSL3_GET_RECORD:decryption failed or bad record mac
Tue May 30 15:07:28 2017 us=861432 90.63.221.168:49046 TLS Error: TLS object -> incoming plaintext read error
Tue May 30 15:07:28 2017 us=861441 90.63.221.168:49046 TLS Error: TLS handshake failed
Tue May 30 15:07:28 2017 us=861527 90.63.221.168:49046 Fatal TLS error (check_tls_errors_co), restarting
Tue May 30 15:07:28 2017 us=861549 90.63.221.168:49046 SIGUSR1[soft,tls-error] received, client-instance restarting
Tue May 30 15:07:28 2017 us=861593 TCP/UDP: Closing socket

comment:2 Changed 7 years ago by Gert Döring

Cc: Steffan Karger added

that's not tls-auth (which would happen before the packets ever reach the SSL library), but that doesn't mean I *know* what it is...

comment:3 Changed 7 years ago by mgcrea

Just tried a clean install of 17.04 with Openvpn v2.4.0 and I still can't connect to the VPN.

comment:4 Changed 7 years ago by krzee king

can you post your server log of the connection too? Maybe you would like realtime support in the IRC channel #openvpn on freenode IRC.
Also use 2.4.2 if you can

Last edited 7 years ago by krzee king (previous) (diff)

comment:5 Changed 7 years ago by Steffan Karger

This looks quite odd. As cron2 said, this is not a tls-auth problem. My best guess is that packets somehow get corrupted. Maybe tranmission actually fails, but more likely we accidentally throw away some bytes or so. Can you maybe provide connection logs (both client and server) with --verb 8?

comment:6 Changed 7 years ago by mgcrea

I've upgrade the local version to v2.4.2 (still not working):

OpenVPN 2.4.2 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on May 11 2017
library versions: OpenSSL 1.0.2g  1 Mar 2016, LZO 2.08
Originally developed by James Yonan
Copyright (C) 2002-2017 OpenVPN Technologies, Inc. <sales@openvpn.net>
Compile time defines: enable_async_push=no enable_comp_stub=no enable_crypto=yes enable_crypto_ofb_cfb=yes enable_debug=yes enable_def_auth=yes enable_dependency_tracking=no enable_dlopen=unknown enable_dlopen_self=unknown enable_dlopen_self_static=unknown enable_fast_install=yes enable_fragment=yes enable_iproute2=yes enable_libtool_lock=yes enable_lz4=yes enable_lzo=yes enable_maintainer_mode=no enable_management=yes enable_multi=yes enable_multihome=yes enable_pam_dlopen=no enable_password_save=yes enable_pedantic=no enable_pf=yes enable_pkcs11=yes enable_plugin_auth_pam=yes enable_plugin_down_root=yes enable_plugins=yes enable_port_share=yes enable_selinux=no enable_server=yes enable_shared=yes enable_shared_with_static_runtimes=no enable_silent_rules=no enable_small=no enable_static=yes enable_strict=no enable_strict_options=no enable_systemd=yes enable_werror=no enable_win32_dll=yes enable_x509_alt_username=yes with_crypto_library=openssl with_gnu_ld=yes with_mem_check=no with_plugindir='${prefix}/lib/openvpn' with_sysroot=no

I can't easily upgrade the server's version:

OpenVPN 2.2.1 x86_64-linux-gnu [SSL] [LZO2] [EPOLL] [PKCS11] [eurephia] [MH] [PF_INET6] [IPv6 payload 20110424-2 (2.2RC2)] built on Dec  1 2014
Originally developed by James Yonan
Copyright (C) 2002-2010 OpenVPN Technologies, Inc. <sales@openvpn.net>

  $ ./configure --build=x86_64-linux-gnu --prefix=/usr --includedir=${prefix}/include --mandir=${prefix}/share/man --infodir=${prefix}/share/info --sysconfdir=/etc --localstatedir=/var --libexecdir=${prefix}/lib/openvpn --disable-maintainer-mode --disable-dependency-tracking CFLAGS=-g -O2 -fPIE -fstack-protector --param=ssp-buffer-size=4 -Wformat -Wformat-security -Werror=format-security CPPFLAGS=-D_FORTIFY_SOURCE=2 CXXFLAGS=-g -O2 -fPIE -fstack-protector --param=ssp-buffer-size=4 -Wformat -Wformat-security -Werror=format-security FFLAGS=-g -O2 LDFLAGS=-Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now --enable-password-save --host=x86_64-linux-gnu --build=x86_64-linux-gnu --prefix=/usr --mandir=${prefix}/share/man --with-ifconfig-path=/sbin/ifconfig --with-route-path=/sbin/route

Compile time defines:  ENABLE_CLIENT_SERVER ENABLE_DEBUG ENABLE_EUREPHIA ENABLE_FRAGMENT ENABLE_HTTP_PROXY ENABLE_MANAGEMENT ENABLE_MULTIHOME ENABLE_PASSWORD_SAVE ENABLE_PORT_SHARE ENABLE_SOCKS USE_CRYPTO USE_LIBDL USE_LZO USE_PF_INET6 USE_PKCS11 USE_SSL

I've put the verbosity to 8 and isolated the client (only one connecting):

I'm available on IRC (@mgcrea) for realtime debugging

comment:7 Changed 7 years ago by plaisthos

This might be also some weird tls library inoperability problem. Do other clients with that UBuntu version work? also try using tls-version-max 1.0 and/or tls-cipher DEFAULT on the client to see if that changes anything.

comment:8 Changed 7 years ago by mgcrea

Thanks plaisthos, I tried the config flags (tls-version-max 1.0 and/or tls-cipher DEFAULT) but it did not work either.

Also tried openvpn built with mbedtls (via https://launchpad.net/~chris-lea/+archive/ubuntu/openvpn-mbedtls) and it does not work either:

So it does not look like it is an OpenSSL issue.

Finally, we've got almost every NUC device ever made (hundreds of devices) and we never had any issue, we have other devices that do connect without issues with the same network (NUC7i3, NUC6i5, NUC5CP, etc.). We only got this TLS issue on this model NUC6CAY on two separate hardware (same model).

Last edited 7 years ago by mgcrea (previous) (diff)

comment:9 Changed 7 years ago by Steffan Karger

The server is rejecting the tls record authentication tag. It somehow expects a different value. Unfortunately I can't spot any cause of this in the --verb 8 logs; all the packet/buffer sizes look just as I would expect.

Just to be clear, the same OS/openvpn version on different hardware *does* work with this server?

Also, did you verify whether connecting to a more modern server works?

This bug report is puzzling...

comment:10 Changed 7 years ago by mgcrea

Exact same OS and setup have been working fine on hundreds (>500) of other devices, with this VPN server (our test VPN), and are working currently (I've duplicated the server on another IP to isolate the logs).

As a business we have to stay up-to-date with latest hardware releases so as Intel stopped the production of NUC5CP devices (low cost celeron), we sourced the replacing device, which is a NUC6CAY and faced this issue during our tests.

To be clear, we have no issue at all (and never had before this NUC) with the same OS (up-to-date Ubuntu 16.04.2LTS) on at least 15 different hardware, most recent being:

  • NUC5CP, NUC5PP, NUC6i3, NUC6i5, NUC7i3

I'm going to try an up-to-date server. Do you want verb 9?

comment:11 Changed 7 years ago by Steffan Karger

--verb 8 should be enough (that prints internal TLS lib messages and buffer sizes).

If you are able to reproduce with a more modern server, could you please try an mbedtls server too? (We might get lucky and have the mbed tls server report a more useful error message.)

comment:12 Changed 7 years ago by mgcrea

Tried with an up-to-date server, still not working:

OpenVPN 2.4.2 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on May 12 2017
library versions: LibreSSL 2.5.4, LZO 2.10
Originally developed by James Yonan
Copyright (C) 2002-2017 OpenVPN Technologies, Inc. <sales@openvpn.net>
Compile time defines: enable_async_push='no' enable_comp_stub='no' enable_crypto='yes' enable_crypto_ofb_cfb='yes' enable_debug='yes' enable_def_auth='yes' enable_dlopen='unknown' enable_dlopen_self='unknown' enable_dlopen_self_static='unknown' enable_fast_install='yes' enable_fragment='yes' enable_iproute2='yes' enable_libtool_lock='yes' enable_lz4='yes' enable_lzo='yes' enable_management='yes' enable_multi='yes' enable_multihome='yes' enable_pam_dlopen='no' enable_pedantic='no' enable_pf='yes' enable_pkcs11='no' enable_plugin_auth_pam='yes' enable_plugin_down_root='yes' enable_plugins='yes' enable_port_share='yes' enable_selinux='no' enable_server='yes' enable_shared='yes' enable_shared_with_static_runtimes='no' enable_small='no' enable_static='yes' enable_strict='no' enable_strict_options='no' enable_systemd='no' enable_werror='no' enable_win32_dll='yes' enable_x509_alt_username='no' with_crypto_library='openssl' with_gnu_ld='yes' with_mem_check='no' with_sysroot='no'

Server logs (verb 8): https://gist.github.com/mgcrea/f6e40b9be671ee357cd5d3c722b3ecdc

Will try an mbedtls server.

comment:13 Changed 7 years ago by plaisthos

Thu Jun 1 15:53:59 2017 us=710060 90.63.221.168:55944 TLS error: The server has no TLS ciphersuites in common with the client. Your --tls-cipher setting might be too restrictive.
Thu Jun 1 15:53:59 2017 us=710090 90.63.221.168:55944 OpenSSL: error:140270C1:SSL routines:ACCEPT_SR_CLNT_HELLO_C:no shared cipher

That is a different error. You can retry that test with tls-cipher DEFAULT on both sides. For some reason your sides cannot agree on a shared cipher.What OpenSSL version does the server have?

comment:14 Changed 7 years ago by mgcrea

Good catch, indeed I did left "tls-cipher DEFAULT" on the client config, removing it did fix the connection.

So:

  • No known client version can connect to v2.2.1 server.
  • v2.4.2-mbedTLS does properly connect to v2.4.2 server.
  • v2.4.2 does properly connect to v2.4.2 server.
Last edited 7 years ago by mgcrea (previous) (diff)

comment:15 Changed 6 years ago by Antonio Quartulli

@mgcrea is this still a problem? From your last post I understand that the issue is gone when using 2.4.2 on the server.

This might well be a bug that has been fixed in the meantime (2.2 is *very* old), even though it wasn't clear what it might be from the log.

comment:16 Changed 3 years ago by Antonio Quartulli

Resolution: invalid
Status: newclosed

closing due to inactivity.

Note: See TracTickets for help on using tickets.