libapparmor: logparse: fix RECORD_INVALID for valid log

v2:
- parse partial log line broken at \n
- add testcase_dbus_10.* for partial log line
- remove quotes from  testcasw_dbus_09.profile

The following log format has been seen in the wild, and currently results
in a RECORD_INVALID

    [4835959.046111] audit: type=1107 audit(1561053426.749:186): pid=640 uid=103 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/org/freedesktop/systemd1" interface="org.freedesktop.systemd1.Manager" member="LookupDynamicUserByName" mask="send" name="org.freedesktop.systemd1" pid=20596 label="/usr/sbin/sshd" peer_pid=1 peer_label="unconfined"
                      exe="/usr/bin/dbus-daemon" sauid=103 hostname=? addr=? terminal=?'

Test parsing the above message with and without the \n embedded between
peer_label= and exec=

Acked-by: Seth Arnold <seth.arnold@canonical.com>
Signed-off-by: John Johansen <john.johansen@canonical.com>
This commit is contained in:
John Johansen 2019-06-22 02:06:54 -07:00
parent 8a8130d4dd
commit 0349cf2d0a
17 changed files with 119 additions and 8 deletions

View file

@ -19,7 +19,12 @@
%{
/* set the following to non-zero to get bison to emit debugging
* information about tokens given and rules matched. */
* information about tokens given and rules matched.
* Also:
* Uncomment the %defines
* parse.error
* parse.trace
*/
#define YYDEBUG 0
#include <string.h>
#include <aalogparse.h>
@ -34,7 +39,9 @@ aa_log_record *ret_record;
* emit messages when asked for. */
void aalogparse_error(void *scanner, char const *s)
{
//printf("ERROR: %s\n", s);
#if (YYDEBUG != 0)
printf("ERROR: %s\n", s);
#endif
ret_record->event = AA_RECORD_INVALID;
}
@ -68,6 +75,11 @@ aa_record_event_type lookup_aa_event(unsigned int type)
%}
%defines
/* uncomment for debugging
%define parse.error verbose
%define parse.trace
*/
%define api.pure
%lex-param{void *scanner}
%parse-param{void *scanner}
@ -128,6 +140,8 @@ aa_record_event_type lookup_aa_event(unsigned int type)
%token TOK_KEY_PEER_PID
%token TOK_KEY_PROFILE
%token TOK_KEY_PEER_PROFILE
%token TOK_KEY_LABEL
%token TOK_KEY_PEER_LABEL
%token TOK_KEY_PEER
%token TOK_AUDIT
%token TOK_KEY_FAMILY
@ -194,7 +208,7 @@ new_syntax:
| TOK_TYPE_AA_ERROR audit_msg key_list { ret_record->event = AA_RECORD_ERROR; }
| TOK_TYPE_UNKNOWN audit_msg key_list { ret_record->event = lookup_aa_event($1); }
| TOK_TYPE_LSM_AVC audit_msg key_list
| TOK_TYPE_USER_AVC audit_user_msg TOK_SINGLE_QUOTE key_list TOK_SINGLE_QUOTE
| TOK_TYPE_USER_AVC audit_user_msg
;
other_audit: TOK_TYPE_OTHER audit_msg TOK_MSG_REST
@ -218,6 +232,11 @@ syslog_type:
{ ret_record->version = AA_RECORD_SYNTAX_V2; free($2); free($4); }
| syslog_date TOK_ID TOK_SYSLOG_KERNEL TOK_DMESG_STAMP key_type audit_id key_list
{ ret_record->version = AA_RECORD_SYNTAX_V2; free($2); free($4); }
/* needs update: hard newline in handling mutiline log messages */
| syslog_date TOK_ID TOK_SYSLOG_KERNEL TOK_DMESG_STAMP TOK_AUDIT TOK_COLON key_type audit_id audit_user_msg_partial_tail
{ ret_record->version = AA_RECORD_SYNTAX_V2; free($2); }
| syslog_date TOK_ID TOK_SYSLOG_KERNEL TOK_DMESG_STAMP TOK_AUDIT TOK_COLON key_type audit_id audit_user_msg_tail
{ ret_record->version = AA_RECORD_SYNTAX_V2; free($2); }
| syslog_date TOK_ID TOK_SYSLOG_KERNEL TOK_DMESG_STAMP TOK_AUDIT TOK_COLON key_type audit_id key_list
{ ret_record->version = AA_RECORD_SYNTAX_V2; free($2); free($4); }
| syslog_date TOK_ID TOK_SYSLOG_KERNEL TOK_AUDIT TOK_COLON key_type audit_id key_list
@ -234,7 +253,13 @@ audit_dispatch:
audit_msg: TOK_KEY_MSG TOK_EQUALS audit_id
;
audit_user_msg: TOK_KEY_MSG TOK_EQUALS audit_id ignored_pid ignored_uid ignored_auid ignored_ses TOK_KEY_MSG TOK_EQUALS
audit_user_msg_partial_tail: ignored_pid ignored_uid ignored_auid ignored_ses TOK_KEY_MSG TOK_EQUALS TOK_SINGLE_QUOTE key_list
;
audit_user_msg_tail: audit_user_msg_partial_tail TOK_SINGLE_QUOTE
;
audit_user_msg: TOK_KEY_MSG TOK_EQUALS audit_id audit_user_msg_tail
;
audit_id: TOK_AUDIT TOK_OPEN_PAREN TOK_AUDIT_DIGITS TOK_PERIOD TOK_AUDIT_DIGITS TOK_COLON TOK_AUDIT_DIGITS TOK_CLOSE_PAREN TOK_COLON
@ -292,6 +317,10 @@ key: TOK_KEY_OPERATION TOK_EQUALS TOK_QUOTED_STRING
{ ret_record->profile = $3;}
| TOK_KEY_PEER_PROFILE TOK_EQUALS safe_string
{ ret_record->peer_profile = $3;}
| TOK_KEY_LABEL TOK_EQUALS safe_string
{ ret_record->profile = $3;}
| TOK_KEY_PEER_LABEL TOK_EQUALS safe_string
{ ret_record->peer_profile = $3;}
| TOK_KEY_FAMILY TOK_EQUALS TOK_QUOTED_STRING
{ ret_record->net_family = $3;}
| TOK_KEY_SOCK_TYPE TOK_EQUALS TOK_QUOTED_STRING

View file

@ -131,6 +131,8 @@ key_pid "pid"
key_peer_pid "peer_pid"
key_profile "profile"
key_peer_profile "peer_profile"
key_label "label"
key_peer_label "peer_label"
key_family "family"
key_sock_type "sock_type"
key_protocol "protocol"
@ -314,6 +316,8 @@ yy_flex_debug = 0;
{key_peer_pid} { return(TOK_KEY_PEER_PID); }
{key_profile} { BEGIN(safe_string); return(TOK_KEY_PROFILE); }
{key_peer_profile} { BEGIN(safe_string); return(TOK_KEY_PEER_PROFILE); }
{key_label} { BEGIN(safe_string); return(TOK_KEY_LABEL); }
{key_peer_label} { BEGIN(safe_string); return(TOK_KEY_PEER_LABEL); }
{key_family} { return(TOK_KEY_FAMILY); }
{key_sock_type} { return(TOK_KEY_SOCK_TYPE); }
{key_protocol} { return(TOK_KEY_PROTOCOL); }

View file

@ -14,6 +14,7 @@ int main(int argc, char **argv)
FILE *testcase;
char log_line[1024];
aa_log_record *test = NULL;
size_t size;
int ret = -1;
if (argc != 2)
@ -32,14 +33,14 @@ int main(int argc, char **argv)
return(1);
}
if (fgets(log_line, 1023, testcase) == NULL)
{
size = fread(log_line, 1, 1023, testcase);
if (ferror(testcase)) {
fprintf(stderr, "Could not read testcase.\n");
fclose(testcase);
return(1);
}
fclose(testcase);
log_line[size] = 0;
test = parse_record(log_line);

View file

@ -0,0 +1 @@
Jun 20 17:57:06 ns1 kernel: [4835959.046111] audit: type=1107 audit(1561053426.749:186): pid=640 uid=103 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call" bus="system" path="/org/freedesktop/systemd1" interface="org.freedesktop.systemd1.Manager" member="LookupDynamicUserByName" mask="send" name="org.freedesktop.systemd1" pid=20596 label="/tmp/apparmor-2.8.0/tests/regression/apparmor/dbus_service" peer_pid=1 peer_label="unconfined" exe="/usr/bin/dbus-daemon" sauid=103 hostname=? addr=? terminal=?'

View file

@ -0,0 +1,18 @@
START
File: testcase_dbus_08.in
Event type: AA_RECORD_ALLOWED
Audit ID: 1561053426.749:186
Operation: dbus_method_call
Denied Mask: send
Profile: /tmp/apparmor-2.8.0/tests/regression/apparmor/dbus_service
Peer profile: unconfined
Name: org.freedesktop.systemd1
Command: /usr/bin/dbus-daemon
PID: 20596
Peer PID: 1
DBus bus: system
DBus path: /org/freedesktop/systemd1
DBus interface: org.freedesktop.systemd1.Manager
DBus member: LookupDynamicUserByName
Epoch: 1561053426
Audit subid: 186

View file

@ -0,0 +1,4 @@
/tmp/apparmor-2.8.0/tests/regression/apparmor/dbus_service {
dbus send bus=system path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=LookupDynamicUserByName peer=(label=unconfined),
}

View file

@ -0,0 +1,2 @@
Jun 20 17:57:06 ns1 kernel: [4835959.046111] audit: type=1107 audit(1561053426.749:186): pid=640 uid=103 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call" bus="system" path="/org/freedesktop/systemd1" interface="org.freedesktop.systemd1.Manager" member="LookupDynamicUserByName" mask="send" name="org.freedesktop.systemd1" pid=20596 label="/tmp/apparmor-2.8.0/tests/regression/apparmor/dbus_service" peer_pid=1 peer_label="unconfined"
exe="/usr/bin/dbus-daemon" sauid=103 hostname=? addr=? terminal=?'

View file

@ -0,0 +1,18 @@
START
File: testcase_dbus_09.in
Event type: AA_RECORD_ALLOWED
Audit ID: 1561053426.749:186
Operation: dbus_method_call
Denied Mask: send
Profile: /tmp/apparmor-2.8.0/tests/regression/apparmor/dbus_service
Peer profile: unconfined
Name: org.freedesktop.systemd1
Command: /usr/bin/dbus-daemon
PID: 20596
Peer PID: 1
DBus bus: system
DBus path: /org/freedesktop/systemd1
DBus interface: org.freedesktop.systemd1.Manager
DBus member: LookupDynamicUserByName
Epoch: 1561053426
Audit subid: 186

View file

@ -0,0 +1,3 @@
/tmp/apparmor-2.8.0/tests/regression/apparmor/dbus_service {
dbus send bus=system path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=LookupDynamicUserByName peer=( name=org.freedesktop.systemd1, label=unconfined),
}

View file

@ -0,0 +1 @@
Jun 20 17:57:06 ns1 kernel: [4835959.046111] audit: type=1107 audit(1561053426.749:186): pid=640 uid=103 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call" bus="system" path="/org/freedesktop/systemd1" interface="org.freedesktop.systemd1.Manager" member="LookupDynamicUserByName" mask="send" name="org.freedesktop.systemd1" pid=20596 label="/tmp/apparmor-2.8.0/tests/regression/apparmor/dbus_service" peer_pid=1 peer_label="unconfined"

View file

@ -0,0 +1,17 @@
START
File: testcase_dbus_10.in
Event type: AA_RECORD_ALLOWED
Audit ID: 1561053426.749:186
Operation: dbus_method_call
Denied Mask: send
Profile: /tmp/apparmor-2.8.0/tests/regression/apparmor/dbus_service
Peer profile: unconfined
Name: org.freedesktop.systemd1
PID: 20596
Peer PID: 1
DBus bus: system
DBus path: /org/freedesktop/systemd1
DBus interface: org.freedesktop.systemd1.Manager
DBus member: LookupDynamicUserByName
Epoch: 1561053426
Audit subid: 186

View file

@ -0,0 +1,4 @@
/tmp/apparmor-2.8.0/tests/regression/apparmor/dbus_service {
dbus send bus=system path=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=LookupDynamicUserByName peer=(label=unconfined),
}

View file

@ -33,7 +33,7 @@ class ReadLog:
'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=(USER_AVC|1107)\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
]

View file

@ -20,6 +20,7 @@ import apparmor.aa
from apparmor.logparser import ReadLog
from apparmor.profile_list import ProfileList
class TestLibapparmorTestMulti(AATest):
'''Parse all libraries/libapparmor/testsuite/test_multi tests and compare the result with the *.out files'''
@ -27,6 +28,9 @@ class TestLibapparmorTestMulti(AATest):
def _run_test(self, params, expected):
# tests[][expected] is a dummy, replace it with the real values
if params.split('/')[-1] in log_to_skip:
return
expected = self._parse_libapparmor_test_multi(params)
with open_file_read('%s.in' % params) as f_in:
@ -140,6 +144,10 @@ class TestLibapparmorTestMulti(AATest):
return exresult
# tests that cause crashes or need user interaction (will be skipped)
log_to_skip = [
'testcase_dbus_09', # multiline log not currently supported
]
# tests that do not produce the expected profile (checked with assertNotEqual)
log_to_profile_known_failures = [
@ -164,6 +172,7 @@ log_to_profile_skip = [
'testcase_syslog_changehat_negative_error', # fails in write_header -> quote_if_needed because data is None
'testcase_changehat_01', # interactive, asks to add a hat
'testcase_dbus_09', # multiline log not currently supported
]
# tests that cause an empty log