Bug 1956836 - AVC denial when setting hostname on GCP using "set-valid-hostname.sh" script
Summary: AVC denial when setting hostname on GCP using "set-valid-hostname.sh" script
Keywords:
Status: POST
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: RHCOS
Version: 4.8
Hardware: All
OS: Linux
low
medium
Target Milestone: ---
: 4.8.0
Assignee: Micah Abbott
QA Contact: Michael Nguyen
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-05-04 14:09 UTC by Micah Abbott
Modified: 2021-05-14 18:23 UTC (History)
15 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of: 1945646
Environment:
Last Closed:
Target Upstream Version:
miabbott: needinfo-


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github openshift os pull 551 0 None open BZ 1956836: overlay: Add rhcos-usrlocal-selinux-fixup.service 2021-05-14 18:23:04 UTC

Comment 1 Micah Abbott 2021-05-04 14:55:04 UTC
When digging into the status of a cluster running `4.8.0-0.nightly-2021-04-30-201824`, it looks like the AVC denial originally reported in BZ#1945646 is still present.

```
sh-4.4# chroot /host 
sh-4.4# audit2allow -a


#============= systemd_hostnamed_t ==============
allow systemd_hostnamed_t initrc_t:dbus send_msg;
sh-4.4# cd /var/log/audit/
sh-4.4# grep -R hostnamed *
audit.log.3:type=SERVICE_START msg=audit(1620134026.498:31): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"
audit.log.3:type=SERVICE_STOP msg=audit(1620134056.512:46): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"
audit.log.3:type=SERVICE_START msg=audit(1620134103.304:32): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"
audit.log.3:type=USER_AVC msg=audit(1620134103.493:36): pid=982 uid=81 auid=4294967295 ses=4294967295 subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc:  denied  { send_msg } for msgtype=method_return dest=:1.14 spid=1256 tpid=1352 scontext=system_u:system_r:systemd_hostnamed_t:s0 tcontext=system_u:system_r:initrc_t:s0 tclass=dbus permissive=0  exe="/usr/bin/dbus-daemon" sauid=81 hostname=? addr=? terminal=?'UID="dbus" AUID="unset" SAUID="dbus"
audit.log.3:type=SERVICE_STOP msg=audit(1620134133.524:55): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"
```

It looks like PID 982 (`dbus-daemon`) is getting activated by PID 1256 (`systemd-hostname`) and that is generating the AVC denial.

Digging into the logs around the time of the AVC denial, there doesn't appear to be any failure related to setting the hostname.

```
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Starting Network Manager...
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.1560] NetworkManager (version 1.30.0-1.el8) is starting... (for the first time)
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.1563] Read config: /etc/NetworkManager/NetworkManager.conf (lib: 10-disable-default-plugins.conf, 20-client-id-from-mac.conf) (etc: 99-keyfiles.conf, hostname.conf, sdn.conf)
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.1593] bus-manager: acquired D-Bus service "org.freedesktop.NetworkManager"
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Started Network Manager.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Reached target Network.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.1676] manager[0x56264d779010]: monitoring kernel firmware directory '/lib/firmware'.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c dbus-daemon[982]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.9' (uid=0 pid=1245 comm="/usr/sbin/NetworkManager --no-daemon " label="system_u:sy>
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Started Update GCP routes for forwarded IPs..
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Starting OpenSSH server daemon...
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Starting Network Manager Wait Online...
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Starting Hostname Service...
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c sshd[1252]: Server listening on 0.0.0.0 port 22.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c sshd[1252]: Server listening on :: port 22.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Started OpenSSH server daemon.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c dbus-daemon[982]: [system] Successfully activated service 'org.freedesktop.hostname1'
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Started Hostname Service.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3002] hostname: hostname: using hostnamed
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3003] hostname: hostname changed from (none) to "ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c"
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3010] dns-mgr[0x56264d76c170]: init: dns=default,systemd-resolved rc-manager=symlink
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3105] Loaded device plugin: NMOvsFactory (/usr/lib64/NetworkManager/1.30.0-1.el8/libnm-device-plugin-ovs.so)
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c gcp-routes.sh[1249]: done applying vip rules
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3150] Loaded device plugin: NMTeamFactory (/usr/lib64/NetworkManager/1.30.0-1.el8/libnm-device-plugin-team.so)
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3151] manager: rfkill: Wi-Fi enabled by radio killswitch; enabled by state file
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3152] manager: rfkill: WWAN enabled by radio killswitch; enabled by state file
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3153] manager: Networking is enabled by state file
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3155] dhcp-init: Using DHCP client 'internal'
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c dbus-daemon[982]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.9' (uid=0 pid=1245 comm="/usr/sbin/NetworkManager --no-daemon " label="sys>
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3166] settings: Loaded settings plugin: keyfile (internal)
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Starting Network Manager Script Dispatcher Service...
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3200] settings: Loaded settings plugin: ifcfg-rh ("/usr/lib64/NetworkManager/1.30.0-1.el8/libnm-settings-plugin-ifcfg-rh.so")
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3222] device (lo): carrier: link connected
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3226] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1)
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3240] manager: (ens4): new Ethernet device (/org/freedesktop/NetworkManager/Devices/2)
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3288] settings: (ens4): created default wired connection 'Wired connection 1'
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3294] device (ens4): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c dbus-daemon[982]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Started Network Manager Script Dispatcher Service.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c kernel: IPv6: ADDRCONF(NETDEV_UP): ens4: link is not ready
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3381] device (ens4): carrier: link connected
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3460] device (ens4): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3494] policy: auto-activating connection 'Wired connection 1' (71988c48-5343-3873-b0a7-b2ea36b42c31)
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3501] device (ens4): Activation: starting connection 'Wired connection 1' (71988c48-5343-3873-b0a7-b2ea36b42c31)
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3502] device (ens4): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3508] manager: NetworkManager state is now CONNECTING
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3511] device (ens4): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3519] device (ens4): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3527] dhcp4 (ens4): activation: beginning transaction (timeout in 45 seconds)
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3615] dhcp4 (ens4): state changed unknown -> bound, address=10.0.128.3
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3643] device (ens4): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3689] device (ens4): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3692] device (ens4): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3697] manager: NetworkManager state is now CONNECTED_LOCAL
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3709] manager: NetworkManager state is now CONNECTED_SITE
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3710] policy: set 'Wired connection 1' (ens4) as default for IPv4 routing and DNS
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c dbus-daemon[982]: [system] Activating via systemd: service name='org.freedesktop.resolve1' unit='dbus-org.freedesktop.resolve1.service' requested by ':1.9' (uid=0 pid=1245 comm="/usr/sbin/NetworkManager --no-daemon " label="system_u:syst>
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c dbus-daemon[982]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.resolve1.service': Unit dbus-org.freedesktop.resolve1.service not found.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3757] device (ens4): Activation: successful, device activated.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3767] manager: NetworkManager state is now CONNECTED_GLOBAL
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c NetworkManager[1245]: <info>  [1620134103.3780] manager: startup complete
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Started Network Manager Wait Online.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Starting Configures OVS with proper host networking configuration...
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Started Network Manager Wait Online.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Starting Configures OVS with proper host networking configuration...
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c configure-ovs.sh[1310]: + touch /var/run/ovs-config-executed
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c configure-ovs.sh[1310]: + rpm -qa
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c systemd[1]: Starting Set GCP Transient Hostname...
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c configure-ovs.sh[1310]: + grep -q openvswitch
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c afterburn[1314]: May 04 13:15:03.441 INFO Fetching http://metadata.google.internal/computeMetadata/v1/instance/hostname: Attempt #1
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c afterburn[1314]: May 04 13:15:03.447 INFO Fetch successful
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c bash[1347]: ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-ci.internal is longer than 63 characters, using trunacated hostname
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c bash[1351]: setting static hostname to ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd-hostnamed[1256]: Changed static host name to 'ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9'
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 NetworkManager[1245]: <info>  [1620134103.4938] hostname: hostname changed from "ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c" to "ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9"
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: console-login-helper-messages-issuegen.service: Succeeded.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: Started Generate console-login-helper-messages issue snippet.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: console-login-helper-messages-issuegen.service: Consumed 22ms CPU time
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: Starting Permit User Sessions...
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: Started Permit User Sessions.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: Started Serial Getty on ttyS0.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: Started Getty on tty1.
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: Reached target Login Prompts.
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 configure-ovs.sh[1310]: + '[' OpenShiftSDN == OVNKubernetes ']'
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 configure-ovs.sh[1310]: + '[' OpenShiftSDN == OpenShiftSDN ']'
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 configure-ovs.sh[1310]: + iface=
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 configure-ovs.sh[1310]: + nmcli connection show ovs-port-phys0
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 configure-ovs.sh[1310]: + nmcli connection show ovs-if-phys0
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 configure-ovs.sh[1310]: + nmcli connection show ovs-port-br-ex
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 configure-ovs.sh[1310]: + nmcli connection show ovs-if-br-ex
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 configure-ovs.sh[1310]: + nmcli connection show br-ex
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 configure-ovs.sh[1310]: + rm -f /etc/NetworkManager/system-connections/br-ex.nmconnection /etc/NetworkManager/system-connections/ovs-if-br-ex.nmconnection /etc/NetworkManager/system-connections/ovs-port-br-ex.nmconnection /etc/NetworkManager/system-connections/>
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 configure-ovs.sh[1310]: + ovs-vsctl --timeout=30 --if-exists del-br br-int -- --if-exists del-br br-local -- --if-exists del-br br-ex
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 configure-ovs.sh[1310]: + [[ -n '' ]]
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: ovs-configuration.service: Succeeded.
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 ovs-vsctl[1399]: ovs|00001|vsctl|INFO|Called as ovs-vsctl --timeout=30 --if-exists del-br br-int -- --if-exists del-br br-local -- --if-exists del-br br-ex
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: Started Configures OVS with proper host networking configuration.
May 04 13:15:04 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: ovs-configuration.service: Consumed 519ms CPU time
May 04 13:15:07 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 chronyd[988]: Selected source 169.254.169.254
May 04 13:15:13 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: NetworkManager-dispatcher.service: Succeeded.
May 04 13:15:13 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd[1]: NetworkManager-dispatcher.service: Consumed 146ms CPU time
```


I think these messages are related to the AVC denial:

```
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c bash[1347]: ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-ci.internal is longer than 63 characters, using trunacated hostname
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9.c.openshift-gce-devel-c bash[1351]: setting static hostname to ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9
May 04 13:15:03 ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9 systemd-hostnamed[1256]: Changed static host name to 'ci-ln-xw294mb-f76d1-slbkd-worker-b-zn9g9'
```

The use of `systemd-hostnamed` appears to be coming from setting the hostname via `hostnamectl` in the MCO `set-valid-hostnames.sh` script that is used on GCP:

https://github.com/openshift/machine-config-operator/blob/master/templates/common/_base/files/usr-local-sbin-set-valid-hostname.yaml#L64


This is kind of an MCO issue, though the RHCOS team helped with that script.  I think we should probably be the ones to investigate how to avoid the AVC denial when using this script.

Comment 2 Colin Walters 2021-05-04 19:33:15 UTC
I think this is a pure selinux policy bug; that looks like something that should be allowed.

Comment 3 Micah Abbott 2021-05-04 20:15:09 UTC
@Miros @Zydenek could you weigh in on a need for an SELinux policy change here?

Comment 4 Daniel Walsh 2021-05-04 21:32:48 UTC
This looks like you have a service on the system that is running as initrc_t, which is causing the issue, since systemd-hostname is not allowed to communicate with it.

Is there some labeling issue on this service?

ps -eZ | grep initrc_t

Comment 5 Micah Abbott 2021-05-05 14:45:33 UTC
(In reply to Daniel Walsh from comment #4)
> This looks like you have a service on the system that is running as
> initrc_t, which is causing the issue, since systemd-hostname is not allowed
> to communicate with it.
> 
> Is there some labeling issue on this service?
> 
> ps -eZ | grep initrc_t

The systemd service is being installed by the MCO:

https://github.com/openshift/machine-config-operator/blob/master/templates/common/_base/units/node-valid-hostname.service.yaml

...and it looks like the service is sourcing the script via `bash` - https://github.com/openshift/machine-config-operator/blob/master/templates/common/_base/units/node-valid-hostname.service.yaml#L13-L15

The comment in that service says that systemd prevents direct execution of that script in /usr/local/sbin.  But having the MCO write out the script to a more appropriate place probably isn't possible due to where we can write files on RHCOS.

Comment 10 Micah Abbott 2021-05-12 18:35:04 UTC
Adjusting priority to low based on BZ scrub.  While we do want to avoid any AVC denials, the functionality appears unaffected, so it doesn't seem like something we need to rush to fix.

Comment 11 Daniel Walsh 2021-05-12 18:48:59 UTC
BTW:

time->Thu Apr  1 13:19:02 2021
type=PROCTITLE msg=audit(1617283142.102:54): proctitle=2F7573722F6C6962657865632F706C6174666F726D2D707974686F6E002D4573002F7573722F7362696E2F74756E6564002D2D6E6F2D64627573
type=SYSCALL msg=audit(1617283142.102:54): arch=c000003e syscall=1 success=yes exit=4 a0=7 a1=7f7a24015680 a2=4 a3=0 items=0 ppid=2553 pid=3473 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="tuned" exe="/usr/libexec/platform-python3.6" subj=system_u:system_r:spc_t:s0 key=(null)
type=AVC msg=audit(1617283142.102:54): avc:  granted  { setsecparam } for  pid=3473 comm="tuned" scontext=system_u:system_r:spc_t:s0 tcontext=system_u:object_r:security_t:s0 tclass=security


This is not a deniel, Notice the `granted`, This means the SELinux policy wants to tell the system any time a processes does a setsecparam,  So this is expected and is not a bug.

Comment 12 Micah Abbott 2021-05-13 14:13:05 UTC
(In reply to Daniel Walsh from comment #11)
> BTW:
> 
> time->Thu Apr  1 13:19:02 2021
> type=PROCTITLE msg=audit(1617283142.102:54):
> proctitle=2F7573722F6C6962657865632F706C6174666F726D2D707974686F6E002D4573002
> F7573722F7362696E2F74756E6564002D2D6E6F2D64627573
> type=SYSCALL msg=audit(1617283142.102:54): arch=c000003e syscall=1
> success=yes exit=4 a0=7 a1=7f7a24015680 a2=4 a3=0 items=0 ppid=2553 pid=3473
> auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0
> tty=(none) ses=4294967295 comm="tuned" exe="/usr/libexec/platform-python3.6"
> subj=system_u:system_r:spc_t:s0 key=(null)
> type=AVC msg=audit(1617283142.102:54): avc:  granted  { setsecparam } for 
> pid=3473 comm="tuned" scontext=system_u:system_r:spc_t:s0
> tcontext=system_u:object_r:security_t:s0 tclass=security
> 
> 
> This is not a deniel, Notice the `granted`, This means the SELinux policy
> wants to tell the system any time a processes does a setsecparam,  So this
> is expected and is not a bug.

Agreed, but what about this message?


```
audit.log.3:type=USER_AVC msg=audit(1620134103.493:36): pid=982 uid=81 auid=4294967295 ses=4294967295 subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc:  denied  { send_msg } for msgtype=method_return dest=:1.14 spid=1256 tpid=1352 scontext=system_u:system_r:systemd_hostnamed_t:s0 tcontext=system_u:system_r:initrc_t:s0 tclass=dbus permissive=0  exe="/usr/bin/dbus-daemon" sauid=81 hostname=? addr=? terminal=?'UID="dbus" AUID="unset" SAUID="dbus"
```

audit2allow is proposing the following:

```
sh-4.4# audit2allow -a


#============= systemd_hostnamed_t ==============
allow systemd_hostnamed_t initrc_t:dbus send_msg;
```

Comment 13 Zdenek Pytela 2021-05-13 15:04:34 UTC
Both the problems were already discussed in bz#1945646. Executing the script directly, without a reference to bash, will make it run in unconfined_service_t.

Frankly, I don't understand this:
> The comment in that service says that systemd prevents direct execution of that script in /usr/local/sbin. 
Why would systemd block it?

Long term solution would probably be confining the service.

Comment 14 Micah Abbott 2021-05-13 15:30:36 UTC
(In reply to Zdenek Pytela from comment #13)
> Both the problems were already discussed in bz#1945646. Executing the script
> directly, without a reference to bash, will make it run in
> unconfined_service_t.
> 
> Frankly, I don't understand this:
> > The comment in that service says that systemd prevents direct execution of that script in /usr/local/sbin. 
> Why would systemd block it?

Yeah, that seems to be misguided.  On a local RHCOS 4.8 node, I was able to successfully run a script in /usr/local/sbin from a systemd service.

Maybe we can just change the service to call out the script directly and solve this issue.

> Long term solution would probably be confining the service.

Comment 15 Micah Abbott 2021-05-13 15:50:01 UTC
(In reply to Micah Abbott from comment #14)
> (In reply to Zdenek Pytela from comment #13)
> > Both the problems were already discussed in bz#1945646. Executing the script
> > directly, without a reference to bash, will make it run in
> > unconfined_service_t.
> > 
> > Frankly, I don't understand this:
> > > The comment in that service says that systemd prevents direct execution of that script in /usr/local/sbin. 
> > Why would systemd block it?
> 
> Yeah, that seems to be misguided.  On a local RHCOS 4.8 node, I was able to
> successfully run a script in /usr/local/sbin from a systemd service.

Looks like my testing was somewhat flawed; newly created files in /usr/local/sbin are getting the `var_t` label:

```
$ ls -lZ /usr/local/sbin/
total 8
-rwxr-xr-x. 1 root root unconfined_u:object_r:var_t:s0 2784 May 13 15:38 set-valid-hostname.sh
```

SELinux is denying the execution of the script in /usr/local/sbin

```
type=AVC msg=audit(1620920257.749:300): avc:  denied  { execute } for  pid=2163 comm="(tname.sh)" name="set-valid-hostname.sh" dev="vda4" ino=23068808 scontext=system_u:system_r:init_t:s0 tcontext=unconfined_u:object_r:var_t:s0 tclass=file permissive=0
```

So this looks like it is rubbing against https://bugzilla.redhat.com/show_bug.cgi?id=1943381


There's no easy mechanism to relabel a file written out by the MCO, so we would have to consider moving the script to /usr/local/bin in the meantime.  Or just wait for the updated SELinux policy as part of the RHEL 8.4.z release.

Comment 16 Daniel Walsh 2021-05-13 18:03:58 UTC
If you move an executable into /usr, you should run restorecon on it, before executing.

The SELinux team decided a few years ago to not have init_t be an unconfined type, which I disagreed with.
And that is causing the AVCs. (Personally init can do anything it wants, so no reason to confine it. But 
I don't control SELinux policy any longer).

Comment 17 Zdenek Pytela 2021-05-13 18:19:58 UTC
(In reply to Micah Abbott from comment #15)
> Looks like my testing was somewhat flawed; newly created files in
> /usr/local/sbin are getting the `var_t` label:
> 
> ```
> $ ls -lZ /usr/local/sbin/
> total 8
> -rwxr-xr-x. 1 root root unconfined_u:object_r:var_t:s0 2784 May 13 15:38
> set-valid-hostname.sh
Such a thing should not happen provided the directory has correct label:

# ls -Zd /usr/local/sbin/
system_u:object_r:bin_t:s0 /usr/local/sbin/
# echo echo > /usr/local/sbin/file
beaker-rhel8# ls -Z /usr/local/sbin/file
unconfined_u:object_r:bin_t:s0 /usr/local/sbin/file

Note if you move a file, it keeps extended attributes; the same for "cp -a".

What would be the output of this command?

# restorecon -Rvn /usr/local/sbin

Comment 18 Micah Abbott 2021-05-13 19:56:26 UTC
(In reply to Zdenek Pytela from comment #17)
> (In reply to Micah Abbott from comment #15)
> > Looks like my testing was somewhat flawed; newly created files in
> > /usr/local/sbin are getting the `var_t` label:
> > 
> > ```
> > $ ls -lZ /usr/local/sbin/
> > total 8
> > -rwxr-xr-x. 1 root root unconfined_u:object_r:var_t:s0 2784 May 13 15:38
> > set-valid-hostname.sh
> Such a thing should not happen provided the directory has correct label:
> 
> # ls -Zd /usr/local/sbin/
> system_u:object_r:bin_t:s0 /usr/local/sbin/
> # echo echo > /usr/local/sbin/file
> beaker-rhel8# ls -Z /usr/local/sbin/file
> unconfined_u:object_r:bin_t:s0 /usr/local/sbin/file
> 
> Note if you move a file, it keeps extended attributes; the same for "cp -a".
> 
> What would be the output of this command?
> 
> # restorecon -Rvn /usr/local/sbin

```
[core@cosa-devsh ~]$ ls -Zd /usr/local/sbin 
system_u:object_r:var_t:s0 /usr/local/sbin
[core@cosa-devsh ~]$ sudo touch /usr/local/sbin/file
[core@cosa-devsh ~]$ ls -Z /usr/local/sbin/file
unconfined_u:object_r:var_t:s0 /usr/local/sbin/file
[core@cosa-devsh ~]$ sudo restorecon -Rvn /usr/local/sbin     
[core@cosa-devsh ~]$ 
```

I think this is https://bugzilla.redhat.com/show_bug.cgi?id=1943381

Comment 19 Colin Walters 2021-05-14 12:59:43 UTC
Ah, yes.  So we can fix this by moving the script to `/usr/local/bin`, or we can add a systemd unit which does a restorecon.  In fact, we need the systemd unit fixup to make in-place updates work.  (ostree does not touch `/var`, it's managed by `systemd-tmpfiles`).

Comment 20 Colin Walters 2021-05-14 18:23:04 UTC
PR in https://github.com/openshift/os/pull/551


Note You need to log in before you can comment on or make changes to this bug.