The denials should be mostly audit logged. Did you check it? I'm not sure how much useful is the information from the audit messages.

I guess this is quite good UX POV and we should definitely improve it ASAP. 

We should put together all the possibilities how to let the admin know what is happening wrong in the most descriptive way.

(In reply to Renaud Métrich from comment #0)
> Description of problem:
> 
> Currently fapolicyd is silent, causing support members a hard life: when
> some issue is due to fapolicyd, it's hard to find what is going on, because
> no log is seen at all, so nobody thinks about fapolicyd being the potential
> culprit.
> This makes us lose a lot of time investigating issues.
> 
> Additionally, running fapolicyd in "debug-deny" mode requires to hack the
> fapolicyd.service unit, as shown below:
> 
> Original (in /usr/lib/systemd/system):
> -------- 8< ---------------- 8< ---------------- 8< ---------------- 8<
> --------
> Type=forking
> ExecStart=/usr/sbin/fapolicyd
> -------- 8< ---------------- 8< ---------------- 8< ---------------- 8<
> --------
> 
> Hacked to see denies (in /etc/systemd/system):
> -------- 8< ---------------- 8< ---------------- 8< ---------------- 8<
> --------
> Type=simple
> ExecStart=/usr/sbin/fapolicyd --debug-deny
> -------- 8< ---------------- 8< ---------------- 8< ---------------- 8<
> --------
> 
> 
> The fapolicyd options should be read from /etc/sysconfig/fapolicyd or
> similar file and not require the daemon to be put in the foreground.
> 
> 
> Version-Release number of selected component (if applicable):
> 
> fapolicyd-0.8.10-3.el8_1.1.x86_64

Hello Renaud,

there is a new syslog_format option for fapolicyd.conf in RHEL8.3 beta. Is it helpful?
Is the latest fapolicyd more convenient?
Can we actually close this bug?

You should not use a deny in the rule, use a deny_audit or deny_syslog to get something recorded. The shipped rules do this by default. So, there shouldn't need to be the need to do anything else.

Hi Steve,

With default rules shipped by fapolicyd-1.0-3.el8_3.2 (RHEL8.3), I do not see any deny at all in the audit log.
I still need to use --debug-deny to see something useful.

Reproducer:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
# cp /bin/true /tmp/
# useradd foo
# su - foo

$ /tmp/true
-bash: /tmp/true: Operation not permitted
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

--> Nothing printed in audit.log, nor in daemon output

After enabling "--debug-deny", I see the rule being hit in daemon output:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
fapolicyd[28317]: rule=13 dec=deny_audit perm=execute auid=0 pid=28456 exe=/usr/bin/bash : path=/tmp/true ftype=application/x-executable
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

use:  ausearch --start today -m fanotify -i

also, execution in /tmp may be blocked by mount permissions and not fapolicyd. It's better to test against the homedir.

"ausearch --start today -m fanotify -i" doesn't work.

There is just no FANOTIFY message in the audit log at all.

I tested, stopping fapolicyd "fixes" the problem, so /tmp is not culprit here (it's actually / on my system).

Is the audit daemon running? Are you on the 8.3 kernel?

Yes, 8.3 and auditd running.

I suspect that maybe there are no audit rules loaded? If so, the audit system suppresses some events. I think this may be a kernel problem.

cp /usr/share/audit/sample-rules/43-module-load.rules /etc/audit/rules.d/
service auditd stop
service auditd start

Should be all better.

Exact! I had no rule.

With sample rules, this know works:

type=PROCTITLE msg=audit(11/13/2020 15:49:48.108:185) : proctitle=-bash 
type=PATH msg=audit(11/13/2020 15:49:48.108:185) : item=0 name=/tmp/true inode=16797947 dev=fd:00 mode=file,755 ouid=root ogid=root rdev=00:00 obj=unconfined_u:object_r:user_tmp_t:s0 nametype=NORMAL cap_fp=none cap_fi=none cap_fe=0 cap_fver=0 cap_frootid=0 
type=CWD msg=audit(11/13/2020 15:49:48.108:185) : cwd=/home/user 
type=SYSCALL msg=audit(11/13/2020 15:49:48.108:185) : arch=x86_64 syscall=execve success=no exit=EPERM(Operation not permitted) a0=0x561984a521f0 a1=0x561984a51040 a2=0x561984a4e470 a3=0x8 items=1 ppid=2073 pid=2117 auid=root uid=user gid=user euid=user suid=user fsuid=user egid=user sgid=user fsgid=user tty=pts0 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(11/13/2020 15:49:48.108:185) : resp=deny 


But well, this doesn't help finding which rule is hit.

Upstream commit b6da9dc adds a note to the rules man page about needing an audit rule.

You are step by step recreating this upstream issue:

https://github.com/linux-application-whitelisting/fapolicyd/issues/84

Hopefully a fix for this can land in 8.4 if the upstream kernel maintainers approve the patch.

Any chance of this coming the RHEL 8 soon? Troubleshooting fapolicyd is really a pain without proper logging.