Seems like openvpn client doesn't correctly interpret configuration file after automatic reconnect

[vbnekit]

Problem point

Client "forget" some [or randomly crashes] parameters [if "pull" option is enabled] after connection was lost or server was restarted.

Problem details

This problem occurs on Windows & Linux clients.
openvpn --config client.ovpn says:

First connection [after start openvpn client] looks like ok:

Tue Sep 11 21:04:01 2018 OpenVPN 2.4.6 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 30 2018
Tue Sep 11 21:04:01 2018 library versions: OpenSSL 1.1.0h  27 Mar 2018, LZO 2.10
Tue Sep 11 21:04:01 2018 TCP/UDP: Preserving recently used remote address: [AF_INET]127.0.0.1:1194
Tue Sep 11 21:04:01 2018 Attempting to establish TCP connection with [AF_INET]127.0.0.1:1194 [nonblock]
Tue Sep 11 21:04:01 2018 TCP connection established with [AF_INET]127.0.0.1:1194
Tue Sep 11 21:04:01 2018 TCPv4_CLIENT link local: (not bound)
Tue Sep 11 21:04:01 2018 TCPv4_CLIENT link remote: [AF_INET]127.0.0.1:1194
Tue Sep 11 21:04:01 2018 [openvpn server] Peer Connection Initiated with [AF_INET]127.0.0.1:1194
Tue Sep 11 21:04:02 2018 TUN/TAP device tap1 opened
Tue Sep 11 21:04:02 2018 Initialization Sequence Completed

After the connection is lost …

Tue Sep 11 21:05:52 2018 Connection reset, restarting [0]
Tue Sep 11 21:05:52 2018 SIGUSR1[soft,connection-reset] received, process restarting

... the connection is retried automatically [and this is good]…

Tue Sep 11 21:06:02 2018 TCP/UDP: Preserving recently used remote address: [AF_INET]127.0.0.1:1194
Tue Sep 11 21:06:02 2018 Attempting to establish TCP connection with [AF_INET]127.0.0.1:1194 [nonblock]
Tue Sep 11 21:06:02 2018 TCP connection established with [AF_INET]127.0.0.1:1194
Tue Sep 11 21:06:02 2018 TCPv4_CLIENT link local: (not bound)
Tue Sep 11 21:06:02 2018 TCPv4_CLIENT link remote: [AF_INET]127.0.0.1:1194

... but we can see next warnings …

ue Sep 11 21:06:02 2018 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1583', remote='link-mtu 1591'
Tue Sep 11 21:06:02 2018 WARNING: 'cipher' is used inconsistently, local='cipher AES-256-GCM', remote='cipher AES-256-CBC'
Tue Sep 11 21:06:02 2018 WARNING: 'auth' is used inconsistently, local='auth [null-digest]', remote='auth SHA1'

... then the connection process is completed successfully [or not?..]

Tue Sep 11 21:06:02 2018 [openvpn server] Peer Connection Initiated with [AF_INET]127.0.0.1:1194
Tue Sep 11 21:06:03 2018 TUN/TAP device tap1 opened
Tue Sep 11 21:06:03 2018 Initialization Sequence Completed

How to reproduce

I sent tar.xz archive with files for reproduce this.

1. start the server on terminal 1: openvpn --config server.ovpn;
2. start the client on terminal 2: openvpn --config client.ovpn;
3. restart the server on terminal 1;
4. watch the client output on terminal 2.

Config files

server.ovpn

dev tap
proto tcp4-server
server-bridge

ca "ca.crt"
dh "dh4096.pem"
key "server.pem"
cert "server.crt"

auth SHA1
keepalive 15 45
cipher AES-256-CBC

client.ovpn

nobind
dev tap
tls-client
proto tcp4-client
remote localhost

ca "ca.crt"
key "client.pem"
cert "client.crt"

pull
auth SHA1
auth-nocache
cipher AES-256-CBC
remote-cert-tls server

Version information

Operating system

Debian GNU/Linux buster

Kernel

Linux 4.17.0-3-amd64 #1 SMP Debian 4.17.17-1 (2018-08-18) x86_64 GNU/Linux

OpenVPN client/server version

openvpn --version output:

OpenVPN 2.4.6 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 30 2018
library versions: OpenSSL 1.1.0h  27 Mar 2018, LZO 2.10
Originally developed by James Yonan
Copyright (C) 2002-2018 OpenVPN 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=needless enable_fragment=yes enable_iproute2=yes enable_libtool_lock=yes enable_lz4=yes enable_lzo=yes enable_maintainer_mode=no enable_management=yes enable_multihome=yes enable_pam_dlopen=no 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_aix_soname=aix with_crypto_library=openssl with_gnu_ld=yes with_mem_check=no with_sysroot=no

[vbnekit]

archive with files for reproduce the problem

[Gert Döring]

can we have the full client log that shows the pushed options on the first and second connect? ("PUSH_REPLY ...")?

@syzzer: this rings a bell, but I can't remember where we've seen this - NCP not running properly on reconnect?

[vbnekit]

For running server in docker

Files

Dockerfile

FROM debian:buster
ENV DEBIAN_FRONTEND noninteractive
RUN apt update && apt full-upgrade -y
RUN apt update && apt install -y apt-utils
RUN apt update && apt install -y openvpn
RUN apt clean
RUN mkdir /root/bugreport/
COPY ca.crt /root/bugreport/
COPY dh4096.pem /root/bugreport/
COPY server.pem /root/bugreport/
COPY server.crt /root/bugreport/
COPY server.ovpn /root/bugreport/
ENTRYPOINT ["/usr/sbin/openvpn", "--config", "/root/bugreport/server.ovpn"]

server.ovpn

nobind
dev tap
tls-client
proto tcp4-client
remote localhost

ca "/root/bugreport/ca.crt"
key "/root/bugreport/client.pem"
cert "/root/bugreport/client.crt"

pull
auth SHA1
auth-nocache
cipher AES-256-CBC
remote-cert-tls server

commands

• build image: docker build -t bugreport .
• create container: docker create --privileged --name bugreport --publish 127.0.0.1:1194:1194/tcp -it bugreport
• start container [and server]: docker start bugreport
• restart container [and server]: docker restart bugreport

[vbnekit]

first time connection

[vbnekit]

reconnect log (verb level 9)

[vbnekit]

can we have the full client log that shows the pushed options on the first and second connect? ("PUSH_REPLY ...")?

yeah, sure.

1st connection: ​https://community.openvpn.net/openvpn/attachment/ticket/1105/before.log.xz
2nd (reconnection): ​https://community.openvpn.net/openvpn/attachment/ticket/1105/after.log.xz

[vbnekit]

Replying to Gert Döring:

can we have the full client log that shows the pushed options on the first and second connect? ("PUSH_REPLY ...")?
...

I accidentally answered in a new branch for comments.

1st connection: ​​https://community.openvpn.net/openvpn/attachment/ticket/1105/before.log.xz
2nd (reconnection): ​​https://community.openvpn.net/openvpn/attachment/ticket/1105/after.log.xz

[Gert Döring]

thanks for the logs. .xz is somewhat annoying to work with ("download, unpack, look, copy back to ticket for commenting") - just having the PUSH_REPLY lines in the ticket itself is easier to look at and see if this is a server or client issue.

Actually it might be a non-issue at all... :-) - does the connection work after reconnecting with warnings?

[vbnekit]

Replying to Gert Döring:

thanks for the logs. .xz is somewhat annoying to work with ("download, unpack, look, copy back to ticket for commenting") - just having the PUSH_REPLY lines in the ticket itself is easier to look at and see if this is a server or client issue.

Actually it might be a non-issue at all... :-) - does the connection work after reconnecting with warnings?

Yes. It seems like ok. But i'm not 100% sure 8).
It works, i can transfer data over bridge & i still can't detect any problems in vitrual network traffic after strange reconnection warnings.

[vbnekit]

Will this be fixed in future versions? =)

[stipa]

Yes, ​https://patchwork.openvpn.net/patch/467/

[Gert Döring]

commit 5fa25eeb7fefdbb17ad639d72fe46f393989159f (master)
commit d2ff5164e68e5101b1da2d2d818e23eb7851dc9f (release/2.4)
Author: Lev Stipakov
Date: Thu Sep 20 16:12:34 2018 +0300

Refactor NCP-negotiable options handling

Signed-off-by: Lev Stipakov <lev@…>
Acked-by: Steffan Karger <steffan.karger@…>
Message-Id: <1537449154-26879-1-git-send-email-lstipakov@…>
URL: ​https://www.mail-archive.com/openvpn-devel@lists.sourceforge.net/msg17477.html
Signed-off-by: Gert Doering <gert@…>

patch is in. So with that the warnings should be gone for good now - stipa ran into the same issue. Will be in 2.4.7, which should happen "later this year".

[Gert Döring]

So, this was 4 years ago - I claim this has been fixed, with the patch above, and with another patch set which addressed more server-pushable options that did not get reset properly on reconnect.

If it still happens with latest 2.4 or 2.5, please reopen.