]> git.ipfire.org Git - thirdparty/rspamd.git/commitdiff
Start implementation of flexible task logging
authorVsevolod Stakhov <vsevolod@highsecure.ru>
Fri, 6 Nov 2015 13:26:28 +0000 (13:26 +0000)
committerVsevolod Stakhov <vsevolod@highsecure.ru>
Fri, 6 Nov 2015 13:26:28 +0000 (13:26 +0000)
src/libserver/cfg_file.h
src/libserver/cfg_utils.c
src/libserver/protocol.c
src/libserver/protocol.h
src/libserver/task.c
src/libserver/task.h
src/lua/lua_util.c

index fba90dbeec6891dd55e4f2d85d270f8380e1a523..9e1164175236db69164a8e89b9221fce2d09c6c5 100644 (file)
@@ -194,6 +194,7 @@ enum rspamd_log_format_flags {
 struct rspamd_log_format {
        enum rspamd_log_format_type type;
        guint flags;
+       gsize len;
        gpointer data;
        struct rspamd_log_format *prev, *next;
 };
index 161482ee2bc847516d4d731c32519a0b40a8f394..084efffad053201fd5c2c166bae7744fc1017185 100644 (file)
@@ -362,6 +362,7 @@ rspamd_config_process_var (struct rspamd_config *cfg, const rspamd_ftok_t *var,
                        lf->data = rspamd_mempool_alloc0 (cfg->cfg_pool,
                                        sizeof (rspamd_ftok_t));
                        memcpy (lf->data, &tok, sizeof (tok));
+                       lf->len = sizeof (tok);
                }
        }
        else {
@@ -391,6 +392,7 @@ rspamd_config_process_var (struct rspamd_config *cfg, const rspamd_ftok_t *var,
 
                id = luaL_ref (cfg->lua_state, LUA_REGISTRYINDEX);
                lf->data = GINT_TO_POINTER (id);
+               lf->len = 0;
        }
 
        DL_APPEND (cfg->log_format, lf);
@@ -437,6 +439,7 @@ rspamd_config_parse_log_format (struct rspamd_config *cfg)
                                lf = rspamd_mempool_alloc0 (cfg->cfg_pool, sizeof (*lf));
                                lf->type = RSPAMD_LOG_STRING;
                                lf->data = rspamd_mempool_alloc (cfg->cfg_pool, p - c + 1);
+                               lf->len = p - c;
                                rspamd_strlcpy (lf->data, c, p - c + 1);
                                DL_APPEND (cfg->log_format, lf);
                                lf = NULL;
@@ -498,6 +501,7 @@ rspamd_config_parse_log_format (struct rspamd_config *cfg)
                        lf = rspamd_mempool_alloc0 (cfg->cfg_pool, sizeof (*lf));
                        lf->type = RSPAMD_LOG_STRING;
                        lf->data = rspamd_mempool_alloc (cfg->cfg_pool, p - c + 1);
+                       lf->len = p - c;
                        rspamd_strlcpy (lf->data, c, p - c + 1);
                        DL_APPEND (cfg->log_format, lf);
                        lf = NULL;
index 992d87186ec2ba7aa8824aee4c6af98a5638801b..35697427fcc93d558445586a140198a966295040 100644 (file)
@@ -607,19 +607,6 @@ rspamd_protocol_handle_request (struct rspamd_task *task,
        return ret;
 }
 
-static void
-write_hashes_to_log (struct rspamd_task *task, rspamd_fstring_t **logbuf)
-{
-       struct mime_text_part *text_part;
-       guint i;
-
-       /* TODO: rework parts hashes */
-       for (i = 0; i < task->text_parts->len; i ++) {
-               text_part = g_ptr_array_index (task->text_parts, i);
-       }
-}
-
-
 /* Structure for writing tree data */
 struct tree_cb_data {
        ucl_object_t *top;
@@ -793,15 +780,11 @@ rspamd_str_list_ucl (GList *str_list)
 
 static ucl_object_t *
 rspamd_metric_symbol_ucl (struct rspamd_task *task, struct metric *m,
-       struct symbol *sym, rspamd_fstring_t **logbuf)
+       struct symbol *sym)
 {
        ucl_object_t *obj = NULL;
        const gchar *description = NULL;
 
-       if (logbuf != NULL) {
-               rspamd_printf_fstring (logbuf, "%s,", sym->name);
-       }
-
        if (sym->def != NULL) {
                description = sym->def->description;
        }
@@ -825,8 +808,7 @@ rspamd_metric_symbol_ucl (struct rspamd_task *task, struct metric *m,
 
 static ucl_object_t *
 rspamd_metric_result_ucl (struct rspamd_task *task,
-       struct metric_result *mres,
-       rspamd_fstring_t **logbuf)
+       struct metric_result *mres)
 {
        GHashTableIter hiter;
        struct symbol *sym;
@@ -837,7 +819,6 @@ rspamd_metric_result_ucl (struct rspamd_task *task,
        gpointer h, v;
        double required_score;
        const gchar *subject;
-       gchar action_char;
 
        m = mres->metric;
        mres->action = rspamd_check_action_metric (task, mres->score,
@@ -846,23 +827,6 @@ rspamd_metric_result_ucl (struct rspamd_task *task,
        action = mres->action;
        is_spam = (action == METRIC_ACTION_REJECT);
 
-       if (RSPAMD_TASK_IS_SKIPPED (task)) {
-               action_char = 'S';
-       }
-       else if (is_spam) {
-               action_char = 'T';
-       }
-       else {
-               action_char = 'F';
-       }
-
-       if (logbuf != NULL) {
-               rspamd_printf_fstring (logbuf, "(%s: %c (%s): [%.2f/%.2f] [",
-                               m->name, action_char,
-                               rspamd_action_to_str (action),
-                               mres->score, required_score);
-       }
-
        obj = ucl_object_typed_new (UCL_OBJECT);
        ucl_object_insert_key (obj,       ucl_object_frombool (is_spam),
                "is_spam", 0, false);
@@ -885,26 +849,10 @@ rspamd_metric_result_ucl (struct rspamd_task *task,
        g_hash_table_iter_init (&hiter, mres->symbols);
        while (g_hash_table_iter_next (&hiter, &h, &v)) {
                sym = (struct symbol *)v;
-               sobj = rspamd_metric_symbol_ucl (task, m, sym, logbuf);
+               sobj = rspamd_metric_symbol_ucl (task, m, sym);
                ucl_object_insert_key (obj, sobj, h, 0, false);
        }
 
-       if (logbuf != NULL) {
-               /* Cut the trailing comma if needed */
-               rspamd_fstring_t *log = *logbuf;
-
-               if (log->str[log->len - 1] == ',') {
-                       log->len--;
-               }
-
-               rspamd_printf_fstring (logbuf, "]), len: %z, time: %s, dns req: %d,",
-                               task->msg.len,
-                               rspamd_log_check_time (task->time_real,
-                                               task->time_virtual,
-                                               task->cfg->clock_res),
-                               task->dns_requests);
-       }
-
        return obj;
 }
 
@@ -1003,42 +951,19 @@ rspamd_ucl_tospamc_output (struct rspamd_task *task,
 }
 
 ucl_object_t *
-rspamd_protocol_write_ucl (struct rspamd_task *task, rspamd_fstring_t **logbuf)
+rspamd_protocol_write_ucl (struct rspamd_task *task)
 {
        struct metric_result *metric_res;
        ucl_object_t *top = NULL, *obj;
        GHashTableIter hiter;
        gpointer h, v;
 
-       if (logbuf != NULL) {
-               rspamd_printf_fstring (logbuf,
-                               "id: <%s>, qid: <%s>, ip: %s, ",
-                               task->message_id,
-                               task->queue_id,
-                               rspamd_inet_address_to_string (task->from_addr));
-
-               if (task->user) {
-                       rspamd_printf_fstring (logbuf, "user: %s, ", task->user);
-               }
-               else if (task->from_envelope) {
-                       InternetAddress *ia;
-
-                       ia = internet_address_list_get_address (task->from_envelope, 0);
-
-                       if (ia && INTERNET_ADDRESS_IS_MAILBOX (ia)) {
-                               InternetAddressMailbox *iamb = INTERNET_ADDRESS_MAILBOX (ia);
-
-                               rspamd_printf_fstring (logbuf, "from: %s, ", iamb->addr);
-                       }
-               }
-       }
-
        g_hash_table_iter_init (&hiter, task->results);
        top = ucl_object_typed_new (UCL_OBJECT);
        /* Convert results to an ucl object */
        while (g_hash_table_iter_next (&hiter, &h, &v)) {
                metric_res = (struct metric_result *)v;
-               obj = rspamd_metric_result_ucl (task, metric_res, logbuf);
+               obj = rspamd_metric_result_ucl (task, metric_res);
                ucl_object_insert_key (top, obj, h, 0, false);
        }
 
@@ -1058,10 +983,6 @@ rspamd_protocol_write_ucl (struct rspamd_task *task, rspamd_fstring_t **logbuf)
        ucl_object_insert_key (top, ucl_object_fromstring (task->message_id),
                        "message-id", 0, false);
 
-       if (logbuf != NULL) {
-               write_hashes_to_log (task, logbuf);
-       }
-
        return top;
 }
 
@@ -1069,7 +990,6 @@ void
 rspamd_protocol_http_reply (struct rspamd_http_message *msg,
        struct rspamd_task *task)
 {
-       rspamd_fstring_t *logbuf;
        struct metric_result *metric_res;
        GHashTableIter hiter;
        gpointer h, v;
@@ -1077,9 +997,6 @@ rspamd_protocol_http_reply (struct rspamd_http_message *msg,
        gdouble required_score;
        gint action;
 
-       /* Output the first line - check status */
-       logbuf = rspamd_fstring_sized_new (1000);
-
        /* Write custom headers */
        g_hash_table_iter_init (&hiter, task->reply_headers);
        while (g_hash_table_iter_next (&hiter, &h, &v)) {
@@ -1088,17 +1005,13 @@ rspamd_protocol_http_reply (struct rspamd_http_message *msg,
                rspamd_http_message_add_header (msg, hn->begin, hv->begin);
        }
 
-       top = rspamd_protocol_write_ucl (task, &logbuf);
+       top = rspamd_protocol_write_ucl (task);
 
        if (!(task->flags & RSPAMD_TASK_FLAG_NO_LOG)) {
                rspamd_roll_history_update (task->worker->srv->history, task);
        }
 
-       if (!(task->flags & RSPAMD_TASK_FLAG_NO_LOG)) {
-               msg_info_task ("%V", logbuf);
-       }
-
-       rspamd_fstring_free (logbuf);
+       rspamd_task_write_log (task);
 
        msg->body = rspamd_fstring_sized_new (1000);
 
index 0342f4ed6fe71c79a253643416d86c98ebfc2a46..a88a482316f2f47e37bbfd39b98cd26be16431ad 100644 (file)
@@ -61,8 +61,7 @@ void rspamd_protocol_http_reply (struct rspamd_http_message *msg,
  * @param logbuf
  * @return
  */
-ucl_object_t * rspamd_protocol_write_ucl (struct rspamd_task *task,
-               rspamd_fstring_t **logbuf);
+ucl_object_t * rspamd_protocol_write_ucl (struct rspamd_task *task);
 
 /**
  * Write reply for specified task command
index 713971506de5fee44800d6f0753c991d06371f7c..5a5eb20440c8bb873bf8a35f4664e39739cb2b26 100644 (file)
@@ -30,6 +30,7 @@
 #include "composites.h"
 #include "stat_api.h"
 #include "unix-std.h"
+#include <utlist.h>
 
 static GQuark
 rspamd_task_quark (void)
@@ -664,3 +665,121 @@ rspamd_learn_task_spam (struct rspamd_classifier_config *cl,
 {
        return rspamd_stat_learn (task, is_spam, task->cfg->lua_state, err);
 }
+
+static gboolean
+rspamd_task_log_check_condition (struct rspamd_task *task,
+               struct rspamd_log_format *lf)
+{
+       gboolean ret = FALSE;
+
+       switch (lf->type) {
+       case RSPAMD_LOG_MID:
+               if (task->message_id && strcmp (task->message_id, "undef") != 0) {
+                       ret = TRUE;
+               }
+               break;
+       case RSPAMD_LOG_QID:
+               if (task->queue_id) {
+                       ret = TRUE;
+               }
+               break;
+       case RSPAMD_LOG_USER:
+               if (task->user) {
+                       ret = TRUE;
+               }
+               break;
+       case RSPAMD_LOG_IP:
+               if (task->from_addr && rspamd_ip_is_valid (task->from_addr)) {
+                       ret = TRUE;
+               }
+               break;
+       case RSPAMD_LOG_SMTP_FROM:
+               if (task->from_envelope &&
+                                       internet_address_list_length (task->from_envelope) > 0) {
+                       ret = TRUE;
+               }
+               break;
+       case RSPAMD_LOG_MIME_FROM:
+               if (task->from_mime &&
+                               internet_address_list_length (task->from_mime) > 0) {
+                       ret = TRUE;
+               }
+               break;
+       default:
+               ret = TRUE;
+               break;
+       }
+
+       return ret;
+}
+
+static rspamd_fstring_t *
+rspamd_task_log_variable (struct rspamd_task *task,
+               struct rspamd_log_format *lf, rspamd_fstring_t *logbuf)
+{
+       rspamd_fstring_t *res = logbuf;
+
+
+       return res;
+}
+
+void
+rspamd_task_write_log (struct rspamd_task *task)
+{
+       rspamd_fstring_t *logbuf;
+       struct rspamd_log_format *lf;
+       struct rspamd_task **ptask;
+       const gchar *lua_str;
+       gsize lua_str_len;
+       lua_State *L;
+
+       g_assert (task != NULL);
+
+       if (task->cfg->log_format == NULL || task->flags & RSPAMD_TASK_FLAG_NO_LOG) {
+               return;
+       }
+
+       logbuf = rspamd_fstring_sized_new (1000);
+
+       DL_FOREACH (task->cfg->log_format, lf) {
+               switch (lf->type) {
+               case RSPAMD_LOG_STRING:
+                       logbuf = rspamd_fstring_append (logbuf, lf->data, lf->len);
+                       break;
+               case RSPAMD_LOG_LUA:
+                       L = task->cfg->lua_state;
+                       lua_rawgeti (L, LUA_REGISTRYINDEX, GPOINTER_TO_INT (lf->data));
+                       ptask = lua_newuserdata (L, sizeof (*ptask));
+                       rspamd_lua_setclass (L, "rspamd{task}", -1);
+                       *ptask = task;
+
+                       if (lua_pcall (L, 1, 1, 0) != 0) {
+                               msg_err_task ("call to log function failed: %s",
+                                               lua_tostring (L, -1));
+                       }
+                       else {
+                               lua_str = lua_tolstring (L, -1, &lua_str_len);
+
+                               if (lua_str != NULL) {
+                                       logbuf = rspamd_fstring_append (logbuf, lua_str, lua_str_len);
+                               }
+                               lua_pop (L, 1);
+                       }
+                       break;
+               default:
+                       /* We have a variable in log format */
+                       if (lf->flags & RSPAMD_LOG_FLAG_CONDITION) {
+                               if (!rspamd_task_log_check_condition (task, lf)) {
+                                       continue;
+                               }
+                       }
+
+                       logbuf = rspamd_task_log_variable (task, lf, logbuf);
+                       break;
+               }
+       }
+
+       msg_info ("%V", logbuf);
+
+       rspamd_fstring_free (logbuf);
+}
index 11862ed53c4cde0cb2d45d81d0c8194a2beb9377..8a9e913a474160ca43c62019fda77778858d761b 100644 (file)
@@ -271,4 +271,9 @@ gboolean rspamd_learn_task_spam (struct rspamd_classifier_config *cl,
        gboolean is_spam,
        GError **err);
 
+/**
+ * Write log line about the specified task if needed
+ */
+void rspamd_task_write_log (struct rspamd_task *task);
+
 #endif /* TASK_H_ */
index 0ea6f4d54cc400c3ec1cfb453da361bb3777982d..48a07d9f27b1eb728d64a9951f32ce9057d94b20 100644 (file)
@@ -221,7 +221,7 @@ lua_util_task_fin (struct rspamd_task *task, void *ud)
 {
        ucl_object_t **target = ud;
 
-       *target = rspamd_protocol_write_ucl (task, NULL);
+       *target = rspamd_protocol_write_ucl (task);
        rdns_resolver_release (task->resolver->r);
 
        return TRUE;
@@ -267,7 +267,7 @@ lua_util_process_message (lua_State *L)
                                        ucl_object_unref (res);
                                }
                                else {
-                                       ucl_object_push_lua (L, rspamd_protocol_write_ucl (task, NULL),
+                                       ucl_object_push_lua (L, rspamd_protocol_write_ucl (task),
                                                        true);
                                        rdns_resolver_release (task->resolver->r);
                                        rspamd_task_free_hard (task);