[apparmor] [patch] Accept more log formats in logparser.py
Christian Boltz
apparmor at cboltz.de
Sun Sep 6 11:28:59 UTC 2015
Hello,
Am Freitag, 24. Juli 2015 schrieb Christian Boltz:
> 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)
Any comments on this patch?
If nobody objects, I'll commit it as Acked-by <timeout> to trunk and 2.9
on tuesday.
> [ 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
--
Wenn's eine kaputte Platte ist: Entsorgen, Backup zurückspielen.
Wenn's kein Backup gibt - nennt sich das ganze "lernen" ;-)
[Arno Lehmann in suse-linux]
More information about the AppArmor
mailing list