From: Vsevolod Stakhov <vsevolod@highsecure.ru>
Date: Mon, 13 Mar 2017 15:52:10 +0000 (+0000)
Subject: [Feature] Cache and insert scan time into the protocol
X-Git-Tag: 1.5.3~38
X-Git-Url: https://source.dussan.org/?a=commitdiff_plain;h=52a47b8cfb1c9acaa1bd0dd78ec295c32849417d;p=rspamd.git

[Feature] Cache and insert scan time into the protocol
---

diff --git a/src/libserver/protocol.c b/src/libserver/protocol.c
index b64f06d97..3096263da 100644
--- 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 86f0df02b..d8b9abdec 100644
--- 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 cb3d45124..4d20edb83 100644
--- 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 ba03d8819..97329ce3b 100644
--- 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					*/