[Feature] Cache and insert scan time into the protocol

diff --git a/src/libserver/protocol.c b/src/libserver/protocol.c
index b64f06d970207a81357903f7a02be22b6bd71885..3096263dacd1be6b0f199c402f0765c75d34520f 100644 (file)
--- a/src/libserver/protocol.c
+++ b/src/libserver/protocol.c
@@ -1111,6 +1111,10 @@ rspamd_protocol_write_ucl (struct rspamd_task *task,
                cached->flags = flags;
                rspamd_mempool_set_variable (task->task_pool, varname,
                                cached, rspamd_protocol_cached_dtor);
+
+               /* We also set scan time here */
+               task->time_real_finish = rspamd_get_ticks ();
+               task->time_virtual_finish = rspamd_get_virtual_ticks ();
        }
 
        if (flags & RSPAMD_PROTOCOL_METRICS) {
@@ -1167,6 +1171,12 @@ rspamd_protocol_write_ucl (struct rspamd_task *task,
        if (flags & RSPAMD_PROTOCOL_BASIC) {
                ucl_object_insert_key (top, ucl_object_fromstring (task->message_id),
                                "message-id", 0, false);
+               ucl_object_insert_key (top,
+                               ucl_object_fromdouble (task->time_real_finish - task->time_real),
+                               "time-real", 0, false);
+               ucl_object_insert_key (top,
+                               ucl_object_fromdouble (task->time_virtual_finish - task->time_virtual),
+                               "time-virtual", 0, false);
        }
 
        if (flags & RSPAMD_PROTOCOL_DKIM) {

diff --git a/src/libserver/roll_history.c b/src/libserver/roll_history.c
index 86f0df02b2c6a99bf81977e1ddb3d83ee73b3e45..d8b9abdec07aed59d2baeba9ef6a3f3ac6fe1f2d 100644 (file)
--- a/src/libserver/roll_history.c
+++ b/src/libserver/roll_history.c
@@ -139,7 +139,7 @@ rspamd_roll_history_update (struct roll_history *history,
                }
        }
 
-       row->scan_time = rspamd_get_ticks () - task->time_real;
+       row->scan_time = task->time_real_finish - task->time_real;
        row->len = task->msg.len;
        g_atomic_int_set (&row->completed, TRUE);
 }

diff --git a/src/libserver/task.c b/src/libserver/task.c
index cb3d451246ed02838755757e9021f5df6fec154b..4d20edb834b8c2ca77a7ea3fb9066c2d90377f41 100644 (file)
--- a/src/libserver/task.c
+++ b/src/libserver/task.c
@@ -1276,13 +1276,14 @@ rspamd_task_log_variable (struct rspamd_task *task,
                var.begin = numbuf;
                break;
        case RSPAMD_LOG_TIME_REAL:
-               var.begin = rspamd_log_check_time (task->time_real, rspamd_get_ticks (),
+               var.begin = rspamd_log_check_time (task->time_real,
+                               task->time_real_finish,
                                task->cfg->clock_res);
                var.len = strlen (var.begin);
                break;
        case RSPAMD_LOG_TIME_VIRTUAL:
                var.begin = rspamd_log_check_time (task->time_virtual,
-                               rspamd_get_virtual_ticks (),
+                               task->time_virtual_finish,
                                task->cfg->clock_res);
                var.len = strlen (var.begin);
                break;

diff --git a/src/libserver/task.h b/src/libserver/task.h
index ba03d88195711af6a1e6f6ec1d214e3357cc74c5..97329ce3ba54da6cead28c7560b99210fb017410 100644 (file)
--- a/src/libserver/task.h
+++ b/src/libserver/task.h
@@ -175,6 +175,8 @@ struct rspamd_task {
        rspamd_mempool_t *task_pool;                                    /**< memory pool for task                                                       */
        double time_real;
        double time_virtual;
+       double time_real_finish;
+       double time_virtual_finish;
        struct timeval tv;
        gboolean (*fin_callback)(struct rspamd_task *task, void *arg);
                                                                                                        /**< calback for filters finalizing                                     */