Description of problem: There are several dhclient related selinux avcs on the overcloud nodes: http://paste.openstack.org/show/587406/ Version-Release number of selected component (if applicable): selinux-policy-3.13.1-102.el7.noarch openstack-selinux-0.7.11-1.el7ost.noarch selinux-policy-targeted-3.13.1-102.el7.noarch How reproducible: 100% Steps to Reproduce: 1. Deploy overcloud with multiple nics and network isolation 2. grep denied /var/log/audit/audit.log on overcloud nodes Actual results: http://paste.openstack.org/show/587406/ Expected results: The audit.log shows clean. Additional info:
confirmed with ryan he could take this one
type=AVC msg=audit(1477850340.629:31): avc: denied { read } for pid=1169 comm="dhclient" name="dhclient-eth0.pid" dev="tmpfs" ino=17164 scontext=system_u:system_r:dhcpc_t:s0 tcontext=system_u:object_r:var_run_t:s0 tclass=file tcontext=system_u:object_r:var_run_t:s0 tclass=file type=AVC msg=audit(1477850340.630:33): avc: denied { write } for pid=1169 comm="dhclient" name="dhclient-eth0.pid" dev="tmpfs" ino=17164 scontext=system_u:system_r:dhcpc_t:s0 tcontext=system_u:object_r:var_run_t:s0 tclass=file restorecon -Rv /var/run/dhclient-eth0.pid restorecon -Rv /var/run/dhclient-eth1.pid
I'm seeing a similar audit log on overcloud-compute-0 on Ravi's setup (10.35.117.74): type=AVC msg=audit(1478094040.740:27): avc: denied { read } for pid=1145 comm="NetworkManager" name="dhclient-enp3s0f1.pid" dev="tmpfs" ino=346 scontext=system_u:system_r:NetworkManager_t:s0 tcontext=system_u:object_r:var_run_t:s0 tclass=file Most likely this is due to a NetworkManager issue with RHEL 7.3 but still investigating.
So it seems like what is happening is that the dhclient started by os_net_config runs first and creates the dhclient pid files. Some time later NetworkManager runs and starts dhclient instances for the same interfaces. Since the pid files are still there NetworkManager can't write to them, and any subsequent accesses will generate the selinunx audit logs because NetworkManager doesn't own these pid files. (Note that this example is from Ravi's system and doesn't match the interface names from the original bug report.) In /var/log/messages: messages:Nov 2 09:40:30 host-172-16-1-28 NetworkManager[1142]: <info> [1478094030.7150] dhcp-init: Using DHCP client 'dhclient' messages:Nov 2 09:40:30 host-172-16-1-28 NetworkManager[1142]: <info> [1478094030.7576] dhcp4 (enp3s0f1): dhclient started with pid 1172 messages:Nov 2 09:40:30 host-172-16-1-28 NetworkManager[1142]: <info> [1478094030.7639] dhcp4 (enp3s0f0): dhclient started with pid 1175 messages:Nov 2 09:40:30 host-172-16-1-28 dhclient[1172]: Can't create /var/run/dhclient-enp3s0f1.pid: Permission denied messages:Nov 2 09:40:30 host-172-16-1-28 dhclient[1175]: Can't create /var/run/dhclient-enp3s0f0.pid: Permission denied The contents of dhclient-enp3s0f1.pid and dhclient-enp3s0f0.pid don't contain the pids of the NetworkManager created instances: [heat-admin@overcloud-controller-0 log]$ cat /var/run/dhclient-enp3s0f0.pid 954 [heat-admin@overcloud-controller-0 log]$ cat /var/run/dhclient-enp3s0f1.pid 1097 As we're not using the dhclient started by NetworkManager I don't expect there to be functional problems beyond the audit messages. Marius - can you provide /var/log/messages from overcloud-controller-0 so I can confirm that your system has the same log messages, i.e.: Can't create /var/run/dhclient-XXX.pid: Permission denied Also, can you indicate if you see any other functional problems on this system beyond the audit logs? Thanks. Still investigating the best way to fix this.
(In reply to Bob Fournier from comment #4) > So it seems like what is happening is that the dhclient started by > os_net_config runs first and creates the dhclient pid files. Some time > later NetworkManager runs and starts dhclient instances for the same > interfaces. Since the pid files are still there NetworkManager can't write > to them, and any subsequent accesses will generate the selinunx audit logs > because NetworkManager doesn't own these pid files. > > (Note that this example is from Ravi's system and doesn't match the > interface names from the original bug report.) > > In /var/log/messages: > messages:Nov 2 09:40:30 host-172-16-1-28 NetworkManager[1142]: <info> > [1478094030.7150] dhcp-init: Using DHCP client 'dhclient' > messages:Nov 2 09:40:30 host-172-16-1-28 NetworkManager[1142]: <info> > [1478094030.7576] dhcp4 (enp3s0f1): dhclient started with pid 1172 > messages:Nov 2 09:40:30 host-172-16-1-28 NetworkManager[1142]: <info> > [1478094030.7639] dhcp4 (enp3s0f0): dhclient started with pid 1175 > messages:Nov 2 09:40:30 host-172-16-1-28 dhclient[1172]: Can't create > /var/run/dhclient-enp3s0f1.pid: Permission denied > messages:Nov 2 09:40:30 host-172-16-1-28 dhclient[1175]: Can't create > /var/run/dhclient-enp3s0f0.pid: Permission denied > > The contents of dhclient-enp3s0f1.pid and dhclient-enp3s0f0.pid don't contain > the pids of the NetworkManager created instances: > [heat-admin@overcloud-controller-0 log]$ cat /var/run/dhclient-enp3s0f0.pid > 954 > [heat-admin@overcloud-controller-0 log]$ cat /var/run/dhclient-enp3s0f1.pid > 1097 > > As we're not using the dhclient started by NetworkManager I don't expect > there to be functional problems beyond the audit messages. > > Marius - can you provide /var/log/messages from overcloud-controller-0 so I > can confirm that your system has the same log messages, i.e.: > Can't create /var/run/dhclient-XXX.pid: Permission denied > > Also, can you indicate if you see any other functional problems on this > system beyond the audit logs? Thanks. > > Still investigating the best way to fix this. This is how the log on compute-0 node looks(I don't have the initial setup anymore): http://paste.openstack.org/show/587870/ I couldn't determine any functional caused by this.
I dropped the blocker flag since it doesn't seem to be impacting the environment during my tests. I would like to see though what's the behavior in a scenario when, say, enabling dhcp (use_dhcp: true) on one of the interfaces that show the AVCs.
@Bob, is there place for a race here? Are we sure NetworkManager can't possibly start its dhclient before os-net-config one (probably breaking the whole setup)?
Should we maybe set NM_CONTROLLED=no in the ifcfg file to make sure NetworkManager does not mess with os-net-config managed devices?
Ihar, I believe what is happening is: - the udev rule runs dhcp-all-interfaces.sh which configures the interfaces for dhcp and brings them up, causing dhclient to run - NetworkManager attempts to start dhclient instances (which generate audit logs because the pid file can't be written) since NM_CONTROLLED is not set - os-net-config runs, which is where NM_CONTROLLED=no is set on the interfaces So, yes I think it is a race condition and could potentially lead to a more serious issue if the dhclient started by NetworkManager runs first It seems that the proper thing to do is set NM_CONTROLLED=no in dhcp-all-interfaces.sh when the interface is first brought up, in addition to in os-net-config.
Upstream fix is in progress which will to use a new environment variable to start either network or NetworkManager as the networking service on RHEL - https://review.openstack.org/#/c/392170/7. This will resolve the contention of both services attempting to start dhclient and get rid of these audit messages.
(In reply to Bob Fournier from comment #9) > Ihar, > > I believe what is happening is: > - the udev rule runs dhcp-all-interfaces.sh which configures the interfaces > for > dhcp and brings them up, causing dhclient to run Note that devices can be configured as unmanaged via udev: See for example /usr/lib/udev/rules.d/85-nm-unmanaged.rules https://cgit.freedesktop.org/NetworkManager/NetworkManager/tree/data/85-nm-unmanaged.rules?id=994f1ca96ea7d675b61006f8199a003354e8d12a Wouldn't that be the better place to avoid the race?
Marius - has this been seen any more? I'm tempted to close this as we have not had any reports in any version in over a year and have not been able to reproduce.
(In reply to Bob Fournier from comment #14) > Marius - has this been seen any more? I'm tempted to close this as we have > not had any reports in any version in over a year and have not been able to > reproduce. Agree, we can close it for now. I haven't seen it for some time.
Thank you.