Bug 2182660

Summary: No audit event recorded when not having any rule
Product: Red Hat Enterprise Linux 9 Reporter: Renaud Métrich <rmetrich>
Component: kernelAssignee: Richard Guy Briggs <rbriggs>
kernel sub component: Audit QA Contact: BaseOS QE Security Team <qe-baseos-security>
Status: CLOSED MIGRATED Docs Contact:
Severity: high    
Priority: high CC: alakatos, dapospis, denli, scorreia, sgrubb
Version: 9.1Keywords: MigratedToJIRA
Target Milestone: rcFlags: pm-rhel: mirror+
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2023-09-25 19:49:55 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:

Description Renaud Métrich 2023-03-29 09:34:12 UTC
Description of problem:

I know it's a known "limitation" of audit subsystem, but it's clear annoying and make us (Support) lose a lot of time regularly.

On a vanilla system not having any audit rule (the default), it happens that audit events are not always recorded.
This makes troubleshooting harder because we lose critical and valuable information.

For example this affected me recently when troubleshooting BZ #2181539.

But there are more scenarios where this happens, e.g. below:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
[root@vm-rhel9 ~]# cat /proc/sys/fs/protected_regular
1
[root@vm-rhel9 ~]# mkdir -p /root/tmp
[root@vm-rhel9 ~]# chmod 1777 /root/tmp
[root@vm-rhel9 ~]# touch /root/tmp/test.txt
[root@vm-rhel9 ~]# useradd test
[root@vm-rhel9 ~]# chown test /root/tmp/test.txt
[root@vm-rhel9 ~]# { echo C0644 12 test.txt ; printf 'hello\ntest1\n'; printf \\000; } | scp -t /root/tmp
scp: /root/tmp/test.txt: Permission denied
scp: protocol error: expected control record
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

Checking the audit log, we see nothing explaining the EACCES *scp* gets.

After adding an audit rule (related or not), and retrying the test, we can then see the reason:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
type=PROCTITLE msg=audit(03/29/2023 11:22:52.311:501) : proctitle=scp -t /root/tmp 
type=PATH msg=audit(03/29/2023 11:22:52.311:501) : item=1 name=/root/tmp/test.txt inode=33576200 dev=fd:00 mode=file,644 ouid=admin ogid=root rdev=00:00 obj=unconfined_u:object_r:admin_home_t:s0 nametype=NORMAL cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0 
type=PATH msg=audit(03/29/2023 11:22:52.311:501) : item=0 name=/root/tmp/ inode=33576201 dev=fd:00 mode=dir,sticky,777 ouid=root ogid=root rdev=00:00 obj=unconfined_u:object_r:admin_home_t:s0 nametype=PARENT cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0 
type=CWD msg=audit(03/29/2023 11:22:52.311:501) : cwd=/root 
type=SYSCALL msg=audit(03/29/2023 11:22:52.311:501) : arch=x86_64 syscall=openat success=no exit=EACCES(Permission denied) a0=AT_FDCWD a1=0x5629b4009500 a2=O_WRONLY|O_CREAT a3=0x1a4 items=2 ppid=12525 pid=12528 auid=root uid=root gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root tty=pts0 ses=6 comm=scp exe=/usr/bin/scp subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key=(null) 
type=ANOM_CREAT msg=audit(03/29/2023 11:22:52.311:501) : op=sticky_create_regular ppid=12525 pid=12528 auid=root uid=root gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root tty=pts0 ses=6 comm=scp exe=/usr/bin/scp subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 res=no 
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

Clearly something has to be done here, it's very often we lose a lot of time due to this limitation.
If nothing can be done, then we at least need to always ship a rule (e.g. the usual one on "/etc/shadow") with default configuration to avoid this pitfall in the future.

Version-Release number of selected component (if applicable):

audit-3.0.7-103.el9.x86_64

How reproducible:

Always, see above.

Comment 2 Steve Grubb 2023-03-29 13:22:24 UTC
I think this is a kernel bug. There is a function, audit_log_path_denied() which is intended to log this event. Because this is a security policy violation and should occur rarely, it should not have to be subjected to the dummy context check. The dummy context check ensures that events are recorded if there are rules loaded. I would suggest deleting the dummy context check in audit_log_path_denied() as the fix.

Comment 3 Renaud Métrich 2023-03-29 14:19:25 UTC
IMHO everything that pops up an event should be always recorded, even when there is no rule.

I need to experiment again, but I'm pretty this can also happen with SELinux AVCs, depending on how the system was started ("audit=1" or nothing).
I'm not sure it has same root cause however.

Comment 4 Renaud Métrich 2023-03-29 14:25:46 UTC
"everything that pops up an event" == "failure event" more precisely

Comment 5 Steve Grubb 2023-03-29 14:35:12 UTC
The problem is that it may be too late in the syscall when the failure occurs to collect enough info for a meaningful event. I know SE linux varies in the quality of its information based on whether rules are loaded or not. It would have to be carefully checked to see if the dummy context check can be removed or if there's a workaround to augment the information that can be logged. For example, if we remove the check and only get a naked ANOM_LINK record, it has the program and user but not which file was being created. You have to somehow trigger the collection of that information so that it makes sense. But then again, maybe we get the full event. It would have to be tested.

Comment 6 Dalibor Pospíšil 2023-07-20 09:39:58 UTC
Wouldn't the kernel/audit be a better component to discuss this?

Comment 7 Steve Grubb 2023-07-20 13:00:40 UTC
Yes, this was identified as a kernel bug in comment 2.

Comment 8 RHEL Program Management 2023-09-25 19:46:09 UTC
Issue migration from Bugzilla to Jira is in process at this time. This will be the last message in Jira copied from the Bugzilla bug.

Comment 9 RHEL Program Management 2023-09-25 19:49:55 UTC
This BZ has been automatically migrated to the issues.redhat.com Red Hat Issue Tracker. All future work related to this report will be managed there.

Due to differences in account names between systems, some fields were not replicated.  Be sure to add yourself to Jira issue's "Watchers" field to continue receiving updates and add others to the "Need Info From" field to continue requesting information.

To find the migrated issue, look in the "Links" section for a direct link to the new issue location. The issue key will have an icon of 2 footprints next to it, and begin with "RHEL-" followed by an integer.  You can also find this issue by visiting https://issues.redhat.com/issues/?jql= and searching the "Bugzilla Bug" field for this BZ's number, e.g. a search like:

"Bugzilla Bug" = 1234567

In the event you have trouble locating or viewing this issue, you can file an issue by sending mail to rh-issues. You can also visit https://access.redhat.com/articles/7032570 for general account information.