Description of problem: The customer noticed that 'chronyc sources' is slow when run via 'oc debug node/<node>' sh-4.2# time chroot /host chronyc -n sources 210 Number of sources = 4 MS Name/IP address Stratum Poll Reach LastRx Last sample =============================================================================== ^+<IP> 3 8 377 56 -994us[ -994us] +/- 48ms ^*<IP> 3 9 377 315 -182us[ -187us] +/- 41ms ^+<IP> 4 8 377 120 +1322us[+1322us] +/- 38ms ^+ <IP> 3 9 377 316 -442us[ -447us] +/- 45ms real 0m7.013s user 0m0.002s sys 0m0.003s Log: type=AVC msg=audit(1601481923.321:268): avc: denied { sendto } for pid=328881 comm="chronyd" path="/host/run/chrony/chronyc.444332.sock" scontext=system_u:system_r:chronyd_t:s0 tcontext=system_u:system_r:spc_t:s0 tclass=unix_dgram_socket permissive=0 Even though chrontd_t is not permitted to transmit to a socket owned by spc_t, the command is eventually successful! # strace -tt chroot /host chronyc -n sources [...] 16:09:06.831567 socket(AF_UNIX, SOCK_DGRAM, 0) = 3 16:09:06.831815 getpid() = 454225 16:09:06.831922 unlink("/var/run/chrony/chronyc.454225.sock") = -1 ENOENT (No such file or directory) 16:09:06.832073 bind(3, {sa_family=AF_UNIX, sun_path="/var/run/chrony/chronyc.454225.sock"}, 110) = 0 16:09:06.832282 chmod("/var/run/chrony/chronyc.454225.sock", 0666) = 0 16:09:06.832431 connect(3, {sa_family=AF_UNIX, sun_path="/var/run/chrony/chronyd.sock"}, 110) = 0 16:09:06.832571 getrandom("\x16\x4d\xd5\xaa\xb8\xdf\xca\x34\x62\x74\xf8\x7d\x43\xc0\x81\x80\xe4\x3f\xe6\x6a\x6a\xde\xea\x19\x2f\xc0\x27\xd8\xb6\xb6\x79\x1c"..., 256, GRND_NONBLOCK) = 256 16:09:06.832756 sendto(3, "\6\1\0\0\0\16\0\0\210\21\v\372\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 32, 0, NULL, 0) = 32 16:09:06.833009 select(4, [3], NULL, NULL, {tv_sec=1, tv_usec=0}) = 0 (Timeout) 16:09:07.834432 sendto(3, "\6\1\0\0\0\16\0\1&\242\275\340\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 32, 0, NULL, 0) = 32 16:09:07.834837 select(4, [3], NULL, NULL, {tv_sec=2, tv_usec=0}) = 0 (Timeout) 16:09:09.837245 sendto(3, "\6\1\0\0\0\16\0\2\34C\224\354\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 32, 0, NULL, 0) = 32 16:09:09.837605 select(4, [3], NULL, NULL, {tv_sec=4, tv_usec=0}) = 0 (Timeout) 16:09:13.842016 getsockname(3, {sa_family=AF_UNIX, sun_path="/var/run/chrony/chronyc.454225.sock"}, [112->38]) = 0 16:09:13.842292 unlink("/var/run/chrony/chronyc.454225.sock") = 0 16:09:13.842504 close(3) = 0 16:09:13.842650 socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 3 16:09:13.842870 connect(3, {sa_family=AF_INET, sin_port=htons(323), sin_addr=inet_addr("127.0.0.1")}, 16) = 0 16:09:13.843073 sendto(3, "\6\1\0\0\0\16\0\0?\300\227\330\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 32, 0, NULL, 0) = 32 16:09:13.843459 select(4, [3], NULL, NULL, {tv_sec=1, tv_usec=0}) = 1 (in [3], left {tv_sec=0, tv_usec=999997}) 16:09:13.843631 recvfrom(3, "\6\2\0\0\0\16\0\2\0\0\0\0\0\0\0\0?\300\227\330\0\0\0\0\0\0\0\0\0\0\0\4", 428, 0, NULL, NULL) = 32 16:09:13.843862 fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 This indicates that chronyd is allowed to communicate with chronyc via IP sockets, but not via UNIX sockets. Workaround: force use of IP with: sh-4.4# time chronyc -n -h localhost sources 210 Number of sources = 4 MS Name/IP address Stratum Poll Reach LastRx Last sample =============================================================================== ^+ <IP> 3 9 377 271 -858us[ -874us] +/- 52ms ^* <IP> 3 9 377 269 -161us[ -177us] +/- 42ms ^+<IP> 4 9 377 75 +1462us[+1462us] +/- 46ms ^+ <IP> 3 9 377 276 -179us[ -195us] +/- 53ms real 0m0.005s user 0m0.001s sys 0m0.004s The final ask for the customer is that: "SELinux could be made to not block communication via UNIX sockets." Version-Release number of selected component (if applicable): 4.5 Actual results: SELinux is blocking UNIX sockets. Expected results: SELinux should not block UNIX sockets.
I was able to reproduce this on an RHCOS 4.6 node in AWS (46.82.202010301241-0). But I am not seeing any evidence of an SELinux denial in my test. However, this does not reproduce on a vanilla RHEL 8 system with a similar set of chrony, kernel, selinux-policy RPMs The `strace` on the RHEL 8 system shows that `chronyc` is able to talk to the UNIX socket successfully, with no timeout. It's not obvious to me why RHCOS is behaving differently here; will need further investigation. Since the system is still functional I'm setting this as a low severity/priority BZ targeted for 4.7 RHCOS 4.6 node: ``` sh-4.4# rpm-ostree status State: idle Deployments: * pivot://quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:12c8c2c4fb915e49e2f1a42f5761b6f8cf1ee84393d22a3fe143bdabc98c05a8 CustomOrigin: Managed by machine-config-operator Version: 46.82.202010301241-0 (2020-10-30T12:45:37Z) ostree://ce0233ed167e2496ed0806af43984cbd063222ddd8229de8b09741fbce414b81 Version: 46.82.202010011740-0 (2020-10-01T17:44:34Z) sh-4.4# rpm -q chrony kernel selinux-policy selinux-policy-targeted chrony-3.5-1.el8.x86_64 kernel-4.18.0-193.28.1.el8_2.x86_64 selinux-policy-3.14.3-41.el8_2.8.noarch selinux-policy-targeted-3.14.3-41.el8_2.8.noarch 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 Tue 2020-11-10 14:28:30 UTC; 2h 15min ago Docs: man:chronyd(8) man:chrony.conf(5) Process: 1169 ExecStartPost=/usr/libexec/chrony-helper update-daemon (code=exited, status=0/SUCCESS) Process: 1134 ExecStart=/usr/sbin/chronyd -f /run/coreos-platform-chrony.conf $OPTIONS (code=exited, status=0/SUCCESS) Main PID: 1166 (chronyd) Tasks: 1 (limit: 102073) Memory: 2.0M CPU: 128ms CGroup: /system.slice/chronyd.service └─1166 /usr/sbin/chronyd -f /run/coreos-platform-chrony.conf Nov 10 14:28:30 localhost systemd[1]: Starting NTP client/server... Nov 10 14:28:30 localhost chronyd[1166]: chronyd version 3.5 starting (+CMDMON +NTP +REFCLOCK +RTC +PRIVDROP +SCFILTER +SIGND +ASYNCDNS +SECHASH +IPV6 +DEBUG) Nov 10 14:28:30 localhost chronyd[1166]: Frequency 8.907 +/- 0.413 ppm read from /var/lib/chrony/drift Nov 10 14:28:30 localhost chronyd[1166]: Using right/UTC timezone to obtain leap second data Nov 10 14:28:30 localhost systemd[1]: Started NTP client/server. Nov 10 14:28:36 ip-10-0-149-205 chronyd[1166]: Selected source 169.254.169.123 Nov 10 14:28:36 ip-10-0-149-205 chronyd[1166]: 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://docs.aws.amazon.com/AWSEC2/latest/UserGuide/set-time.html server 169.254.169.123 prefer iburst minpoll 4 maxpoll 4 sh-4.4# time chronyc -n sources 210 Number of sources = 1 MS Name/IP address Stratum Poll Reach LastRx Last sample =============================================================================== ^* 169.254.169.123 3 4 377 10 +6171ns[ +12us] +/- 412us real 0m7.006s user 0m0.000s sys 0m0.002s sh-4.4# journalctl | grep -e chrony -e avc Nov 10 14:26:20 ip-10-0-149-205 coreos-platform-chrony: Updated chrony to use aws configuration /run/coreos-platform-chrony.conf Nov 10 14:26:27 ip-10-0-149-205 chronyd[1494]: chronyd version 3.5 starting (+CMDMON +NTP +REFCLOCK +RTC +PRIVDROP +SCFILTER +SIGND +ASYNCDNS +SECHASH +IPV6 +DEBUG) Nov 10 14:26:27 ip-10-0-149-205 chronyd[1494]: Using right/UTC timezone to obtain leap second data Nov 10 14:26:35 ip-10-0-149-205 chronyd[1494]: Selected source 169.254.169.123 Nov 10 14:26:35 ip-10-0-149-205 chronyd[1494]: System clock TAI offset set to 37 seconds Nov 10 14:27:39 ip-10-0-149-205 chronyd[1494]: chronyd exiting Nov 10 14:27:39 ip-10-0-149-205 systemd[1]: chronyd.service: Consumed 30ms CPU time Nov 10 14:28:25 localhost coreos-platform-chrony: Updated chrony to use aws configuration /run/coreos-platform-chrony.conf Nov 10 14:28:30 localhost chronyd[1166]: chronyd version 3.5 starting (+CMDMON +NTP +REFCLOCK +RTC +PRIVDROP +SCFILTER +SIGND +ASYNCDNS +SECHASH +IPV6 +DEBUG) Nov 10 14:28:30 localhost chronyd[1166]: Frequency 8.907 +/- 0.413 ppm read from /var/lib/chrony/drift Nov 10 14:28:30 localhost chronyd[1166]: Using right/UTC timezone to obtain leap second data Nov 10 14:28:36 ip-10-0-149-205 chronyd[1166]: Selected source 169.254.169.123 Nov 10 14:28:36 ip-10-0-149-205 chronyd[1166]: System clock TAI offset set to 37 seconds Nov 10 14:28:40 ip-10-0-149-205 hyperkube[1526]: I1110 14:28:40.054245 1526 factory.go:216] Factory "systemd" was unable to handle container "/system.slice/chronyd.service" Nov 10 14:28:40 ip-10-0-149-205 hyperkube[1526]: I1110 14:28:40.054256 1526 factory.go:216] Factory "crio" was unable to handle container "/system.slice/chronyd.service" Nov 10 14:28:40 ip-10-0-149-205 hyperkube[1526]: I1110 14:28:40.054268 1526 factory.go:212] Using factory "raw" for container "/system.slice/chronyd.service" Nov 10 14:28:40 ip-10-0-149-205 hyperkube[1526]: I1110 14:28:40.054640 1526 manager.go:987] Added container: "/system.slice/chronyd.service" (aliases: [], namespace: "") Nov 10 14:28:40 ip-10-0-149-205 hyperkube[1526]: I1110 14:28:40.054916 1526 handler.go:325] Added event &{/system.slice/chronyd.service 2020-11-10 14:28:40.052396397 +0000 UTC containerCreation {<nil>}} Nov 10 14:28:40 ip-10-0-149-205 hyperkube[1526]: I1110 14:28:40.055847 1526 container.go:490] Start housekeeping for container "/system.slice/chronyd.service" ``` RHEL 8 node: ``` [cloud-user@ip-10-10-10-40 ~]$ cat /etc/os-release NAME="Red Hat Enterprise Linux" VERSION="8.2 (Ootpa)" ID="rhel" ID_LIKE="fedora" VERSION_ID="8.2" PLATFORM_ID="platform:el8" PRETTY_NAME="Red Hat Enterprise Linux 8.2 (Ootpa)" ANSI_COLOR="0;31" CPE_NAME="cpe:/o:redhat:enterprise_linux:8.2: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.2 REDHAT_SUPPORT_PRODUCT="Red Hat Enterprise Linux" REDHAT_SUPPORT_PRODUCT_VERSION="8.2" [cloud-user@ip-10-10-10-40 ~]$ rpm -q chrony kernel selinux-policy selinux-policy-targeted chrony-3.5-1.el8.x86_64 kernel-4.18.0-193.el8.x86_64 kernel-4.18.0-193.28.1.el8_2.x86_64 selinux-policy-3.14.3-41.el8_2.8.noarch selinux-policy-targeted-3.14.3-41.el8_2.8.noarch $ uname -a Linux ip-10-10-10-40.us-west-2.compute.internal 4.18.0-193.28.1.el8_2.x86_64 #1 SMP Fri Oct 16 13:38:49 EDT 2020 x86_64 x86_64 x86_64 GNU/Linux [cloud-user@ip-10-10-10-40 ~]$ sudo systemctl status chronyd ● chronyd.service - NTP client/server Loaded: loaded (/usr/lib/systemd/system/chronyd.service; enabled; vendor preset: enabled) Drop-In: /etc/systemd/system/chronyd.service.d └─override.conf Active: active (running) since Tue 2020-11-10 16:39:13 UTC; 5min ago Docs: man:chronyd(8) man:chrony.conf(5) Process: 717 ExecStartPost=/usr/libexec/chrony-helper update-daemon (code=exited, status=0/SUCCESS) Process: 690 ExecStart=/usr/sbin/chronyd -f /etc/coreos-platform-chrony.conf $OPTIONS (code=exited, status=0/SUCCESS) Main PID: 693 (chronyd) Tasks: 1 (limit: 23808) Memory: 2.0M CGroup: /system.slice/chronyd.service └─693 /usr/sbin/chronyd -f /etc/coreos-platform-chrony.conf Nov 10 16:39:13 ip-10-10-10-40.us-west-2.compute.internal systemd[1]: Starting NTP client/server... Nov 10 16:39:13 ip-10-10-10-40.us-west-2.compute.internal chronyd[693]: chronyd version 3.5 starting (+CMDMON +NTP +REFCLOCK +RTC +PRIVDROP +SCFILTER +SIGND +ASYNCDNS +SECHASH +IPV6 +DEBUG) Nov 10 16:39:13 ip-10-10-10-40.us-west-2.compute.internal chronyd[693]: Frequency 3.913 +/- 0.041 ppm read from /var/lib/chrony/drift Nov 10 16:39:13 ip-10-10-10-40.us-west-2.compute.internal chronyd[693]: Using right/UTC timezone to obtain leap second data Nov 10 16:39:13 ip-10-10-10-40.us-west-2.compute.internal systemd[1]: Started NTP client/server. Nov 10 16:39:21 ip-10-10-10-40.us-west-2.compute.internal chronyd[693]: Selected source 169.254.169.123 Nov 10 16:39:21 ip-10-10-10-40.us-west-2.compute.internal chronyd[693]: System clock TAI offset set to 37 seconds [cloud-user@ip-10-10-10-40 ~]$ cat /etc/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://docs.aws.amazon.com/AWSEC2/latest/UserGuide/set-time.html server 169.254.169.123 prefer iburst minpoll 4 maxpoll 4 [cloud-user@ip-10-10-10-40 ~]$ time chronyc -n sources 210 Number of sources = 1 MS Name/IP address Stratum Poll Reach LastRx Last sample =============================================================================== ^* 169.254.169.123 3 4 377 1 +8302ns[ +11us] +/- 521us real 0m0.002s user 0m0.000s sys 0m0.002s # strace -tt chronyc -n sources ... 16:49:54.608956 socket(AF_UNIX, SOCK_DGRAM, 0) = 3 16:49:54.609055 getpid() = 12602 16:49:54.609151 unlink("/var/run/chrony/chronyc.12602.sock") = -1 ENOENT (No such file or directory) 16:49:54.609258 bind(3, {sa_family=AF_UNIX, sun_path="/var/run/chrony/chronyc.12602.sock"}, 110) = 0 16:49:54.609387 chmod("/var/run/chrony/chronyc.12602.sock", 0666) = 0 16:49:54.609503 connect(3, {sa_family=AF_UNIX, sun_path="/var/run/chrony/chronyd.sock"}, 110) = 0 16:49:54.609608 gettimeofday({tv_sec=1605026994, tv_usec=609631}, NULL) = 0 16:49:54.609709 getrandom("\xf7\xd3\xbc\x40\xc0\xb7\x20\x55\xda\xd9\x79\xd6\x7f\x50\x37\xd0\x98\x81\xf3\x54\xbf\x08\x07\x75\xb3\x75\x6b\x16\xa6\xb6\x09\x4e"..., 256, GRND_NONBLOCK) = 256 16:49:54.609813 sendto(3, "\6\1\0\0\0\16\0\0\256\35\32\355\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 32, 0, NULL, 0) = 32 16:49:54.610279 select(4, [3], NULL, NULL, {tv_sec=1, tv_usec=0}) = 1 (in [3], left {tv_sec=0, tv_usec=999999}) 16:49:54.610393 recvfrom(3, "\6\2\0\0\0\16\0\2\0\0\0\0\0\0\0\0\256\35\32\355\0\0\0\0\0\0\0\0\0\0\0\1", 428, 0, NULL, NULL) = 32 16:49:54.610506 fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0), ...}) = 0 ... ```
*** This bug has been marked as a duplicate of bug 1839065 ***
Created https://github.com/openshift/oc/issues/641 for the fix in `oc`.
*** Bug 1924926 has been marked as a duplicate of this bug. ***