[apparmor] About duplicate AVC audit entries

[John Johansen]

On 10/05/2017 11:31 AM, Vincas Dargis wrote:
> Hi,
> 
> I have just tried 4.14 kernel on Debian, and noticed some.. strange (at least for me) lines:
> 
> type=AVC msg=audit(1507226290.397:616): apparmor="ALLOWED" operation="file_perm" profile="/usr/sbin/avahi-daemon" pid=526 comm="avahi-daemon" family="unix" sock_type="stream" protocol=0 requested_mask="receive" denied_mask="receive"
> type=AVC msg=audit(1507226290.397:616): apparmor="ALLOWED" operation="file_perm" profile="/usr/sbin/avahi-daemon" pid=526 comm="avahi-daemon" family="unix" sock_type="stream" protocol=0 requested_mask="receive" denied_mask="receive"
> type=AVC msg=audit(1507226290.397:616): apparmor="ALLOWED" operation="recvmsg" profile="/usr/sbin/avahi-daemon" pid=526 comm="avahi-daemon" family="unix" sock_type="stream" protocol=0 requested_mask="receive" denied_mask="receive"
> type=SYSCALL msg=audit(1507226290.397:616): arch=c000003e syscall=0 success=yes exit=0 a0=5 a1=7ffc322960de a2=1 a3=67 items=0 ppid=1 pid=526 auid=4294967295 uid=116 gid=119 euid=116 suid=116 fsuid=116 egid=119 sgid=119 fsgid=119 tty=(none) ses=4294967295 comm="avahi-daemon" exe="/usr/sbin/avahi-daemon" key=(null)
> type=PROCTITLE msg=audit(1507226290.397:616): proctitle=2F7573722F7362696E2F61766168692D6461656D6F6E002D73
> 
> 
> First two AVC entries `file_perm` are identical and then another with `recvmsg`, and only after SYSCALL/PROCTITLE.
> 
> I do not have a lot of AppArmor experience, though I would expect three AVC,SYSCALL,PROCTITLE sequences, rather than this AVC,AVC,AVC,SYSCALL,PROCTITLE one.
> 

Its not uncommon to get duplicate events, sometimes due to
applications (doesn't appear to be the case here), some times due to
how the kernel is setup. The LSM (which apparmor is built on top of)
is setup as a set of permission hooks that get called at various
points where a security decision gets made, a single syscall can call
multiple hooks. In fact apparmor has a very simple caps logging
duplicate elimination system because the caps system gets called back
into multiple times on a single syscall. Generally when denying
something we would only log the first error and then the syscall
begins to unwind (though this is not necessarily true for capability
checks). For allow messages however you will get an audit event for
each hook called over the coarse of a syscall that apparmor didn't
have a rule for, making multiple AVC messages per syscall common in
the ALLOWED case. This specific set of events is odd specifically the
double file_perm, a file read on a unix socket could certainly trip
both the file and unix recvmsg hooks, but without more digging I can't
explain the double file_perm entries.

The ordering of apparmor rules with respect to other kernel messages
can also be slightly out of expected order if you are using rsyslog
etc instead of auditd, because the apparmor messages go through the
audit subsystem and its messaging can get reordered some vs. the rest
of the regular kernel printk stream.

Also of note is we are trying once again to get apparmor moved away
from audit type 1400 (AVC) which will make it easier to use the audit
tools with apparmor messages