mullvad / mullvadvpn-app

The Mullvad VPN client app for desktop and mobile
https://mullvad.net/
GNU General Public License v3.0
4.94k stars 336 forks source link

Openvpn client config option 'persist-tun' causes permanent tunnel disconnection if internet connectivity is disconnected for an extended period #3645

Open tryphe opened 2 years ago

tryphe commented 2 years ago

Issue report

Issue description

I've had a problem with permanent disconnections while (1) using the Mullvad app and (2) a standalone Openvpn setup without the app installed. I'm new to using Openvpn/Mullvad so this just started happening. The gateway of my client often goes down for periods longer than 5 minutes, which I cannot prevent. When this happens, specfically disconnections of a few minutes or longer, the tunnel remains up but is never able to push traffic. Either restarting the Mullvad app or sudo service openvpn@mullvad_xx restart will always resolve the situation, which seems to hint at the tunnel interface persisting between service restarts as the culprit. I've googled this problem and there are several lookalike problems going back several years, and the only "solution" I can find is a workaround script that pings a server and restarts openvpn if too many pings are dropped.

While following the Mullvad howto tutorial to configure Openvpn on Linux, it gives instructions to use the config generator. I tried different combinations of config settings and the permanent disconnection behavior always appears when persist-tun is enabled.

I repeated these steps while running ping 8.8.8.8 and journalctl -xfe to reveal the behavior:

I tallied up the instances where the connection didn't recover and did recover. I only waited about 5 minutes during testing to wait and see if it would automatically reconnect, but it'll sit there for hours disconnected, which is how I noticed the problem. After plugging the network cable of the client gateway back into the switch, with persist-tun off, it was able to reconnect 100% of the time, versus 0% of the time with the persist-tun on:

stays disconnected reconnects
persist-tun ON 9 0
persist-tun OFF 0 8

This seems to happen with both the app and standalone Openvpn setups, however the duration of disconnection was sometimes short enough for the connection to recover, hence my confusion. But keeping it disconnected for longer than a few minutes caused the behavior to appear.

Given that similar bugs have happened in the past due to the tap driver, which I cannot say is the cause of this issue, the persistent tunnel option seems to be a source of problems. Given the popularity of Debian 11 and Openvpn, I think it's fair to say this config option should be disabled on this setup (I didn't test other platforms) specifically in the Linux HOWTO, but perhaps on the app as well, as I feel like someone else will run into this issue. If someone absolutely needs this option enabled for some reason, I think they should be aware that this option can cause problems.

I cannot say if this will fix the disconnection behavior in the app itself as I did all config testing specifically with the Openvpn standalone setup, and I didn't look into how to alter the config of the app.

I'll file a bug report with Openvpn later as I initially thought it was a Mullvad issue, but the cause seems to be lower level. I have not tried different versions of Openvpn. Note: I did take a brief look through the openvpn sourceforge issues and couldn't see anything similar, or any changelogs with anything that stands out as related to this issue.

My setup is very simple, so I hope that it's easily reproducible for someone else.

Operating system and configuration

Operating system: Debian 11 Bullseye, kernel 5.10.0-14-amd64. Very minimal setup, is running no other software. App version: 2022-1 and 2022-2beta Resolvconf has been disabled to reduce complexity, though the bug still appears with or without it. Ipv6 has been disabled via:

  /etc/sysctl.conf
    net.ipv6.conf.all.disable_ipv6 = 1
    net.ipv6.conf.default.disable_ipv6 = 1
    net.ipv6.conf.lo.disable_ipv6 = 1
  /etc/hosts
    <remove ipv6 lines>

Openvpn package:

$ dpkg -l | grep openvpn
ii  openvpn                              2.5.1-3

/etc/network/interfaces:

auto lo
iface lo inet loopback

auto enp0s3
iface enp0s3 inet static
 address 192.168.0.3
 netmask 255.255.255.0
 broadcast 192.168.0.255
 gateway 192.168.0.1
 dns-nameservers 192.168.0.2

/etc/openvpn/mullvad_xx.conf:

client
dev tun
### I turned on these next two options to match the server and suppress warnings but they don't affect the bug
tun-mtu 1500    
comp-lzo           
resolv-retry infinite
nobind
persist-key
persist-tun
verb 3
remote-cert-tls server
ping 10
ping-restart 60
sndbuf 524288
rcvbuf 524288
cipher AES-256-CBC
tls-cipher TLS-DHE-RSA-WITH-AES-256-GCM-SHA384:TLS-DHE-RSA-WITH-AES-256-CBC-SHA
proto udp4
pull-filter ignore "route-ipv6"
pull-filter ignore "ifconfig-ipv6"
auth-user-pass mullvad_userpass.txt
ca mullvad_ca.crt
#tun-ipv6
script-security 2
up /etc/openvpn/update-resolv-conf
down /etc/openvpn/update-resolv-conf
fast-io
remote-random
remote us-lax-001.mullvad.net 1301
remote us-lax-102.mullvad.net 1301
remote us-lax-007.mullvad.net 1301
remote us-lax-013.mullvad.net 1301
remote us-lax-011.mullvad.net 1301
remote us-lax-008.mullvad.net 1301
remote us-lax-002.mullvad.net 1301
remote us-lax-003.mullvad.net 1301
remote us-lax-012.mullvad.net 1301
remote us-lax-006.mullvad.net 1301
remote us-lax-009.mullvad.net 1301
remote us-lax-005.mullvad.net 1301
remote us-lax-101.mullvad.net 1301
remote us-lax-004.mullvad.net 1301
remote us-lax-010.mullvad.net 1301
remote us-lax-014.mullvad.net 1301

Example Logs with commentary added


-----------------------
Openvpn starts and the connection is working fine:
-----------------------

Jun  8 13:51:12 debian11 ovpn-mullvad_us_lax[522]: DEPRECATED OPTION: --cipher set to 'AES-256-CBC' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM). Future OpenVPN version will ignore --cipher for cipher negotiations. Add 'AES-256-CBC' to --data-ciphers or change --cipher 'AES-256-CBC' to --data-ciphers-fallback 'AES-256-CBC' to silence this warning.
Jun  8 13:51:13 debian11 systemd[1]: Started OpenVPN connection to mullvad_us_lax.
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: WARNING: file 'mullvad_userpass.txt' is group or others accessible
Jun  8 13:51:13 debian11 systemd[1]: Starting Permit User Sessions...
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: OpenVPN 2.5.1 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on May 14 2021
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: library versions: OpenSSL 1.1.1n  15 Mar 2022, LZO 2.10
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: TCP/UDP: Preserving recently used remote address: [AF_INET]198.54.129.74:1301
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: Socket Buffers: R=[212992->425984] S=[212992->425984]
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: UDP link local: (not bound)
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: UDP link remote: [AF_INET]198.54.129.74:1301
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: TLS: Initial packet from [AF_INET]198.54.129.74:1301, sid=b6dabb4f 9de80784
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: VERIFY OK: depth=2, C=SE, ST=Gotaland, L=Gothenburg, O=Amagicom AB, OU=Mullvad, CN=Mullvad Root CA v2, emailAddress=security@mullvad.net
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: VERIFY OK: depth=1, C=SE, ST=Gotaland, O=Amagicom AB, OU=Mullvad, CN=Mullvad Intermediate CA v4, emailAddress=security@mullvad.net
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: VERIFY KU OK
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: Validating certificate extended key usage
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: VERIFY EKU OK
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: VERIFY OK: depth=0, C=SE, ST=Gotaland, O=Amagicom AB, OU=Mullvad, CN=us-lax-102.mullvad.net, emailAddress=security@mullvad.net
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1557', remote='link-mtu 1558'
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: WARNING: 'comp-lzo' is present in remote config but missing in local config, remote='comp-lzo'
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: Control Channel: TLSv1.3, cipher TLSv1.3 TLS_CHACHA20_POLY1305_SHA256, 4096 bit RSA
Jun  8 13:51:13 debian11 ovpn-mullvad_us_lax[522]: [us-lax-102.mullvad.net] Peer Connection Initiated with [AF_INET]198.54.129.74:1301
Jun  8 13:51:13 debian11 ntpd[528]: Soliciting pool server 159.89.86.140
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: SENT CONTROL [us-lax-102.mullvad.net]: 'PUSH_REQUEST' (status=1)
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: PUSH: Received control message: 'PUSH_REPLY,dhcp-option DNS 10.15.0.1,redirect-gateway def1 bypass-dhcp,route-ipv6 0000::/2,route-ipv6 4000::/2,route-ipv6 8000::/2,route-ipv6 C000::/2,comp-lzo no,route-gateway 10.15.0.1,topology subnet,socket-flags TCP_NODELAY,ifconfig-ipv6 fdda:d0d0:cafe:1301::1005/64 fdda:d0d0:cafe:1301::,ifconfig 10.15.0.7 255.255.0.0,peer-id 5,cipher AES-256-GCM'
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: Pushed option removed by filter: 'route-ipv6 0000::/2'
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: Pushed option removed by filter: 'route-ipv6 4000::/2'
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: Pushed option removed by filter: 'route-ipv6 8000::/2'
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: Pushed option removed by filter: 'route-ipv6 C000::/2'
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: Pushed option removed by filter: 'ifconfig-ipv6 fdda:d0d0:cafe:1301::1005/64 fdda:d0d0:cafe:1301::'
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: OPTIONS IMPORT: compression parms modified
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: OPTIONS IMPORT: --socket-flags option modified
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: NOTE: setsockopt TCP_NODELAY=1 failed
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: OPTIONS IMPORT: --ifconfig/up options modified
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: OPTIONS IMPORT: route options modified
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: OPTIONS IMPORT: route-related options modified
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: OPTIONS IMPORT: peer-id set
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: OPTIONS IMPORT: adjusting link_mtu to 1624
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: OPTIONS IMPORT: data channel crypto options modified
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: Data Channel: using negotiated cipher 'AES-256-GCM'
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: net_route_v4_best_gw query: dst 0.0.0.0
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: net_route_v4_best_gw result: via 192.168.0.152 dev enp0s3
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: ROUTE_GATEWAY 192.168.0.152/255.255.255.0 IFACE=enp0s3 HWADDR=08:00:27:f3:bb:1b
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: TUN/TAP device tun0 opened
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: net_iface_mtu_set: mtu 1500 for tun0
Jun  8 13:51:14 debian11 kernel: [   11.311898] tun: Universal TUN/TAP device driver, 1.6
Jun  8 13:51:14 debian11 systemd-udevd[260]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: net_iface_up: set tun0 up
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: net_addr_v4_add: 10.15.0.7/16 dev tun0
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: /etc/openvpn/update-resolv-conf tun0 1500 1552 10.15.0.7 255.255.0.0 init
Jun  8 13:51:14 debian11 root: [OpenVPN:update-resolve-conf] missing binary /sbin/resolvconf
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: net_route_v4_add: 198.54.129.74/32 via 192.168.0.152 dev [NULL] table 0 metric -1
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: net_route_v4_add: 0.0.0.0/1 via 10.15.0.1 dev [NULL] table 0 metric -1
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: net_route_v4_add: 128.0.0.0/1 via 10.15.0.1 dev [NULL] table 0 metric -1
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Jun  8 13:51:14 debian11 ovpn-mullvad_us_lax[522]: Initialization Sequence Completed

-----------------
<Cable is unplugged here after a minute of connectivity>
-----------------

Jun  8 13:54:24 debian11 ovpn-mullvad_us_lax[522]: [us-lax-102.mullvad.net] Inactivity timeout (--ping-restart), restarting
Jun  8 13:54:24 debian11 ovpn-mullvad_us_lax[522]: SIGUSR1[soft,ping-restart] received, process restarting
Jun  8 13:54:24 debian11 ovpn-mullvad_us_lax[522]: Restart pause, 5 second(s)
Jun  8 13:54:29 debian11 ovpn-mullvad_us_lax[522]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun  8 13:54:29 debian11 ovpn-mullvad_us_lax[522]: TCP/UDP: Preserving recently used remote address: [AF_INET]198.54.129.74:1301
Jun  8 13:54:29 debian11 ovpn-mullvad_us_lax[522]: Socket Buffers: R=[212992->425984] S=[212992->425984]
Jun  8 13:54:29 debian11 ovpn-mullvad_us_lax[522]: NOTE: setsockopt TCP_NODELAY=1 failed
Jun  8 13:54:29 debian11 ovpn-mullvad_us_lax[522]: UDP link local: (not bound)
Jun  8 13:54:29 debian11 ovpn-mullvad_us_lax[522]: UDP link remote: [AF_INET]198.54.129.74:1301
Jun  8 13:55:29 debian11 ovpn-mullvad_us_lax[522]: [UNDEF] Inactivity timeout (--ping-restart), restarting
Jun  8 13:55:29 debian11 ovpn-mullvad_us_lax[522]: SIGUSR1[soft,ping-restart] received, process restarting
Jun  8 13:55:29 debian11 ovpn-mullvad_us_lax[522]: Restart pause, 5 second(s)
Jun  8 13:55:34 debian11 ovpn-mullvad_us_lax[522]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun  8 13:55:34 debian11 ovpn-mullvad_us_lax[522]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.46.114.171:1301
Jun  8 13:55:34 debian11 ovpn-mullvad_us_lax[522]: Socket Buffers: R=[212992->425984] S=[212992->425984]
Jun  8 13:55:34 debian11 ovpn-mullvad_us_lax[522]: NOTE: setsockopt TCP_NODELAY=1 failed
Jun  8 13:55:34 debian11 ovpn-mullvad_us_lax[522]: UDP link local: (not bound)
Jun  8 13:55:34 debian11 ovpn-mullvad_us_lax[522]: UDP link remote: [AF_INET]89.46.114.171:1301
Jun  8 13:56:34 debian11 ovpn-mullvad_us_lax[522]: [UNDEF] Inactivity timeout (--ping-restart), restarting
Jun  8 13:56:34 debian11 ovpn-mullvad_us_lax[522]: SIGUSR1[soft,ping-restart] received, process restarting
Jun  8 13:56:34 debian11 ovpn-mullvad_us_lax[522]: Restart pause, 5 second(s)
Jun  8 13:56:39 debian11 ovpn-mullvad_us_lax[522]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun  8 13:56:40 debian11 ovpn-mullvad_us_lax[522]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.46.114.15:1301
Jun  8 13:56:40 debian11 ovpn-mullvad_us_lax[522]: Socket Buffers: R=[212992->425984] S=[212992->425984]
Jun  8 13:56:40 debian11 ovpn-mullvad_us_lax[522]: NOTE: setsockopt TCP_NODELAY=1 failed
Jun  8 13:56:40 debian11 ovpn-mullvad_us_lax[522]: UDP link local: (not bound)
Jun  8 13:56:40 debian11 ovpn-mullvad_us_lax[522]: UDP link remote: [AF_INET]89.46.114.15:1301
Jun  8 13:57:40 debian11 ovpn-mullvad_us_lax[522]: [UNDEF] Inactivity timeout (--ping-restart), restarting
Jun  8 13:57:40 debian11 ovpn-mullvad_us_lax[522]: SIGUSR1[soft,ping-restart] received, process restarting
Jun  8 13:57:40 debian11 ovpn-mullvad_us_lax[522]: Restart pause, 5 second(s)
Jun  8 13:57:45 debian11 ovpn-mullvad_us_lax[522]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun  8 13:57:45 debian11 ovpn-mullvad_us_lax[522]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.46.114.119:1301
Jun  8 13:57:45 debian11 ovpn-mullvad_us_lax[522]: Socket Buffers: R=[212992->425984] S=[212992->425984]
Jun  8 13:57:45 debian11 ovpn-mullvad_us_lax[522]: NOTE: setsockopt TCP_NODELAY=1 failed
Jun  8 13:57:45 debian11 ovpn-mullvad_us_lax[522]: UDP link local: (not bound)
Jun  8 13:57:45 debian11 ovpn-mullvad_us_lax[522]: UDP link remote: [AF_INET]89.46.114.119:1301
Jun  8 13:58:45 debian11 ovpn-mullvad_us_lax[522]: [UNDEF] Inactivity timeout (--ping-restart), restarting
Jun  8 13:58:45 debian11 ovpn-mullvad_us_lax[522]: SIGUSR1[soft,ping-restart] received, process restarting
Jun  8 13:58:45 debian11 ovpn-mullvad_us_lax[522]: Restart pause, 5 second(s)
Jun  8 13:58:50 debian11 ovpn-mullvad_us_lax[522]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun  8 13:58:50 debian11 ovpn-mullvad_us_lax[522]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.46.114.145:1301
Jun  8 13:58:50 debian11 ovpn-mullvad_us_lax[522]: Socket Buffers: R=[212992->425984] S=[212992->425984]
Jun  8 13:58:50 debian11 ovpn-mullvad_us_lax[522]: NOTE: setsockopt TCP_NODELAY=1 failed
Jun  8 13:58:50 debian11 ovpn-mullvad_us_lax[522]: UDP link local: (not bound)
Jun  8 13:58:50 debian11 ovpn-mullvad_us_lax[522]: UDP link remote: [AF_INET]89.46.114.145:1301
Jun  8 13:59:50 debian11 ovpn-mullvad_us_lax[522]: [UNDEF] Inactivity timeout (--ping-restart), restarting
Jun  8 13:59:50 debian11 ovpn-mullvad_us_lax[522]: SIGUSR1[soft,ping-restart] received, process restarting
Jun  8 13:59:50 debian11 ovpn-mullvad_us_lax[522]: Restart pause, 5 second(s)
Jun  8 13:59:55 debian11 ovpn-mullvad_us_lax[522]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun  8 13:59:55 debian11 ovpn-mullvad_us_lax[522]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.46.114.54:1301
Jun  8 13:59:55 debian11 ovpn-mullvad_us_lax[522]: Socket Buffers: R=[212992->425984] S=[212992->425984]
Jun  8 13:59:55 debian11 ovpn-mullvad_us_lax[522]: NOTE: setsockopt TCP_NODELAY=1 failed
Jun  8 13:59:55 debian11 ovpn-mullvad_us_lax[522]: UDP link local: (not bound)
Jun  8 13:59:55 debian11 ovpn-mullvad_us_lax[522]: UDP link remote: [AF_INET]89.46.114.54:1301
Jun  8 14:00:55 debian11 ovpn-mullvad_us_lax[522]: [UNDEF] Inactivity timeout (--ping-restart), restarting
Jun  8 14:00:55 debian11 ovpn-mullvad_us_lax[522]: SIGUSR1[soft,ping-restart] received, process restarting
Jun  8 14:00:55 debian11 ovpn-mullvad_us_lax[522]: Restart pause, 5 second(s)
Jun  8 14:01:00 debian11 ovpn-mullvad_us_lax[522]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun  8 14:01:00 debian11 ovpn-mullvad_us_lax[522]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.46.114.80:1301
Jun  8 14:01:00 debian11 ovpn-mullvad_us_lax[522]: Socket Buffers: R=[212992->425984] S=[212992->425984]
Jun  8 14:01:00 debian11 ovpn-mullvad_us_lax[522]: NOTE: setsockopt TCP_NODELAY=1 failed
Jun  8 14:01:00 debian11 ovpn-mullvad_us_lax[522]: UDP link local: (not bound)
Jun  8 14:01:00 debian11 ovpn-mullvad_us_lax[522]: UDP link remote: [AF_INET]89.46.114.80:1301
Jun  8 14:02:01 debian11 ovpn-mullvad_us_lax[522]: [UNDEF] Inactivity timeout (--ping-restart), restarting
Jun  8 14:02:01 debian11 ovpn-mullvad_us_lax[522]: SIGUSR1[soft,ping-restart] received, process restarting
Jun  8 14:02:01 debian11 ovpn-mullvad_us_lax[522]: Restart pause, 5 second(s)
Jun  8 14:02:06 debian11 ovpn-mullvad_us_lax[522]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun  8 14:02:06 debian11 ovpn-mullvad_us_lax[522]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.46.114.93:1301
Jun  8 14:02:06 debian11 ovpn-mullvad_us_lax[522]: Socket Buffers: R=[212992->425984] S=[212992->425984]
Jun  8 14:02:06 debian11 ovpn-mullvad_us_lax[522]: NOTE: setsockopt TCP_NODELAY=1 failed
Jun  8 14:02:06 debian11 ovpn-mullvad_us_lax[522]: UDP link local: (not bound)
Jun  8 14:02:06 debian11 ovpn-mullvad_us_lax[522]: UDP link remote: [AF_INET]89.46.114.93:1301

-----------------------
<Network cable plugged in at 14:02>
-----------------------

-----------------------
At 14:06:00, there is no other log activity. Sometimes there is more activity but reconnection does not 
happen. However, if "persist-tun" is disabled, this happens, and Openvpn correctly reconnects:
-----------------------

Jun  8 14:57:16 debian11 ovpn-mullvad_us_lax[1134]: [UNDEF] Inactivity timeout (--ping-restart), restarting
Jun  8 14:57:16 debian11 ovpn-mullvad_us_lax[1134]: SIGUSR1[soft,ping-restart] received, process restarting
Jun  8 14:57:16 debian11 ovpn-mullvad_us_lax[1134]: Restart pause, 5 second(s)
Jun  8 14:57:21 debian11 ovpn-mullvad_us_lax[1134]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Jun  8 14:57:21 debian11 ovpn-mullvad_us_lax[1134]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.46.114.184:1301
Jun  8 14:57:21 debian11 ovpn-mullvad_us_lax[1134]: Socket Buffers: R=[212992->425984] S=[212992->425984]
Jun  8 14:57:21 debian11 ovpn-mullvad_us_lax[1134]: NOTE: setsockopt TCP_NODELAY=1 failed
Jun  8 14:57:21 debian11 ovpn-mullvad_us_lax[1134]: UDPv4 link local: (not bound)
Jun  8 14:57:21 debian11 ovpn-mullvad_us_lax[1134]: UDPv4 link remote: [AF_INET]89.46.114.184:1301
Jun  8 14:57:52 debian11 ovpn-mullvad_us_lax[1134]: TLS: Initial packet from [AF_INET]89.46.114.184:1301, sid=821afba6 6f952956
Jun  8 14:57:52 debian11 ovpn-mullvad_us_lax[1134]: VERIFY OK: depth=2, C=SE, ST=Gotaland, L=Gothenburg, O=Amagicom AB, OU=Mullvad, CN=Mullvad Root CA v2, emailAddress=security@mullvad.net
Jun  8 14:57:52 debian11 ovpn-mullvad_us_lax[1134]: VERIFY OK: depth=1, C=SE, ST=Gotaland, O=Amagicom AB, OU=Mullvad, CN=Mullvad Intermediate CA v4, emailAddress=security@mullvad.net
Jun  8 14:57:52 debian11 ovpn-mullvad_us_lax[1134]: VERIFY KU OK
Jun  8 14:57:52 debian11 ovpn-mullvad_us_lax[1134]: Validating certificate extended key usage
Jun  8 14:57:52 debian11 ovpn-mullvad_us_lax[1134]: ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Jun  8 14:57:52 debian11 ovpn-mullvad_us_lax[1134]: VERIFY EKU OK
Jun  8 14:57:52 debian11 ovpn-mullvad_us_lax[1134]: VERIFY OK: depth=0, C=SE, ST=Gotaland, O=Amagicom AB, OU=Mullvad, CN=us-lax-014.mullvad.net, emailAddress=security@mullvad.net
Jun  8 14:57:52 debian11 ovpn-mullvad_us_lax[1134]: Control Channel: TLSv1.3, cipher TLSv1.3 TLS_CHACHA20_POLY1305_SHA256, 4096 bit RSA
Jun  8 14:57:52 debian11 ovpn-mullvad_us_lax[1134]: [us-lax-014.mullvad.net] Peer Connection Initiated with [AF_INET]89.46.114.184:1301
Jun  8 14:57:53 debian11 ovpn-mullvad_us_lax[1134]: SENT CONTROL [us-lax-014.mullvad.net]: 'PUSH_REQUEST' (status=1)
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: SENT CONTROL [us-lax-014.mullvad.net]: 'PUSH_REQUEST' (status=1)
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: PUSH: Received control message: 'PUSH_REPLY,dhcp-option DNS 10.15.0.1,redirect-gateway def1 bypass-dhcp,route-ipv6 0000::/2,route-ipv6 4000::/2,route-ipv6 8000::/2,route-ipv6 C000::/2,comp-lzo no,route-gateway 10.15.0.1,topology subnet,socket-flags TCP_NODELAY,ifconfig-ipv6 fdda:d0d0:cafe:1301::1000/64 fdda:d0d0:cafe:1301::,ifconfig 10.15.0.2 255.255.0.0,peer-id 0,cipher AES-256-GCM'
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: Pushed option removed by filter: 'route-ipv6 0000::/2'
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: Pushed option removed by filter: 'route-ipv6 4000::/2'
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: Pushed option removed by filter: 'route-ipv6 8000::/2'
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: Pushed option removed by filter: 'route-ipv6 C000::/2'
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: Pushed option removed by filter: 'ifconfig-ipv6 fdda:d0d0:cafe:1301::1000/64 fdda:d0d0:cafe:1301::'
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: OPTIONS IMPORT: compression parms modified
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: OPTIONS IMPORT: --socket-flags option modified
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: NOTE: setsockopt TCP_NODELAY=1 failed
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: OPTIONS IMPORT: --ifconfig/up options modified
Jun  8 14:57:58 debian11 systemd-udevd[1159]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: OPTIONS IMPORT: route options modified
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: OPTIONS IMPORT: route-related options modified
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: OPTIONS IMPORT: peer-id set
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: OPTIONS IMPORT: adjusting link_mtu to 1625
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: OPTIONS IMPORT: data channel crypto options modified
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: Data Channel: using negotiated cipher 'AES-256-GCM'
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: net_route_v4_best_gw query: dst 0.0.0.0
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: net_route_v4_best_gw result: via 192.168.0.152 dev enp0s3
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: ROUTE_GATEWAY 192.168.0.152/255.255.255.0 IFACE=enp0s3 HWADDR=08:00:27:f3:bb:1b
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: TUN/TAP device tun0 opened
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: net_iface_mtu_set: mtu 1500 for tun0
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: net_iface_up: set tun0 up
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: net_addr_v4_add: 10.15.0.2/16 dev tun0
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: /etc/openvpn/update-resolv-conf tun0 1500 1553 10.15.0.2 255.255.0.0 init
Jun  8 14:57:58 debian11 root: [OpenVPN:update-resolve-conf] missing binary /sbin/resolvconf
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: net_route_v4_add: 89.46.114.184/32 via 192.168.0.152 dev [NULL] table 0 metric -1
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: net_route_v4_add: 0.0.0.0/1 via 10.15.0.1 dev [NULL] table 0 metric -1
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: net_route_v4_add: 128.0.0.0/1 via 10.15.0.1 dev [NULL] table 0 metric -1
Jun  8 14:57:58 debian11 ovpn-mullvad_us_lax[1134]: Initialization Sequence Completed
pinkisemils commented 2 years ago

I see you've posted a lot of logs about a vanilla OpenVPN, but this repository is only really meant to deal with our client. Our client doesn't pass the --persist-tun argument to our OpenVPN instance, and it isn't enabled by default. If you believe there's an issue with the generated config files, I suggest you email support.

Having tested this by just blocking traffic to a specific relay via a firewall, when using UDP and TCP, our client enters the reconnecting state and will attempt to connect to a different relay unless the user informs it to stop. And once connectivity returns, the client will end up connecting back. I also suggest using WireGuard, be it with our or regular clients, as it will help immensely with reconnecting quicker. However, if there are issues with the app not recovering after trying to reconnect for several minutes, I suggest sending a problem report from the app as it will make it at lot easier to understand what's going on. Also, it'd be interesting to see what ip route get default returns when you've lost connectivity.