[apparmor] Understanding log messages (when prof != comm)

[John Johansen]

On 05/10/2016 10:32 PM, apparmor at raf.org wrote:

<<snip>>

>>
>>> There is a separate profile for each postfix executable.
>>>
>> okay
>>
>>> The profile /etc/apparmor.d/usr.lib.postfix.master contains:
>>>
>>>   /usr/lib/postfix/smtp Px,
>>>
>>> The profile /etc/apparmor.d/usr.lib.postfix.smtp contains:
>>>
>>>   /{var/spool/postfix/,}active/[0-9A-F]* rwk,
>>>
>> ah, another potential point of confusion. The name of the file
>> containing the profile is arbitrary. It is just there to help
>> humans find the various profiles. The file can even contain
>> multiple profiles.
>>
>> You could have a single postfix file which contained the
>> profiles
>>   profile /usr/lib/postfix/smp { }
>>   profile /usr/lib/postfix/foobar { }
>>   ...
> 
> Sorry I didn't mention it before but the debian package that contains
> these postfix profiles each contain a single profile with no "profile"
> keyword and so the attachment defaults to the profile name which is
> indicated by the name of the file (with slashes instead of fullstops/periods).
> I haven't changed that structure. I have only added a few rules where
> needed. Other profiles in that debian have multiple profiles per file
> but not the postfix ones.
> 

okay thanks

>> now with that said back to the rule and the log message
>>
>>> I'm seeing apparmor log messages that contain:
>>>
>>>   profile="/usr/lib/postfix/master"
>>>   op="file_lock"
>>>   name="/var/spool/postfix/active/01FBB1FA73"
>>>   comm="smtp"
>>>   req="k"
>>>   denied="k"
>>>
>>> This makes me think that the profile for master needs to have
>>> a rule added like the above rule for smtp but the comm="smtp"
>>> makes me think that this log message is about smtp, not master,
>>> but smtp already has this rule.
>>>
>>> What am I not understanding here? Why is the profile for master
>>> being mentioned in the log message rather than the profile for smtp?
>>> Is it master or smtp that is trying to lock the file in question?
>>> Which profile needs a new rule? Does the master profile needs the
>>> same rule as the smtp profile, or is the rule in the smtp profile
>>> incorrect?
>>
>> the rule from the /etc/apparmor.d/usr.lib.postfix.smtp
>> profile should allow that denial, however from the
>> profile= entry we can see that the application is NOT
>> being confined by the /etc/apparmor.d/usr.lib.postfix.smtp
>> profile it is being confined by the 
>>   /usr/lib/postfix/master profile.
>>
>> and the comm is smtp
>>
>> So why would this happen? First up I am assuming you don't
>> have any custom attachments defined for those profiles.
> 
> That's correct.
> 
>> The first thing that comes to my mind is that the smtp
>> program was not run from /usr/lib/postfix/smtp which would
>> mean the Px rule was not applied.
> 
> I don't understand how that is possible. Since the master profile
> is in effect, master must have started smtp and it wouldn't start
> any smtp other than /usr/lib/postfix/smtp and, even if it tried,
> there is no rule to allow it to do so. It can only start the
> binaries that apparmor allows it to.
> 
> And /usr/lib/postfix/smtp is the only executable named smtp
> on the host.
> 
Well I was thinking another none postix process could have started
it. Eg was aa-exec but something else could have. Not saying that
did happen, just a possibility to look into

>> Other potential reasons would be postfix is using change_onexec
>> to override the rule. This is unlikely as I am unaware of any
>> such modification to postfix, and the postfix/master profile
>> would also need the correct change_profile rules.
> 
> And I certainly didn't make any such modification. :-)
> 
>> Another possibility is that smtp was run via something that
>> is confined by a different profile. Eg from the terminal I
>> can do
>>
>>   aa-exec -p /usr/lib/postfix/master -- smtp ...
>>
>> and it will run under the postfix/master profile
> 
> I'd remember if I had done that. :-)
> 

Well I would hope so :)

>> you need to check where the smtp profile is in the filesystem
>> to make sure the attachment is correct.
> 
> The smtp profile is in /etc/apparmor.d/usr.lib.postfix.smtp
> and the profile name and attachment are both "/usr/lib/postfix/smtp".
> 

okay

>> And you should check
>> the parent pid and comm/confinement (ps -Z for the profile
>> information), to ensure it is being started by the postfix/master
>> profile.
> 
> pstree tells me that the smtp processes were all started by master.
> I would have thought that the profile field in the log message also
> indicates this (barring manual use of aa-exec of course).
> 
sure the profile field certainly hints at that but, the message is
odd in more than one way so its worth checking

With pstree is showing smtp processes are all started by master,
what are their security fields showing

  ps aux -Z | grep smtp

should do the trick. Do any of them show that they are confined
by the wrong profile?


>> Oh and you didn't mention what the attachment/profile name
>> of the /etc/apparmor.d/usr.lib.postfix.smtp profile actually
>> is. Check there as well to make sure it is correct
> 
> The attachment and profile name are both "/usr/lib/postfix/smtp".
> 
> Here are all of the postfix-related profiles/attachments and
> the exec rules that they contain:
> 
>   /usr/lib/postfix/anvil
>     /usr/lib/postfix/anvil rmix,
> 
>   /usr/lib/postfix/bounce
>     /usr/lib/postfix/bounce rmix,
> 
>   /usr/lib/postfix/cleanup
>     /usr/lib/postfix/cleanup rmix,
> 
>   /usr/lib/postfix/discard
>     /usr/lib/postfix/discard rmix,
> 
>   /usr/lib/postfix/error
>     /usr/lib/postfix/error rmix,
> 
>   /usr/lib/postfix/flush
>     /usr/lib/postfix/flush rmix,
> 
>   /usr/lib/postfix/lmtp
>     /usr/lib/postfix/lmtp rmix,
> 
>   /usr/lib/postfix/local
>     /usr/bin/procmail             Px,
>     /usr/lib/mailman/mail/mailman Px,
>     /var/mailman/mail/wrapper     Px,
>     /usr/bin/mlmmj-recieve        Px,
>     /usr/lib/postfix/local        rmix,
>     /bin/bash                     mixr,
>     /bin/date                     mixr,
> 
>   /usr/lib/postfix/master
>     /usr/lib/postfix/anvil           Px,
>     /usr/lib/postfix/bounce          Px,
>     /usr/lib/postfix/cleanup         Px,
>     /usr/lib/postfix/flush           Px,
>     /usr/lib/postfix/local           Px,
>     /usr/lib/postfix/master          rmix,
>     /usr/lib/postfix/nqmgr           Px,
>     /usr/lib/postfix/proxymap        Px,
>     /usr/lib/postfix/pickup          Px,
>     /usr/lib/postfix/pipe            Px,
>     /usr/lib/postfix/qmgr            Px,
>     /usr/lib/postfix/scache          Px,
>     /usr/lib/postfix/showq           Px,
>     /usr/lib/postfix/smtp            Px,
>     /usr/lib/postfix/smtpd           Px,
>     /usr/lib/postfix/tlsmgr          Px,
>     /usr/lib/postfix/trivial-rewrite Px,
>     /usr/lib/postfix/error           Px,
> 
>   /usr/lib/postfix/nqmgr
>     /usr/lib/postfix/nqmgr rmix,
> 
>   /usr/lib/postfix/oqmgr
>     /usr/lib/postfix/oqmgr rmix,
> 
>   /usr/lib/postfix/pickup
>     /usr/lib/postfix/pickup rmix,
> 
>   /usr/lib/postfix/pipe
>     /usr/lib/postfix/pipe rmix,
> 
>   /usr/lib/postfix/proxymap
>     /usr/lib/postfix/proxymap rmix,
> 
>   /usr/lib/postfix/qmgr
>     /usr/lib/postfix/qmgr rmix,
> 
>   /usr/lib/postfix/qmqpd
>     /usr/lib/postfix/qmqpd rmix,
> 
>   /usr/lib/postfix/scache
>     /usr/lib/postfix/scache rmix,
> 
>   /usr/lib/postfix/showq
>     /usr/lib/postfix/showq rmix,
> 
>   /usr/lib/postfix/smtp
>     /usr/lib/postfix/smtp rmix,
> 
>   /usr/lib/postfix/smtpd
>     /usr/lib/postfix/smtpd rmix,
>     /usr/sbin/postdrop rPx,
> 
>   /usr/lib/postfix/spawn
>     /usr/lib/postfix/spawn rmix,
> 
>   /usr/lib/postfix/tlsmgr
>     /usr/lib/postfix/tlsmgr rmix,
> 
>   /usr/lib/postfix/trivial-rewrite
>     /usr/lib/postfix/trivial-rewrite rmix,
> 
>   /usr/lib/postfix/verify
>     /usr/lib/postfix/verify rmix,
> 
>   /usr/lib/postfix/virtual
>     /usr/lib/postfix/virtual rmix,
> 
> So the only profiles that allow smtp to be executed are
> master and smtp itself.
> 
> Thanks for all of your explanations. It was quite a heroic effort.
> But I'm still at a loss to explain this log message or what to do
> about it. :-(
> 
thanks. Though your answers didn't really make me happy :)

This is quite weird, some more info would be useful

version of apparmor?  apparmor_parser -V
kernel version? Any custom patches on it?

Oh and was the message straight from dmesg, or a logging daemon, and
if so which one auditd?, syslog? ...

We have had cases in the past where there was ring buffer overflow
causing 2 log messages to be spliced together? So the full original
log message, unedited might help in checking for splicing etc.

Not that we have seen that recently but it was a problem in the past