Bug 1164696

Summary: networkmanager-openvpn fails to connect
Product: [Fedora] Fedora Reporter: Minus Zero <minuszero>
Component: selinux-policy-targetedAssignee: Miroslav Grepl <mgrepl>
Status: CLOSED ERRATA QA Contact: Ben Levenson <benl>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 21CC: choeger, dcbw, dwalsh, huzaifas, jklimes, minuszero, patrick, psimerda, steve, thaller
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: selinux-policy-3.13.1-99.fc21 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-12-03 17:15:38 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Minus Zero 2014-11-17 07:48:11 UTC 
After the latest update of networkmanager-openvpn I am not able to connect. When I tried to edit the connection the VPN tab was missing. It was also missing when trying to add a new vpn connection.

Version:
NetworkManager-openvpn-0.9.9.0-3.20141110gitda5fb9b.fc21.x86_64

I tried connecting with l2tp and pptp, but it was also failing to connect, though the vpn tab was there for both.
Comment 1 Jirka Klimes 2014-11-18 09:18:33 UTC 
Do you have NetworkManager-openvpn-gnome installed? Can you attach logs (/var/log/messages or from the journal)?
Comment 2 Patrick Laimbock 2014-11-18 10:26:13 UTC 
I also see an AVC when trying to setup an OpenVPN link from NetworkManager.

NetworkManager-openvpn-gnome is installed:

# rpm -qa | grep NetworkManager | sort
NetworkManager-0.9.10.0-13.git20140704.fc21.x86_64
NetworkManager-config-connectivity-fedora-0.9.10.0-13.git20140704.fc21.x86_64
NetworkManager-glib-0.9.10.0-13.git20140704.fc21.x86_64
NetworkManager-l2tp-0.9.8.7-3.fc21.x86_64
NetworkManager-openconnect-0.9.8.4-4.fc21.x86_64
NetworkManager-openvpn-0.9.9.0-3.20141110gitda5fb9b.fc21.x86_64
NetworkManager-openvpn-gnome-0.9.9.0-3.20141110gitda5fb9b.fc21.x86_64
NetworkManager-pptp-0.9.8.2-6.fc21.x86_64
NetworkManager-pptp-gnome-0.9.8.2-6.fc21.x86_64
NetworkManager-vpnc-0.9.9.0-6.git20140428.fc21.x86_64
NetworkManager-vpnc-gnome-0.9.9.0-6.git20140428.fc21.x86_64
NetworkManager-wifi-0.9.10.0-13.git20140704.fc21.x86_64


Here is the output from /var/log/messages:

Nov 18 11:22:24 silver NetworkManager[923]: <info> Starting VPN service 'openvpn'...
Nov 18 11:22:24 silver NetworkManager[923]: <info> VPN service 'openvpn' started (org.freedesktop.NetworkManager.openvpn), PID 7256
Nov 18 11:22:24 silver NetworkManager[923]: <info> VPN service 'openvpn' appeared; activating connections
Nov 18 11:22:24 silver NetworkManager[923]: <info> VPN plugin state changed: starting (3)
Nov 18 11:22:24 silver NetworkManager: nm-openvpn-Message: openvpn started with pid 7258
Nov 18 11:22:24 silver NetworkManager[923]: <info> VPN connection 'Office' (ConnectInteractive) reply received.
Nov 18 11:22:24 silver nm-openvpn[7258]: OpenVPN 2.3.4 x86_64-redhat-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Aug 26 2014
Nov 18 11:22:24 silver nm-openvpn[7258]: library versions: OpenSSL 1.0.1j-fips 15 Oct 2014, LZO 2.08
Nov 18 11:22:24 silver nm-openvpn[7258]: MANAGEMENT: Socket bind[4] failed on unix domain socket /var/run/NetworkManager/nm-openvpn-6b0e2c5d-021f-451b-96e2-6a30c80ca417: Permission denied
Nov 18 11:22:24 silver nm-openvpn[7258]: Exiting due to fatal error
Nov 18 11:22:24 silver dbus[843]: [system] Activating service name='org.fedoraproject.Setroubleshootd' (using servicehelper)
Nov 18 11:22:24 silver NetworkManager: (nm-openvpn-service:7256): nm-openvpn-WARNING **: openvpn exited with error code 1
Nov 18 11:22:24 silver NetworkManager[923]: <warn> VPN plugin failed: connect-failed (1)
Nov 18 11:22:24 silver NetworkManager[923]: <info> VPN plugin state changed: stopped (6)
Nov 18 11:22:24 silver NetworkManager[923]: <info> VPN plugin state change reason: unknown (0)
Nov 18 11:22:24 silver NetworkManager[923]: <warn> error disconnecting VPN: Could not process the request because no VPN connection was active.
Nov 18 11:22:24 silver gnome-session: (gnome-shell:1957): libnm-glib-WARNING **: async_got_type: could not read properties for /org/freedesktop/NetworkManager/ActiveConnection/10: Method "Get" with signature "ss" on interface "org.freedesktop.DBus.Properties" doesn't exist
Nov 18 11:22:24 silver gnome-session: (gnome-shell:1957): libnm-glib-WARNING **: Device activation failed: (1) Creating object for path '/org/freedesktop/NetworkManager/ActiveConnection/10' failed in libnm-glib.
Nov 18 11:22:25 silver dbus[843]: [system] Successfully activated service 'org.fedoraproject.Setroubleshootd'
Nov 18 11:22:25 silver setroubleshoot: SELinux is preventing openvpn from search access on the directory NetworkManager. For complete SELinux messages. run sealert -l d1553576-8e12-483b-ad8c-38eea87829b1
Nov 18 11:22:25 silver python: SELinux is preventing openvpn from search access on the directory NetworkManager.

*****  Plugin catchall (100. confidence) suggests   **************************

If you believe that openvpn should be allowed search access on the NetworkManager directory by default.
Then you should report this as a bug.
You can generate a local policy module to allow this access.
Do
allow this access for now by executing:
# grep openvpn /var/log/audit/audit.log | audit2allow -M mypol
# semodule -i mypol.pp
Comment 3 Minus Zero 2014-11-19 07:37:56 UTC 
Yes NetworkManager-openvpn-gnome is installed.

/var/logs/messages

Nov 19 09:13:24 localhost NetworkManager[919]: <info> Starting VPN service 'openvpn'...
Nov 19 09:13:24 localhost NetworkManager[919]: <info> VPN service 'openvpn' started (org.freedesktop.NetworkManager.openvpn), PID 2454
Nov 19 09:13:24 localhost kernel: [  515.504806] tun: Universal TUN/TAP device driver, 1.6
Nov 19 09:13:24 localhost kernel: [  515.504812] tun: (C) 1999-2004 Max Krasnyansky <maxk>
Nov 19 09:13:24 localhost kernel: tun: Universal TUN/TAP device driver, 1.6
Nov 19 09:13:24 localhost kernel: tun: (C) 1999-2004 Max Krasnyansky <maxk>
Nov 19 09:13:24 localhost NetworkManager[919]: <info> VPN service 'openvpn' appeared; activating connections
Nov 19 09:13:24 localhost NetworkManager[919]: <info> VPN plugin state changed: init (1)
Nov 19 09:13:24 localhost NetworkManager[919]: <info> VPN plugin state changed: starting (3)
Nov 19 09:13:24 localhost NetworkManager: nm-openvpn-Message: openvpn started with pid 2463
Nov 19 09:13:24 localhost NetworkManager[919]: <info> VPN connection 'PIA' (ConnectInteractive) reply received.
Nov 19 09:13:24 localhost nm-openvpn[2463]: OpenVPN 2.3.4 x86_64-redhat-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Aug 26 2014
Nov 19 09:13:24 localhost nm-openvpn[2463]: library versions: OpenSSL 1.0.1j-fips 15 Oct 2014, LZO 2.08
Nov 19 09:13:24 localhost nm-openvpn[2463]: MANAGEMENT: Socket bind[4] failed on unix domain socket /var/run/NetworkManager/nm-openvpn-b508d3c6-c5a2-42cc-8ae4-cead1547091f: Permission denied
Nov 19 09:13:24 localhost nm-openvpn[2463]: Exiting due to fatal error
Nov 19 09:13:24 localhost NetworkManager: (nm-openvpn-service:2454): nm-openvpn-WARNING **: openvpn exited with error code 1
Nov 19 09:13:24 localhost NetworkManager[919]: <warn> VPN plugin failed: connect-failed (1)
Nov 19 09:13:24 localhost NetworkManager[919]: <info> VPN plugin state changed: stopped (6)
Nov 19 09:13:24 localhost NetworkManager[919]: <info> VPN plugin state change reason: unknown (0)
Nov 19 09:13:24 localhost NetworkManager[919]: <warn> error disconnecting VPN: Could not process the request because no VPN connection was active.
Nov 19 09:13:27 localhost NetworkManager[919]: <info> Starting VPN service 'l2tp'...
Nov 19 09:13:27 localhost NetworkManager[919]: <info> VPN service 'l2tp' started (org.freedesktop.NetworkManager.l2tp), PID 2470
Nov 19 09:13:27 localhost NetworkManager[919]: <info> VPN service 'l2tp' appeared; activating connections
Nov 19 09:13:27 localhost NetworkManager[919]: <info> VPN plugin state changed: init (1)
Nov 19 09:13:27 localhost NetworkManager[919]: <info> VPN connection 'VPN connection 1' (ConnectInteractive) reply received.
Nov 19 09:13:27 localhost NetworkManager[919]: <info> VPN plugin state changed: starting (3)
Nov 19 09:13:27 localhost NetworkManager[919]: <info> VPN connection 'VPN connection 1' (Connect) reply received.
Nov 19 09:13:27 localhost NetworkManager[919]: <warn> VPN connection 'VPN connection 1' failed to connect: 'couldn't look up L2TP VPN gateway IP address 'sweden.internetprivateaccess.com' (-2)'.
Nov 19 09:13:27 localhost NetworkManager[919]: <warn> error disconnecting VPN: Could not process the request because no VPN connection was active.
Nov 19 09:13:29 localhost NetworkManager[919]: <info> Starting VPN service 'pptp'...
Nov 19 09:13:29 localhost NetworkManager[919]: <info> VPN service 'pptp' started (org.freedesktop.NetworkManager.pptp), PID 2477
Nov 19 09:13:29 localhost NetworkManager[919]: <info> VPN service 'pptp' appeared; activating connections
Nov 19 09:13:29 localhost NetworkManager[919]: <info> VPN plugin state changed: init (1)
Nov 19 09:13:29 localhost NetworkManager[919]: <info> VPN connection 'VPN connection 2' (ConnectInteractive) reply received.
Nov 19 09:13:29 localhost NetworkManager[919]: <info> VPN plugin state changed: starting (3)
Nov 19 09:13:29 localhost NetworkManager[919]: <info> VPN connection 'VPN connection 2' (Connect) reply received.
Nov 19 09:13:29 localhost NetworkManager[919]: <warn> VPN connection 'VPN connection 2' failed to connect: 'couldn't look up PPTP VPN gateway IP address 'sweden.internetprivateaccess.com' (-2)'.
Nov 19 09:13:30 localhost NetworkManager[919]: <warn> error disconnecting VPN: Could not process the request because no VPN connection was active.
Nov 19 09:13:38 localhost dbus[776]: [system] Activating via systemd: service name='net.reactivated.Fprint' unit='fprintd.service'
Nov 19 09:13:38 localhost dbus[776]: [system] Successfully activated service 'net.reactivated.Fprint'
Nov 19 09:13:38 localhost fprintd: Launching FprintObject
Nov 19 09:13:38 localhost fprintd: ** Message: D-Bus service launched with name: net.reactivated.Fprint
Nov 19 09:13:38 localhost fprintd: ** Message: entering main loop
Nov 19 09:13:44 localhost NetworkManager[919]: <info> VPN service 'openvpn' disappeared
Nov 19 09:13:47 localhost NetworkManager: (nm-l2tp-service:2470): GLib-CRITICAL **: Source ID 7 was not found when attempting to remove it
Nov 19 09:13:47 localhost NetworkManager[919]: <info> VPN service 'l2tp' disappeared
Nov 19 09:13:50 localhost NetworkManager: (nm-pptp-service:2477): GLib-CRITICAL **: Source ID 7 was not found when attempting to remove it
Nov 19 09:13:50 localhost NetworkManager[919]: <info> VPN service 'pptp' disappeared
Nov 19 09:14:08 localhost fprintd: ** Message: No devices in use, exit
Comment 4 Jirka Klimes 2014-11-21 09:05:51 UTC 
(In reply to Patrick Laimbock from comment #2)
> I also see an AVC when trying to setup an OpenVPN link from NetworkManager.
> 
> Nov 18 11:22:24 silver nm-openvpn[7258]: library versions: OpenSSL
> 1.0.1j-fips 15 Oct 2014, LZO 2.08
> Nov 18 11:22:24 silver nm-openvpn[7258]: MANAGEMENT: Socket bind[4] failed
> on unix domain socket
> /var/run/NetworkManager/nm-openvpn-6b0e2c5d-021f-451b-96e2-6a30c80ca417:
> Permission denied
> Nov 18 11:22:24 silver nm-openvpn[7258]: Exiting due to fatal error

Well this is due to a SELinux denial. Latest NetworkManager-openvpn update uses unix domain socket instead of TCP socket. So the SELinux policy needs updating.

nm-openvpn-service uses /run/NetworkManager/nm-openvpn-<uuid> file as a management socket to communicate with openvpn.
More info in commit https://git.gnome.org/browse/network-manager-openvpn/commit/?id=790477334c8e24eb93b00385b5c6ab8a7a0de888

Please, update the SELinux policies for that.

AVC:
===
time->Fri Nov 21 09:33:28 2014
type=PROCTITLE msg=audit(1416558808.300:528): proctitle=2F7573722F7362696E2F6F70656E76706E002D2D72656D6F7465006F76706E2D706878322E7265646861742E636F6D003131393400756470002D2D6E6F62696E64002D2D6465760074756E002D2D617574682D6E6F6361636865002D2D7379736C6F67006E6D2D6F70656E76706E002D2D7363726970742D7365637572697479
type=SYSCALL msg=audit(1416558808.300:528): arch=c000003e syscall=87 success=no exit=-2 a0=7fc68a0e8466 a1=0 a2=8 a3=21 items=0 ppid=2684 pid=2696 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="openvpn" exe="/usr/sbin/openvpn" subj=system_u:system_r:openvpn_t:s0 key=(null)
type=AVC msg=audit(1416558808.300:528): avc:  denied  { search } for  pid=2696 comm="openvpn" name="NetworkManager" dev="tmpfs" ino=18803 scontext=system_u:system_r:openvpn_t:s0 tcontext=system_u:object_r:NetworkManager_var_run_t:s0 tclass=dir permissive=1
----
time->Fri Nov 21 09:33:28 2014
type=PROCTITLE msg=audit(1416558808.300:529): proctitle=2F7573722F7362696E2F6F70656E76706E002D2D72656D6F7465006F76706E2D706878322E7265646861742E636F6D003131393400756470002D2D6E6F62696E64002D2D6465760074756E002D2D617574682D6E6F6361636865002D2D7379736C6F67006E6D2D6F70656E76706E002D2D7363726970742D7365637572697479
type=SYSCALL msg=audit(1416558808.300:529): arch=c000003e syscall=49 success=yes exit=0 a0=4 a1=7fc68a0e8464 a2=6e a3=21 items=0 ppid=2684 pid=2696 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="openvpn" exe="/usr/sbin/openvpn" subj=system_u:system_r:openvpn_t:s0 key=(null)
type=AVC msg=audit(1416558808.300:529): avc:  denied  { create } for  pid=2696 comm="openvpn" name="nm-openvpn-9e87e0fb-46b6-42cd-9d46-041f005b98c5" scontext=system_u:system_r:openvpn_t:s0 tcontext=system_u:object_r:NetworkManager_var_run_t:s0 tclass=sock_file permissive=1
type=AVC msg=audit(1416558808.300:529): avc:  denied  { add_name } for  pid=2696 comm="openvpn" name="nm-openvpn-9e87e0fb-46b6-42cd-9d46-041f005b98c5" scontext=system_u:system_r:openvpn_t:s0 tcontext=system_u:object_r:NetworkManager_var_run_t:s0 tclass=dir permissive=1
type=AVC msg=audit(1416558808.300:529): avc:  denied  { write } for  pid=2696 comm="openvpn" name="NetworkManager" dev="tmpfs" ino=18803 scontext=system_u:system_r:openvpn_t:s0 tcontext=system_u:object_r:NetworkManager_var_run_t:s0 tclass=dir permissive=1
----
time->Fri Nov 21 09:33:28 2014
type=PROCTITLE msg=audit(1416558808.489:530): proctitle="/usr/libexec/nm-openvpn-service"
type=SYSCALL msg=audit(1416558808.489:530): arch=c000003e syscall=42 success=yes exit=0 a0=6 a1=7fffa12cda40 a2=6e a3=129 items=0 ppid=1 pid=2684 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="nm-openvpn-serv" exe="/usr/libexec/nm-openvpn-service" subj=system_u:system_r:NetworkManager_t:s0 key=(null)
type=AVC msg=audit(1416558808.489:530): avc:  denied  { connectto } for  pid=2684 comm="nm-openvpn-serv" path="/run/NetworkManager/nm-openvpn-9e87e0fb-46b6-42cd-9d46-041f005b98c5" scontext=system_u:system_r:NetworkManager_t:s0 tcontext=system_u:system_r:openvpn_t:s0 tclass=unix_stream_socket permissive=1
----
time->Fri Nov 21 09:34:08 2014
type=PROCTITLE msg=audit(1416558848.100:533): proctitle=2F7573722F7362696E2F6F70656E76706E002D2D72656D6F7465006F76706E2D706878322E7265646861742E636F6D003131393400756470002D2D6E6F62696E64002D2D6465760074756E002D2D617574682D6E6F6361636865002D2D7379736C6F67006E6D2D6F70656E76706E002D2D7363726970742D7365637572697479
type=SYSCALL msg=audit(1416558848.100:533): arch=c000003e syscall=87 success=yes exit=0 a0=7fc68a0e8466 a1=7fc68a109670 a2=7fc68a109670 a3=20 items=0 ppid=2684 pid=2696 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="openvpn" exe="/usr/sbin/openvpn" subj=system_u:system_r:openvpn_t:s0 key=(null)
type=AVC msg=audit(1416558848.100:533): avc:  denied  { unlink } for  pid=2696 comm="openvpn" name="nm-openvpn-9e87e0fb-46b6-42cd-9d46-041f005b98c5" dev="tmpfs" ino=32405 scontext=system_u:system_r:openvpn_t:s0 tcontext=system_u:object_r:NetworkManager_var_run_t:s0 tclass=sock_file permissive=1
type=AVC msg=audit(1416558848.100:533): avc:  denied  { remove_name } for  pid=2696 comm="openvpn" name="nm-openvpn-9e87e0fb-46b6-42cd-9d46-041f005b98c5" dev="tmpfs" ino=32405 scontext=system_u:system_r:openvpn_t:s0 tcontext=system_u:object_r:NetworkManager_var_run_t:s0 tclass=dir permissive=1
type=AVC msg=audit(1416558848.100:533): avc:  denied  { write } for  pid=2696 comm="openvpn" name="NetworkManager" dev="tmpfs" ino=18803 scontext=system_u:system_r:openvpn_t:s0 tcontext=system_u:object_r:NetworkManager_var_run_t:s0 tclass=dir permissive=1
type=AVC msg=audit(1416558848.100:533): avc:  denied  { search } for  pid=2696 comm="openvpn" name="NetworkManager" dev="tmpfs" ino=18803 scontext=system_u:system_r:openvpn_t:s0 tcontext=system_u:object_r:NetworkManager_var_run_t:s0 tclass=dir permissive=1
Comment 5 Miroslav Grepl 2014-11-21 09:56:33 UTC 
Has been already fixed.`
Comment 6 Fedora Update System 2014-11-21 12:24:13 UTC 
selinux-policy-3.13.1-99.fc21 has been submitted as an update for Fedora 21.
https://admin.fedoraproject.org/updates/selinux-policy-3.13.1-99.fc21
Comment 7 Fedora Update System 2014-12-03 17:15:38 UTC 
selinux-policy-3.13.1-99.fc21 has been pushed to the Fedora 21 stable repository.  If problems still persist, please make note of it in this bug report.