sw-collector: Iterate through history logs

The logrotate function causes the apt history to be split into
several parts at arbitrary points in time. If history.log only
is parsed then some package installation changes stored in
zipped backup history files might get lost.

Thus sw-collector now searches all backup history files until
a date older than the current event stored in the collector.db
database is found, so that no entries get overlooked.

diff --git a/src/sw-collector/sw-collector.c b/src/sw-collector/sw-collector.c
index a24170d76bc1a432239c4cb783e79f871f61bbdb..8beddc48ea1ea5e50dcba3c6e4aade6ea3e36173 100644 (file)
--- a/src/sw-collector/sw-collector.c
+++ b/src/sw-collector/sw-collector.c
@@ -2,6 +2,8 @@
  * Copyright (C) 2017 Andreas Steffen
  * HSR Hochschule fuer Technik Rapperswil
  *
+ * Copyright (C) 2021 Andreas Steffen, strongSec GmbH
+ *
  * This program is free software; you can redistribute it and/or modify it
  * under the terms of the GNU General Public License as published by the
  * Free Software Foundation; either version 2 of the License, or (at your
@@ -19,6 +21,7 @@
 #include <errno.h>
 #include <getopt.h>
 #include <unistd.h>
+#include <sysexits.h>
 #ifdef HAVE_SYSLOG
 # include <syslog.h>
 #endif
@@ -35,6 +38,10 @@
 
 #include <swid_gen/swid_gen.h>
 #include <swid_gen/swid_gen_info.h>
+
+#define DEFAULT_HISTORY_LOG            "/var/log/apt/history.log"
+#define NO_ITERATION                   -1
+
 /**
  * global debug output variables
  */
@@ -223,49 +230,27 @@ static collector_op_t do_args(int argc, char *argv[], bool *full_tags,
 }
 
 /**
- * Extract software events from apt history log files
+ * Extract software events from a specific apt history log file
  */
-static int extract_history(sw_collector_db_t *db)
+static int extract_history_file(sw_collector_db_t *db,
+                                                               sw_collector_history_t *history, char *last_time,
+                                                               uint32_t last_eid, char *path, int level)
 {
-       sw_collector_history_t *history = NULL;
-       uint32_t epoch, last_eid, eid = 0;
-       char *history_path, *last_time = NULL, rfc_time[21];
-       chunk_t *h, history_chunk, line, cmd;
-       int status = EXIT_FAILURE;
-       bool skip = TRUE;
-
-       /* open history file for reading */
-       history_path = lib->settings->get_str(lib->settings, "%s.history", NULL,
-                                                                                 lib->ns);
-       if (!history_path)
-       {
-               fprintf(stderr, "sw-collector.history path not set.\n");
-               return EXIT_FAILURE;
-       }
-       h = chunk_map(history_path, FALSE);
+       chunk_t *h, history_chunk, line, command;
+       char rfc_time[21], *new_path = NULL, *cmd = NULL;
+       int status = EXIT_FAILURE, rc;
+       bool skip = TRUE, first_skip = TRUE;
+       size_t len, cmd_len;
+       uint32_t eid = 0;
+
+       h = chunk_map(path, FALSE);
        if (!h)
        {
-               fprintf(stderr, "opening '%s' failed: %s", history_path,
-                               strerror(errno));
-               return EXIT_FAILURE;
-       }
-       history_chunk = *h;
-
-       /* Instantiate history extractor */
-       history = sw_collector_history_create(db, 1);
-       if (!history)
-       {
-               chunk_unmap(h);
-               return EXIT_FAILURE;
+               return EX_NOINPUT;
        }
+       DBG1(DBG_IMC, "opened '%s'", path);
 
-       /* retrieve last event in database */
-       if (!db->get_last_event(db, &last_eid, &epoch, &last_time) || !last_eid)
-       {
-               goto end;
-       }
-       DBG0(DBG_IMC, "Last-Event: %s, eid = %u, epoch = %u",
-                                  last_time, last_eid, epoch);
+       history_chunk = *h;
 
        /* parse history file */
        while (fetchline(&history_chunk, &line))
@@ -274,12 +259,12 @@ static int extract_history(sw_collector_db_t *db)
                {
                        continue;
                }
-               if (!extract_token(&cmd, ':', &line))
+               if (!extract_token(&command, ':', &line))
                {
                        fprintf(stderr, "terminator symbol ':' not found.\n");
                        goto end;
                }
-               if (match("Start-Date", &cmd))
+               if (match("Start-Date", &command))
                {
                        if (!history->extract_timestamp(history, line, rfc_time))
                        {
@@ -289,8 +274,58 @@ static int extract_history(sw_collector_db_t *db)
                        /* have we reached new history entries? */
                        if (skip && strcmp(rfc_time, last_time) > 0)
                        {
+                               if (first_skip && level != NO_ITERATION)
+                               {
+                                       DBG0(DBG_IMC, "   Warning: %s of first entry on level %d"
+                                                                 " is newer", rfc_time, level);
+
+                                       /* try to parse history log on next level */
+                                       len = strlen(path) + 6;
+                                       new_path = malloc(len);
+                                       snprintf(new_path, len, DEFAULT_HISTORY_LOG ".%d", ++level);
+                                       rc = extract_history_file(db, history, last_time, last_eid,
+                                                                                         new_path, level);
+                                       if (rc == EX_NOINPUT)
+                                       {
+                                               /* try to uncompress history log */
+                                               cmd_len = strlen(new_path) + 20;
+                                               cmd = malloc(cmd_len);
+                                               snprintf(cmd, cmd_len, "/usr/bin/gunzip %s.gz", new_path);
+                                               if (system(cmd) == 0)
+                                               {
+                                                       rc = extract_history_file(db, history, last_time,
+                                                                                                         last_eid, new_path, level);
+                                                       if (rc == EX_NOINPUT)
+                                                       {
+                                                               fprintf(stderr, "opening '%s' failed: %s\n",
+                                                                               path, strerror(errno));
+                                                       }
+
+                                                       /* re-compress the history log */
+                                                       snprintf(cmd, cmd_len, "/usr/bin/gzip %s", new_path);
+                                                       if (system(cmd) != 0)
+                                                       {
+                                                               fprintf(stderr, "gzip command failed");
+                                                       }
+                                               }
+                                               else
+                                               {
+                                                       /* no further [compressed] history log available */
+                                                       rc = EXIT_SUCCESS;
+                                               }
+                                               free(cmd);
+                                       }
+                                       free(new_path);
+
+                                       if (rc != EXIT_SUCCESS)
+                                       {
+                                               goto end;
+                                       }
+                               }
                                skip = FALSE;
                        }
+                       first_skip = FALSE;
+
                        if (skip)
                        {
                                continue;
@@ -302,15 +337,14 @@ static int extract_history(sw_collector_db_t *db)
                        {
                                goto end;
                        }
-                       DBG1(DBG_IMC, "Start-Date: %s, eid = %u, epoch = %u",
-                                                  rfc_time, eid, epoch);
+                       DBG1(DBG_IMC, "Start-Date: %s, eid = %u", rfc_time, eid);
                }
                else if (skip)
                {
                        /* skip old history entries which have already been processed */
                        continue;
                }
-               else if (match("Install", &cmd))
+               else if (match("Install", &command))
                {
                        DBG1(DBG_IMC, "  Install:");
                        if (!history->extract_packages(history, line, eid, SW_OP_INSTALL))
@@ -318,7 +352,7 @@ static int extract_history(sw_collector_db_t *db)
                                goto end;
                        }
                }
-               else if (match("Upgrade", &cmd))
+               else if (match("Upgrade", &command))
                {
                        DBG1(DBG_IMC, "  Upgrade:");
                        if (!history->extract_packages(history, line, eid, SW_OP_UPGRADE))
@@ -326,7 +360,7 @@ static int extract_history(sw_collector_db_t *db)
                                goto end;
                        }
                }
-               else if (match("Remove", &cmd))
+               else if (match("Remove", &command))
                {
                        DBG1(DBG_IMC, "  Remove:");
                        if (!history->extract_packages(history, line, eid, SW_OP_REMOVE))
@@ -334,7 +368,7 @@ static int extract_history(sw_collector_db_t *db)
                                goto end;
                        }
                }
-               else if (match("Purge", &cmd))
+               else if (match("Purge", &command))
                {
                        DBG1(DBG_IMC, "  Purge:");
                        if (!history->extract_packages(history, line, eid, SW_OP_REMOVE))
@@ -342,7 +376,7 @@ static int extract_history(sw_collector_db_t *db)
                                goto end;
                        }
                }
-               else if (match("End-Date", &cmd))
+               else if (match("End-Date", &command))
                {
                        /* Process 'max_count' events at a time */
                        if (max_count > 0 && eid - last_eid == max_count)
@@ -352,17 +386,62 @@ static int extract_history(sw_collector_db_t *db)
                        }
                }
        }
+       status = EXIT_SUCCESS;
 
-       if (history->merge_installed_packages(history))
+end:
+       chunk_unmap(h);
+
+       return status;
+}
+
+/**
+ * Extract software events from apt history log files
+ */
+static int extract_history(sw_collector_db_t *db)
+{
+       sw_collector_history_t *history = NULL;
+       uint32_t epoch, last_eid;
+       int status = EXIT_FAILURE;
+       char *path, *last_time = NULL;
+       int level;
+
+       /* open history file for reading */
+       path = lib->settings->get_str(lib->settings, "%s.history",
+                                                                 DEFAULT_HISTORY_LOG, lib->ns);
+
+       /* retrieve last event in database */
+       if (!db->get_last_event(db, &last_eid, &epoch, &last_time) || !last_eid)
        {
-               status = EXIT_SUCCESS;
+               goto end;
        }
+       DBG0(DBG_IMC, "Last-Event: %s, eid = %u, epoch = %u",
+                                  last_time, last_eid, epoch);
 
-end:
-       free(last_time);
+       /* iterate through history log files in the default path only */
+       level = streq(path, DEFAULT_HISTORY_LOG) ? 0 : NO_ITERATION;
+
+       history = sw_collector_history_create(db, 1);
+       if (!history)
+       {
+               goto end;
+       }
+
+       status = extract_history_file(db, history, last_time, last_eid, path, level);
+       if (status == EXIT_SUCCESS)
+       {
+               if (!history->merge_installed_packages(history))
+               {
+                       status = EXIT_FAILURE;
+               }
+       }
+       else if (status == EX_NOINPUT)
+       {
+               fprintf(stderr, "opening '%s' failed: %s\n", path, strerror(errno));
+       }
        history->destroy(history);
-       chunk_unmap(h);
 
+end:
+       free(last_time);
        return status;
 }
 

diff --git a/testing/scripts/build-baseimage b/testing/scripts/build-baseimage
index d3c7f82b3e3fdc6d0f34e8dcdd39b77ae5964881..26786a9166661693cbf2ac8e43bfdc1485ca8728 100755 (executable)
--- a/testing/scripts/build-baseimage
+++ b/testing/scripts/build-baseimage
@@ -21,7 +21,7 @@ INC=$INC,gnat,gprbuild,acpid,acpi-support-base,libldns-dev,libunbound-dev
 INC=$INC,dnsutils,libsoup2.4-dev,ca-certificates,unzip,libsystemd-dev
 INC=$INC,python3,python3-setuptools,python3-dev,python3-pip,apt-transport-https
 INC=$INC,libjson-c-dev,libxslt1-dev,libapache2-mod-wsgi-py3
-INC=$INC,libxerces-c-dev,libgcrypt20-dev,traceroute,iptables
+INC=$INC,libxerces-c-dev
 case "$BASEIMGSUITE" in
 bullseye)
        INC=$INC,libiptc-dev
@@ -53,6 +53,7 @@ esac
 SERVICES="apache2 dbus isc-dhcp-server slapd bind9 freeradius"
 INC=$INC,${SERVICES// /,}
 # packages to install via APT, for SWIMA tests
+APT1="libgcrypt20-dev traceroute iptables"
 APT="tmux"
 # additional services to disable
 SERVICES="$SERVICES systemd-timesyncd.service"
@@ -136,6 +137,12 @@ log_status $?
 log_action "Update package sources"
 execute_chroot "apt-get update"
 log_action "Install packages via APT"
+execute_chroot "apt-get -y install $APT1"
+log_action "Move history.log to history.log.1"
+execute_chroot "mv /var/log/apt/history.log /var/log/apt/history.log.1"
+log_action "Compress history.log.1 to history.log.1.gz"
+execute_chroot "gzip /var/log/apt/history.log.1"
+log_action "Install more packages via APT"
 execute_chroot "apt-get -y install $APT"
 log_action "Install packages from custom repo"
 execute_chroot "apt-get -y upgrade"

diff --git a/testing/tests/tnc/tnccs-20-ev-pt-tls/evaltest.dat b/testing/tests/tnc/tnccs-20-ev-pt-tls/evaltest.dat
index d5d6fa5831a7bd6091ec7a47dbb9db3472d740b0..44eab57fa2e682f81a056e4d50dabdf2e6ff7e5c 100644 (file)
--- a/testing/tests/tnc/tnccs-20-ev-pt-tls/evaltest.dat
+++ b/testing/tests/tnc/tnccs-20-ev-pt-tls/evaltest.dat
@@ -17,8 +17,8 @@ alice::cat /var/log/daemon.log::accepting PT-TLS stream from PH_IP_CAROL::YES
 alice::cat /var/log/daemon.log::SASL PLAIN authentication successful::YES
 alice::cat /var/log/daemon.log::SASL client identity is.*carol::YES
 alice::cat /var/log/daemon.log::user AR identity.*carol.*authenticated by password::YES
-alice::cat /var/log/daemon.log::received software ID events with ... items for request 9 at last eid 2 of epoch::YES
+alice::cat /var/log/daemon.log::received software ID events with ... items for request 9 at last eid 3 of epoch::YES
 alice::cat /var/log/daemon.log::3 SWID tag target::YES
-alice::cat /var/log/daemon.log::received software inventory with 3 items for request 9 at last eid 2 of epoch::YES
+alice::cat /var/log/daemon.log::received software inventory with 3 items for request 9 at last eid 3 of epoch::YES
 alice::cat /var/log/daemon.log::successful system command: ssh root@moon.*logger -t charon-systemd -p auth.alert.*host with IP address 192.168.0.100 is allowed::YES
 moon::cat /var/log/auth.log::host with IP address 192.168.0.100 is allowed::YES

diff --git a/testing/tests/tnc/tnccs-20-ev-pt-tls/hosts/carol/etc/pts/collector.sql b/testing/tests/tnc/tnccs-20-ev-pt-tls/hosts/carol/etc/pts/collector.sql
index 548c101e48a19e5f1f06caf75ee43f43ba8b7683..e3733a129abd27e768905bf19aa7e8792e20f062 100644 (file)
--- a/testing/tests/tnc/tnccs-20-ev-pt-tls/hosts/carol/etc/pts/collector.sql
+++ b/testing/tests/tnc/tnccs-20-ev-pt-tls/hosts/carol/etc/pts/collector.sql
@@ -23,17 +23,17 @@ INSERT INTO sw_identifiers (
 INSERT INTO sw_events (
   eid, sw_id, action
 ) VALUES (
-  2, 1, 2
+  3, 1, 2
 );
 
 INSERT INTO sw_events (
   eid, sw_id, action
 ) VALUES (
-  2, 2, 2
+  3, 2, 2
 );
 
 INSERT INTO sw_events (
   eid, sw_id, action
 ) VALUES (
-  2, 3, 2
+  3, 3, 2
 );