[apparmor] [patch] Raise AppArmorBug on unknown request_mask in logparser.py

[Christian Boltz]

Hello,

Am Freitag, 11. Dezember 2015 schrieb Seth Arnold:
> On Fri, Dec 11, 2015 at 08:52:13PM +0100, Christian Boltz wrote:
> > an unknown request_mask means something strange[tm] happened, so we
> > should raise AppArmorBug (which gives us a full backtrace) instead
> > of
> > AppArmorException (which "just" prints an error message)
> 
> I'm not sure I like this; it feels like a useful way to catch the
> send -> senw error, but it is pretty brittle about running on kernels
> that may know more mediation types than the userspace, or bitflips in
> logs that may turn send into Send. 

The check is done based on the event nowadays, so dbus events can no 
longer crash the file event handling. 

For everything else, I _want_ to be informed so that I or someone else 
can upate the tools. I also want to catch such things as early as 
possible - debugging a "delayed" error is more funny[tm] because it's
nearly impossible to find out what caused it [1].

> And I really don't know how a user
> is supposed to cope with this once they run into it -- 

That's easy - they are supposed to open a bugreport, ideally including 
the problematic log line ;-) - and switching to AppArmorBug means we'll 
get more useful debug info to find out what caused the unknown mask.

An alternative solution would be a try/except game some levels / 
function calls upwards so that the exception can print the original log 
line causing the problem. That would probably need to happen in 
read_log(), when calling self.add_event_to_tree().

How do you like this one?

# aa-logprof -f <(echo 'Dec 11 10:24:07 gw-dc01 kernel: [2214272.912766] type=1400 audit(1449822247.549:21251): apparmor="ALLOWED" operation="file_inherit" profile="/usr/sbin/smbd" name="/foo/bar" pid=7112 comm="nsupdate" requested_mask="foo" denied_mask="foo" fsuid=0 ouid=0')
Reading log entries from /dev/fd/63.
Updating AppArmor profiles in /etc/apparmor.d.

ERROR: Log contains unknown mode foo

This error was caused by the log line:
Dec 11 10:24:07 gw-dc01 kernel: [2214272.912766] type=1400 audit(1449822247.549:21251): apparmor="ALLOWED" operation="file_inherit" profile="/usr/sbin/smbd" name="/foo/bar" pid=7112 comm="nsupdate" requested_mask="foo" denied_mask="foo" fsuid=0 ouid=0


The only disadvantage is that it doesn't include the bugreport hint that
comes with AppArmorBug ;-)

That all said, here's the alternative patch:


[patch] More useful logparser failure reports

If parse_event_for_tree() raises an AppArmorException (for example
because of an invalid/unknown request_mask), catch it in read_log() and 
re-raise it together with the log line causing the Exception.


I propose this patch for trunk and 2.10.
(2.9 doesn't have apparmor.fail, which means the error message would
print out some literal '\n')


[ 38-more-useful-logparser-failure-reports.diff ]

=== modified file ./utils/apparmor/logparser.py
--- utils/apparmor/logparser.py 2015-12-11 23:44:49.488162724 +0100
+++ utils/apparmor/logparser.py 2015-12-11 23:44:45.112190142 +0100
@@ -402,7 +402,11 @@
             event = self.parse_log_record(line)
             #print(event)
             if event:
-                self.add_event_to_tree(event)
+                try:
+                    self.add_event_to_tree(event)
+                except AppArmorException as e:
+                    raise AppArmorException('%(msg)s\n\nThis error was caused by the log line:\n%(logline)s' %
+                            {'msg': e.value, 'logline': line})
         self.LOG.close()
         self.logmark = ''
         return self.log


> the "easy"
> answer is to edit either the logs or the program and i'll let you
> guess which one happens first. ;)

Depends on the user ;-)

Besides that, editing the program needs to be done only once, while
unknown log events can happen again and again.


Regards,

Christian Boltz

[1] We had more than one problem where a hasher surprised us with some
    unexpected content, and that usually only exploded when writing the
    profile. Now try to find out how/when the broken content was stored
    in the hasher...
-- 
The only reason coders' computers work better than non-coders'
computers is coders know computers are schizophrenic little children
with auto-immune diseases and we don't beat them when they're bad.
[http://www.stilldrinking.org/programming-sucks]