file-logger: Add option to log messages as JSON objects

Closes strongswan/strongswan#2222

diff --git a/conf/options/charon-logging.opt b/conf/options/charon-logging.opt
index 05f30553d5494f1e19b7ba171f07c8b5fb580c23..79958f3078b9c34ffd00e6eea25c91dedacf4bfd 100644 (file)
--- a/conf/options/charon-logging.opt
+++ b/conf/options/charon-logging.opt
@@ -26,8 +26,18 @@ charon.filelog.<name>.flush_line = no
        Enabling this option disables block buffering and enables line buffering.
 
 charon.filelog.<name>.ike_name = no
-       Prefix each log entry with the connection name and a unique numerical
-       identifier for each IKE_SA.
+       Add the connection name and a unique numerical identifier for the current
+       IKE_SA to each log entry if available.
+
+charon.filelog.<name>.json = no
+       If enabled, each log entry is written to the file as a JSON object.
+
+       Enables writing each log entry as a JSON object to the file. The properties
+       are "time" (if `time_format` is set), "thread", "group", "level" and "msg".
+       Newlines, double quotes and backslashes are escaped in the latter. If
+       `ike_name` is enabled, "ikesa-uniqueid" and "ikesa-name" are added to the
+       object if available. The `log_level` option does not apply if this is
+       enabled.
 
 charon.filelog.<name>.log_level = no
        Add the log level of each message after the subsystem (e.g. [IKE2]).

diff --git a/src/conftest/conftest.c b/src/conftest/conftest.c
index 7506df2ce46b03e25830e044df9ec44b2ff46629..7e46e61567085c562f4da8460a92dd4ea2b00af2 100644 (file)
--- a/src/conftest/conftest.c
+++ b/src/conftest/conftest.c
@@ -383,7 +383,7 @@ static void load_log_levels(file_logger_t *logger, char *section)
 static void load_logger_options(file_logger_t *logger, char *section)
 {
        char *time_format;
-       bool add_ms, ike_name, log_level;
+       bool add_ms, ike_name, log_level, json;
 
        time_format = conftest->test->get_str(conftest->test,
                                        "log.%s.time_format", NULL, section);
@@ -393,8 +393,10 @@ static void load_logger_options(file_logger_t *logger, char *section)
                                        "log.%s.ike_name", FALSE, section);
        log_level = conftest->test->get_bool(conftest->test,
                                        "log.%s.log_level", FALSE, section);
+       json = conftest->test->get_bool(conftest->test,
+                                       "log.%s.json", FALSE, section);
 
-       logger->set_options(logger, time_format, add_ms, ike_name, log_level);
+       logger->set_options(logger, time_format, add_ms, ike_name, log_level, json);
 }
 
 /**
@@ -460,7 +462,7 @@ int main(int argc, char *argv[])
        lib->credmgr->add_set(lib->credmgr, &conftest->creds->set);
 
        logger = file_logger_create("stdout");
-       logger->set_options(logger, NULL, FALSE, FALSE, FALSE);
+       logger->set_options(logger, NULL, FALSE, FALSE, FALSE, FALSE);
        logger->open(logger, FALSE, FALSE);
        logger->set_level(logger, DBG_ANY, LEVEL_CTRL);
        charon->bus->add_logger(charon->bus, &logger->logger);

diff --git a/src/libcharon/bus/listeners/file_logger.c b/src/libcharon/bus/listeners/file_logger.c
index 5fcdc95ef3684eedf5f9ede09188c7b7af03ceab..b2ac7b36ec65dfadc8248e53ae69e2ccb3ec3305 100644 (file)
--- a/src/libcharon/bus/listeners/file_logger.c
+++ b/src/libcharon/bus/listeners/file_logger.c
@@ -1,5 +1,5 @@
 /*
- * Copyright (C) 2012-2020 Tobias Brunner
+ * Copyright (C) 2012-2024 Tobias Brunner
  * Copyright (C) 2006 Martin Willi
  *
  * Copyright (C) secunet Security Networks AG
@@ -80,6 +80,11 @@ struct private_file_logger_t {
         */
        bool log_level;
 
+       /**
+        * Print log messages as JSON objects
+        */
+       bool json;
+
        /**
         * Mutex to ensure multi-line log messages are not torn apart
         */
@@ -95,11 +100,13 @@ METHOD(logger_t, log_, void,
        private_file_logger_t *this, debug_t group, level_t level, int thread,
        ike_sa_t* ike_sa, const char *message)
 {
-       char groupstr[5], timestr[128], namestr[128] = "";
-       const char *current = message, *next;
+       char groupstr[5], timestr[128];
+       char idstr[11] = "", namestr[128] = "", nameidstr[142];
+       const char *current = message, *next = NULL;
        struct tm tm;
        timeval_t tv;
        time_t s;
+       size_t time_len;
        u_int ms = 0;
 
        this->lock->read_lock(this->lock);
@@ -115,67 +122,101 @@ METHOD(logger_t, log_, void,
                s = tv.tv_sec;
                ms = tv.tv_usec / 1000;
                localtime_r(&s, &tm);
-               strftime(timestr, sizeof(timestr), this->time_format, &tm);
-       }
+               time_len = strftime(timestr, sizeof(timestr), this->time_format, &tm);
 
-       if (this->log_level)
-       {
-               snprintf(groupstr, sizeof(groupstr), "%N%d", debug_names, group,
-                                level);
-       }
-       else
-       {
-               snprintf(groupstr, sizeof(groupstr), "%N", debug_names, group);
+               if (this->add_ms && sizeof(timestr) - time_len > 4)
+               {
+                       snprintf(&timestr[time_len], sizeof(timestr)-time_len, ".%03u", ms);
+               }
        }
 
        if (this->ike_name && ike_sa)
        {
+               snprintf(idstr, sizeof(idstr), "%u", ike_sa->get_unique_id(ike_sa));
                if (ike_sa->get_peer_cfg(ike_sa))
                {
-                       snprintf(namestr, sizeof(namestr), " <%s|%d>",
-                               ike_sa->get_name(ike_sa), ike_sa->get_unique_id(ike_sa));
+                       snprintf(namestr, sizeof(namestr), "%s", ike_sa->get_name(ike_sa));
                }
-               else
-               {
-                       snprintf(namestr, sizeof(namestr), " <%d>",
-                               ike_sa->get_unique_id(ike_sa));
-               }
-       }
-       else
-       {
-               namestr[0] = '\0';
        }
 
-       /* prepend a prefix in front of every line */
        this->mutex->lock(this->mutex);
-       while (TRUE)
+       if (this->json)
        {
-               next = strchr(current, '\n');
+               fprintf(this->out, "{");
                if (this->time_format)
                {
-                       if (this->add_ms)
-                       {
-                               fprintf(this->out, "%s.%03u %.2d[%s]%s ",
-                                               timestr, ms, thread, groupstr, namestr);
-                       }
-                       else
+                       fprintf(this->out, "\"time\":\"%s\",", timestr);
+               }
+               fprintf(this->out, "\"thread\":%u,\"group\":\"%N\",\"level\":%u,",
+                               thread, debug_names, group, level);
+               if (idstr[0])
+               {
+                       fprintf(this->out, "\"ikesa-uniqueid\":\"%s\",", idstr);
+               }
+               if (namestr[0])
+               {
+                       fprintf(this->out, "\"ikesa-name\":\"%s\",", namestr);
+               }
+               fprintf(this->out, "\"msg\":\"");
+               /* replace some characters incompatible with JSON strings */
+               for (next = current; *next; next++)
+               {
+                       const char *esc;
+
+                       switch (*next)
                        {
-                               fprintf(this->out, "%s %.2d[%s]%s ",
-                                               timestr, thread, groupstr, namestr);
+                               case '\n':
+                                       esc = "\\n";
+                                       break;
+                               case '\\':
+                                       esc = "\\\\";
+                                       break;
+                               case '"':
+                                       esc = "\\\"";
+                                       break;
+                               default:
+                                       continue;
                        }
+                       fprintf(this->out, "%.*s%s", (int)(next - current), current, esc);
+                       current = next + 1;
+               }
+               fprintf(this->out, "%s\"}\n", current);
+       }
+       else
+       {
+               if (this->log_level)
+               {
+                       snprintf(groupstr, sizeof(groupstr), "%N%d", debug_names, group,
+                                        level);
                }
                else
                {
-                       fprintf(this->out, "%.2d[%s]%s ",
-                                       thread, groupstr, namestr);
+                       snprintf(groupstr, sizeof(groupstr), "%N", debug_names, group);
                }
-               if (next == NULL)
+               snprintf(nameidstr, sizeof(nameidstr), " <%s%s%s>", namestr,
+                                namestr[0] ? "|" : "", idstr);
+               /* prepend the prefix in front of every line */
+               while (TRUE)
                {
-                       fprintf(this->out, "%s\n", current);
-                       break;
+                       next = strchr(current, '\n');
+                       if (this->time_format)
+                       {
+                               fprintf(this->out, "%s %.2d[%s]%s ",
+                                               timestr, thread, groupstr, nameidstr);
+                       }
+                       else
+                       {
+                               fprintf(this->out, "%.2d[%s]%s ",
+                                               thread, groupstr, nameidstr);
+                       }
+                       if (!next)
+                       {
+                               fprintf(this->out, "%s\n", current);
+                               break;
+                       }
+                       fprintf(this->out, "%.*s\n", (int)(next - current), current);
+                       current = next + 1;
                }
-               fprintf(this->out, "%.*s\n", (int)(next - current), current);
-               current = next + 1;
        }
 #ifndef HAVE_SETLINEBUF
        if (this->flush_line)
@@ -218,7 +259,7 @@ METHOD(file_logger_t, set_level, void,
 
 METHOD(file_logger_t, set_options, void,
        private_file_logger_t *this, char *time_format, bool add_ms, bool ike_name,
-       bool log_level)
+       bool log_level, bool json)
 {
        this->lock->write_lock(this->lock);
        free(this->time_format);
@@ -226,6 +267,7 @@ METHOD(file_logger_t, set_options, void,
        this->add_ms = add_ms;
        this->ike_name = ike_name;
        this->log_level = log_level;
+       this->json = json;
        this->lock->unlock(this->lock);
 }
 

diff --git a/src/libcharon/bus/listeners/file_logger.h b/src/libcharon/bus/listeners/file_logger.h
index b466ea351256f9ab5866c982a141605284c37c5c..a26b6511072a28bc5b1ee626966cdcb1a5a36415 100644 (file)
--- a/src/libcharon/bus/listeners/file_logger.h
+++ b/src/libcharon/bus/listeners/file_logger.h
@@ -53,9 +53,10 @@ struct file_logger_t {
         *                                              current second after the timestamp
         * @param ike_name              TRUE to prefix the name of the IKE_SA
         * @param log_level             TRUE to include the log level in the message
+        * @param json                  TRUE to log as JSON objects
         */
        void (*set_options) (file_logger_t *this, char *time_format, bool add_ms,
-                                                bool ike_name, bool log_level);
+                                                bool ike_name, bool log_level, bool json);
 
        /**
         * Open (or reopen) the log file according to the given parameters

diff --git a/src/libcharon/daemon.c b/src/libcharon/daemon.c
index c48fa0a6f0aa5865a1183f52b2c3b5f90cec14b3..5722d16d8ffa60e12984b56cfc64b014e540286d 100644 (file)
--- a/src/libcharon/daemon.c
+++ b/src/libcharon/daemon.c
@@ -493,7 +493,7 @@ static void load_file_logger(private_daemon_t *this, char *section,
        file_logger_t *file_logger;
        debug_t group;
        level_t def;
-       bool add_ms, ike_name, log_level, flush_line, append;
+       bool add_ms, ike_name, log_level, json, flush_line, append;
        char *time_format, *filename;
 
        time_format = lib->settings->get_str(lib->settings,
@@ -504,6 +504,8 @@ static void load_file_logger(private_daemon_t *this, char *section,
                                                "%s.filelog.%s.ike_name", FALSE, lib->ns, section);
        log_level = lib->settings->get_bool(lib->settings,
                                                "%s.filelog.%s.log_level", FALSE, lib->ns, section);
+       json = lib->settings->get_bool(lib->settings,
+                                               "%s.filelog.%s.json", FALSE, lib->ns, section);
        flush_line = lib->settings->get_bool(lib->settings,
                                                "%s.filelog.%s.flush_line", FALSE, lib->ns, section);
        append = lib->settings->get_bool(lib->settings,
@@ -518,7 +520,7 @@ static void load_file_logger(private_daemon_t *this, char *section,
        }
 
        file_logger->set_options(file_logger, time_format, add_ms, ike_name,
-                                                        log_level);
+                                                        log_level, json);
        file_logger->open(file_logger, flush_line, append);
 
        def = lib->settings->get_int(lib->settings, "%s.filelog.%s.default", 1,