Comment 9 for bug 1700079

Revision history for this message
Marius Gedminas (mgedmin) wrote :

Bug still there in 18.04.5 LTS. Had an unattended security upgrade of openvpn on May 5, which shut down the old ovpn-server:

    | May 05 06:14:19 fridge ovpn-server[3384]: event_wait : Interrupted system call (code=4)
    | May 05 06:14:19 fridge ovpn-server[3384]: /sbin/ip route del 10.8.0.0/24
    | May 05 06:14:19 fridge ovpn-server[3384]: openvpn_execve: unable to fork: Resource temporarily unavailable (errno=11)
    | May 05 06:14:19 fridge ovpn-server[3384]: Exiting due to fatal error

and started a new one

    | May 05 06:14:19 fridge ovpn-server[13115]: OpenVPN 2.4.4 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Apr 27 2021
    ...
    | May 05 06:14:19 fridge ovpn-server[13116]: /sbin/ip link set dev tun1 up mtu 1500
    | May 05 06:14:19 fridge ovpn-server[13116]: /sbin/ip addr add dev tun1 local 10.8.0.1 peer 10.8.0.2
    | May 05 06:14:19 fridge ovpn-server[13116]: /sbin/ip route add 10.8.0.0/24 via 10.8.0.2
    | May 05 06:14:19 fridge ovpn-server[13116]: ERROR: Linux route add command failed: external program exited with error status: 2

and then clients could connect to the VPN server but did not get any network connectivity through it.

I'm wondering if there's a race between the old ovpn-server running /sbin/ip route del vs the new opvpn-server running /sbin/ip route add?

Also curiously systemctl status openvpn@server a few days later showed

    | ● <email address hidden> - OpenVPN connection to server
    | Loaded: loaded (/lib/systemd/system/openvpn@.service; indirect; vendor preset: enabled)
    | Active: active (running) since Fri 2021-04-16 07:36:38 EEST; 3 weeks 0 days ago
    | Docs: man:openvpn(8)
    | https://community.openvpn.net/openvpn/wiki/Openvpn24ManPage
    | https://community.openvpn.net/openvpn/wiki/HOWTO
    | Main PID: 13116 (openvpn)
    | Status: "Initialization Sequence Completed"
    | Tasks: 0 (limit: 4915)
    | CGroup: /<email address hidden>
    | ‣ 13116 /usr/sbin/openvpn --writepid /run/openvpn/server.pid --daemon ovpn-server --cd /etc/openvpn --config /etc/openvpn/server.conf
    |
    | May 04 19:36:22 fridge ovpn-server[3384]: laurynas2/78.58.248.51:52905 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
    | May 04 19:36:22 fridge ovpn-server[3384]: laurynas2/78.58.248.51:52905 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
    | May 04 19:36:22 fridge ovpn-server[3384]: laurynas2/78.58.248.51:52905 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
    | May 04 20:22:09 fridge ovpn-server[3384]: laurynas2/78.58.248.51:52905 [laurynas2] Inactivity timeout (--ping-restart), restarting
    | May 04 20:22:09 fridge ovpn-server[3384]: laurynas2/78.58.248.51:52905 SIGUSR1[soft,ping-restart] received, client-instance restarting
    | May 05 00:43:45 fridge ovpn-server[3384]: TLS Error: cannot locate HMAC in incoming packet from [AF_INET]185.200.118.51:33488
    | May 05 06:14:19 fridge ovpn-server[3384]: event_wait : Interrupted system call (code=4)
    | May 05 06:14:19 fridge ovpn-server[3384]: /sbin/ip route del 10.8.0.0/24
    | May 05 06:14:19 fridge ovpn-server[3384]: openvpn_execve: unable to fork: Resource temporarily unavailable (errno=11)
    | May 05 06:14:19 fridge ovpn-server[3384]: Exiting due to fatal error

i.e. the PID was of the new instance, but all the log entries were from the old instance.

A service openvpn@server restart fixed everything.