I'm experiencing this with network-manager-openvpn, but a quick grep through
the source suggests it is a bug in the core network-manager vpn support and
not in the openvpn plugin itself.
Scenario:
* Start a VPN connection that requires entering secrets (e.g. openvpn with
the PAM plugin on the server)
* Accidentally fat-finger the password
* Reconnect immediately and type the password correctly this time
* Wait a minute and watch NM kill the successfully started VPN
Syslog:
Starting the connection and fat fingering the password:
Sep 22 09:50:23 xyzzy NetworkManager[848]: (nm-openvpn-service:20864): nm-openvpn-WARNING **: (nm-openvpn-service.c:1269):nm_openvpn_start_openvpn_binary: runtime check failed: (priv->mgt_path == NULL)
Sep 22 09:50:23 xyzzy NetworkManager[848]: <info> VPN plugin state changed: starting (3)
Sep 22 09:50:23 xyzzy NetworkManager[848]: nm-openvpn-Message: openvpn started with pid 22961
Sep 22 09:50:23 xyzzy NetworkManager[848]: <info> VPN connection 'xyzzy' (Connect) reply received.
Sep 22 09:50:23 xyzzy nm-openvpn[22961]: OpenVPN 2.3.7 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Sep 8 2015
Sep 22 09:50:23 xyzzy nm-openvpn[22961]: library versions: OpenSSL 1.0.2d 9 Jul 2015, LZO 2.08
Sep 22 09:50:23 xyzzy nm-openvpn[22961]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Sep 22 09:50:23 xyzzy nm-openvpn[22961]: NOTE: chroot will be delayed because of --client, --pull, or --up-delay
Sep 22 09:50:23 xyzzy nm-openvpn[22961]: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
Sep 22 09:50:23 xyzzy nm-openvpn[22961]: UDPv4 link local: [undef]
Sep 22 09:50:23 xyzzy nm-openvpn[22961]: UDPv4 link remote: [AF_INET]xyzzyip:xyzzyport
Sep 22 09:50:25 xyzzy nm-openvpn[22961]: [server] Peer Connection Initiated with [AF_INET]xyzzyip:xyzzyport
Sep 22 09:50:27 xyzzy nm-openvpn[22961]: AUTH: Received control message: AUTH_FAILED
Sep 22 09:50:27 xyzzy nm-openvpn[22961]: SIGUSR1[soft,auth-failure] received, process restarting
Sep 22 09:50:27 xyzzy NetworkManager[848]: <warn> VPN plugin failed: login-failed (0)
Sep 22 09:50:27 xyzzy NetworkManager[848]: <info> VPN plugin state changed: stopped (6)
Sep 22 09:50:27 xyzzy NetworkManager[848]: <info> VPN plugin state change reason: login-failed (10)
Sep 22 09:50:27 xyzzy NetworkManager[848]: (nm-openvpn-service:20864): nm-openvpn-WARNING **: Password verification failed
Sep 22 09:50:27 xyzzy NetworkManager[848]: <warn> error disconnecting VPN: Could not process the request because no VPN connection was active.
Oops, reconnect!
Sep 22 09:50:31 xyzzy NetworkManager[848]: (nm-openvpn-service:20864): nm-openvpn-WARNING **: (nm-openvpn-service.c:1269):nm_openvpn_start_openvpn_binary: runtime check failed: (priv->mgt_path == NULL)
Sep 22 09:50:31 xyzzy NetworkManager[848]: nm-openvpn-Message: openvpn started with pid 23033
Sep 22 09:50:31 xyzzy NetworkManager[848]: <info> VPN plugin state changed: starting (3)
Sep 22 09:50:31 xyzzy NetworkManager[848]: <info> VPN connection 'xyzzy' (Connect) reply received.
Sep 22 09:50:31 xyzzy nm-openvpn[23033]: OpenVPN 2.3.7 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Sep 8 2015
Sep 22 09:50:31 xyzzy nm-openvpn[23033]: library versions: OpenSSL 1.0.2d 9 Jul 2015, LZO 2.08
Sep 22 09:50:32 xyzzy nm-openvpn[23033]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Sep 22 09:50:32 xyzzy nm-openvpn[23033]: NOTE: chroot will be delayed because of --client, --pull, or --up-delay
Sep 22 09:50:32 xyzzy nm-openvpn[23033]: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
Sep 22 09:50:32 xyzzy nm-openvpn[23033]: UDPv4 link local: [undef]
Sep 22 09:50:32 xyzzy nm-openvpn[23033]: UDPv4 link remote: [AF_INET]xyzzyip:xyzzyport
Sep 22 09:50:33 xyzzy nm-openvpn[23033]: [server] Peer Connection Initiated with [AF_INET]xyzzyip:xyzzyport
Sep 22 09:50:35 xyzzy nm-openvpn[23033]: TUN/TAP device tap0 opened
Sep 22 09:50:35 xyzzy nm-openvpn[23033]: /usr/lib/NetworkManager/nm-openvpn-service-openvpn-helper --tap -- tap0 1500 1574 xyzzy 255.255.255.0 init
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): new Tun device (carrier: OFF, driver: 'tun', ifindex: 6)
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> devices added (path: /sys/devices/virtual/net/tap0, iface: tap0)
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> device added (path: /sys/devices/virtual/net/tap0, iface: tap0): no ifupdown configuration found.
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> VPN connection 'xyzzy' (IP Config Get) reply received.
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> VPN connection 'xyzzy' (IP4 Config Get) reply received.
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> VPN plugin state changed: started (4)
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> VPN connection 'xyzzy' (IP6 Config Get) reply received.
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> VPN Gateway: xyzzyip
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> Tunnel Device: tap0
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> IPv4 configuration:
blahblahblah
Sep 22 09:50:35 xyzzy nm-openvpn[23033]: chroot to '/var/lib/openvpn/chroot' and cd to '/' succeeded
Sep 22 09:50:35 xyzzy nm-openvpn[23033]: GID set to nm-openvpn
Sep 22 09:50:35 xyzzy nm-openvpn[23033]: UID set to nm-openvpn
Sep 22 09:50:35 xyzzy nm-openvpn[23033]: Initialization Sequence Completed
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> IPv6 configuration:
blahblahblah
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> VPN connection 'xyzzy' (IP Config Get) complete.
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): link connected
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> keyfile: add connection in-memory (25d87337-a0de-4b1f-bd2e-1fa21d08ef81,"tap0")
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): device state change: unmanaged -> unavailable (reason 'connection-assumed') [10 20 41]
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): device state change: unavailable -> disconnected (reason 'connection-assumed') [20 30 41]
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): Activation: starting connection 'tap0' (25d87337-a0de-4b1f-bd2e-1fa21d08ef81)
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): device state change: prepare -> config (reason 'none') [40 50 0]
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): device state change: config -> ip-config (reason 'none') [50 70 0]
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): device state change: ip-config -> ip-check (reason 'none') [70 80 0]
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): device state change: ip-check -> secondaries (reason 'none') [80 90 0]
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): device state change: secondaries -> activated (reason 'none') [90 100 0]
Sep 22 09:50:35 xyzzy dbus[880]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> Policy set 'tap0' (tap0) as default for IPv4 routing and DNS.
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> Policy set 'tap0' (tap0) as default for IPv6 routing and DNS.
Sep 22 09:50:35 xyzzy NetworkManager[848]: <info> (tap0): Activation: successful, device activated.
Sep 22 09:50:35 xyzzy dbus[880]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Sep 22 09:50:35 xyzzy nm-dispatcher: Dispatching action 'vpn-up' for tap0
Sep 22 09:50:37 xyzzy nm-dispatcher: Dispatching action 'up' for tap0
And then, the bug: the connect timer from the first failed attempt fires,
and kills the second sucessful attempt :(
Sep 22 09:51:23 xyzzy NetworkManager[848]: libnm-glib-Message: Connect timer expired, disconnecting.
Sep 22 09:51:23 xyzzy NetworkManager[848]: nm-openvpn-Message: Terminated openvpn daemon with PID 23033.