Add run-aa-test and aa_log_extract_tokens.pl

A number of tests use the script `run-aa-test`. Add the shell port of this
script to common so that it doesn't need to be replicated in multiple
places.

This script uses `aa_log_extract_tokens.pl`, so pull that into common too.

Signed-off-by: Martyn Welch <martyn.welch@collabora.co.uk>

aa_log_extract_tokens.pl

+#!/usr/bin/env perl
+# vim: set sts=4 sw=4 et tw=80 :
+#
+#    Copyright (c) 2006 Novell, Inc. All Rights Reserved.
+#    Copyright (c) 2010 Canonical, Ltd.
+#    Copyright (c) 2012-2015 Collabora Ltd.
+#
+#    This program is free software; you can redistribute it and/or
+#    modify it under the terms of version 2 of the GNU General Public
+#    License as published by the Free Software Foundation.
+#
+#    This program is distributed in the hope that it will be useful,
+#    but WITHOUT ANY WARRANTY; without even the implied warranty of
+#    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+#    GNU General Public License for more details.
+#
+#    You should have received a copy of the GNU General Public License
+#    along with this program; if not, contact Novell, Inc.
+#
+#    To contact Novell about this file by physical or electronic mail,
+#    you may find current contact information at www.novell.com.
+
+# Example script to extract tokens from apparmor events in audit.log
+# We use auditd because otherwise messages are lost if they come too quickly
+# http://wiki.apparmor.net/index.php/AppArmorMonitoring#Realtime_information
+#
+#
+# Example complaint event:
+# type=AVC msg=audit(1344659645.579:153): apparmor="ALLOWED" operation="open"
+# parent=15215 profile="/home/chaiwala/bin/*" name="/etc/group" pid=15216
+# comm="ls" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
+#
+# Example audit event:
+# type=AVC msg=audit(1344735566.384:827): apparmor="AUDIT" operation="getattr"
+# parent=16769 profile="/home/chaiwala/bin/*" name="/etc/localtime" pid=16770
+# comm="ls" requested_mask="r" fsuid=1000 ouid=0
+#
+
+use strict;
+use warnings;
+
+use LibAppArmor qw();
+
+use constant DEBUG => $ENV{AA_LOG_DEBUG};
+
+my $event;
+my $record;
+my $value;
+my $profile_wanted;
+my @event_modes;
+my @skip_names;
+my %records_order;
+
+sub usage {
+    print("Usage: $0 <event mode> [event mode]...\n");
+    print("And pipe logs to it\n");
+    print("Valid values for [event mode] are: PERMITTING, REJECTING, AUDITING\n");
+}
+
+# Ensure there are some arguments
+if ($#ARGV < 0) {
+    usage();
+    exit(1);
+}
+
+# Ensure that the arguments are all valid
+foreach (@ARGV) {
+    SWITCH: {
+        if (/PERMITTING/) { last SWITCH; }
+        if (/REJECTING/) { last SWITCH; }
+        if (/AUDITING/) { last SWITCH; }
+        usage();
+        exit(1);
+    }
+}
+
+# Valid values we'll use: PERMITTING, REJECTING, AUDITING
+# Valid values that we're not interested in: STATUS, ERROR, UNKNOWN, HINT
+# PERMITTING is emitted when:
+# * AppArmor is in "normal" audit mode[1]
+# * A profile loaded in complain mode matches something
+# REJECTING is emitted when:
+# * AppArmor is in "normal" audit mode[1]
+# * A profile loaded in enforce mode matches something
+# AUDITING is emitted when:
+# * AppArmor is in "all" audit mode[1]
+#
+# 1. http://wiki.apparmor.net/index.php/AppArmor_Failures#Module_audit_settings
+@event_modes = @ARGV;
+
+# We're being lazy and getting arguments from the environment instead of doing 
+# getopt parsing
+$profile_wanted = $ENV{'AA_PROFILE_WANTED'};
+
+# Regex of file paths to skip accesses to
+@skip_names=(
+    "/etc/ld\.so\.cache",
+    "/lib/i386-linux-gnu/libc.*\.so",
+    "/dev/pts/.*",
+    "/dev/(null|zero|random|urandom)",
+);
+
+# Arbitrary order, but we want to keep it constant.
+# chaiwala-apparmor-tests rely on the following order.
+%records_order = (
+  'profile' => 1,
+  'sdmode' => 2,
+  'denied_mask' => 3,
+  'operation' => 4,
+  'name' => 5,
+  'request_mask' => 6,
+  );
+
+sub records_sort {
+  if (exists $records_order{$a} && exists $records_order{$b})
+  {
+    return ($records_order{$a}) <=> ($records_order{$b});
+  }
+
+  if (! exists $records_order{$a} && !exists $records_order{$b})
+  {
+    return $a cmp $b;
+  }
+
+  return exists $records_order{$a} ? -1 : 1;
+}
+
+# Simplified from Immunix::AppArmor.
+sub stringify_sdmode {
+    my $sdmode = shift;
+
+    return 'ERROR' if $sdmode == 1;
+    return 'AUDITING' if $sdmode == 2;
+    return 'PERMITTING' if $sdmode == 3;
+    return 'REJECTING' if $sdmode == 4;
+    return 'HINT' if $sdmode == 5;
+    return 'STATUS' if $sdmode == 6;
+
+    # no idea - output *something*
+    return $sdmode;
+}
+
+# Simplified from Immunix::AppArmor. We're not using its parse_event
+# because that only works properly for events whose mask is something
+# like r or w, not for events whose mask is more like receive or send;
+# this version is more "raw", and hopefully a little more robust against
+# AA changes.
+sub parse_event {
+    my %ev = ();
+    my $msg = shift;
+    chomp($msg);
+    my $event = LibAppArmor::parse_record($msg);
+
+    $ev{resource} = LibAppArmor::aa_log_record::swig_info_get($event);
+    $ev{active_hat} = LibAppArmor::aa_log_record::swig_active_hat_get($event);
+    $ev{sdmode} = LibAppArmor::aa_log_record::swig_event_get($event);
+    $ev{time} = LibAppArmor::aa_log_record::swig_epoch_get($event);
+    $ev{operation} = LibAppArmor::aa_log_record::swig_operation_get($event);
+    $ev{profile} = LibAppArmor::aa_log_record::swig_profile_get($event);
+    $ev{name} = LibAppArmor::aa_log_record::swig_name_get($event);
+    $ev{name2} = LibAppArmor::aa_log_record::swig_name2_get($event);
+    $ev{attr} = LibAppArmor::aa_log_record::swig_attribute_get($event);
+    $ev{parent} = LibAppArmor::aa_log_record::swig_parent_get($event);
+    $ev{pid} = LibAppArmor::aa_log_record::swig_pid_get($event);
+    $ev{task} = LibAppArmor::aa_log_record::swig_task_get($event);
+    $ev{info} = LibAppArmor::aa_log_record::swig_info_get($event);
+    $ev{denied_mask} = LibAppArmor::aa_log_record::swig_denied_mask_get($event);
+    $ev{request_mask} = LibAppArmor::aa_log_record::swig_requested_mask_get($event);
+    $ev{magic_token} = LibAppArmor::aa_log_record::swig_magic_token_get($event);
+    $ev{family} = LibAppArmor::aa_log_record::swig_net_family_get($event);
+    $ev{protocol} = LibAppArmor::aa_log_record::swig_net_protocol_get($event);
+    $ev{sock_type} = LibAppArmor::aa_log_record::swig_net_sock_type_get($event);
+
+    LibAppArmor::free_record($event);
+
+    if (! $ev{sdmode}) {
+        return undef;
+    }
+
+    $ev{sdmode} = stringify_sdmode($ev{sdmode});
+
+    if (DEBUG) {
+        print STDERR "/----\n";
+        foreach my $k (sort keys %ev) {
+            if (defined $ev{$k}) {
+                print STDERR "\t", $k, "\t", $ev{$k}, "\n";
+            }
+        }
+        print STDERR "\\----\n";
+    }
+
+    return \%ev;
+}
+
+EVENT: while (<STDIN>) {
+    # This doesn't give us all the tokens, unfortunately.
+    # Only gives us: profile, sdmode, time, denied_mask, pid, operation,
+    # parent (parent pid), name (filename), request_mask
+    # (FIXME: it could now give more if we want them)
+    $event = parse_event($_);
+
+    if (!$event ||
+        !(grep { $_ eq $$event{'sdmode'} } @event_modes) ||
+        ($profile_wanted && ($$event{'profile'} ne $profile_wanted)))
+    {
+        next EVENT;
+    }
+
+    foreach (@skip_names) {
+        if (defined $$event{'name'} && $$event{'name'} =~ /$_/) {
+            next EVENT;
+        }
+    }
+
+    print "====\n";
+    # This is pretty much it. Go forth and use this hash in whatever way.
+    foreach $record (sort records_sort keys %$event) {
+        $value = $$event{$record};
+        next unless $value;
+        # Skip records that keep changing with every invocation
+        SWITCH: {
+            if ($record eq "time") { last SWITCH; }
+            if ($record eq "pid") { last SWITCH; }
+            if ($record eq "parent") { last SWITCH; }
+            print "$record:$value\n";
+        }
+    }
+}

run-aa-test

+#!/bin/sh
+#
+# Copyright © 2018 Collabora Ltd.
+#
+# Based on python version of run-aa-test
+#
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+
+ALTERNATIVE_SEPARATOR="## alternative ##"
+END=2
+
+case $(echo ${LAUNCH_DBUS} | tr [A-Z] [a-z]) in
+0 | no | false)
+	LAUNCH_DBUS="False"
+	;;
+*)
+	LAUNCH_DBUS="True"
+esac
+
+case $(echo ${RUN_AS_USER} | tr [A-Z] [a-z]) in
+0 | no | false)
+	RUN_AS_USER="False"
+	;;
+*)
+	RUN_AS_USER="True"
+esac
+
+CHAIWALA_UID=1000
+CHAIWALA_USER="user"
+
+# Check parameters
+if [ $# -lt 2 ]; then
+
+	echo "Usage: run-aa-test <expectation-file> <command> <argument-1> <argument-2> …"
+	echo "\"export LAUNCH_DBUS=no\" in the test script to not launch a dbus session."
+	echo "\"export RUN_AS_USER=no\" in the test script to not run as ${CHAIWALA_USER}"
+	exit 1
+fi
+
+EXPECT_FILE=$1
+shift
+
+if [ ! -r ${EXPECT_FILE} ]; then
+	echo "Cannot read specified expectation file: ${EXPECT_FILE}"
+	exit 1
+fi
+
+if [ ! -x $1 ]; then
+	echo "Cannot execute specified test executable: $1"
+	exit 1
+fi
+
+SOMETHING_FAILED="False"
+# typically "normal.expected" or "malicious.expected"
+TEST_TITLE=$( basename ${EXPECT_FILE} )
+
+# Touch .bash_history, which we use in some tests, if it's not there.
+bash_history="/home/${CHAIWALA_USER}/.bash_history"
+if [ ! -r ${bash_history} ]; then
+	RET=$( sudo -u ${CHAIWALA_USER} touch ${bash_history} )
+	if [ $RET != 0 ]; then
+		echo "Failed to create .bash_history: $RET"
+		exit 1
+	fi
+fi
+
+# Catch any new lines added to audit.log
+AUDIT_FILE=$( mktemp )
+tail -n0 -f /var/log/audit/audit.log > ${AUDIT_FILE} &
+AUDIT_PID=$!
+
+if [ "${LAUNCH_DBUS}" = "True" ]; then
+	# Start a new D-Bus session for this test
+	CMD="dbus-run-session -- $*"
+else
+	CMD="$*"
+fi
+
+CMDLINE=""
+for PREFIX in '' '/usr/lib/apertis-tests/'; do
+	TOOL="${PREFIX}common/run-test-in-systemd"
+	if [ -x ${TOOL} ]; then
+		CMDLINE=${TOOL}
+		break
+	fi
+done
+
+if [ "$CMDLINE" = "" ]; then
+	echo "common/run-test-in-systemd not found"
+	exit 1
+fi
+
+CMDLINE="${CMDLINE} --no-lava"
+
+if [ "${RUN_AA_TEST_TIMEOUT}" != "" ]; then
+	CMDLINE="${CMDLINE} --timeout=${RUN_AA_TEST_TIMEOUT}"
+fi
+
+if [ "${RUN_AS_USER}" = "True" ]; then
+	CMDLINE="${CMDLINE} --user=${CHAIWALA_UID}"
+else
+	CMDLINE="${CMDLINE} --system"
+fi
+
+CMDLINE="${CMDLINE} ${CMD}"
+
+echo "#=== running test script: ${CMDLINE} ==="
+
+setsid ${CMDLINE}
+RET=$?
+
+echo "#--- end of test script, status: ${RET}"
+
+if [ "${RET}" = "0" ]; then
+	echo "${TEST_TITLE}_underlying_tests: pass"
+else
+	echo "# ${CMDLINE} exited ${RET}"
+	# typically "normal.expected_underlying_tests: fail"
+	echo "${TEST_TITLE}_underlying_tests: fail"
+	SOMETHING_FAILED="True"
+fi
+
+# Give auditd time to log the entries.
+sleep 3
+
+# Need to stop tailing audit
+kill ${AUDIT_PID}
+
+echo "#=== ${TEST_TITLE} ==="
+
+echo "#---8<--- raw output in audit log"
+cat ${AUDIT_FILE} | sed 's/^/# /'
+echo "#--->8---"
+
+echo "#---8<--- expected output from aa_log_extract_tokens.pl"
+cat ${EXPECT_FILE} | sed 's/^/# /'
+echo "#--->8---"
+
+EXPECT_SPLIT_DIR=$(mktemp -d)
+
+cp ${EXPECT_FILE} ${EXPECT_SPLIT_DIR}/REMAIN
+
+EXPECT_COUNT=1
+
+SEPARATOR=$( grep -m1 -x -n "${ALTERNATIVE_SEPARATOR}" ${EXPECT_SPLIT_DIR}/REMAIN | cut -d: -f1 )
+while [ "${SEPARATOR}" != "" ]; do
+	echo "SEPARATOR=\"${SEPARATOR}\""
+	echo "REMAIN:"
+	cat ${EXPECT_SPLIT_DIR}/REMAIN
+	head -n $((${SEPARATOR}-1)) ${EXPECT_SPLIT_DIR}/REMAIN > ${EXPECT_SPLIT_DIR}/EXPECT${EXPECT_COUNT}
+	SEPARATOR=$((${SEPARATOR}+1))
+	tail -n +${SEPARATOR} ${EXPECT_SPLIT_DIR}/REMAIN > ${EXPECT_SPLIT_DIR}/REMAIN.new
+	mv ${EXPECT_SPLIT_DIR}/REMAIN.new ${EXPECT_SPLIT_DIR}/REMAIN
+	EXPECT_COUNT=$((${EXPECT_COUNT}+1))
+	SEPARATOR=$( grep -m1 -x -n "${ALTERNATIVE_SEPARATOR}" ${EXPECT_SPLIT_DIR}/REMAIN | cut -d: -f1 )
+done
+
+mv ${EXPECT_SPLIT_DIR}/REMAIN ${EXPECT_SPLIT_DIR}/EXPECT${EXPECT_COUNT}
+
+PARSE_FILE="${EXPECT_SPLIT_DIR}/PARSE"
+
+RET=$( cat ${AUDIT_FILE} | common/aa_log_extract_tokens.pl REJECTING > ${PARSE_FILE} )
+
+if [ "${RET}" != "0" ]; then
+	echo "# aa_log_extract_tokens.pl failed, trying line-by-line..."
+
+	LINES=$(wc -l ${AUDIT_FILE} | cut -d ' ' -f1 )
+	
+	cat ${AUDIT_FILE} | while read LINE; do
+		echo ${LINE} | common/aa_log_extract_tokens.pl REJECTING 2>${EXPECT_SPLIT_DIR}/STDERR > ${EXPECT_SPLIT_DIR}/STDOUT
+		RET=$?
+		cat ${EXPECT_SPLIT_DIR}/STDOUT >> ${EXPECT_SPLIT_DIR}/ERRPARSE
+
+		cat ${EXPECT_SPLIT_DIR}/STDERR | sed 's/^/E: /' >> ${EXPECT_SPLIT_DIR}/ERRPARSE
+
+		if [ "$RET" != "0" ]; then
+			echo -n "^ original line: ${LINE}" >> ${EXPECT_SPLIT_DIR}/ERRPARSE
+		fi
+	done
+
+	mv ${EXPECT_SPLIT_DIR}/ERRPARSE ${PARSE_FILE}
+fi
+
+echo "#---8<--- actual output from aa_log_extract_tokens.pl"
+cat ${PARSE_FILE} | sed 's/^/# /'
+echo "#--->8---"
+
+MATCH_EXPECTATION="False"
+
+# We might have alternative expectations, take that into consideration.
+OUTPUT_MD5=$( cat ${PARSE_FILE} | md5sum )
+COUNT=$( ls -1 ${EXPECT_SPLIT_DIR}/EXPECT* | wc -l )
+NUM=1
+while [ $((${NUM} <= ${COUNT})) = 1 ]; do
+	EXPECTED_MD5=$( cat ${EXPECT_SPLIT_DIR}/EXPECT${NUM} | md5sum )
+	if [ "${OUTPUT_MD5}" = "${EXPECTED_MD5}" ]; then
+		echo "# audit log matches alternative expectation ${NUM}/${COUNT}"
+		MATCH_EXPECTATION="True"
+	fi
+	NUM=$((${NUM}+1))
+done
+
+if [ "${MATCH_EXPECTATION}" = "True" ]; then
+	echo "${TEST_TITLE}: pass"
+else
+	echo "#---8<--- diff"
+	diff -urN ${EXPECT_SPLIT_DIR}/EXPECT${NUM} ${PARSE_FILE}
+	echo "#--->8---"
+	echo "${TEST_TITLE}: fail"
+	SOMETHING_FAILED="True"
+fi
+
+if [ "${SOMETHING_FAILED}" = "True" ]; then
+	exit 1
+fi
+
+exit 0