[apparmor] [patch] Accept more log formats in logparser.py
Christian Boltz
apparmor at cboltz.de
Fri Jul 24 21:31:25 UTC 2015
Hello,
logparser.py does a regex check on log lines as performance improvement
so that it only hands over lines that look like AppArmor events to
LibAppArmor parsing. Those regexes were incomplete and didn't cover all
log formats LibAppArmor accepts, with the end result of "overlooking"
events.
This patch splits off common parts of the regex, adds more regexes for
several log types and finally merges everything into one regex.
test-libapparmor-test_multi.py now also checks all test_multi log lines
against the regex to ensure logparser.py doesn't silently ignore events.
test-logparser.py gets adjusted to the merged RE_LOG_ALL regex.
Finally, add a new test that was posted on IRC to the test_multi set.
I propose this patch for trunk and 2.9.
(except the test-libapparmor-test_multi.py changes, unless we also
commit that to 2.9)
[ 83-logparser-accept-more-log-formats.diff ]
=== modified file ./utils/apparmor/logparser.py
--- utils/apparmor/logparser.py 2015-07-24 23:20:16.116932487 +0200
+++ utils/apparmor/logparser.py 2015-07-24 23:06:28.476246575 +0200
@@ -26,8 +26,24 @@
_ = init_translation()
class ReadLog:
- RE_LOG_v2_6_syslog = re.compile('kernel:\s+(\[[\d\.\s]+\]\s+)?(audit:\s+)?type=\d+\s+audit\([\d\.\:]+\):\s+apparmor=')
- RE_LOG_v2_6_audit = re.compile('type=AVC\s+(msg=)?audit\([\d\.\:]+\):\s+apparmor=')
+ RE_audit_time_id = '(msg=)?audit\([\d\.\:]+\):\s+' # 'audit(1282626827.320:411): '
+ RE_kernel_time = '\[[\d\.\s]+\]' # '[ 1612.746129]'
+ RE_type_num = '1[45][0-9][0-9]' # 1400..1599
+ RE_aa_or_op = '(apparmor=|operation=)'
+
+ RE_log_parts = [
+ 'kernel:\s+(' + RE_kernel_time + '\s+)?(audit:\s+)?type=' + RE_type_num + '\s+' + RE_audit_time_id + RE_aa_or_op, # v2_6 syslog
+ 'kernel:\s+(' + RE_kernel_time + '\s+)?' + RE_audit_time_id + 'type=' + RE_type_num + '\s+' + RE_aa_or_op,
+ 'type=(AVC|APPARMOR[_A-Z]*|' + RE_type_num + ')\s+' + RE_audit_time_id + '(type=' + RE_type_num + '\s+)?' + RE_aa_or_op, # v2_6 audit and dmesg
+ 'type=USER_AVC\s+' + RE_audit_time_id + '.*apparmor=', # dbus
+ 'type=UNKNOWN\[' + RE_type_num + '\]\s+' + RE_audit_time_id + RE_aa_or_op,
+ 'dbus\[[0-9]+\]:\s+apparmor=', # dbus
+ ]
+
+ # used to pre-filter log lines so that we hand over only relevant lines to LibAppArmor parsing
+ RE_LOG_ALL = re.compile('(' + '|'.join(RE_log_parts) + ')')
+
+
# Used by netdomain to identify the operation types
# New socket names
OPERATION_TYPES = {'create': 'net',
@@ -62,7 +78,7 @@
if self.next_log_entry:
sys.stderr.out('A log entry already present: %s' % self.next_log_entry)
self.next_log_entry = self.LOG.readline()
- while not self.RE_LOG_v2_6_syslog.search(self.next_log_entry) and not self.RE_LOG_v2_6_audit.search(self.next_log_entry) and not (self.logmark and self.logmark in self.next_log_entry):
+ while not self.RE_LOG_ALL.search(self.next_log_entry) and not (self.logmark and self.logmark in self.next_log_entry):
self.next_log_entry = self.LOG.readline()
if not self.next_log_entry:
break
=== modified file ./utils/test/test-libapparmor-test_multi.py
--- utils/test/test-libapparmor-test_multi.py 2015-07-24 23:20:16.116932487 +0200
+++ utils/test/test-libapparmor-test_multi.py 2015-07-24 23:19:08.390969221 +0200
@@ -44,6 +44,10 @@
if parsed_event and expected:
parsed_items = dict(parsed_event.items())
+ # check if the line passes the regex in logparser.py
+ if not parser.RE_LOG_ALL.search(loglines2[0]):
+ raise Exception("Log event doesn't match RE_LOG_ALL")
+
for label in expected:
if label in [
'file', # filename of the *.in file
=== modified file ./utils/test/test-logparser.py
--- utils/test/test-logparser.py 2015-04-03 17:41:51.356126460 +0200
+++ utils/test/test-logparser.py 2015-07-24 23:17:43.248043596 +0200
@@ -28,8 +28,7 @@
self.assertEqual(parsed_event['aamode'], 'PERMITTING')
self.assertEqual(parsed_event['request_mask'], 'wc')
- self.assertIsNotNone(ReadLog.RE_LOG_v2_6_audit.search(event))
- self.assertIsNone(ReadLog.RE_LOG_v2_6_syslog.search(event))
+ self.assertIsNotNone(ReadLog.RE_LOG_ALL.search(event))
def test_parse_event_audit_2(self):
event = 'type=AVC msg=audit(1322614918.292:4376): apparmor="ALLOWED" operation="file_perm" parent=16001 profile=666F6F20626172 name="/home/foo/.bash_history" pid=17011 comm="bash" requested_mask="rw" denied_mask="rw" fsuid=0 ouid=1000'
@@ -39,8 +38,7 @@
self.assertEqual(parsed_event['aamode'], 'PERMITTING')
self.assertEqual(parsed_event['request_mask'], 'rw')
- self.assertIsNotNone(ReadLog.RE_LOG_v2_6_audit.search(event))
- self.assertIsNone(ReadLog.RE_LOG_v2_6_syslog.search(event))
+ self.assertIsNotNone(ReadLog.RE_LOG_ALL.search(event))
def test_parse_event_syslog_1(self):
# from https://bugs.launchpad.net/apparmor/+bug/1399027
@@ -51,8 +49,7 @@
self.assertEqual(parsed_event['aamode'], 'PERMITTING')
self.assertEqual(parsed_event['request_mask'], 'rw')
- self.assertIsNone(ReadLog.RE_LOG_v2_6_audit.search(event))
- self.assertIsNotNone(ReadLog.RE_LOG_v2_6_syslog.search(event))
+ self.assertIsNotNone(ReadLog.RE_LOG_ALL.search(event))
def test_parse_event_syslog_2(self):
# from https://bugs.launchpad.net/apparmor/+bug/1399027
@@ -63,8 +60,7 @@
self.assertEqual(parsed_event['aamode'], 'PERMITTING')
self.assertEqual(parsed_event['request_mask'], 'r')
- self.assertIsNone(ReadLog.RE_LOG_v2_6_audit.search(event))
- self.assertIsNotNone(ReadLog.RE_LOG_v2_6_syslog.search(event))
+ self.assertIsNotNone(ReadLog.RE_LOG_ALL.search(event))
def test_parse_disconnected_path(self):
# from https://bugzilla.opensuse.org/show_bug.cgi?id=918787
@@ -91,8 +87,7 @@
'time': 1424425690
})
- self.assertIsNotNone(ReadLog.RE_LOG_v2_6_audit.search(event))
- self.assertIsNone(ReadLog.RE_LOG_v2_6_syslog.search(event))
+ self.assertIsNotNone(ReadLog.RE_LOG_ALL.search(event))
if __name__ == "__main__":
=== modified file ./libraries/libapparmor/testsuite/test_multi/testcase_syslog_read.in
--- libraries/libapparmor/testsuite/test_multi/testcase_syslog_read.in 2015-07-24 23:20:16.117932427 +0200
+++ libraries/libapparmor/testsuite/test_multi/testcase_syslog_read.in 2015-07-24 21:27:41.403459751 +0200
@@ -0,0 +1 @@
+Jul 25 15:02:00 redacted kernel: [ 296.524447] audit: type=1400 audit(1437850920.403:64): apparmor="ALLOWED" operation="open" profile="/usr/sbin/vsftpd" name="/home/bane/foo" pid=1811 comm="vsftpd" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
=== modified file ./libraries/libapparmor/testsuite/test_multi/testcase_syslog_read.out
--- libraries/libapparmor/testsuite/test_multi/testcase_syslog_read.out 2015-07-24 23:20:16.117932427 +0200
+++ libraries/libapparmor/testsuite/test_multi/testcase_syslog_read.out 2015-07-24 21:29:09.680128070 +0200
@@ -0,0 +1,15 @@
+START
+File: testcase_syslog_read.in
+Event type: AA_RECORD_ALLOWED
+Audit ID: 1437850920.403:64
+Operation: open
+Mask: r
+Denied Mask: r
+fsuid: 1000
+ouid: 1000
+Profile: /usr/sbin/vsftpd
+Name: /home/bane/foo
+Command: vsftpd
+PID: 1811
+Epoch: 1437850920
+Audit subid: 64
Regards,
Christian Boltz
--
If Linus is calling you an idiot then you probably think "Could be that
he is right.". If I call you an idiot than I don't expect you to belief
me. That's ok ;) [Rüdiger Meier in opensuse-factory]
More information about the AppArmor
mailing list