Merge pull request #1230 from ejoerns/configurable-event-logging

Configurable Event Logging

Makefile.am

@@ -44,6 +44,7 @@ librauc_la_SOURCES = \
 	src/context.c \
 	src/crypt.c \
 	src/dm.c \
+	src/event_log.c \
 	src/hash_index.c \
 	src/install.c \
 	src/manifest.c \
@@ -66,6 +67,7 @@ librauc_la_SOURCES = \
 	include/context.h \
 	include/crypt.h \
 	include/dm.h \
+	include/event_log.h \
 	include/hash_index.h \
 	include/emmc.h \
 	include/gpt.h \
@@ -102,9 +104,9 @@ endif
 
 nodist_librauc_la_SOURCES = \
 	$(gdbus_installer_generated)
-librauc_la_CFLAGS = $(AM_CFLAGS) $(CODE_COVERAGE_CFLAGS)
-librauc_la_LDFLAGS = $(AM_LDFLAGS) $(CODE_COVERAGE_LDFLAGS)
-librauc_la_LIBADD = $(GLIB_LIBS) $(CURL_LIBS) $(OPENSSL_LIBS) $(FDISK_LIBS) $(NL3_LIBS)
+librauc_la_CFLAGS = $(AM_CFLAGS) $(JSON_GLIB_CFLAGS) $(CODE_COVERAGE_CFLAGS)
+librauc_la_LDFLAGS = $(AM_LDFLAGS) $(JSON_GLIB_LDFLAGS) $(CODE_COVERAGE_LDFLAGS)
+librauc_la_LIBADD = $(GLIB_LIBS) $(CURL_LIBS) $(OPENSSL_LIBS) $(FDISK_LIBS) $(NL3_LIBS) $(JSON_GLIB_LIBS)
 
 bin_PROGRAMS = rauc
 

docs/advanced.rst

@@ -1594,3 +1594,62 @@ https://github.com/caruhome/upparat
 It is also available via PyPI:
 
 https://pypi.org/project/upparat/
+
+.. _sec-advanced-event-log:
+
+RAUC Installation History and Event logging
+-------------------------------------------
+
+Even if RAUC mainly focuses on logging information to stdout or into the
+journal (when using systemd), this might be insufficient for some purposes and
+especially for keeping long-term history of what RAUC changed on the system.
+
+A common problem for example can be journal rotation. Since storage is limited
+and the journal contains a lot of other information, it needs to be rotated at
+some point.
+However, one might want to preserve the history of what RAUC installed on the
+system or when the system rebooted, went into fallback, etc. for very long or
+even the full life time of the device.
+
+Another motivation can be to have a clearly separated distinct log location
+where other system components or a service technician (that should not have
+access to the whole system) should have a look into.
+
+The RAUC 'event logging' handling targets these and other cases.
+It defines a distinct set of events that might be of interest for later
+introspection, debugging or informative output.
+
+Via RAUC's ``system.conf`` one or several loggers can be configured with
+selectable output format, event filters, and also basic log rotation is
+supported.
+
+A new logger can be registered with adding a ``log.<loggername>`` section to
+the ``system.conf``.
+
+To have e.g. an unlimited human-readable short log of the installations
+happened on the system, use::
+
+  [log.install-log]
+  filename=install.log
+  events=install
+  output-format=short
+
+Or, if you want a json-based log of all events, limited to 1M per log file and
+5 rotation files to keep, use::
+
+  [log.all-json-log]
+  filename=all-json.log
+  output-format=json
+  max-size=1M
+  max-files=5
+
+If an error occurs during logging (such as disk full or write errors), that
+logger is marked as broken and no longer used.
+An ongoing installation is **not** aborted.
+
+For a full reference of supported configuration options, see
+:ref:`logger sections reference <ref-logger-sections>`.
+
+.. note:: All events logged using the internal event logging framework will
+   also be forwarded to the default logger and thus be visible e.g. in the
+   journal (when using systemd).

docs/reference.rst

@@ -697,6 +697,55 @@ No built-in slot update will run and no hook will be executed.
   ``<key>``.
   ``-`` is converted to ``_`` for use as an environment variable name.
 
+.. _ref-logger-sections:
+
+**[log.<logger>] sections**
+
+With a logger section, a *RAUC event logger* can be configured.
+The ``<logger>`` suffix determines the internal name of the logger and must be
+unique per ``system.conf``.
+
+For an overview over the event logging framework in RAUC and its purpose, have
+a look at :ref:`sec-advanced-event-log`.
+
+``filename``
+  The log file name used for logging.
+  If no absolute path is given, the location is assumed to be relative to the
+  ``data-directory``.
+  Using a relative file name without ``data-directory`` set will cause a
+  configuration error.
+
+``events``
+  Semicolon-separated list of events to log. Currently supported event types are:
+
+  * ``install`` - Logs start and end of installation
+  * ``boot`` - Logs boot information
+  * ``mark`` - Logs slot marking information
+  * ``all`` - Log all events (cannot be combined with other events)
+
+``format``
+  The output format used for the logger. Supported values are
+
+  * ``readable``: readable mutli-line output
+  * ``short``: Single-line readable output
+  * ``json``: single-line JSON output
+  * ``json-pretty``: formatted JSON output
+
+``max-size``
+  Allows to configure a basic log rotation.
+  When given, the logger's log file will be rotated before reaching
+  the size configured with ``max-size`` and renamed to ``<filename>.1``.
+  Existing rotation file names will be incremented by one.
+  The oldest file is removed.
+  To configure a maximum number of files to keep, see ``max-files``.
+  Values support common suffixes like ``K``, ``M``, ``G``, to ``T``.
+
+``max-files``
+  Configures the maximum number of files to keep per logger.
+  E.g. if set to ``3``, only ``<filename>``, ``<filename>.1`` and
+  ``<filename>.2`` will be kept during rotation.
+  Defaults to 10 if unset.
+
 .. _sec_ref_formats:
 
 Bundle Formats

include/config_file.h

@@ -85,6 +85,9 @@ typedef struct {
 	gchar *encryption_key;
 	gchar *encryption_cert;
 
+	/* logging */
+	GList *loggers;
+
 	GHashTable *slots;
 	/* flag to ensure slot states were determined */
 	gboolean slot_states_determined;

include/event_log.h

@@ -0,0 +1,132 @@
+#pragma once
+
+#include <glib.h>
+#include <gio/gio.h>
+
+/**
+ * @file event_log.h
+ * @brief Implementation of structured event log handling for RAUC
+ *
+ * Structured glib log message with the special domain (GLIB_DOMAIN)
+ * 'rauc-event' will be written to files by registered loggers.
+ *
+ * Required fields are:
+ *
+ * * "GLIB_DOMAIN": Must be "rauc-event"
+ * * "RAUC_EVENT_TYPE": The type of event. Will be used for filtering by loggers
+ * * "MESSAGE" : The log message
+ * * "MESSAGE_ID" : The ID of the message. Must be unique per message type.
+ *
+ * Optional fields for providing context information are:
+ *
+ * * "BOOT_ID" : The boot ID associated with the log message
+ * * "BUNDLE_HASH" : The bundle hash associated with the log message
+ * * "BUNDLE_VERSION" : The bundle version associated with the log message
+ * * "TRANSACTION_ID" : The transaction ID associated with the log message
+ * * "SLOT_NAME" : The slot name associated with the log message
+ * * "SLOT_BOOTNAME" : The bootname associated with the log message
+ *
+ * To log events, modules should define their own logging method that creates
+ * a log structure array and calls g_log_structured_array().
+ */
+
+#define R_EVENT_LOG_DOMAIN "rauc-event"
+
+/* Event log type for system boot detection */
+#define R_EVENT_LOG_TYPE_BOOT "boot"
+/* Event log type for slot marking (good,bad,active) */
+#define R_EVENT_LOG_TYPE_MARK "mark"
+/* Event log type for installation start or termination */
+#define R_EVENT_LOG_TYPE_INSTALL "install"
+/* Event log type for background service start or stop */
+#define R_EVENT_LOG_TYPE_SERVICE "service"
+/* Event log type for slot updates */
+#define R_EVENT_LOG_TYPE_WRITE_SLOT "writeslot"
+
+typedef struct _REventLogger REventLogger;
+
+typedef enum {
+	/* Readable, timestamped output, including "MESSAGE" and all known log fields */
+	R_EVENT_LOGFMT_READABLE,
+	/* Readable, timestamped output, containing only "MESSAGE" field */
+	R_EVENT_LOGFMT_READABLE_SHORT,
+	/* JSON-formatted output */
+	R_EVENT_LOGFMT_JSON,
+	/* Same as R_EVENT_LOGFMT_JSON but with newlines for readability */
+	R_EVENT_LOGFMT_JSON_PRETTY,
+} REventLogFormat;
+
+typedef struct _REventLogger {
+	/* configured information */
+	gchar *name;
+	gchar *filename;
+	gchar **events;
+	REventLogFormat format;
+	goffset maxsize;
+	guint maxfiles;
+	/* runtime information */
+	gboolean configured;
+	gboolean broken;
+	goffset filesize;
+	GFileOutputStream *logstream;
+	void (*writer)(REventLogger* logger, const GLogField *fields, gsize n_fields);
+} REventLogger;
+
+/**
+ * Tests type string for being a supported event log type.
+ *
+ * @param type Type string to test
+ *
+ * @return TRUE if supported, FALSE otherwise
+ */
+gboolean r_event_log_is_supported_type(const gchar *type);
+
+/**
+ * Custom structured logging function.
+ *
+ * To be used for g_log_set_writer_func() to set globally as the glib logger.
+ *
+ * All log messages will be forwarded to g_log_writer_default() first.
+ *
+ * Log messages of GLIB_DOMAIN 'rauc-event' will then be passed to event
+ * logging where they are filtered by RAUC_EVENT_TYPE and forwarded to the
+ * respective handlers registered for this event type.
+ *
+ * @param log_level log level, either from GLogLevelFlags, or a user-defined level
+ * @param fields key–value pairs of structured data forming the log message.
+ * @param n_fields number of elements in the fields array
+ * @param user_data user data passed to g_log_set_writer_func()
+ *
+ * @return G_LOG_WRITER_HANDLED on success, G_LOG_WRITER_UNHANDLED otherwise
+ */
+GLogWriterOutput r_event_log_writer(GLogLevelFlags log_level, const GLogField *fields, gsize n_fields, gpointer user_data);
+
+/**
+ * Sets up a logger.
+ *
+ * Attempts to open the log file under the given filename and to query the
+ * size.
+ *
+ * If setting up the logger fails, it will be marked as 'broken'.
+ *
+ * @param logger Logger to set up
+ */
+void r_event_log_setup_logger(REventLogger *logger);
+
+/**
+ * Frees event logging structure.
+ *
+ * @param config Logger to free
+ */
+void r_event_log_free_logger(REventLogger *logger);
+
+G_DEFINE_AUTOPTR_CLEANUP_FUNC(REventLogger, r_event_log_free_logger);
+
+/**
+ * Simple Logging convenience method.
+ *
+ * @param type Event type string
+ * @param message Message to log
+ */
+void r_event_log_message(const gchar *type, const gchar *message, ...)
+__attribute__((__format__(__printf__, 2, 3)));

meson.build

@@ -109,6 +109,7 @@ sources_rauc = files([
   'src/crypt.c',
   'src/dm.c',
   'src/emmc.c',
+  'src/event_log.c',
   'src/hash_index.c',
   'src/install.c',
   'src/manifest.c',

qemu-test-rauc-config

@@ -5,6 +5,11 @@ grubenv=/tmp/boot/grub/grubenv
 # HACK: must be on a separate partition for real systems
 data-directory=/tmp/rauc
 
+[log.testlogger]
+# create an event log file under /tmp/rauc/event.log
+filename=event.log
+events=all
+
 [keyring]
 path=ca.cert.pem