Re: [PATCH] ausearch: Add checkpoint capability and have incomplete logs carry forward when processing multiple audit.log files

Hello, Below is my diff between what you sent and svn at commit 831. -Steve On Tuesday, May 14, 2013 06:51:17 AM Burn Alting wrote: diff -urpNb audit-2.3.1.orig/docs/ausearch.8 audit-2.3.1/docs/ausearch.8 --- audit-2.3.1.orig/docs/ausearch.8 2013-05-13 08:58:31.000000000 -0400 +++ audit-2.3.1/docs/ausearch.8 2013-05-13 17:45:07.924216379 -0400 @@ -21,6 +21,25 @@ Search for an event based on the given \ .BR \-c ,\ \-\-comm \ \fIcomm-name\fP Search for an event based on the given \fIcomm name\fP. The comm name is the executable's name from the task structure. .TP +.BR \-\-checkpoint \ \fIcheckpoint-file\fP +Checkpoint the output between successive invocations of ausearch such that only events not +previously output will print in subsequent invocations. + +An auditd event is made up of one or more records. When processing events, ausearch defines +events as either complete or in-complete. A complete event is either a single record event or +one whose event time occurred 2 seconds in the past compared to the event being currently +processed. + +A checkpoint is achieved by recording the last completed event output along with the device +number and inode of the file the last completed event appeared in \fIcheckpoint-file\fP. On a subsequent invocation, +ausearch will load this checkpoint data and as it processes the log files, it will discard all +complete events until it matches the checkpointed one. At this point, it will start +outputting complete events. + +Should the file or checkpointed completed event not be found, an error will result and ausearch +will terminate. + +.TP .BR \-e,\ \-\-exit \ \fIexit-code-or-errno\fP Search for an event based on the given syscall \fIexit code or errno\fP. .TP @@ -144,6 +163,16 @@ String based matches must match the whol .BR \-x ,\ \-\-executable \ \fIexecutable\fP Search for an event matching the given \fIexecutable\fP name. +.SS "Exit status:" +.TP +0 +if OK, +1 +if nothing found, or argument errors or minor file acces/read errors, +10 +bad checkpoint data, +11 +checkpoint processing error .SH "SEE ALSO" .BR auditd (8), .BR pam_loginuid (8). diff -urpNb audit-2.3.1.orig/src/ausearch.c audit-2.3.1/src/ausearch.c --- audit-2.3.1.orig/src/ausearch.c 2013-05-13 17:43:51.165214494 -0400 +++ audit-2.3.1/src/ausearch.c 2013-05-13 17:45:07.924216379 -0400 @@ -40,6 +40,7 @@ #include "ausearch-options.h" #include "ausearch-lol.h" #include "ausearch-lookup.h" +#include "ausearch-checkpt.h" static FILE *log_fd = NULL; @@ -54,6 +55,10 @@ static int process_stdin(void); static int process_file(char *filename); static int get_record(llist **); +extern const char *checkpt_filename; /* checkpoint file name */ +static int have_chkpt_data = 0; /* flag to indicate we have checkpoint data we + * need to compare events against + */ extern char *user_file; extern int force_logs; extern int match(llist *l); @@ -90,6 +95,35 @@ int main(int argc, char *argv[]) set_aumessage_mode(MSG_STDERR, DBG_NO); (void) umask( umask( 077 ) | 027 ); + /* + * Load the checkpoint file if requested + */ + if (checkpt_filename) { + rc = load_ChkPt(checkpt_filename); + /* + * If < -1, then some load/parse error + * If == -1 then no file present (OK) + * If == 0, then checkpoint has data + */ + if (rc < -1) { + (void)free((void *)checkpt_filename); + free_ChkPtMemory(); + return 10; /* bad checkpoint status file */ + } else if (rc == -1) { + /* + * No file, so no checking required. This just means + * we have never checkpointed before and this is the + * first time. + */ + have_chkpt_data = 0; + } else { + /* + * We will need to check + */ + have_chkpt_data++; + } + } + lol_create(&lo); if (user_file) rc = process_file(user_file); @@ -99,6 +133,22 @@ int main(int argc, char *argv[]) rc = process_stdin(); else rc = process_logs(); + + /* + * Generate a checkpoint if required + */ + if (checkpt_filename) { + /* + * Providing we haven't failed + */ + if (!checkpt_failure) + (void)save_ChkPt(checkpt_filename); + free_ChkPtMemory(); + (void)free((void *)checkpt_filename); + if (checkpt_failure) + rc = 11; + } + lol_clear(&lo); ilist_clear(event_type); free(event_type); @@ -120,6 +170,8 @@ static int process_logs(void) struct daemon_conf config; char *filename; int len, num = 0; + int found_chkpt_file = -1; + int ret; /* Load config so we know where logs are */ if (load_config(&config, TEST_SEARCH)) { @@ -141,9 +193,43 @@ static int process_logs(void) do { if (access(filename, R_OK) != 0) break; + + /* + * If we have prior checkpoint data, we ignore files till we + * find the file we last checkpointed from + */ + if (checkpt_filename && have_chkpt_data) { + struct stat sbuf; + + if (stat(filename, &sbuf)) { + fprintf(stderr, "Error stat'ing %s (%s)\n", + filename, strerror(errno)); + free(filename); + return 1; + } + /* + * Have we accessed the checkpointed file? + * If so, stop checking further files. + */ + if ( + (sbuf.st_dev == chkpt_input_dev) + && + (sbuf.st_ino == chkpt_input_ino) + ) { + found_chkpt_file = num++; + break; + } + } + num++; snprintf(filename, len, "%s.%d", config.log_file, num); } while (1); + /* + * If we have a checkpoint loaded but haven't found it's file we need to error + */ + if (checkpt_filename && have_chkpt_data && found_chkpt_file == -1) + return 10; + num--; /* * We note how many files we need to process @@ -156,7 +242,6 @@ static int process_logs(void) else snprintf(filename, len, "%s", config.log_file); do { - int ret; if ((ret = process_file(filename))) { free(filename); free_config(&config); @@ -175,8 +260,88 @@ static int process_logs(void) else break; } while (1); + /* + * If performing a checkpoint, set the checkpointed + * file details - ie remember the last file processed + */ + ret = 0; + if (checkpt_filename) + ret = set_ChkPtFileDetails(filename); + free(filename); free_config(&config); + return ret; +} + +/* + * Decide if we should start outputing events given we loaded a checkpoint. + * + * The previous checkpoint will have recorded the last event outputted, + * if there was one. For nothing to be have been output, either the audit.log file + * was empty, all the events in it were incomplete or ??? + * + * We can return + * 0 no output + * 1 can output + * 2 can output but not this event + */ +static int chkpt_output_decision(event * e) +{ + static int can_output = 0; + + /* + * Short cut. Once we made the decision, it's made for good + */ + if (can_output) + return 1; + + /* + * If there was no checkpoint file, we turn on output + */ + if (have_chkpt_data == 0) { + can_output = 1; + return 1; /* can output on this event */ + } + + /* + * If the previous checkpoint had no recorded output, then + * we assume everything was partial so we turn on output + */ + if (chkpt_input_levent.sec == 0) { + can_output = 1; + return 1; /* can output on this event */ + } + + if ( + chkpt_input_levent.sec == e->sec + && + chkpt_input_levent.milli == e->milli + && + chkpt_input_levent.serial == e->serial + && + chkpt_input_levent.type == e->type + ) { + /* + * So far a match, so now check the nodes + */ + if (chkpt_input_levent.node == NULL && e->node == NULL) { + can_output = 1; + return 2; /* output after this event */ + } + if ( + chkpt_input_levent.node + && + e->node + && + (strcmp(chkpt_input_levent.node, e->node) == 0) + ) { + can_output = 1; + return 2; /* output after this event */ + } + /* + * The nodes are different. Drop thru to a no output return value + */ + } return 0; } @@ -184,6 +349,7 @@ static int process_log_fd(void) { llist *entries; // entries in a record int ret; + int do_output = 1; /* For each record in file */ do { @@ -191,9 +357,34 @@ static int process_log_fd(void) if ((ret != 0)||(entries->cnt == 0)) { break; } - + // FIXME - what about events that straddle files? + /* FIXED: + * We now only flush all events on the last log file being + * processed. Thus incomplete events are 'carried forward' to + * be completed from the rest of it's records we expect to find + * in the next file we are about to process. + */ if (match(entries)) { + /* + * If we are checkpointing, decide if we output + * this event + */ + if (checkpt_filename) + do_output = chkpt_output_decision(&entries->e); + + if (do_output == 1) { output_record(entries); + + /* Remember this event if checkpointing */ + if (checkpt_filename) { + if (set_ChkPtLastEvent(&entries->e)) { + list_clear(entries); + free(entries); + fclose(log_fd); + return 4; /* no memory */ + } + } + } found = 1; if (just_one) { list_clear(entries); @@ -299,14 +490,15 @@ static int get_record(llist **l) * If we are the last file being processed, we mark all incomplete * events as complete so they will be printed. */ - if ((ferror_unlocked(log_fd) && errno == EINTR) || feof_unlocked(log_fd)) { /* * Only mark all events as L_COMPLETE if we are the * last file being processed. + * We DO NOT do this if we are checkpointing. */ if (files_to_process == 0) { + if (!checkpt_filename) terminate_all_events(&lo); } *l = get_ready_event(&lo); diff -urpNb audit-2.3.1.orig/src/ausearch-checkpt.c audit-2.3.1/src/ausearch-checkpt.c --- audit-2.3.1.orig/src/ausearch-checkpt.c 1969-12-31 19:00:00.000000000 -0500 +++ audit-2.3.1/src/ausearch-checkpt.c 2013-05-13 17:45:07.925216379 -0400 @@ -0,0 +1,264 @@ +#include <stdlib.h> +#include <errno.h> +#include <sys/stat.h> +#include <unistd.h> +#include <string.h> +#include <stdio.h> +#include "ausearch-checkpt.h" + +#define DBG 0 /* set to non-zero for debug */ + +/* + * Remember why we failed + */ +unsigned checkpt_failure = 0; + +/* + * Remember the file we were processing when we had incomplete events. + * We remember this via it's dev and inode + */ +static dev_t checkpt_dev = (dev_t)NULL; +static ino_t checkpt_ino = (ino_t)NULL; + +/* + * Remember the last event output + */ +static event last_event = {0, 0, 0, NULL, 0}; + +/* + * Loaded values from a given checkpoint file + */ +dev_t chkpt_input_dev = (dev_t)NULL; +ino_t chkpt_input_ino = (ino_t)NULL; + +event chkpt_input_levent = {0, 0, 0, NULL, 0}; + +/* + * Record the dev_t and ino_t of the given file + * + * Rtns: + * 1 Failed to get status + * 0 OK + */ +int +set_ChkPtFileDetails(char * fn) +{ + struct stat sbuf; + + if (stat(fn, &sbuf) != 0) { + fprintf(stderr, "Cannot stat audit file for checkpoint details - %s: %s\n", + fn, strerror(errno)); + checkpt_failure |= CP_STATFAILED; + return 1; + } + checkpt_dev = sbuf.st_dev; + checkpt_ino = sbuf.st_ino; + return 0; +} + +/* + * Save the given event in the last_event record + * Rtns: + * 1 no memory + * 0 OK + */ +int +set_ChkPtLastEvent(event * e) +{ + /* + * Set the event node if necessary + */ + if (e->node) { + if (last_event.node) { + if (strcmp(e->node, last_event.node) != 0) { + (void)free((void *)last_event.node); + last_event.node = strdup(e->node); + } + } else { + last_event.node = strdup(e->node); + } + if (last_event.node == NULL) { + fprintf(stderr, "No memory to allocate checkpoint last event node name\n"); + return 1; + } + } else { + if (last_event.node) + (void)free((void *)last_event.node); + last_event.node = NULL; + } + last_event.sec = e->sec; + last_event.milli = e->milli; + last_event.serial = e->serial; + last_event.type = e->type; + return 0; +} + +/* + * Free all checkpoint memory + */ +void +free_ChkPtMemory() +{ + if (last_event.node) + (void)free((void *)last_event.node); + last_event.node = NULL; + if (chkpt_input_levent.node) + (void)free((void *)chkpt_input_levent.node); + chkpt_input_levent.node = NULL; +} + +/* + * Save the checkpoint to the given file + * Rtns: + * 1 io error + * 0 OK + */ +int +save_ChkPt(const char * fn) +{ + FILE * fd; + + if ((fd = fopen(fn, "w")) == NULL) { + fprintf(stderr, "Cannot open checkpoint file - %s: %s\n", + fn, strerror(errno)); + checkpt_failure |= CP_STATUSIO; + return 1; + } + fprintf(fd, "dev=0x%X\ninode=0x%X\n", + (unsigned int)checkpt_dev, (unsigned int)checkpt_ino); + fprintf(fd, "output=%s %lu.%03d:%lu 0x%X\n", + last_event.node ? last_event.node : "-", + (long unsigned int)last_event.sec, last_event.milli, + last_event.serial, last_event.type); + (void)fclose(fd); + return 0; +} + +/* + * Parse a checkpoint file "output=" record + * Rtns + * 1 failed to parse or no memory + * 0 parsed OK + */ +static int parse_checkpt_event(char * lbuf, int ndix, event * e) +{ + char * rest; + + /* + * Find the space after the node, then make it '\0' so + * we terminate the node value. We leave 'rest' at the start + * of the event time/serial element + */ + rest = strchr(&lbuf[ndix], ' '); + if (rest == NULL) { + fprintf(stderr, "Malformed output/event checkpoint line near node - [%s]\n", + lbuf); + checkpt_failure |= CP_STATUSBAD; + return 1; + } + *rest++ = '\0'; + + if (lbuf[ndix] == '-') { + e->node = NULL; + } else { + e->node = strdup(&lbuf[ndix]); + if (e->node == NULL) { + fprintf(stderr, "No memory for node when loading checkpoint line - [%s]\n", + lbuf); + checkpt_failure |= CP_NOMEM; + return 1; + } + } + if (sscanf(rest, "%lu.%03d:%lu 0x%X", &e->sec, &e->milli, &e->serial, &e->type) != 4) { + fprintf(stderr, "Malformed output/event checkpoint line afer node - [%s]\n", + lbuf); + checkpt_failure |= CP_STATUSBAD; + return 1; + } + + return 0; +} + +/* + * Load the checkpoint from the given file + * Rtns: + * < -1 error + * == -1 no file present + * == 0 loaded data + */ +int +load_ChkPt(const char * fn) +{ +#define MAX_LN 1023 /* good size */ + FILE * fd; + char lbuf[MAX_LN]; + + + if ((fd = fopen(fn, "r")) == NULL) { + if (errno == ENOENT) + return -1; + fprintf(stderr, "Cannot open checkpoint file - %s: %s\n", + fn, strerror(errno)); + return -2; + } + while (fgets(lbuf, MAX_LN, fd) != NULL) { + int len = strlen(lbuf); + + if (lbuf[len - 1] == '\n') /* drop the newline */ + lbuf[len - 1] = '\0'; + + if (strncmp(lbuf, "dev=", 4) == 0) { + errno = 0; + chkpt_input_dev = strtoul(&lbuf[4], NULL, 16); + if (errno) { + fprintf(stderr, "Malformed dev checkpoint line - [%s]\n", + lbuf); + checkpt_failure |= CP_STATUSBAD; + break; + } + } else if (strncmp(lbuf, "inode=", 6) == 0) { + errno = 0; + chkpt_input_ino = strtoul(&lbuf[6], NULL, 16); + if (errno) { + fprintf(stderr, "Malformed inode checkpoint line - [%s]\n", + lbuf); + checkpt_failure |= CP_STATUSBAD; + break; + } + } else if (strncmp(lbuf, "output=", 7) == 0) { + if (parse_checkpt_event(lbuf, 7, &chkpt_input_levent)) { + break; + } + } else { + fprintf(stderr, "Malformed unknown checkpoint line - [%s]\n", + lbuf); + checkpt_failure |= CP_STATUSBAD; + break; + } + } + if ( + (chkpt_input_ino == (ino_t)NULL) + || + (chkpt_input_dev == (dev_t)NULL) + ) { + fprintf(stderr, "Missing dev/inode lines from checkpoint file %s\n", + fn); + checkpt_failure |= CP_STATUSBAD; + } + (void)fclose(fd); + + if (checkpt_failure) + return -3; + +#if DBG + { + fprintf(stderr, "Loaded %s - dev: 0x%X, ino: 0x%X\n", + fn, chkpt_input_dev, chkpt_input_ino); + fprintf(stderr, "output:%s %d.%03d:%lu 0x%X\n", + chkpt_input_levent.node ? chkpt_input_levent.node : "-", + chkpt_input_levent.sec, chkpt_input_levent.milli, + chkpt_input_levent.serial, chkpt_input_levent.type); + } +#endif /* DBG */ + return 0; +} diff -urpNb audit-2.3.1.orig/src/ausearch-checkpt.h audit-2.3.1/src/ausearch-checkpt.h --- audit-2.3.1.orig/src/ausearch-checkpt.h 1969-12-31 19:00:00.000000000 -0500 +++ audit-2.3.1/src/ausearch-checkpt.h 2013-05-13 17:45:07.925216379 -0400 @@ -0,0 +1,24 @@ +#ifndef CHECKPT_HEADER +#define CHECKPT_HEADER + +#include <sys/types.h> +#include "ausearch-llist.h" + +extern int set_ChkPtFileDetails(char *); +extern int set_ChkPtLastEvent(event * e); +extern void free_ChkPtMemory(); +extern int save_ChkPt(const char *); +extern int load_ChkPt(const char *); + +#define CP_NOMEM 0x0001 /* no memory when creating checkpoint list */ +#define CP_STATFAILED 0x0002 /* stat() call on last log file failed */ +#define CP_STATUSIO 0x0004 /* cannot open/read/write checkpoint file */ +#define CP_STATUSBAD 0x0008 /* malformed status checkpoint entries */ + +extern unsigned checkpt_failure; + +extern dev_t chkpt_input_dev; +extern ino_t chkpt_input_ino; +extern event chkpt_input_levent; + +#endif /* CHECKPT_HEADER */ diff -urpNb audit-2.3.1.orig/src/ausearch-options.c audit-2.3.1/src/ausearch-options.c --- audit-2.3.1.orig/src/ausearch-options.c 2013-05-13 08:58:31.000000000 -0400 +++ audit-2.3.1/src/ausearch-options.c 2013-05-13 17:45:07.926216379 -0400 @@ -65,6 +65,7 @@ const char *event_subject = NULL; const char *event_object = NULL; const char *event_uuid = NULL; const char *event_vmname = NULL; +const char *checkpt_filename = NULL; /* checkpoint filename if present */ report_t report_format = RPT_DEFAULT; ilist *event_type; @@ -81,13 +82,14 @@ S_HOSTNAME, S_INTERP, S_INFILE, S_MESSAG S_TIME_END, S_TIME_START, S_TERMINAL, S_ALL_UID, S_EFF_UID, S_UID, S_LOGINID, S_VERSION, S_EXACT_MATCH, S_EXECUTABLE, S_CONTEXT, S_SUBJECT, S_OBJECT, S_PPID, S_KEY, S_RAW, S_NODE, S_IN_LOGS, S_JUST_ONE, S_SESSION, S_EXIT, -S_LINEBUFFERED, S_UUID, S_VMNAME}; +S_LINEBUFFERED, S_UUID, S_VMNAME, S_CHECKPOINT}; static struct nv_pair optiontab[] = { { S_EVENT, "-a" }, { S_EVENT, "--event" }, { S_COMM, "-c" }, { S_COMM, "--comm" }, + { S_CHECKPOINT, "--checkpoint" }, { S_EXIT, "-e" }, { S_EXIT, "--exit" }, { S_FILENAME, "-f" }, @@ -176,6 +178,7 @@ static void usage(void) printf("usage: ausearch [options]\n" "\t-a,--event <Audit event id>\tsearch based on audit event id\n" "\t-c,--comm <Comm name>\t\tsearch based on command line name\n" + "\t--checkpoint <checkpoint file>\tsearch from last complete event\n" "\t-e,--exit <Exit code or errno>\tsearch based on syscall exit code\n" "\t-f,--file <File name>\t\tsearch based on file name\n" "\t-ga,--gid-all <all Group id>\tsearch based on All group ids\n" @@ -1099,6 +1102,19 @@ int check_params(int count, char *vars[] case S_LINEBUFFERED: line_buffered = 1; break; + case S_CHECKPOINT: + if (!optarg) { + fprintf(stderr, + "Argument is required for %s\n", + vars[c]); + retval = -1; + } else { + checkpt_filename = strdup(optarg); + if (checkpt_filename == NULL) + retval = -1; + c++; + } + break; default: fprintf(stderr, "%s is an unsupported option\n", vars[c]); diff -urpNb audit-2.3.1.orig/src/Makefile.am audit-2.3.1/src/Makefile.am --- audit-2.3.1.orig/src/Makefile.am 2013-05-13 08:58:31.000000000 -0400 +++ audit-2.3.1/src/Makefile.am 2013-05-13 17:45:07.926216379 -0400 @@ -26,7 +26,7 @@ SUBDIRS = test INCLUDES = -I${top_srcdir} -I${top_srcdir}/lib -I${top_srcdir}/src/libev sbin_PROGRAMS = auditd auditctl aureport ausearch autrace AM_CFLAGS = -D_GNU_SOURCE -noinst_HEADERS = auditd-config.h auditd-event.h auditd-listen.h ausearch-llist.h ausearch-options.h auditctl-llist.h aureport-options.h ausearch-parse.h aureport-scan.h ausearch-lookup.h ausearch-int.h auditd-dispatch.h ausearch-string.h ausearch-nvpair.h ausearch-common.h ausearch-avc.h ausearch-time.h ausearch-lol.h idata.h +noinst_HEADERS = auditd-config.h auditd-event.h auditd-listen.h ausearch-llist.h ausearch-options.h auditctl-llist.h aureport-options.h ausearch-parse.h aureport-scan.h ausearch-lookup.h ausearch-int.h auditd-dispatch.h ausearch-string.h ausearch-nvpair.h ausearch-common.h ausearch-avc.h ausearch-time.h ausearch-lol.h idata.h ausearch-checkpt.h auditd_SOURCES = auditd.c auditd-event.c auditd-config.c auditd-reconfig.c auditd-sendmail.c auditd-dispatch.c if ENABLE_LISTENER @@ -45,7 +45,7 @@ auditctl_LDADD = -L${top_builddir}/lib - aureport_SOURCES = aureport.c auditd-config.c ausearch-llist.c aureport-options.c ausearch-string.c ausearch-parse.c aureport-scan.c aureport-output.c ausearch-lookup.c ausearch-int.c ausearch-time.c ausearch-nvpair.c ausearch-avc.c ausearch-lol.c aureport_LDADD = -L${top_builddir}/lib -laudit -ausearch_SOURCES = ausearch.c auditd-config.c ausearch-llist.c ausearch-options.c ausearch-report.c ausearch-match.c ausearch-string.c ausearch-parse.c ausearch-int.c ausearch-time.c ausearch-nvpair.c ausearch-lookup.c ausearch-avc.c ausearch-lol.c +ausearch_SOURCES = ausearch.c auditd-config.c ausearch-llist.c ausearch-options.c ausearch-report.c ausearch-match.c ausearch-string.c ausearch-parse.c ausearch-int.c ausearch-time.c ausearch-nvpair.c ausearch-lookup.c ausearch-avc.c ausearch-lol.c ausearch-checkpt.c ausearch_LDADD = -L${top_builddir}/lib -laudit -L${top_builddir}/auparse -lauparse autrace_SOURCES = autrace.c delete_all.c auditctl-llist.c