Bug 1598302

Summary: SELinux is preventing systemd-journal from search access on the directory /var/log/journal/UUID
Product: [Fedora] Fedora Reporter: Chris Murphy <bugzilla>
Component: selinux-policyAssignee: Lukas Vrabec <lvrabec>
Status: CLOSED INSUFFICIENT_DATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 28CC: bugzilla, dwalsh, lvrabec, mgrepl, plautrba, pmoore
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-08-13 14:48:32 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:
Attachments:
Description Flags
journal none

Description Chris Murphy 2018-07-05 04:01:45 UTC
Description of problem:

SELinux is preventing systemd-journal from search access on the directory /var/log/journal/bbe68372db9f4c589a1f67f008e70864.


Version-Release number of selected component (if applicable):
systemd-238-8.git0e0aa59.fc28.x86_64
selinux-policy-3.14.1-32.fc28.noarch


How reproducible:
Not sure yet, 1 for 1.

Steps to Reproduce:
I don't know, this hasn't happened before now. The only change to the system is I just put /var/log on F2FS. I copied old /var/log on Btrfs to new /var/log on F2FS using cp -a. I then mount new /var/log in place, and used restorecon -rv and updated fstab. I've rebooted several times to confirm systemd is mounting /var/log correctly, and only then does it flush the journal from /run to /var. It had been working right up until dnf make cache timer kicked off.


Actual results:

Many many AVC messages suddenly started appearing in GNOME. And then the whole system hung up completely, it was not recoverable, I had to force power off.


Expected results:

Something more graceful, not sure. Maybe it's an unsupported configuration.


Additional info:

SELinux is preventing systemd-journal from search access on the directory /var/log/journal/bbe68372db9f4c589a1f67f008e70864.

*****  Plugin restorecon (99.5 confidence) suggests   ************************

If you want to fix the label. 
/var/log/journal/bbe68372db9f4c589a1f67f008e70864 default label should be var_log_t.
Then you can run restorecon. The access attempt may have been stopped due to insufficient permissions to access a parent directory in which case try to change the following command accordingly.
Do
# /sbin/restorecon -v /var/log/journal/bbe68372db9f4c589a1f67f008e70864

*****  Plugin catchall (1.49 confidence) suggests   **************************

If you believe that systemd-journal should be allowed search access on the bbe68372db9f4c589a1f67f008e70864 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:
# ausearch -c 'systemd-journal' --raw | audit2allow -M my-systemdjournal
# semodule -X 300 -i my-systemdjournal.pp

Additional Information:
Source Context                system_u:system_r:syslogd_t:s0
Target Context                system_u:object_r:rpm_var_cache_t:s0
Target Objects                /var/log/journal/bbe68372db9f4c589a1f67f008e70864
                              [ dir ]
Source                        systemd-journal
Source Path                   systemd-journal
Port                          <Unknown>
Host                          f28h.local
Source RPM Packages           systemd-238-8.git0e0aa59.fc28.x86_64
Target RPM Packages           
Policy RPM                    selinux-policy-3.14.1-32.fc28.noarch
Selinux Enabled               True
Policy Type                   targeted
Enforcing Mode                Enforcing
Host Name                     f28h.local
Platform                      Linux f28h.local 4.17.4-200.fc28.x86_64 #1 SMP Tue
                              Jul 3 14:06:39 UTC 2018 x86_64 x86_64
Alert Count                   471
First Seen                    2018-07-04 21:35:51 MDT
Last Seen                     2018-07-04 21:35:59 MDT
Local ID                      95e6df49-de12-4f6e-ac9f-5df04a477a04

Raw Audit Messages
type=AVC msg=audit(1530761759.305:2329): avc:  denied  { search } for  pid=485 comm="systemd-journal" name="log" dev="nvme0n1p6" ino=4889201 scontext=system_u:system_r:syslogd_t:s0 tcontext=system_u:object_r:rpm_var_cache_t:s0 tclass=dir permissive=0


type=SYSCALL msg=audit(1530761759.305:2329): arch=x86_64 syscall=openat success=no exit=EACCES a0=ffffff9c a1=56191fc70850 a2=90800 a3=0 items=1 ppid=1 pid=485 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm=systemd-journal exe=/usr/lib/systemd/systemd-journald subj=system_u:system_r:syslogd_t:s0 key=(null)

type=CWD msg=audit(1530761759.305:2329): cwd=/

type=PATH msg=audit(1530761759.305:2329): item=0 name=/var/log/journal/bbe68372db9f4c589a1f67f008e70864 nametype=UNKNOWN cap_fp=0000000000000000 cap_fi=0000000000000000 cap_fe=0 cap_fver=0

Hash: systemd-journal,syslogd_t,rpm_var_cache_t,dir,search

Comment 1 Chris Murphy 2018-07-05 04:03:42 UTC
This line:
>Source Context                system_u:system_r:syslogd_t:s0

seems bogus.

[chris@f28h ~]$ ls -lZ /var/log/journal/
total 4
drwxr-sr-x+ 2 root systemd-journal system_u:object_r:var_log_t:s0 3488 Jul  4 21:48 bbe68372db9f4c589a1f67f008e70864
[chris@f28h ~]$

Comment 2 Chris Murphy 2018-07-05 04:08:24 UTC
Created attachment 1456645 [details]
journal

[chris@f28h ~]$ sudo journalctl -b-1 -o short-monotonic | grep -v drm > journal-avcjournald.txt

There are 21,000+ AVC messages.

Comment 3 Chris Murphy 2018-07-05 04:25:59 UTC
I wonder if this is related. It appears a few minutes before the tens of thousands of avc messages.

/var/log/sa (which is present contrary the message) has label system_u:object_r:sysstat_log_t:s0


Jul 04 21:30:03 f28h.local systemd[1]: Starting system activity accounting tool...
Jul 04 21:30:03 f28h.local sa1[4745]: Cannot open /var/log/sa: No such file or directory
Jul 04 21:30:03 f28h.local systemd[1]: sysstat-collect.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Jul 04 21:30:03 f28h.local systemd[1]: sysstat-collect.service: Failed with result 'exit-code'.
Jul 04 21:30:03 f28h.local systemd[1]: Failed to start system activity accounting tool.
Jul 04 21:30:03 f28h.local audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=sysstat-collect comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'


But there is no AVC for this failure itself. The directory exists has correct permissions and label, and contents (bunch of files from June).

Comment 4 Chris Murphy 2018-07-05 19:34:27 UTC
Bizarre, I haven't changed anything since filing this and now I'm not getting the 'sa1 cannot open /var/log/sa' message, or the systat-collect failure, or any avc's on /var/log/journal/<uuid>

I'll keep this open for now but at the moment it's looking like a sunspots bug.

Comment 5 Lukas Vrabec 2018-07-20 12:12:37 UTC
Are you able to reproduce it? 

Thanks,
Lukas.

Comment 6 Chris Murphy 2018-08-13 14:48:32 UTC
Nope. It hasn't happened again, systemd-journald on f2fs /var/log has been stable since. I'll assume some kind of user or transient error following the initial switch.