[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