mirrors
/
rspamd
mirror of https://github.com/vstakhov/rspamd.git
Watch 1
Star 0
Fork 0
Code Issues 0 Releases 159 Wiki Activity
Browse Source

[Feature] Rework logging configuration for rspamadm case

tags/1.7.0
Vsevolod Stakhov 6 years ago
parent
c11f4f3b96
commit
577a34501b
7 changed files with 229 additions and 168 deletions
Split View Show Diff Stats
  1. 16
    11
      src/libserver/cfg_file.h
  2. 57
    34
      src/libserver/cfg_rcl.c
  3. 5
    5
      src/libserver/cfg_utils.c
  4. 1
    1
      src/libserver/protocol.c
  5. 3
    3
      src/libserver/task.c
  6. 145
    114
      src/libutil/logger.c
  7. 2
    0
      src/rspamadm/rspamadm.c

+ 16
- 11
src/libserver/cfg_file.h View File

@@ -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;

+ 57
- 34
src/libserver/cfg_rcl.c View File

@@ -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
*/

+ 5
- 5
src/libserver/cfg_utils.c View File

@@ -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;

+ 1
- 1
src/libserver/protocol.c View File

@@ -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 (

+ 3
- 3
src/libserver/task.c View File

@@ -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;
}

+ 145
- 114
src/libutil/logger.c View File

@@ -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);
}
}
}

+ 2
- 0
src/rspamadm/rspamadm.c View File

@@ -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);

Write Preview
Loading…
Cancel
Save