Package: network-manager Version: 1.0.6-1 Severity: normal 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. -- System Information: Debian Release: stretch/sid APT prefers testing APT policy: (990, 'testing'), (500, 'unstable'), (1, 'experimental') Architecture: amd64 (x86_64) Foreign Architectures: i386 Kernel: Linux 4.1.0-2-amd64 (SMP w/4 CPU cores) Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8) Shell: /bin/sh linked to /bin/dash Init: systemd (via /run/systemd/system) Versions of packages network-manager depends on: ii adduser 3.113+nmu3 ii dbus 1.10.0-3 ii init-system-helpers 1.23 ii isc-dhcp-client 4.3.3-3 ii libbluetooth3 5.33-1 ii libc6 2.19-20 ii libdbus-1-3 1.10.0-3 ii libdbus-glib-1-2 0.102-1 ii libglib2.0-0 2.44.1-1.1 ii libgnutls-deb0-28 3.3.17-1 ii libgudev-1.0-0 230-2 ii libmm-glib0 1.4.10-1 ii libndp0 1.4-2 ii libnewt0.52 0.52.18-1 ii libnl-3-200 3.2.26-1 ii libnl-genl-3-200 3.2.26-1 ii libnl-route-3-200 3.2.26-1 ii libnm0 1.0.6-1 ii libpam-systemd 225-1 ii libpolkit-agent-1-0 0.105-12 ii libpolkit-gobject-1-0 0.105-12 ii libreadline6 6.3-8+b3 ii libsoup2.4-1 2.50.0-2 ii libsystemd0 225-1 ii libteamdctl0 1.18-1 ii libuuid1 2.26.2-9 ii lsb-base 9.20150826 ii policykit-1 0.105-12 ii udev 225-1 ii wpasupplicant 2.3-2.1 Versions of packages network-manager recommends: ii crda 3.13-1 ii dnsmasq-base 2.75-1 ii iptables 1.4.21-2+b1 ii iputils-arping 3:20121221-5+b2 pn modemmanager <none> pn ppp <none> Versions of packages network-manager suggests: ii avahi-autoipd 0.6.31-5 pn libteam-utils <none> -- Configuration Files: /etc/NetworkManager/NetworkManager.conf changed: [main] plugins=ifupdown,keyfile no-auto-default= [ifupdown] managed=false -- no debconf information
