While investigating BZ#1924869, I noticed that `chronyc sources` took longer than expected to return. Looks like there is a SELinux denial happening: ``` $ oc get clusterversion NAME VERSION AVAILABLE PROGRESSING SINCE STATUS version 4.7.0-0.nightly-2021-02-03-165316 True False 20m Cluster version is 4.7.0-0.nightly-2021-02-03-165316 $ oc get nodes NAME STATUS ROLES AGE VERSION ci-ln-jmidrn2-f76d1-cnrf2-master-0 Ready master 40m v1.20.0+e761892 ci-ln-jmidrn2-f76d1-cnrf2-master-1 Ready master 39m v1.20.0+e761892 ci-ln-jmidrn2-f76d1-cnrf2-master-2 Ready master 40m v1.20.0+e761892 ci-ln-jmidrn2-f76d1-cnrf2-worker-b-6zr4q Ready worker 31m v1.20.0+e761892 ci-ln-jmidrn2-f76d1-cnrf2-worker-c-r49rf Ready worker 31m v1.20.0+e761892 ci-ln-jmidrn2-f76d1-cnrf2-worker-d-fcqkj Ready worker 31m v1.20.0+e761892 $ oc debug node/ci-ln-jmidrn2-f76d1-cnrf2-worker-d-fcqkj Creating debug namespace/openshift-debug-node-xvbwj ... Starting pod/ci-ln-jmidrn2-f76d1-cnrf2-worker-d-fcqkj-debug ... To use host binaries, run `chroot /host` Pod IP: 10.0.32.4 If you don't see a command prompt, try pressing enter. sh-4.4# chroot /host sh-4.4# rpm-ostree status State: idle Deployments: * pivot://quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:11e0e55d2cc0284cdd8c7dff8db26a25e8146daf6a71ce5abc26fa2f17f2b639 CustomOrigin: Managed by machine-config-operator Version: 47.83.202102031122-0 (2021-02-03T11:25:46Z) ostree://8e87a86b9444784ab29e7917fa82e00d5e356f18b19449946b687ee8dc27c51a Version: 47.83.202101161239-0 (2021-01-16T12:43:01Z) sh-4.4# rpm -q chrony selinux-policy chrony-3.5-1.el8.x86_64 selinux-policy-3.14.3-54.el8_3.2.noarch sh-4.4# ausearch -m avc ---- time->Wed Feb 3 21:35:14 2021 type=PROCTITLE msg=audit(1612388114.762:57): proctitle=2F7573722F6C6962657865632F706C6174666F726D2D707974686F6E002D4573002F7573722F7362696E2F74756E6564002D2D6E6F2D64627573 type=SYSCALL msg=audit(1612388114.762:57): arch=c000003e syscall=1 success=yes exit=4 a0=7 a1=7f515c015a70 a2=4 a3=0 items=0 ppid=2468 pid=3105 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:sp c_t:s0 key=(null) type=AVC msg=audit(1612388114.762:57): avc: granted { setsecparam } for pid=3105 comm="tuned" scontext=system_u:system_r:spc_t:s0 tcontext=system_u:object_r:security_t:s0 tclass=security ``` No denials listed here. Just checking the state of chronyd and the use of the GCP specific config: ``` sh-4.4# systemctl status chronyd ● chronyd.service - NTP client/server Loaded: loaded (/usr/lib/systemd/system/chronyd.service; enabled; vendor preset: enabled) Drop-In: /run/systemd/generator/chronyd.service.d └─coreos-platform-chrony.conf Active: active (running) since Wed 2021-02-03 21:34:19 UTC; 33min ago Docs: man:chronyd(8) man:chrony.conf(5) Process: 1132 ExecStartPost=/usr/libexec/chrony-helper update-daemon (code=exited, status=0/SUCCESS) Process: 1122 ExecStart=/usr/sbin/chronyd -f /run/coreos-platform-chrony.conf $OPTIONS (code=exited, status=0/SUCCESS) Main PID: 1129 (chronyd) Tasks: 1 (limit: 95257) Memory: 2.5M CPU: 37ms CGroup: /system.slice/chronyd.service └─1129 /usr/sbin/chronyd -f /run/coreos-platform-chrony.conf Feb 03 21:34:19 ci-ln-jmidrn2-f76d1-cnrf2-worker-d-fcqkj.c.openshift-gce-devel-c systemd[1]: Starting NTP client/server... Feb 03 21:34:19 ci-ln-jmidrn2-f76d1-cnrf2-worker-d-fcqkj.c.openshift-gce-devel-c chronyd[1129]: chronyd version 3.5 starting (+CMDMON +NTP +REFCLOCK +RTC +PRIVDROP +SCFILTER +SIGND +ASYNCDNS +SECHASH +IPV6 +DEBUG) Feb 03 21:34:19 ci-ln-jmidrn2-f76d1-cnrf2-worker-d-fcqkj.c.openshift-gce-devel-c chronyd[1129]: Frequency -86.285 +/- 78.054 ppm read from /var/lib/chrony/drift Feb 03 21:34:19 ci-ln-jmidrn2-f76d1-cnrf2-worker-d-fcqkj.c.openshift-gce-devel-c chronyd[1129]: Using right/UTC timezone to obtain leap second data Feb 03 21:34:19 ci-ln-jmidrn2-f76d1-cnrf2-worker-d-fcqkj.c.openshift-gce-devel-c systemd[1]: Started NTP client/server. Feb 03 21:34:24 ci-ln-jmidrn2-f76d1-cnrf2-worker-d-fcqkj chronyd[1129]: Selected source 169.254.169.254 Feb 03 21:34:24 ci-ln-jmidrn2-f76d1-cnrf2-worker-d-fcqkj chronyd[1129]: System clock TAI offset set to 37 seconds sh-4.4# cat /run/coreos-platform-chrony.conf # Generated by coreos-platform-chrony - do not edit directly # Use public servers from the pool.ntp.org project. # Please consider joining the pool (http://www.pool.ntp.org/join.html). #pool 2.rhel.pool.ntp.org iburst # Record the rate at which the system clock gains/losses time. driftfile /var/lib/chrony/drift # Allow the system clock to be stepped in the first three updates # if its offset is larger than 1 second. #makestep 1.0 3 # Enable kernel synchronization of the real-time clock (RTC). rtcsync # Enable hardware timestamping on all interfaces that support it. #hwtimestamp * # Increase the minimum number of selectable sources required to adjust # the system clock. #minsources 2 # Allow NTP client access from local network. #allow 192.168.0.0/16 # Serve time even if not synchronized to a time source. #local stratum 10 # Specify file containing keys for NTP authentication. keyfile /etc/chrony.keys # Get TAI-UTC offset and leap seconds from the system tz database. leapsectz right/UTC # Specify directory for log files. logdir /var/log/chrony # Select which information is logged. #log measurements statistics tracking # Allow the system clock step on any clock update. # It will avoid the time resynchronization issue when VMs are resumed from suspend. # See https://bugzilla.redhat.com/show_bug.cgi?id=1780165 for more information. makestep 1.0 -1 # See also https://cloud.google.com/compute/docs/instances/managing-instances#configure-ntp # and https://cloud.google.com/compute/docs/images/configuring-imported-images server metadata.google.internal prefer iburst ``` Now if we time how long `chronyc sources` takes: ``` sh-4.4# time chronyc sources 210 Number of sources = 1 MS Name/IP address Stratum Poll Reach LastRx Last sample =============================================================================== ^* metadata.google.internal 2 7 377 230 +7807ns[ +10us] +/- 304us real 0m7.010s user 0m0.001s sys 0m0.002s sh-4.4# ausearch -m avc ---- time->Wed Feb 3 21:35:14 2021 type=PROCTITLE msg=audit(1612388114.762:57): proctitle=2F7573722F6C6962657865632F706C6174666F726D2D707974686F6E002D4573002F7573722F7362696E2F74756E6564002D2D6E6F2D64627573 type=SYSCALL msg=audit(1612388114.762:57): arch=c000003e syscall=1 success=yes exit=4 a0=7 a1=7f515c015a70 a2=4 a3=0 items=0 ppid=2468 pid=3105 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(1612388114.762:57): avc: granted { setsecparam } for pid=3105 comm="tuned" scontext=system_u:system_r:spc_t:s0 tcontext=system_u:object_r:security_t:s0 tclass=security ---- time->Wed Feb 3 22:08:20 2021 type=PROCTITLE msg=audit(1612390100.853:72): proctitle=2F7573722F7362696E2F6368726F6E7964002D66002F72756E2F636F72656F732D706C6174666F726D2D6368726F6E792E636F6E66 type=SYSCALL msg=audit(1612390100.853:72): arch=c000003e syscall=44 success=no exit=-13 a0=8 a1=7fff0d6546d0 a2=20 a3=0 items=0 ppid=1 pid=1129 auid=4294967295 uid=994 gid=992 euid=994 suid=994 fsuid=994 egid=992 sgid=992 fsgid=992 tty=(none) ses=4294967295 comm="chronyd" exe="/usr/sbin/chronyd" subj=system_u:system_r:chronyd_t:s0 key=(null) type=AVC msg=audit(1612390100.853:72): avc: denied { sendto } for pid=1129 comm="chronyd" path="/host/run/chrony/chronyc.36667.sock" scontext=system_u:system_r:chronyd_t:s0 tcontext=system_u:system_r:spc_t:s0 tclass=unix_dgram_socket permissive=0 ---- time->Wed Feb 3 22:08:21 2021 type=PROCTITLE msg=audit(1612390101.854:73): proctitle=2F7573722F7362696E2F6368726F6E7964002D66002F72756E2F636F72656F732D706C6174666F726D2D6368726F6E792E636F6E66 type=SYSCALL msg=audit(1612390101.854:73): arch=c000003e syscall=44 success=no exit=-13 a0=8 a1=7fff0d6546d0 a2=20 a3=0 items=0 ppid=1 pid=1129 auid=4294967295 uid=994 gid=992 euid=994 suid=994 fsuid=994 egid=992 sgid=992 fsgid=992 tty=(none) ses=4294967295 comm="chronyd" exe="/usr/sbin/chronyd" subj=system_u:system_r:chronyd_t:s0 key=(null) type=AVC msg=audit(1612390101.854:73): avc: denied { sendto } for pid=1129 comm="chronyd" path="/host/run/chrony/chronyc.36667.sock" scontext=system_u:system_r:chronyd_t:s0 tcontext=system_u:system_r:spc_t:s0 tclass=unix_dgram_socket permissive=0 ---- time->Wed Feb 3 22:08:23 2021 type=PROCTITLE msg=audit(1612390103.854:74): proctitle=2F7573722F7362696E2F6368726F6E7964002D66002F72756E2F636F72656F732D706C6174666F726D2D6368726F6E792E636F6E66 type=SYSCALL msg=audit(1612390103.854:74): arch=c000003e syscall=44 success=no exit=-13 a0=8 a1=7fff0d6546d0 a2=20 a3=0 items=0 ppid=1 pid=1129 auid=4294967295 uid=994 gid=992 euid=994 suid=994 fsuid=994 egid=992 sgid=992 fsgid=992 tty=(none) ses=4294967295 comm="chronyd" exe="/usr/sbin/chronyd" subj=system_u:system_r:chronyd_t:s0 key=(null) type=AVC msg=audit(1612390103.854:74): avc: denied { sendto } for pid=1129 comm="chronyd" path="/host/run/chrony/chronyc.36667.sock" scontext=system_u:system_r:chronyd_t:s0 tcontext=system_u:system_r:spc_t:s0 tclass=unix_dgram_socket permissive=0 ``` I haven't tried to reproduce this in vanilla RHEL 8.3 yet, so filing against RHCOS initially
Needs additional investigation on vanilla RHEL 8
Hmm, not reproducing on vanilla RHEL 8 ``` [miabbott@miabbott-rhel-8a ~]$ cat /etc/os-release NAME="Red Hat Enterprise Linux" VERSION="8.3 (Ootpa)" ID="rhel" ID_LIKE="fedora" VERSION_ID="8.3" PLATFORM_ID="platform:el8" PRETTY_NAME="Red Hat Enterprise Linux 8.3 (Ootpa)" ANSI_COLOR="0;31" CPE_NAME="cpe:/o:redhat:enterprise_linux:8.3:GA" HOME_URL="https://www.redhat.com/" BUG_REPORT_URL="https://bugzilla.redhat.com/" REDHAT_BUGZILLA_PRODUCT="Red Hat Enterprise Linux 8" REDHAT_BUGZILLA_PRODUCT_VERSION=8.3 REDHAT_SUPPORT_PRODUCT="Red Hat Enterprise Linux" REDHAT_SUPPORT_PRODUCT_VERSION="8.3" [miabbott@miabbott-rhel-8a ~]$ rpm -q chrony selinux-policy chrony-3.5-1.el8.x86_64 selinux-policy-3.14.3-54.el8_3.2.noarch [miabbott@miabbott-rhel-8a ~]$ systemctl status chronyd ● chronyd.service - NTP client/server Loaded: loaded (/usr/lib/systemd/system/chronyd.service; enabled; vendor preset: enabled) Active: active (running) since Thu 2021-02-25 16:34:32 UTC; 9min ago Docs: man:chronyd(8) man:chrony.conf(5) Process: 773 ExecStartPost=/usr/libexec/chrony-helper update-daemon (code=exited, status=0/SUCCESS) Process: 722 ExecStart=/usr/sbin/chronyd $OPTIONS (code=exited, status=0/SUCCESS) Main PID: 745 (chronyd) Tasks: 1 (limit: 23399) Memory: 1.9M CGroup: /system.slice/chronyd.service └─745 /usr/sbin/chronyd Feb 25 16:34:32 localhost systemd[1]: Starting NTP client/server... Feb 25 16:34:32 localhost chronyd[745]: chronyd version 3.5 starting (+CMDMON +NTP +REFCLOCK +RTC +PRIVDROP +SCFILTER +SIGND +ASYNCDNS +SECHASH +IPV6 +DEBUG) Feb 25 16:34:32 localhost chronyd[745]: Using right/UTC timezone to obtain leap second data Feb 25 16:34:32 localhost systemd[1]: Started NTP client/server. Feb 25 16:34:42 miabbott-rhel-8a chronyd[745]: Selected source 169.254.169.254 Feb 25 16:34:42 miabbott-rhel-8a chronyd[745]: System clock TAI offset set to 37 seconds [miabbott@miabbott-rhel-8a ~]$ time chronyc sources 210 Number of sources = 1 MS Name/IP address Stratum Poll Reach LastRx Last sample =============================================================================== ^* metadata.google.internal 2 6 377 44 +25us[ +18us] +/- 737us real 0m0.003s user 0m0.001s sys 0m0.002s [miabbott@miabbott-rhel-8a ~]$ cat /etc/chrony.conf # These servers were defined in the installation: server metadata.google.internal iburst # Use public servers from the pool.ntp.org project. # Please consider joining the pool (http://www.pool.ntp.org/join.html). # Record the rate at which the system clock gains/losses time. driftfile /var/lib/chrony/drift # Allow the system clock to be stepped in the first three updates # if its offset is larger than 1 second. makestep 1.0 3 # Enable kernel synchronization of the real-time clock (RTC). rtcsync # Enable hardware timestamping on all interfaces that support it. #hwtimestamp * # Increase the minimum number of selectable sources required to adjust # the system clock. #minsources 2 # Allow NTP client access from local network. #allow 192.168.0.0/16 # Serve time even if not synchronized to a time source. #local stratum 10 # Specify file containing keys for NTP authentication. keyfile /etc/chrony.keys # Get TAI-UTC offset and leap seconds from the system tz database. leapsectz right/UTC # Specify directory for log files. logdir /var/log/chrony # Select which information is logged. #log measurements statistics tracking [miabbott@miabbott-rhel-8a ~]$ sudo ausearch -m avc <no matches> ```
From initial review, this looks like a failure from running as spc_t (privileged container) vs unconfined_t on the node that can be worked around using systemd-run. I remember another bug about that but have not found it yet.
This is a duplicate of https://bugzilla.redhat.com/show_bug.cgi?id=1896369 which is marked as duplicate of https://bugzilla.redhat.com/show_bug.cgi?id=1839065 for which I filed https://github.com/openshift/oc/issues/641. We can decide to work on that if needed. *** This bug has been marked as a duplicate of bug 1896369 ***