From bae5cd020f84fbf84cbbe446f0726287604f150a Mon Sep 17 00:00:00 2001 From: Vsevolod Stakhov Date: Mon, 30 Oct 2023 15:32:35 +0000 Subject: [PATCH] [Project] Preliminary support of JSON logging --- src/libserver/cfg_file.h | 17 +++---- src/libserver/cfg_rcl.cxx | 5 ++ src/libserver/logger/logger.c | 68 +++++++++++++++++++++------ src/libserver/logger/logger_console.c | 23 ++++----- 4 files changed, 75 insertions(+), 38 deletions(-) diff --git a/src/libserver/cfg_file.h b/src/libserver/cfg_file.h index 4e432af60..22f754938 100644 --- a/src/libserver/cfg_file.h +++ b/src/libserver/cfg_file.h @@ -59,14 +59,15 @@ enum rspamd_log_type { }; enum rspamd_log_cfg_flags { - RSPAMD_LOG_FLAG_DEFAULT = 0, - RSPAMD_LOG_FLAG_SYSTEMD = (1 << 0), - RSPAMD_LOG_FLAG_COLOR = (1 << 1), - RSPAMD_LOG_FLAG_RE_CACHE = (1 << 2), - RSPAMD_LOG_FLAG_USEC = (1 << 3), - RSPAMD_LOG_FLAG_RSPAMADM = (1 << 4), - RSPAMD_LOG_FLAG_ENFORCED = (1 << 5), - RSPAMD_LOG_FLAG_SEVERITY = (1 << 6), + RSPAMD_LOG_FLAG_DEFAULT = 0u, + RSPAMD_LOG_FLAG_SYSTEMD = (1u << 0u), + RSPAMD_LOG_FLAG_COLOR = (1u << 1u), + RSPAMD_LOG_FLAG_RE_CACHE = (1u << 2u), + RSPAMD_LOG_FLAG_USEC = (1u << 3u), + RSPAMD_LOG_FLAG_RSPAMADM = (1u << 4u), + RSPAMD_LOG_FLAG_ENFORCED = (1u << 5u), + RSPAMD_LOG_FLAG_SEVERITY = (1u << 6u), + RSPAMD_LOG_FLAG_JSON = (1u << 7u), }; struct rspamd_worker_log_pipe { diff --git a/src/libserver/cfg_rcl.cxx b/src/libserver/cfg_rcl.cxx index e7828ff90..3f6ca2c56 100644 --- a/src/libserver/cfg_rcl.cxx +++ b/src/libserver/cfg_rcl.cxx @@ -283,6 +283,11 @@ rspamd_rcl_logging_handler(rspamd_mempool_t *pool, const ucl_object_t *obj, cfg->log_flags |= RSPAMD_LOG_FLAG_SYSTEMD; } + val = ucl_object_lookup_any(obj, "json", "log_json", nullptr); + if (val && ucl_object_toboolean(val)) { + cfg->log_flags |= RSPAMD_LOG_FLAG_JSON; + } + val = ucl_object_lookup(obj, "log_re_cache"); if (val && ucl_object_toboolean(val)) { cfg->log_flags |= RSPAMD_LOG_FLAG_RE_CACHE; diff --git a/src/libserver/logger/logger.c b/src/libserver/logger/logger.c index 9b9d302f2..58cb31969 100644 --- a/src/libserver/logger/logger.c +++ b/src/libserver/logger/logger.c @@ -1042,27 +1042,41 @@ gsize rspamd_log_fill_iov(struct iovec *iov, bool log_severity = (logger->flags & RSPAMD_LOG_FLAG_SEVERITY); bool log_rspamadm = (logger->flags & RSPAMD_LOG_FLAG_RSPAMADM); bool log_systemd = (logger->flags & RSPAMD_LOG_FLAG_SYSTEMD); + bool log_json = (logger->flags & RSPAMD_LOG_FLAG_JSON); + + if (log_json) { + /* Some sanity to avoid too many branches */ + log_color = false; + log_severity = true; + log_systemd = false; + } gint r; if (iov == NULL) { - if (log_rspamadm) { - if (logger->log_level == G_LOG_LEVEL_DEBUG) { - return 4; - } - else { - return 3; /* No time component */ - } - } - else if (log_systemd) { - return 3; + /* This is the case when we just return a number of IOV required for the logging */ + if (log_json) { + return 3; /* Preamble, message, "}\n" */ } else { - if (log_color) { - return 5; + if (log_rspamadm) { + if (logger->log_level == G_LOG_LEVEL_DEBUG) { + return 4; + } + else { + return 3; /* No time component */ + } + } + else if (log_systemd) { + return 3; } else { - return 4; + if (log_color) { + return 5; + } + else { + return 4; + } } } } @@ -1070,11 +1084,35 @@ gsize rspamd_log_fill_iov(struct iovec *iov, static gchar timebuf[64], modulebuf[64]; static gchar tmpbuf[256]; - if (!log_systemd) { + if (!log_json && !log_systemd) { log_time(ts, logger, timebuf, sizeof(timebuf)); } - if (!log_rspamadm) { + if (G_UNLIKELY(log_json)) { + /* Perform JSON logging */ + r = rspamd_snprintf(tmpbuf, sizeof(tmpbuf), "{\"ts\": %L, " + "\"pid\": %P, " + "\"severity\": \"%s\", " + "\"worker_type\": \"%s\", " + "\"id\": \"%s\", " + "\"module\": \"%s\", " + "\"function\": \"%s\", " + "\"message\": \"", + (gint64) (ts * 1e6), + logger->pid, + rspamd_get_log_severity_string(level_flags), + logger->process_type, + id, + module, + function); + iov[0].iov_base = tmpbuf; + iov[0].iov_len = r; + iov[1].iov_base = (void *) message; + iov[1].iov_len = mlen; + iov[2].iov_base = (void *) "\"}\n"; + iov[2].iov_len = sizeof("\"}\n") - 1; + } + else if (G_LIKELY(!log_rspamadm)) { if (!log_systemd) { if (log_color) { if (level_flags & (G_LOG_LEVEL_INFO | G_LOG_LEVEL_MESSAGE)) { diff --git a/src/libserver/logger/logger_console.c b/src/libserver/logger/logger_console.c index 691566ab9..9af931faf 100644 --- a/src/libserver/logger/logger_console.c +++ b/src/libserver/logger/logger_console.c @@ -28,10 +28,6 @@ static const gchar lf_chr = '\n'; struct rspamd_console_logger_priv { gint fd; gint crit_fd; - gboolean log_severity; - gboolean log_color; - gboolean log_rspamadm; - gboolean log_tty; }; /* Copy & paste :( */ @@ -63,11 +59,8 @@ rspamd_log_console_init(rspamd_logger_t *logger, struct rspamd_config *cfg, struct rspamd_console_logger_priv *priv; priv = g_malloc0(sizeof(*priv)); - priv->log_color = (logger->flags & RSPAMD_LOG_FLAG_COLOR); - priv->log_severity = (logger->flags & RSPAMD_LOG_FLAG_SEVERITY); - priv->log_rspamadm = (logger->flags & RSPAMD_LOG_FLAG_RSPAMADM); - if (priv->log_rspamadm) { + if (logger->flags & RSPAMD_LOG_FLAG_RSPAMADM) { priv->fd = dup(STDOUT_FILENO); priv->crit_fd = dup(STDERR_FILENO); } @@ -85,12 +78,11 @@ rspamd_log_console_init(rspamd_logger_t *logger, struct rspamd_config *cfg, return NULL; } - if (isatty(priv->fd)) { - priv->log_tty = true; - } - else if (priv->log_color) { - /* Disable colors for not a tty */ - priv->log_color = false; + if (!isatty(priv->fd)) { + if (logger->flags & RSPAMD_LOG_FLAG_COLOR) { + /* Disable colors for not a tty */ + logger->flags &= ~RSPAMD_LOG_FLAG_COLOR; + } } return priv; @@ -160,7 +152,8 @@ bool rspamd_log_console_log(const gchar *module, const gchar *id, fd = priv->crit_fd; } else { - if (priv->log_rspamadm && (level_flags & G_LOG_LEVEL_WARNING)) { + /* Use stderr if we are in rspamadm mode and severity is more than WARNING */ + if ((rspamd_log->flags & RSPAMD_LOG_FLAG_RSPAMADM) && (level_flags & G_LOG_LEVEL_WARNING)) { fd = priv->crit_fd; } else { -- 2.39.5