Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Blocks not appearing in the audit logs when using deny_audit #84

Closed
scholarsmate opened this issue Jul 17, 2020 · 36 comments
Closed

Blocks not appearing in the audit logs when using deny_audit #84

scholarsmate opened this issue Jul 17, 2020 · 36 comments
Labels

Comments

@scholarsmate
Copy link
Contributor

I just built and installed fapolicyd via an RPM ($ sudo yum install -y /home/scholarsmate/rpmbuild/RPMS/x86_64/fapolicyd-1.0.1-1.x86_64.rpm). Everything is stock, except I created a rule to deny (with audit) /usr/local/bin/xz. The details of the test are below.

[root@centos8-awc fapolicyd]# systemctl status fapolicyd
● fapolicyd.service - File Access Policy Daemon
   Loaded: loaded (/usr/lib/systemd/system/fapolicyd.service; enabled; vendor preset: disabled)
   Active: active (running) since Fri 2020-07-17 17:48:00 EDT; 5min ago
  Process: 17557 ExecStart=/usr/sbin/fapolicyd (code=exited, status=0/SUCCESS)
 Main PID: 17558 (fapolicyd)
    Tasks: 4 (limit: 50484)
   Memory: 17.0M
   CGroup: /system.slice/fapolicyd.service
           └─17558 /usr/sbin/fapolicyd

Jul 17 17:48:00 centos8-awc systemd[1]: Starting File Access Policy Daemon...
Jul 17 17:48:00 centos8-awc systemd[1]: fapolicyd.service: Can't open PID file /run/fapolicyd.pid (yet?) after start: No such file or directory
Jul 17 17:48:00 centos8-awc systemd[1]: Started File Access Policy Daemon.
Jul 17 17:48:00 centos8-awc fapolicyd[17558]: Initializing the database
Jul 17 17:48:00 centos8-awc fapolicyd[17558]: fapolicyd integrity is 0
Jul 17 17:48:00 centos8-awc fapolicyd[17558]: Loading rpmdb backend
Jul 17 17:48:00 centos8-awc fapolicyd[17558]: Checking database
Jul 17 17:48:00 centos8-awc fapolicyd[17558]: Importing data from rpmdb backend
Jul 17 17:48:00 centos8-awc fapolicyd[17558]: Importing data from file backend
Jul 17 17:48:00 centos8-awc fapolicyd[17558]: Database checks OK
[root@centos8-awc fapolicyd]# fapolicyd-cli --list
-> %languages=application/x-bytecode.ocaml,application/x-bytecode.python,application/java-archive,text/javascript,text/x-awk,text/x-gawk,text/x-java,text/x-lisp,text/x-lua,text/x-m4,text/x-perl,text/x-php,text/x-python,text/x-R,text/x-ruby,text/x-script.guile,text/x-tcl,text/x-luatex,text/x-systemtap
1. allow perm=any uid=0 : dir=/var/tmp/
2. allow perm=any uid=0 trust=1 : all
3. deny_audit perm=any pattern=ld_so : all
4. allow perm=open exe=/usr/bin/rpm : all
5. allow perm=open exe=/usr/libexec/platform-python3.6 comm=dnf : all
6. deny_audit perm=any exe=/usr/local/bin/xz : all
7. allow perm=open all : ftype=application/x-sharedlib trust=1
8. deny_audit perm=open all : ftype=application/x-sharedlib
9. allow perm=execute all : trust=1
10. allow perm=any uid=0 : dir=/tmp/ansible
11. allow perm=any uid=0 : dir=/root/.ansible/tmp/
12. allow perm=open all : ftype=%languages trust=1
13. deny_audit perm=any all : ftype=%languages
14. allow perm=any all : ftype=text/x-shellscript
15. deny_audit perm=execute all : all
16. allow perm=open all : all
[root@centos8-awc fapolicyd]# tail -n2 /var/log/audit/audit.log
type=SERVICE_STOP msg=audit(1595022480.436:314): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=fapolicyd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"
type=SERVICE_START msg=audit(1595022480.445:315): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=fapolicyd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"
[root@centos8-awc fapolicyd]# /usr/local/bin/xz --version
/usr/local/bin/xz: error while loading shared libraries: liblzma.so.5: cannot open shared object file: Operation not permitted
[root@centos8-awc fapolicyd]# tail -n2 /var/log/audit/audit.log
type=SERVICE_STOP msg=audit(1595022480.436:314): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=fapolicyd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"
type=SERVICE_START msg=audit(1595022480.445:315): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=fapolicyd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"
[root@centos8-awc fapolicyd]#

I was expecting something to show up in /var/log/audit/audit.log, but nothing was written to it after the execution of /usr/local/bin/xz was blocked. Is this the expected behavior?

Thanks.

@stevegrubb
Copy link
Member

Rule 6 says it will not allow xz to access any files. This probably means its own shared objects at link time. And that is probably why it blocks. To block execution of xz, you probably want deny_audit perm=execute all : path=/usr/local/bin/xz. Also, I think you would want this below the shared object rules but before the elf executables.

It is not expected that a rule with deny_audit would not log something. I just tested this on my system using the rule as given and I see an event. However, its rule 15 which is a general no execution rule.

@scholarsmate
Copy link
Contributor Author

I'm still having a devil of a time getting something to show up in the audit log. I went and updated the rule per your suggestion and now it appears to properly deny execution by bash, but the deny event still isn't appearing in the audit.log.

If I run fapolicyd like this: # fapolicyd --debug, I can see the deny:

rule=8 dec=deny_audit perm=execute auid=1001 pid=18670 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable
rule=16 dec=allow perm=open auid=1001 pid=18670 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable
rule=16 dec=allow perm=open auid=1001 pid=18670 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable

Here is the list of rules:

# fapolicyd-cli --list
-> %languages=application/x-bytecode.ocaml,application/x-bytecode.python,application/java-archive,text/javascript,text/x-awk,text/x-gawk,text/x-java,text/x-lisp,text/x-lua,text/x-m4,text/x-perl,text/x-php,text/x-python,text/x-R,text/x-ruby,text/x-script.guile,text/x-tcl,text/x-luatex,text/x-systemtap
1. allow perm=any uid=0 : dir=/var/tmp/
2. allow perm=any uid=0 trust=1 : all
3. deny_audit perm=any pattern=ld_so : all
4. allow perm=open exe=/usr/bin/rpm : all
5. allow perm=open exe=/usr/libexec/platform-python3.6 comm=dnf : all
6. allow perm=open all : ftype=application/x-sharedlib trust=1
7. deny_audit perm=open all : ftype=application/x-sharedlib
8. deny_audit perm=execute all : path=/usr/local/bin/xz
9. allow perm=execute all : trust=1
10. allow perm=any uid=0 : dir=/tmp/ansible
11. allow perm=any uid=0 : dir=/root/.ansible/tmp/
12. allow perm=open all : ftype=%languages trust=1
13. deny_audit perm=any all : ftype=%languages
14. allow perm=any all : ftype=text/x-shellscript
15. deny_audit perm=execute all : all
16. allow perm=open all : all

Here's the test:

Root terminal:

# date && tail -n1 /var/log/audit/audit.log
Fri Jul 17 23:37:48 EDT 2020
type=SERVICE_STOP msg=audit(1595042919.234:569): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"
# date && tail -n1 /var/log/audit/audit.log
Fri Jul 17 23:37:55 EDT 2020
type=SERVICE_STOP msg=audit(1595042919.234:569): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"
#

User terminal:

$ date && /usr/local/bin/xz --version
Fri Jul 17 23:37:52 EDT 2020
-bash: /usr/local/bin/xz: Operation not permitted
$

So we can see rule #8 is denying execution of /usr/local/bin/xz and its a deny_audit rule, but the audit.log remains untouched for the duration of the test.

Any suggestions on where I should look next?

@scholarsmate
Copy link
Contributor Author

scholarsmate commented Jul 18, 2020

Another data point. If I change the rule from deny_audit, to deny_log, I get an entry in /var/log/messages, but still no entry in /var/log/audit/audit.log.

[root@centos8-awc fapolicyd]# fapolicyd-cli --list
-> %languages=application/x-bytecode.ocaml,application/x-bytecode.python,application/java-archive,text/javascript,text/x-awk,text/x-gawk,text/x-java,text/x-lisp,text/x-lua,text/x-m4,text/x-perl,text/x-php,text/x-python,text/x-R,text/x-ruby,text/x-script.guile,text/x-tcl,text/x-luatex,text/x-systemtap
1. allow perm=any uid=0 : dir=/var/tmp/
2. allow perm=any uid=0 trust=1 : all
3. deny_audit perm=any pattern=ld_so : all
4. allow perm=open exe=/usr/bin/rpm : all
5. allow perm=open exe=/usr/libexec/platform-python3.6 comm=dnf : all
6. allow perm=open all : ftype=application/x-sharedlib trust=1
7. deny_audit perm=open all : ftype=application/x-sharedlib
8. deny_log perm=execute all : path=/usr/local/bin/xz
9. allow perm=execute all : trust=1
10. allow perm=any uid=0 : dir=/tmp/ansible
11. allow perm=any uid=0 : dir=/root/.ansible/tmp/
12. allow perm=open all : ftype=%languages trust=1
13. deny_audit perm=any all : ftype=%languages
14. allow perm=any all : ftype=text/x-shellscript
15. deny_audit perm=execute all : all
16. allow perm=open all : all
[root@centos8-awc fapolicyd]# tail -n0 -f /var/log/messages /var/log/audit/audit.log
==> /var/log/messages <==

==> /var/log/audit/audit.log <==

==> /var/log/messages <==
Jul 17 23:58:23 centos8-awc fapolicyd[18767]: rule=8 dec=deny_log perm=execute auid=1001 pid=18953 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable

@stevegrubb
Copy link
Member

I don't know if this fixes the issue or not, but Commit 5833afe corrects the mask used to decide what info goes to the kernel at decision time. Additionally, commit a742616 fixes the internal accounting of deny vs allow. Aside from that, I don't have any guess about what could be happening.

@scholarsmate
Copy link
Contributor Author

Thanks Steve, I'll pull down the latest and give it another whirl later today and update this thread with my results.

@scholarsmate
Copy link
Contributor Author

No dice! The latest code deadlocks my system when started via systemctl start fapolicyd. So after rebooting, then running it in debug mode, here's what we see, when I try to login via ssh:

[root@centos8-awc ~]# fapolicyd-cli --list
-> %languages=application/x-bytecode.ocaml,application/x-bytecode.python,application/java-archive,text/javascript,text/x-awk,text/x-gawk,text/x-java,text/x-lisp,text/x-lua,text/x-m4,text/x-perl,text/x-php,text/x-python,text/x-R,text/x-ruby,text/x-script.guile,text/x-tcl,text/x-luatex,text/x-systemtap
1. allow perm=any uid=0 : dir=/var/tmp/
2. allow perm=any uid=0 trust=1 : all
3. deny_audit perm=any pattern=ld_so : all
4. allow perm=open exe=/usr/bin/rpm : all
5. allow perm=open exe=/usr/libexec/platform-python3.6 comm=dnf : all
6. allow perm=open all : ftype=application/x-sharedlib trust=1
7. deny_audit perm=open all : ftype=application/x-sharedlib
8. allow perm=execute all : trust=1
9. allow perm=any uid=0 : dir=/tmp/ansible
10. allow perm=any uid=0 : dir=/root/.ansible/tmp/
11. allow perm=open all : ftype=%languages trust=1
12. deny_audit perm=any all : ftype=%languages
13. allow perm=any all : ftype=text/x-shellscript
14. deny_audit perm=execute all : all
15. allow perm=open all : all
[root@centos8-awc ~]# fapolicyd --debug
Loaded 15 rules
Changed to uid 991
Initializing the database
fapolicyd integrity is 0
backend rpmdb registered
backend file registered
Loading rpmdb backend
Loading file backend
Checking database
Importing data from rpmdb backend
Importing data from file backend
Database checks OK
added /dev/shm mount point
added / mount point
added /boot mount point
added /boot/efi mount point
added /run/user/1000 mount point
Starting to listen for events
rule=2 dec=allow perm=execute auid=-1 pid=1266 exe=/usr/sbin/sshd : path=/usr/sbin/sshd ftype=application/x-executable

The ssh hangs until I CTRL-C fapolicyd, then I can login. Then I restart fapolicyd in debug mode and try to run something, it locks everything up again.

rule=14 dec=deny_audit perm=execute auid=1001 pid=1315 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable
rule=15 dec=allow perm=open auid=1001 pid=1315 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable
rule=2 dec=allow perm=open auid=-1 pid=956 exe=/usr/sbin/agetty : path=/etc/issue ftype=text/plain

Even the VM console itself is locked. My only recourse is to CTRL-C fapolicyd.

@stevegrubb
Copy link
Member

It was missing a set of parenthesis in policy.h. Last commit should fix that.

@scholarsmate
Copy link
Contributor Author

I can confirm that the system no longer deadlocks with this change. I'm still not able to get anything in the audit log.

User terminal:

$ /usr/local/bin/xz --version
-bash: /usr/local/bin/xz: Operation not permitted
$ /usr/local/bin/xz --version
-bash: /usr/local/bin/xz: Operation not permitted
$

Root terminal:

# fapolicyd-cli --list
-> %languages=application/x-bytecode.ocaml,application/x-bytecode.python,application/java-archive,text/javascript,text/x-awk,text/x-gawk,text/x-java,text/x-lisp,text/x-lua,text/x-m4,text/x-perl,text/x-php,text/x-python,text/x-R,text/x-ruby,text/x-script.guile,text/x-tcl,text/x-luatex,text/x-systemtap
1. allow perm=any uid=0 : dir=/var/tmp/
2. allow perm=any uid=0 trust=1 : all
3. deny_audit perm=any pattern=ld_so : all
4. allow perm=open exe=/usr/bin/rpm : all
5. allow perm=open exe=/usr/libexec/platform-python3.6 comm=dnf : all
6. allow perm=open all : ftype=application/x-sharedlib trust=1
7. deny_audit perm=open all : ftype=application/x-sharedlib
8. allow perm=execute all : trust=1
9. allow perm=any uid=0 : dir=/tmp/ansible
10. allow perm=any uid=0 : dir=/root/.ansible/tmp/
11. allow perm=open all : ftype=%languages trust=1
12. deny_audit perm=any all : ftype=%languages
13. allow perm=any all : ftype=text/x-shellscript
14. deny_audit perm=execute all : all
15. allow perm=open all : all
[root@centos8-awc ~]# fapolicyd --debug
Loaded 15 rules
Changed to uid 991
Initializing the database
fapolicyd integrity is 0
backend rpmdb registered
backend file registered
Loading rpmdb backend
Loading file backend
Creating database
Loading data from rpmdb backend
Loading data from file backend
added /dev/shm mount point
added / mount point
added /boot mount point
added /boot/efi mount point
added /run/user/1000 mount point
added /run/user/1001 mount point
Starting to listen for events
rule=14 dec=deny_audit perm=execute auid=1001 pid=8887 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable
rule=15 dec=allow perm=open auid=1001 pid=8887 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable
rule=15 dec=allow perm=open auid=1001 pid=8887 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable
^Cshutting down...
Inter-thread max queue depth 1
Allowed accesses: 2
Denied accesses: 1
Database max pages: 10240
Database pages in use: 1268 (12%)
Subject cache size: 1549
Subject slots in use: 1 (0%)
Subject hits: 2
Subject misses: 1
Subject evictions: 0 (0%)
Object cache size: 8191
Object slots in use: 1 (0%)
Object hits: 2
Object misses: 1
Object evictions: 0 (0%)
[root@centos8-awc ~]# systemctl status fapolicyd
● fapolicyd.service - File Access Policy Daemon
   Loaded: loaded (/usr/lib/systemd/system/fapolicyd.service; disabled; vendor preset: disabled)
   Active: inactive (dead)
[root@centos8-awc ~]# systemctl start fapolicyd
[root@centos8-awc ~]# tail -n0 -f /var/log/audit/audit.log

Running in debug mode, we see that rule 14 is what's blocking the execution of /usr/local/bin/xz and we see that the rule is a deny_audit rule. When running via systemd, the execution gets blocked, but still nothing shows up in the audit log.

I'm trying to collect some fapolicyd audit logs so I can take libauparse for a spin, but I need sample data!

@stevegrubb
Copy link
Member

Wild guess, does "ldd /usr/sbin/fapolicyd" show that libaudit.so.1.0.0 is linked to it?

@scholarsmate
Copy link
Contributor Author

# ldd /usr/sbin/fapolicyd | grep audit
	libaudit.so.1 => /lib64/libaudit.so.1 (0x00007f17b7f38000)

@scholarsmate
Copy link
Contributor Author

In policy.c, in the make_policy_decision function, I added msg(LOG_INFO, "XXX 0x%X", response.response); right after write(fd, &response, sizeof(struct fanotify_response));. Here is what I'm seeing:

Running fapolicyd --debug:

...
rule=15 dec=allow perm=open auid=1000 pid=1964 exe=/usr/bin/gnome-shell : path=/usr/share/zoneinfo/America/New_York ftype=application/octet-stream
XXX 0x1
rule=14 dec=deny_audit perm=execute auid=1000 pid=10470 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable
XXX 0x12
rule=15 dec=allow perm=open auid=1000 pid=10470 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable
XXX 0x1
...

Running systemctl start fapolicyd:
/var/log/messages:

...
Jul 27 16:29:56 centos8 fapolicyd[10492]: XXX 0x1
Jul 27 16:29:56 centos8 fapolicyd[10492]: XXX 0x12
Jul 27 16:29:56 centos8 fapolicyd[10492]: XXX 0x1
...

/var/log/audit/audit.log:

...
type=SERVICE_START msg=audit(1595881744.822:245): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=fapolicyd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"

This is on a fresh installation of CentOS 8.2 with all the latest updates applied.

[root@centos8 audit]# cat /etc/redhat-release
CentOS Linux release 8.2.2004 (Core)
[root@centos8 audit]# uname -a
Linux centos8 4.18.0-193.6.3.el8_2.x86_64 #1 SMP Wed Jun 10 11:09:32 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
[root@centos8 audit]#

From there, here is how the prerequisites and the build are run to setup the test:
as root:

[root@centos8 ~]# yum install -y libtool make libudev-devel kernel-headers systemd-devel libgcrypt-devel rpm-devel file libcap-ng-devel libseccomp-devel python3-devel epel-release diffutils rpm-build dnf-plugins-core git && yum config-manager --set-enabled PowerTools && yum install -y file-devel lmdb-devel
[root@centos8 ~]# cp -a /usr/bin/xz /usr/local/bin

as user:

$ mkdir ~/git && cd ~/git && git clone https://github.com/linux-application-whitelisting/fapolicyd.git && cd fapolicyd/ && ./autogen.sh && ./configure --with-audit --disable-shared && make && make dist && rpmbuild -ta fapolicyd-1.0.1.tar.gz && sudo yum install -y ${HOME}/rpmbuild/RPMS/x86_64/fapolicyd-1.0.1-1.x86_64.rpm

@stevegrubb
Copy link
Member

It appears that what is going into the kernel is correct. If audit is enabled and there is an audit pid, shown by auditctl -s, then it should be going into the audit logs.

@scholarsmate
Copy link
Contributor Author

I just installed RHEL 8.3 beta and fapolicyd from the official repository. I copied xz from /usr/bin to /usr/local/bin so that it will fail rule 14, setting up the test. In debug mode, we see this when I run /usr/local/bin/xz --version as a user:

rule=14 dec=deny_audit perm=execute auid=1000 pid=37631 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable
rule=15 dec=allow perm=open auid=1000 pid=37631 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable
rule=15 dec=allow perm=open auid=1000 pid=37631 exe=/usr/bin/bash : path=/usr/local/bin/xz ftype=application/x-executable

Next we run systemctl start fapolicyd and systemctl status fapolicyd:

● fapolicyd.service - File Access Policy Daemon
   Loaded: loaded (/usr/lib/systemd/system/fapolicyd.service; disabled; vendor preset: disabled)
   Active: active (running) since Tue 2020-07-28 21:20:53 EDT; 6s ago
  Process: 37644 ExecStart=/usr/sbin/fapolicyd (code=exited, status=0/SUCCESS)
 Main PID: 37645 (fapolicyd)
    Tasks: 4 (limit: 23348)
   Memory: 14.7M
   CGroup: /system.slice/fapolicyd.service
           └─37645 /usr/sbin/fapolicyd

Jul 28 21:20:53 rhel8 systemd[1]: Starting File Access Policy Daemon...
Jul 28 21:20:53 rhel8 systemd[1]: Started File Access Policy Daemon.
Jul 28 21:20:53 rhel8 fapolicyd[37645]: Initializing the database
Jul 28 21:20:53 rhel8 fapolicyd[37645]: fapolicyd integrity is 0
Jul 28 21:20:53 rhel8 fapolicyd[37645]: Loading rpmdb backend
Jul 28 21:20:54 rhel8 fapolicyd[37645]: Checking database
Jul 28 21:20:54 rhel8 fapolicyd[37645]: Importing data from rpmdb backend
Jul 28 21:20:54 rhel8 fapolicyd[37645]: Importing data from file backend
Jul 28 21:20:54 rhel8 fapolicyd[37645]: Database checks OK

I tail -f /var/log/audit/audit.log, then as a user, I run /usr/local/bin/xz --version again:

[scholarsmate@rhel8 ~]$ /usr/local/bin/xz --version
-bash: /usr/local/bin/xz: Operation not permitted
[scholarsmate@rhel8 ~]$

Still nothing appears in the /var/log/audit/audit.log!

Here's some data that may help:

[root@rhel8 ~]# yum info fapolicyd
Updating Subscription Management repositories.
Last metadata expiration check: 0:16:23 ago on Tue 28 Jul 2020 09:14:35 PM EDT.
Installed Packages
Name         : fapolicyd
Version      : 1.0
Release      : 3.el8
Architecture : x86_64
Size         : 241 k
Source       : fapolicyd-1.0-3.el8.src.rpm
Repository   : @System
From repo    : rhel-8-for-x86_64-appstream-beta-rpms
Summary      : Application Whitelisting Daemon
URL          : http://people.redhat.com/sgrubb/fapolicyd
License      : GPLv3+
Description  : Fapolicyd (File Access Policy Daemon) implements application whitelisting
             : to decide file access rights. Applications that are known via a reputation
             : source are allowed access while unknown applications are not. The daemon
             : makes use of the kernel's fanotify interface to determine file access rights.

[root@rhel8 ~]# fapolicyd-cli --list
-> %languages=application/x-bytecode.ocaml,application/x-bytecode.python,application/java-archive,text/javascript,text/x-awk,text/x-gawk,text/x-java,text/x-lisp,text/x-lua,text/x-m4,text/x-perl,text/x-php,text/x-python,text/x-R,text/x-ruby,text/x-script.guile,text/x-tcl,text/x-luatex,text/x-systemtap
1. allow perm=any uid=0 : dir=/var/tmp/
2. allow perm=any uid=0 trust=1 : all
3. deny_audit perm=any pattern=ld_so : all
4. allow perm=open exe=/usr/bin/rpm : all
5. allow perm=open exe=/usr/libexec/platform-python3.6 comm=dnf : all
6. allow perm=open all : ftype=application/x-sharedlib trust=1
7. deny_audit perm=open all : ftype=application/x-sharedlib
8. allow perm=execute all : trust=1
9. allow perm=any uid=0 : dir=/tmp/ansible
10. allow perm=any uid=0 : dir=/root/.ansible/tmp/
11. allow perm=open all : ftype=%languages trust=1
12. deny_audit perm=any all : ftype=%languages
13. allow perm=any all : ftype=text/x-shellscript
14. deny_audit perm=execute all : all
15. allow perm=open all : all
[root@rhel8 ~]# cat /etc/fapolicyd/fapolicyd.conf
#
# This file controls the configuration of the file access policy daemon.
# See the fapolicyd.conf man page for explanation.
#

permissive = 0
nice_val = 14
q_size = 640
uid = fapolicyd
gid = fapolicyd
do_stat_report = 1
detailed_report = 1
db_max_size = 40
subj_cache_size = 1549
obj_cache_size = 8191
watch_fs = ext2,ext3,ext4,tmpfs,xfs,vfat,iso9660
trust = rpmdb,file
syslog_format = rule,dec,perm,auid,pid,exe,:,path,ftype
[root@rhel8 ~]# cat /etc/redhat-release
Red Hat Enterprise Linux release 8.3 Beta (Ootpa)
[root@rhel8 ~]# uname -a
Linux rhel8 4.18.0-221.el8.x86_64 #1 SMP Thu Jun 25 20:58:19 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
[root@rhel8 ~]# auditctl -s
enabled 1
failure 1
pid 1003
rate_limit 0
backlog_limit 8192
lost 0
backlog 0
backlog_wait_time 60000
loginuid_immutable 0 unlocked
[root@rhel8 ~]#

It appears that the audit behavior is the same on CentOS 8.2 and RHEL 8.3 beta.

@stevegrubb
Copy link
Member

What do you get when you do:
ausearch --start today -m fanotify -i

@scholarsmate
Copy link
Contributor Author

Still nothing.

root terminal:

[root@rhel8 ~]# systemctl start fapolicyd

user terminal:

[scholarsmate@rhel8 ~]$ /usr/local/bin/xz --version
-bash: /usr/local/bin/xz: Operation not permitted
[scholarsmate@rhel8 ~]$

root terminal:

[root@rhel8 ~]# ausearch --start today -m fanotify -i
<no matches>
[root@rhel8 ~]#

@scholarsmate
Copy link
Contributor Author

I tried Fedora 32 now in addition to RHEL 8.2, RHEL 8.3 beta, CentOS 8.1 and CentOS 8.2 and have the same results across all 5 of these operating systems. It's consistent on these fresh installs using the official repos and the code currently in master for CentOS (so at least version 1.0). Can this not be reproduced?

root terminal:

[root@localhost ~]# systemctl start fapolicyd

user terminal:

[scholarsmate@localhost ~]$ /usr/local/bin/xz --version
-bash: /usr/local/bin/xz: Operation not permitted
[scholarsmate@localhost ~]$

root terminal:

[root@localhost ~]# ausearch --start today -m fanotify -i
<no matches>
[root@localhost ~]#

Relevant info:

[root@localhost ~]# cat /etc/redhat-release && uname -a && yum info fapolicyd && fapolicyd-cli --list && cat /etc/fapolicyd/fapolicyd.conf && auditctl -s
Fedora release 32 (Thirty Two)
Linux localhost.localdomain 5.6.6-300.fc32.x86_64 #1 SMP Tue Apr 21 13:44:19 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
Last metadata expiration check: 0:18:12 ago on Wed 29 Jul 2020 04:24:16 PM EDT.
Installed Packages
Name         : fapolicyd
Version      : 1.0
Release      : 3.fc32
Architecture : x86_64
Size         : 258 k
Source       : fapolicyd-1.0-3.fc32.src.rpm
Repository   : @System
From repo    : updates
Summary      : Application Whitelisting Daemon
URL          : http://people.redhat.com/sgrubb/fapolicyd
License      : GPLv3+
Description  : Fapolicyd (File Access Policy Daemon) implements application whitelisting
             : to decide file access rights. Applications that are known via a reputation
             : source are allowed access while unknown applications are not. The daemon
             : makes use of the kernel's fanotify interface to determine file access rights.

-> %languages=application/x-bytecode.ocaml,application/x-bytecode.python,application/java-archive,text/javascript,text/x-awk,text/x-gawk,text/x-java,text/x-lisp,text/x-lua,text/x-m4,text/x-perl,text/x-php,text/x-python,text/x-R,text/x-ruby,text/x-script.guile,text/x-tcl,text/x-luatex,text/x-systemtap
1. allow perm=any uid=0 : dir=/var/tmp/
2. allow perm=any uid=0 trust=1 : all
3. deny_audit perm=any pattern=ld_so : all
4. allow perm=open exe=/usr/bin/rpm : all
5. allow perm=open exe=/usr/bin/python3.8 comm=dnf : all
6. allow perm=open all : ftype=application/x-sharedlib trust=1
7. deny_audit perm=open all : ftype=application/x-sharedlib
8. allow perm=execute all : trust=1
9. allow perm=any uid=0 : dir=/tmp/ansible
10. allow perm=any uid=0 : dir=/root/.ansible/tmp/
11. allow perm=open all : ftype=%languages trust=1
12. deny_audit perm=any all : ftype=%languages
13. allow perm=any all : ftype=text/x-shellscript
14. deny_audit perm=execute all : all
15. allow perm=open all : all
#
# This file controls the configuration of the file access policy daemon.
# See the fapolicyd.conf man page for explanation.
#

permissive = 0
nice_val = 14
q_size = 640
uid = fapolicyd
gid = fapolicyd
do_stat_report = 1
detailed_report = 1
db_max_size = 40
subj_cache_size = 1549
obj_cache_size = 8191
watch_fs = ext2,ext3,ext4,tmpfs,xfs,vfat,iso9660
trust = rpmdb,file
integrity = none
syslog_format = rule,dec,perm,auid,pid,exe,:,path,ftype
enabled 1
failure 1
pid 791
rate_limit 0
backlog_limit 64
lost 0
backlog 0
backlog_wait_time 60000
loginuid_immutable 0 unlocked
[root@localhost ~]# 

@stevegrubb
Copy link
Member

I've reproduced this on the 8.2 kernel.

@scholarsmate
Copy link
Contributor Author

One more data point. I built from master and installed the built RPM on this Fedora 32 instance and the results are the same... access to /usr/local/bin/xz is denied by rule 14, a deny_audit rule, but still nothing appears in /var/log/audit/audit.log. Hopefully this can be reproduced and diagnosed on your side. These are fresh installs and in many cases installing fapolicyd straight from the official repositories and in all cases using the same rules file with the same test. Copy /usr/bin/xz to /usr/local/bin/xz and have rule 14 deny access to it when run as a regular user. Nothing fancy -- everything is installed using the defaults. Takes about 20 - 30 minutes from start to finish to setup and test on a VM.

@stevegrubb
Copy link
Member

cp /usr/share/audit/sample-rules/43-module-load.rules /etc/audit/rules.d/
service auditd stop
service auditd start
Should be all better. Looks like this requires audit rules of any kind to be loaded to get something out...which is not intuitive and explains why its working on my system and not yours.

@scholarsmate
Copy link
Contributor Author

Even with that rules file in place and restarting the services, I'm not finding anything in the audit log on Fedora 32.

root terminal:

[root@localhost ~]# cp /usr/share/audit/sample-rules/43-module-load.rules /etc/audit/rules.d/
[root@localhost ~]# ll /etc/audit/rules.d/
total 8
-rw-r--r--. 1 root root 398 Jul 29 19:13 43-module-load.rules
-rw-------. 1 root root 284 Apr 22 18:37 audit.rules
[root@localhost ~]# systemctl stop fapolicyd && service auditd stop && sleep 5 && service auditd start && systemctl start fapolicyd
Stopping logging:                                          [  OK  ]
Redirecting to /bin/systemctl start auditd.service
[root@localhost ~]# systemctl status fapolicyd
● fapolicyd.service - File Access Policy Daemon
     Loaded: loaded (/usr/lib/systemd/system/fapolicyd.service; disabled; vendor preset: disabled)
     Active: active (running) since Wed 2020-07-29 21:21:52 EDT; 16s ago
    Process: 39247 ExecStart=/usr/sbin/fapolicyd (code=exited, status=0/SUCCESS)
   Main PID: 39248 (fapolicyd)
      Tasks: 4 (limit: 4630)
     Memory: 12.0M
        CPU: 568ms
     CGroup: /system.slice/fapolicyd.service
             └─39248 /usr/sbin/fapolicyd

Jul 29 21:21:52 localhost.localdomain systemd[1]: Starting File Access Policy Daemon...
Jul 29 21:21:52 localhost.localdomain systemd[1]: fapolicyd.service: Failed to parse PID from file /run/fapolicyd.pid: Invalid argument
Jul 29 21:21:52 localhost.localdomain fapolicyd[39248]: Initializing the database
Jul 29 21:21:52 localhost.localdomain fapolicyd[39248]: fapolicyd integrity is 0
Jul 29 21:21:52 localhost.localdomain fapolicyd[39248]: Loading rpmdb backend
Jul 29 21:21:52 localhost.localdomain systemd[1]: Started File Access Policy Daemon.
Jul 29 21:21:53 localhost.localdomain fapolicyd[39248]: Checking database
Jul 29 21:21:53 localhost.localdomain fapolicyd[39248]: Importing data from rpmdb backend
Jul 29 21:21:53 localhost.localdomain fapolicyd[39248]: Importing data from file backend
Jul 29 21:21:53 localhost.localdomain fapolicyd[39248]: Database checks OK
[root@localhost ~]# 

user terminal:

[scholarsmate@localhost fapolicyd]$ /usr/local/bin/xz --version
-bash: /usr/local/bin/xz: Operation not permitted
[scholarsmate@localhost fapolicyd]$

root terminal:

[root@localhost ~]# ausearch --start today -m fanotify -i
<no matches>
[root@localhost ~]# 

@scholarsmate
Copy link
Contributor Author

I had success on RHEL 8.3 beta.

root terminal:

[root@rhel8 ~]# cp /usr/share/audit/sample-rules/43-module-load.rules /etc/audit/rules.d/
[root@rhel8 ~]# ll /etc/audit/rules.d/
total 8
-rw-r--r--. 1 root root 398 Jul 29 21:39 43-module-load.rules
-rw-------. 1 root root 244 Jul 28 20:48 audit.rules
[root@rhel8 ~]# systemctl stop fapolicyd && service auditd stop && sleep 5 && service auditd start && systemctl start fapolicyd
Stopping logging:                                          [  OK  ]
Redirecting to /bin/systemctl start auditd.service
[root@rhel8 ~]# systemctl status fapolicyd
● fapolicyd.service - File Access Policy Daemon
   Loaded: loaded (/usr/lib/systemd/system/fapolicyd.service; disabled; vendor preset: disabled)
   Active: active (running) since Wed 2020-07-29 21:39:38 EDT; 26s ago
  Process: 3278 ExecStart=/usr/sbin/fapolicyd (code=exited, status=0/SUCCESS)
 Main PID: 3279 (fapolicyd)
    Tasks: 4 (limit: 23337)
   Memory: 35.2M
   CGroup: /system.slice/fapolicyd.service
           └─3279 /usr/sbin/fapolicyd

Jul 29 21:39:38 rhel8 systemd[1]: Starting File Access Policy Daemon...
Jul 29 21:39:38 rhel8 systemd[1]: fapolicyd.service: Can't open PID file /run/fapolicyd.pid (yet?) after start: No such file or directo>
Jul 29 21:39:38 rhel8 systemd[1]: Started File Access Policy Daemon.
Jul 29 21:39:38 rhel8 fapolicyd[3279]: Initializing the database
Jul 29 21:39:38 rhel8 fapolicyd[3279]: fapolicyd integrity is 0
Jul 29 21:39:38 rhel8 fapolicyd[3279]: Loading rpmdb backend
Jul 29 21:39:39 rhel8 fapolicyd[3279]: Checking database
Jul 29 21:39:39 rhel8 fapolicyd[3279]: Importing data from rpmdb backend
Jul 29 21:39:39 rhel8 fapolicyd[3279]: Importing data from file backend
Jul 29 21:39:39 rhel8 fapolicyd[3279]: Database checks OK
[root@rhel8 ~]# ausearch --start today -m fanotify -i
----
type=PROCTITLE msg=audit(07/29/2020 21:40:33.831:145) : proctitle=-bash 
type=PATH msg=audit(07/29/2020 21:40:33.831:145) : item=0 name=/usr/local/bin/xz inode=33563020 dev=fd:00 mode=file,755 ouid=root ogid=root rdev=00:00 obj=system_u:object_r:bin_t:s0 nametype=NORMAL cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0 
type=CWD msg=audit(07/29/2020 21:40:33.831:145) : cwd=/home/scholarsmate 
type=SYSCALL msg=audit(07/29/2020 21:40:33.831:145) : arch=x86_64 syscall=execve success=no exit=EPERM(Operation not permitted) a0=0x55ed14116310 a1=0x55ed14220e40 a2=0x55ed141149c0 a3=0x0 items=1 ppid=3115 pid=3287 auid=scholarsmate uid=scholarsmate gid=scholarsmate euid=scholarsmate suid=scholarsmate fsuid=scholarsmate egid=scholarsmate sgid=scholarsmate fsgid=scholarsmate tty=pts1 ses=4 comm=bash exe=/usr/bin/bash subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key=(null) 
type=FANOTIFY msg=audit(07/29/2020 21:40:33.831:145) : resp=deny 
[root@rhel8 ~]# cat /etc/redhat-release 
Red Hat Enterprise Linux release 8.3 Beta (Ootpa)
[root@rhel8 ~]#

@scholarsmate
Copy link
Contributor Author

This is the first time I'm seeing an audit log. This is full of great information. Is there a way to trace this denial back to the matching fapolicyd rule?

@stevegrubb
Copy link
Member

Unfortunately not. I was forbidden to make the change that would allow it. The decision was something like they do not want to make kernel changes that benefit a single application. This is exactly the reason why the syslog option was added.

@scholarsmate
Copy link
Contributor Author

scholarsmate commented Jul 30, 2020

I can understand the "benefit a single application" argument and I don't disagree. However, when creating a framework, it's not unusual to have a field for "context". In C/C++ we see this with callbacks taking a void pointer that it just passes through. For audit logging, can a reasonable argument be made for something like a "context field" that different applications can use for their own purposes (a CLOB) to pass information similar to a void pointer in callbacks? For FANOTIFY denial context would be the rule ID, for other applications it can be something else. A context field could benefit all applications that use the audit subsystem, so the "benefit a single application" argument no longer applies. Sometimes engineering requires a dollop of marketing, but I digress.

If it's not currently possible to use the audit log to create an "audit2allow" workalike, and parsing syslog is a dicy proposition considering that the logging format is user-defined, which could make processing the data we need problematic or impossible.

@scholarsmate
Copy link
Contributor Author

scholarsmate commented Aug 3, 2020

Alternatively, are there any other fields in the audit record that can be coopted for the rule ID?

Another option might to use journald.

@stevegrubb
Copy link
Member

The problem is that we have no control over any fields from user space. The code is here:
https://github.com/linux-audit/audit-kernel/blob/master/fs/notify/fanotify/fanotify.c#L181
Part is check to allow or deny. Then it check if the audit bit is on. It only passes the response to the audit function because struct fanotify_response only has 2, 32 bit members. One is the fd, the other is the response. I can try to propose again the use of the upper 16 bits for context. But it was shot down last try.

@scholarsmate
Copy link
Contributor Author

scholarsmate commented Aug 6, 2020

It is important to know the rule ID responsible for a file access being denied and this traceability, is objectively, an audit function. The tradeoff in this proposal is that the rule limit (and distinct responses) will be capped at 64K, which sounds completely reasonable. I think we should advocate hard for this. Please try again and let me know if there is anything I can do to help!

@scholarsmate
Copy link
Contributor Author

Thinking a bit more on the rule ID and the judgement unioned into the 32 bit response... using the upper 3 bytes (24 bits) for the rule ID and the lower byte (8 bits) might be a superior split yielding limits of 2^24 (~16.7 million) rule IDs and 2^8 (256) distinct types of judgements.

@stevegrubb
Copy link
Member

I don't think we can be that greedy taking all the bits. I was thinking of 3 for context type and 8 for context. I'm mulling over whether its worth 5 more bits to identify the exact item that was objected to. That would leave 13 bits for future use.

@scholarsmate
Copy link
Contributor Author

3 for context type for 8 distinct types
13 for context (rule ID) for up to 8192 rules
16 bits remain for future use, no?

@stevegrubb
Copy link
Member

3 bits allows 8 different context_types. Of which none and rules would be initially defined. Then under context_type=rules, 8 bits would allow 256 rules to be identified. A policy with more rules is utterly messed up. Then 5 more bits allow up to 32 objects in the rules category to be pointed to. We currently have 3 bits allocated for a response. So, 3+3+8+5=19 used. 32 - 19 = 13 unused bits.

@scholarsmate
Copy link
Contributor Author

scholarsmate commented Aug 7, 2020

Then 5 more bits allow up to 32 objects in the rules category to be pointed to.

I don't know what this means? Can you restate that or give me an example?

I'm also not convinced that there won't be reasonable use cases where the number of rules can number into the hundreds. The richness provided in the current rules language means that a lot of ground can be covered in a handful of rules. I'm thinking of examples where the rules are very targeted and specific aimed at specific applications and services, for specific groups and specific users. Entities that are skeptical of ftype determinations will also tend to have a larger number of rules in their policies. Simple automated tooling will lack the logic required to coalesce a set of narrowly focused rules into a single, more complex rule. Being able to trace an audit event back to the responsible rule ID is a big win.

@stevegrubb
Copy link
Member

stevegrubb commented Feb 9, 2023

A kernel patch has been accpepted upstream. The new audit record will look like this when translated:

type=FANOTIFY msg=audit(02/06/2023 17:42:13.837:298) : resp=deny fan_type=rule_info fan_info=13 subj_trust=unknown obj_trust=no

This says that access is denied, the additional info is a rule number, rule 13 triggered, subject trust is unknown, and object is not trusted. That should allow closing the loop via audit records. With that, I think we can close this issue. Also, the accepted patch allows 32 bits to express the rule number.

@stevegrubb
Copy link
Member

Closing.

@ASC-BT
Copy link

ASC-BT commented Apr 10, 2023

@stevegrubb please list a link to the patch so we can track its implementation.

@stevegrubb
Copy link
Member

stevegrubb commented Apr 16, 2023

jw3 added a commit to ctc-oss/fapolicy-analyzer that referenced this issue Jul 4, 2023
Add support for analyzing from kernel audit logs
---

Adds an "audit" analyze event source that reads fanotify events from
libaudit to be displayed in the analyzer. The records are read into the
common Event structure that allows them to flow through the same API as
the events from syslog and debug logs.

The entrypoint to this functionality is found in the Analyze menu and
behaves similar to syslog where there is not a prompt to provide a path
to the log file. The backend uses the libaudit API to locate and parse
the system audit log.

This currently only has runtime support in the Kernel on Fedora Rawhide
(fc39), so while the backend is always built the frontend is disabled on
all other platforms.

It is anticipated that rhel 8 and 9 will both contain the required audit
support at some point in the future. The build is currently wired into
both of them with the feature flag disabled, hiding the functionality in
the UI.

The audit support is implemented using bindgen to create native bindings
to libaudit and auparse. To enable this our build requirements have
grown to include clang and the audit dev libs to support building the
bindings with bindgen. These bindings are generated at compile time and
are excluded from version control.

### Also adds
- Adds Python LogType enum in place of some magic strings
- Plumbs Cargo feature support into the python build
- Improves the make header-check to support piping the output

### Requires
- Kernel >= 6.3
- Audit >= 3.1
- fapolicyd >= 1.2

It may be possible to move the feature flag to a runtime check, allowing
upgraded systems to use the audit feature, but this is not within the scope
of this PR. Given that that there is no support outside of fc39, there
is some time to refine audit related capability before it has wide
applicability.

### Reference
-
linux-audit/audit-kernel@032bffd
-
linux-audit/audit-userspace@d1aec22
-
https://lore.kernel.org/linux-fsdevel/20230207120921.7pgh6uxs7ze7hkjo@quack3/
- linux-application-whitelisting/fapolicyd#84
-
linux-application-whitelisting/fapolicyd@ee9c99a

Closes #294
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants