From: Vsevolod Stakhov Date: Wed, 14 Feb 2018 15:45:56 +0000 (+0000) Subject: [Feature] Rework logging configuration for rspamadm case X-Git-Tag: 1.7.0~184 X-Git-Url: https://source.dussan.org/?a=commitdiff_plain;h=577a34501b40fcc5982c5ddfc326ddf1c66b13de;p=rspamd.git [Feature] Rework logging configuration for rspamadm case --- diff --git a/src/libserver/cfg_file.h b/src/libserver/cfg_file.h index 2a6c29955..7e306fe5c 100644 --- a/src/libserver/cfg_file.h +++ b/src/libserver/cfg_file.h @@ -64,6 +64,15 @@ enum rspamd_log_type { RSPAMD_LOG_FILE }; +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), +}; + struct rspamd_worker_log_pipe { gint fd; gint type; @@ -228,12 +237,12 @@ enum rspamd_log_format_type { }; enum rspamd_log_format_flags { - RSPAMD_LOG_FLAG_DEFAULT = 0, - RSPAMD_LOG_FLAG_OPTIONAL = (1 << 0), - RSPAMD_LOG_FLAG_MIME_ALTERNATIVE = (1 << 1), - RSPAMD_LOG_FLAG_CONDITION = (1 << 2), - RSPAMD_LOG_FLAG_SYMBOLS_SCORES = (1 << 3), - RSPAMD_LOG_FLAG_SYMBOLS_PARAMS = (1 << 4) + RSPAMD_LOG_FMT_FLAG_DEFAULT = 0, + RSPAMD_LOG_FMT_FLAG_OPTIONAL = (1 << 0), + RSPAMD_LOG_FMT_FLAG_MIME_ALTERNATIVE = (1 << 1), + RSPAMD_LOG_FMT_FLAG_CONDITION = (1 << 2), + RSPAMD_LOG_FMT_FLAG_SYMBOLS_SCORES = (1 << 3), + RSPAMD_LOG_FMT_FLAG_SYMBOLS_PARAMS = (1 << 4) }; struct rspamd_log_format { @@ -324,11 +333,7 @@ struct rspamd_config { GList *debug_symbols; /**< symbols to debug */ GHashTable *debug_modules; /**< logging modules to debug */ struct rspamd_cryptobox_pubkey *log_encryption_key; /**< encryption key for logs */ - gboolean log_color; /**< output colors for console output */ - gboolean log_extended; /**< log extended information */ - gboolean log_systemd; /**< special case for systemd logger */ - gboolean log_re_cache; /**< show statistics about regexps */ - gboolean log_usec; /**< log microseconds if possible */ + guint log_flags; /**< logging flags */ guint log_error_elts; /**< number of elements in error logbuf */ guint log_error_elt_maxlen; /**< maximum size of error log element */ struct rspamd_worker_log_pipe *log_pipes; diff --git a/src/libserver/cfg_rcl.c b/src/libserver/cfg_rcl.c index 08896f484..889bc7072 100644 --- a/src/libserver/cfg_rcl.c +++ b/src/libserver/cfg_rcl.c @@ -228,6 +228,27 @@ rspamd_rcl_logging_handler (rspamd_mempool_t *pool, const ucl_object_t *obj, } } + /* Handle flags */ + val = ucl_object_lookup_any (obj, "color", "log_color", NULL); + if (val && ucl_object_toboolean (val)) { + cfg->log_flags |= RSPAMD_LOG_FLAG_COLOR; + } + + val = ucl_object_lookup_any (obj, "systemd", "log_systemd", NULL); + if (val && ucl_object_toboolean (val)) { + cfg->log_flags |= RSPAMD_LOG_FLAG_SYSTEMD; + } + + val = ucl_object_lookup (obj, "log_re_cache"); + if (val && ucl_object_toboolean (val)) { + cfg->log_flags |= RSPAMD_LOG_FLAG_RE_CACHE; + } + + val = ucl_object_lookup_any (obj, "usec", "log_usec", NULL); + if (val && ucl_object_toboolean (val)) { + cfg->log_flags |= RSPAMD_LOG_FLAG_USEC; + } + return rspamd_rcl_section_parse_defaults (cfg, section, cfg->cfg_pool, obj, cfg, err); } @@ -1728,12 +1749,6 @@ rspamd_rcl_config_init (struct rspamd_config *cfg) G_STRUCT_OFFSET (struct rspamd_config, log_urls), 0, "Write each URL found in a message to the log file"); - rspamd_rcl_add_default_handler (sub, - "log_re_cache", - rspamd_rcl_parse_struct_boolean, - G_STRUCT_OFFSET (struct rspamd_config, log_re_cache), - 0, - "Write statistics of regexp processing to log (useful for hyperscan)"); rspamd_rcl_add_default_handler (sub, "debug_ip", rspamd_rcl_parse_struct_ucl, @@ -1746,30 +1761,6 @@ rspamd_rcl_config_init (struct rspamd_config *cfg) G_STRUCT_OFFSET (struct rspamd_config, debug_symbols), 0, "Enable debug for the specified symbols"); - rspamd_rcl_add_default_handler (sub, - "log_color", - rspamd_rcl_parse_struct_boolean, - G_STRUCT_OFFSET (struct rspamd_config, log_color), - 0, - "Enable colored output (for console logging)"); - rspamd_rcl_add_default_handler (sub, - "color", - rspamd_rcl_parse_struct_boolean, - G_STRUCT_OFFSET (struct rspamd_config, log_color), - 0, - "Enable colored output (for console logging)"); - rspamd_rcl_add_default_handler (sub, - "log_systemd", - rspamd_rcl_parse_struct_boolean, - G_STRUCT_OFFSET (struct rspamd_config, log_systemd), - 0, - "Enable systemd compatible logging"); - rspamd_rcl_add_default_handler (sub, - "systemd", - rspamd_rcl_parse_struct_boolean, - G_STRUCT_OFFSET (struct rspamd_config, log_systemd), - 0, - "Enable systemd compatible logging"); rspamd_rcl_add_default_handler (sub, "debug_modules", rspamd_rcl_parse_struct_string_list, @@ -1802,12 +1793,44 @@ rspamd_rcl_config_init (struct rspamd_config *cfg) G_STRUCT_OFFSET (struct rspamd_config, log_error_elt_maxlen), RSPAMD_CL_FLAG_UINT, "Size of each element in error log buffer (1000 by default)"); - rspamd_rcl_add_default_handler (sub, + + /* Documentation only options, handled in log_handler to map flags */ + rspamd_rcl_add_doc_by_path (cfg, + "logging", + "Enable colored output (for console logging)", + "log_color", + UCL_BOOLEAN, + NULL, + 0, + NULL, + 0); + rspamd_rcl_add_doc_by_path (cfg, + "logging", + "Enable systemd compatible logging", + "systemd", + UCL_BOOLEAN, + NULL, + 0, + NULL, + 0); + rspamd_rcl_add_doc_by_path (cfg, + "logging", + "Write statistics of regexp processing to log (useful for hyperscan)", + "log_re_cache", + UCL_BOOLEAN, + NULL, + 0, + NULL, + 0); + rspamd_rcl_add_doc_by_path (cfg, + "logging", + "Use microseconds resolution for timestamps", "log_usec", - rspamd_rcl_parse_struct_boolean, - G_STRUCT_OFFSET (struct rspamd_config, log_usec), + UCL_BOOLEAN, + NULL, 0, - "Use microseconds resolution for timestamps"); + NULL, + 0); /** * Options section */ diff --git a/src/libserver/cfg_utils.c b/src/libserver/cfg_utils.c index 36af1926a..20f4dd163 100644 --- a/src/libserver/cfg_utils.c +++ b/src/libserver/cfg_utils.c @@ -147,7 +147,7 @@ rspamd_config_new (void) cfg->map_file_watch_multiplier = DEFAULT_MAP_FILE_WATCH_MULTIPLIER; cfg->log_level = G_LOG_LEVEL_WARNING; - cfg->log_extended = TRUE; + cfg->log_flags = RSPAMD_LOG_FLAG_DEFAULT; cfg->check_text_attachements = TRUE; @@ -342,7 +342,7 @@ rspamd_config_process_var (struct rspamd_config *cfg, const rspamd_ftok_t *var, g_assert (var != NULL); if (var->len > 3 && rspamd_lc_cmp (var->begin, "if_", 3) == 0) { - flags |= RSPAMD_LOG_FLAG_CONDITION; + flags |= RSPAMD_LOG_FMT_FLAG_CONDITION; tok.begin = var->begin + 3; tok.len = var->len - 3; } @@ -375,15 +375,15 @@ rspamd_config_process_var (struct rspamd_config *cfg, const rspamd_ftok_t *var, } else if (rspamd_ftok_cstr_equal (&tok, "symbols_scores", TRUE)) { type = RSPAMD_LOG_SYMBOLS; - flags |= RSPAMD_LOG_FLAG_SYMBOLS_SCORES; + flags |= RSPAMD_LOG_FMT_FLAG_SYMBOLS_SCORES; } else if (rspamd_ftok_cstr_equal (&tok, "symbols_params", TRUE)) { type = RSPAMD_LOG_SYMBOLS; - flags |= RSPAMD_LOG_FLAG_SYMBOLS_PARAMS; + flags |= RSPAMD_LOG_FMT_FLAG_SYMBOLS_PARAMS; } else if (rspamd_ftok_cstr_equal (&tok, "symbols_scores_params", TRUE)) { type = RSPAMD_LOG_SYMBOLS; - flags |= RSPAMD_LOG_FLAG_SYMBOLS_PARAMS|RSPAMD_LOG_FLAG_SYMBOLS_SCORES; + flags |= RSPAMD_LOG_FMT_FLAG_SYMBOLS_PARAMS|RSPAMD_LOG_FMT_FLAG_SYMBOLS_SCORES; } else if (rspamd_ftok_cstr_equal (&tok, "ip", TRUE)) { type = RSPAMD_LOG_IP; diff --git a/src/libserver/protocol.c b/src/libserver/protocol.c index 41d4111df..791938401 100644 --- a/src/libserver/protocol.c +++ b/src/libserver/protocol.c @@ -1276,7 +1276,7 @@ rspamd_protocol_http_reply (struct rspamd_http_message *msg, rspamd_task_write_log (task); - if (task->cfg->log_re_cache) { + if (task->cfg->log_flags & RSPAMD_LOG_FLAG_RE_CACHE) { restat = rspamd_re_cache_get_stat (task->re_rt); g_assert (restat != NULL); msg_info_task ( diff --git a/src/libserver/task.c b/src/libserver/task.c index 961af1c9f..257c3eed6 100644 --- a/src/libserver/task.c +++ b/src/libserver/task.c @@ -1066,11 +1066,11 @@ rspamd_task_log_metric_res (struct rspamd_task *task, rspamd_printf_fstring (&symbuf, ",%s", sym->name); } - if (lf->flags & RSPAMD_LOG_FLAG_SYMBOLS_SCORES) { + if (lf->flags & RSPAMD_LOG_FMT_FLAG_SYMBOLS_SCORES) { rspamd_printf_fstring (&symbuf, "(%.2f)", sym->score); } - if (lf->flags & RSPAMD_LOG_FLAG_SYMBOLS_PARAMS) { + if (lf->flags & RSPAMD_LOG_FMT_FLAG_SYMBOLS_PARAMS) { rspamd_printf_fstring (&symbuf, "{"); if (sym->options) { @@ -1425,7 +1425,7 @@ rspamd_task_write_log (struct rspamd_task *task) break; default: /* We have a variable in log format */ - if (lf->flags & RSPAMD_LOG_FLAG_CONDITION) { + if (lf->flags & RSPAMD_LOG_FMT_FLAG_CONDITION) { if (!rspamd_task_log_check_condition (task, lf)) { continue; } diff --git a/src/libutil/logger.c b/src/libutil/logger.c index 487ca2633..c775a0055 100644 --- a/src/libutil/logger.c +++ b/src/libutil/logger.c @@ -78,6 +78,7 @@ struct rspamd_logger_s { u_char *buf; } io_buf; gint fd; + guint flags; gboolean is_buffered; gboolean enabled; gboolean is_debug; @@ -433,6 +434,7 @@ rspamd_set_logger (struct rspamd_config *cfg, } logger->cfg = cfg; + logger->flags = cfg->log_flags; /* Set up buffer */ if (cfg->log_buffered) { @@ -849,7 +851,7 @@ file_log_function (const gchar *module, const gchar *id, const gchar *message, gpointer arg) { - gchar tmpbuf[256], timebuf[64], modulebuf[64]; + static gchar tmpbuf[256], timebuf[64], modulebuf[64]; gchar *m; gdouble now; struct tm *tms; @@ -877,130 +879,130 @@ file_log_function (const gchar *module, const gchar *id, return; } } - /* Check repeats */ - mlen = strlen (message); - cksum = rspamd_log_calculate_cksum (message, mlen); - - if (cksum == rspamd_log->last_line_cksum) { - rspamd_log->repeats++; - if (rspamd_log->repeats > REPEATS_MIN && rspamd_log->repeats < - REPEATS_MAX) { - /* Do not log anything */ - if (rspamd_log->saved_message == NULL) { - rspamd_log->saved_message = g_strdup (message); - rspamd_log->saved_function = g_strdup (function); - - if (module) { - rspamd_log->saved_module = g_strdup (module); - } - if (id) { - rspamd_log->saved_id = g_strdup (id); + if (!(rspamd_log->flags & RSPAMD_LOG_FLAG_RSPAMADM)) { + /* Check repeats */ + mlen = strlen (message); + cksum = rspamd_log_calculate_cksum (message, mlen); + + if (cksum == rspamd_log->last_line_cksum) { + rspamd_log->repeats++; + if (rspamd_log->repeats > REPEATS_MIN && rspamd_log->repeats < + REPEATS_MAX) { + /* Do not log anything */ + if (rspamd_log->saved_message == NULL) { + rspamd_log->saved_message = g_strdup (message); + rspamd_log->saved_function = g_strdup (function); + + if (module) { + rspamd_log->saved_module = g_strdup (module); + } + + if (id) { + rspamd_log->saved_id = g_strdup (id); + } + + rspamd_log->saved_loglevel = level_flags; } - rspamd_log->saved_loglevel = level_flags; + return; } + else if (rspamd_log->repeats > REPEATS_MAX) { + rspamd_snprintf (tmpbuf, + sizeof (tmpbuf), + "Last message repeated %ud times", + rspamd_log->repeats); + rspamd_log->repeats = 0; + /* It is safe to use temporary buffer here as it is not static */ + if (rspamd_log->saved_message) { + file_log_function (rspamd_log->saved_module, + rspamd_log->saved_id, + rspamd_log->saved_function, + rspamd_log->saved_loglevel, + rspamd_log->saved_message, + arg); - return; - } - else if (rspamd_log->repeats > REPEATS_MAX) { - rspamd_snprintf (tmpbuf, - sizeof (tmpbuf), - "Last message repeated %ud times", - rspamd_log->repeats); - rspamd_log->repeats = 0; - /* It is safe to use temporary buffer here as it is not static */ - if (rspamd_log->saved_message) { - file_log_function (rspamd_log->saved_module, - rspamd_log->saved_id, - rspamd_log->saved_function, - rspamd_log->saved_loglevel, - rspamd_log->saved_message, - arg); - - g_free (rspamd_log->saved_message); - g_free (rspamd_log->saved_function); - g_free (rspamd_log->saved_module); - g_free (rspamd_log->saved_id); - rspamd_log->saved_message = NULL; - rspamd_log->saved_function = NULL; - rspamd_log->saved_module = NULL; - rspamd_log->saved_id = NULL; - } + g_free (rspamd_log->saved_message); + g_free (rspamd_log->saved_function); + g_free (rspamd_log->saved_module); + g_free (rspamd_log->saved_id); + rspamd_log->saved_message = NULL; + rspamd_log->saved_function = NULL; + rspamd_log->saved_module = NULL; + rspamd_log->saved_id = NULL; + } - file_log_function ("logger", NULL, - G_STRFUNC, - rspamd_log->saved_loglevel, - tmpbuf, - arg); - file_log_function (module, id, - function, - level_flags, - message, - arg); - rspamd_log->repeats = REPEATS_MIN + 1; - return; - } - } - else { - /* Reset counter if new message differs from saved message */ - rspamd_log->last_line_cksum = cksum; - if (rspamd_log->repeats > REPEATS_MIN) { - rspamd_snprintf (tmpbuf, - sizeof (tmpbuf), - "Last message repeated %ud times", - rspamd_log->repeats); - rspamd_log->repeats = 0; - if (rspamd_log->saved_message) { - file_log_function (rspamd_log->saved_module, - rspamd_log->saved_id, - rspamd_log->saved_function, + file_log_function ("logger", NULL, + G_STRFUNC, rspamd_log->saved_loglevel, - rspamd_log->saved_message, + tmpbuf, arg); - - g_free (rspamd_log->saved_message); - g_free (rspamd_log->saved_function); - g_free (rspamd_log->saved_module); - g_free (rspamd_log->saved_id); - rspamd_log->saved_message = NULL; - rspamd_log->saved_function = NULL; - rspamd_log->saved_module = NULL; - rspamd_log->saved_id = NULL; + file_log_function (module, id, + function, + level_flags, + message, + arg); + rspamd_log->repeats = REPEATS_MIN + 1; + return; } - - file_log_function ("logger", NULL, - G_STRFUNC, - level_flags, - tmpbuf, - arg); - /* It is safe to use temporary buffer here as it is not static */ - file_log_function (module, id, - function, - level_flags, - message, - arg); - return; } else { - rspamd_log->repeats = 0; - } - } + /* Reset counter if new message differs from saved message */ + rspamd_log->last_line_cksum = cksum; + if (rspamd_log->repeats > REPEATS_MIN) { + rspamd_snprintf (tmpbuf, + sizeof (tmpbuf), + "Last message repeated %ud times", + rspamd_log->repeats); + rspamd_log->repeats = 0; + if (rspamd_log->saved_message) { + file_log_function (rspamd_log->saved_module, + rspamd_log->saved_id, + rspamd_log->saved_function, + rspamd_log->saved_loglevel, + rspamd_log->saved_message, + arg); - if (rspamd_log->cfg->log_extended) { + g_free (rspamd_log->saved_message); + g_free (rspamd_log->saved_function); + g_free (rspamd_log->saved_module); + g_free (rspamd_log->saved_id); + rspamd_log->saved_message = NULL; + rspamd_log->saved_function = NULL; + rspamd_log->saved_module = NULL; + rspamd_log->saved_id = NULL; + } + + file_log_function ("logger", NULL, + G_STRFUNC, + level_flags, + tmpbuf, + arg); + /* It is safe to use temporary buffer here as it is not static */ + file_log_function (module, id, + function, + level_flags, + message, + arg); + return; + } + else { + rspamd_log->repeats = 0; + } + } if (!got_time) { now = rspamd_get_calendar_ticks (); } /* Format time */ - if (!rspamd_log->cfg->log_systemd) { + if (!(rspamd_log->flags & RSPAMD_LOG_FLAG_SYSTEMD)) { time_t sec = now; gsize r; tms = localtime (&sec); r = strftime (timebuf, sizeof (timebuf), "%F %H:%M:%S", tms); - if (rspamd_log->cfg->log_usec) { + if (rspamd_log->flags & RSPAMD_LOG_FLAG_USEC) { gchar usec_buf[16]; rspamd_snprintf (usec_buf, sizeof (usec_buf), "%.5f", @@ -1012,7 +1014,7 @@ file_log_function (const gchar *module, const gchar *id, cptype = g_quark_to_string (rspamd_log->process_type); - if (rspamd_log->cfg->log_color) { + if (rspamd_log->flags & RSPAMD_LOG_FLAG_COLOR) { if (level_flags & G_LOG_LEVEL_INFO) { /* White */ r = rspamd_snprintf (tmpbuf, sizeof (tmpbuf), "\033[0;37m"); @@ -1030,7 +1032,7 @@ file_log_function (const gchar *module, const gchar *id, r = 0; } - if (!rspamd_log->cfg->log_systemd) { + if (!(rspamd_log->flags & RSPAMD_LOG_FLAG_SYSTEMD)) { r += rspamd_snprintf (tmpbuf + r, sizeof (tmpbuf) - r, "%s #%P(%s) ", @@ -1083,7 +1085,7 @@ file_log_function (const gchar *module, const gchar *id, iov[3].iov_base = (void *) &lf_chr; iov[3].iov_len = 1; - if (rspamd_log->cfg->log_color) { + if (rspamd_log->flags & RSPAMD_LOG_FLAG_COLOR) { iov[4].iov_base = "\033[0m"; iov[4].iov_len = sizeof ("\033[0m") - 1; /* Call helper (for buffering) */ @@ -1095,19 +1097,48 @@ file_log_function (const gchar *module, const gchar *id, } } else { - iov[0].iov_base = (void *) message; - iov[0].iov_len = mlen; - iov[1].iov_base = (void *) &lf_chr; - iov[1].iov_len = 1; - if (rspamd_log->cfg->log_color) { - iov[2].iov_base = "\033[0m"; - iov[2].iov_len = sizeof ("\033[0m") - 1; + /* Rspamadm logging version */ + mlen = strlen (message); + + if (rspamd_log->flags & RSPAMD_LOG_FLAG_COLOR) { + if (level_flags & G_LOG_LEVEL_INFO) { + /* White */ + r = rspamd_snprintf (tmpbuf, sizeof (tmpbuf), "\033[0;37m"); + } + else if (level_flags & G_LOG_LEVEL_WARNING) { + /* Magenta */ + r = rspamd_snprintf (tmpbuf, sizeof (tmpbuf), "\033[0;32m"); + } + else if (level_flags & G_LOG_LEVEL_CRITICAL) { + /* Red */ + r = rspamd_snprintf (tmpbuf, sizeof (tmpbuf), "\033[1;31m"); + } + + iov[0].iov_base = (void *) tmpbuf; + iov[0].iov_len = r; + iov[1].iov_base = (void *) message; + iov[1].iov_len = mlen; + r = 2; + } + else { + iov[0].iov_base = (void *) message; + iov[0].iov_len = mlen; + r = 1; + } + + + iov[r++].iov_base = (void *) &lf_chr; + iov[r++].iov_len = 1; + + if (rspamd_log->flags & RSPAMD_LOG_FLAG_COLOR) { + iov[r++].iov_base = "\033[0m"; + iov[r++].iov_len = sizeof ("\033[0m") - 1; /* Call helper (for buffering) */ - file_log_helper (rspamd_log, iov, 3); + file_log_helper (rspamd_log, iov, r); } else { /* Call helper (for buffering) */ - file_log_helper (rspamd_log, iov, 2); + file_log_helper (rspamd_log, iov, r); } } } diff --git a/src/rspamadm/rspamadm.c b/src/rspamadm/rspamadm.c index 67b93149a..73988f848 100644 --- a/src/rspamadm/rspamadm.c +++ b/src/rspamadm/rspamadm.c @@ -295,6 +295,8 @@ main (gint argc, gchar **argv, gchar **env) cfg->log_level = G_LOG_LEVEL_WARNING; cfg->log_type = RSPAMD_LOG_CONSOLE; + /* Avoid timestamps printing */ + cfg->log_flags = RSPAMD_LOG_FLAG_RSPAMADM; rspamd_set_logger (cfg, process_quark, &rspamd_main->logger, rspamd_main->server_pool); (void) rspamd_log_open (rspamd_main->logger);