[Rework] Rething slow timer

diff --git a/src/libserver/symcache/symcache_runtime.cxx b/src/libserver/symcache/symcache_runtime.cxx
index 15f970d8c37b3c088928ae70f0b37540ef974201..741e75183b7a9e929cc7796fcd0bd713cd61ada5 100644 (file)
--- a/src/libserver/symcache/symcache_runtime.cxx
+++ b/src/libserver/symcache/symcache_runtime.cxx
@@ -1,5 +1,5 @@
 /*
- * Copyright 2023 Vsevolod Stakhov
+ * Copyright 2024 Vsevolod Stakhov
  *
  * Licensed under the Apache License, Version 2.0 (the "License");
  * you may not use this file except in compliance with the License.
@@ -51,6 +51,12 @@ auto symcache_runtime::create(struct rspamd_task *task, symcache &cache) -> symc
        checkpoint->profile_start = now;
        checkpoint->lim = rspamd_task_get_required_score(task, task->result);
 
+       /*
+        * We enable profiling if the following conditions are met:
+        * - we have not profiled for a long time
+        * - message is large
+        * - random probability
+        */
        if ((cache.get_last_profile() == 0.0 || now > cache.get_last_profile() + PROFILE_MAX_TIME) ||
                (task->msg.len >= PROFILE_MESSAGE_SIZE_THRESHOLD) ||
                (rspamd_random_double_fast() >= (1 - PROFILE_PROBABILITY))) {
@@ -332,10 +338,7 @@ auto symcache_runtime::process_pre_postfilters(struct rspamd_task *task,
                auto dyn_item = get_dynamic_item(item->id);
 
                if (!dyn_item->started && !dyn_item->finished) {
-                       if (has_slow) {
-                               /* Delay */
-                               has_slow = false;
-
+                       if (slow_status == slow_status::enabled) {
                                return false;
                        }
 
@@ -424,10 +427,7 @@ auto symcache_runtime::process_filters(struct rspamd_task *task, symcache &cache
 
                        process_symbol(task, cache, item.get(), dyn_item);
 
-                       if (has_slow) {
-                               /* Delay */
-                               has_slow = false;
-
+                       if (slow_status == slow_status::enabled) {
                                return false;
                        }
                }
@@ -654,7 +654,7 @@ rspamd_symcache_delayed_item_cb(EV_P_ ev_timer *w, int what)
        if (cbd->event) {
                cbd->event = nullptr;
 
-               /* Timer will be stopped here */
+               /* Timer will be stopped here; `has_slow` is also reset there */
                rspamd_session_remove_event(cbd->task->s,
                                                                        rspamd_symcache_delayed_item_fin, cbd);
 
@@ -732,7 +732,7 @@ auto symcache_runtime::finalize_item(struct rspamd_task *task, cache_dynamic_ite
                }
                else {
                        /* Just reset as no timer is added */
-                       has_slow = FALSE;
+                       slow_status = slow_status::none;
                        return false;
                }
 
@@ -744,34 +744,32 @@ auto symcache_runtime::finalize_item(struct rspamd_task *task, cache_dynamic_ite
                auto diff = ((ev_now(task->event_loop) - profile_start) * 1e3 -
                                         dyn_item->start_msec);
 
+               if (G_UNLIKELY(RSPAMD_TASK_IS_PROFILING(task))) {
+                       rspamd_task_profile_set(task, item->symbol.c_str(), diff);
+               }
+
+               if (rspamd_worker_is_scanner(task->worker)) {
+                       rspamd_set_counter(item->cd, diff);
+               }
+
                if (diff > slow_diff_limit) {
 
-                       if (!has_slow) {
-                               has_slow = true;
+                       if (slow_status == slow_status::none) {
+                               slow_status = slow_status::enabled;
 
-                               msg_info_task("slow rule: %s(%d): %.2f ms; enable slow timer delay",
+                               msg_info_task("slow rule: %s(%d): %.2f ms; enable 100ms idle timer to allow other rules to be finished",
                                                          item->symbol.c_str(), item->id,
                                                          diff);
-
                                if (enable_slow_timer()) {
-                                       /* Allow network execution */
                                        return;
                                }
                        }
                        else {
-                               msg_info_task("slow rule: %s(%d): %.2f ms",
+                               msg_info_task("slow rule: %s(%d): %.2f ms; idle timer has already been activated for this scan",
                                                          item->symbol.c_str(), item->id,
                                                          diff);
                        }
                }
-
-               if (G_UNLIKELY(RSPAMD_TASK_IS_PROFILING(task))) {
-                       rspamd_task_profile_set(task, item->symbol.c_str(), diff);
-               }
-
-               if (rspamd_worker_is_scanner(task->worker)) {
-                       rspamd_set_counter(item->cd, diff);
-               }
        }
 
        process_item_rdeps(task, item);

diff --git a/src/libserver/symcache/symcache_runtime.hxx b/src/libserver/symcache/symcache_runtime.hxx
index aa8f66c0f21eef27a7a6742893bb82611d4b9446..181b32880d38f41ae681fcdffb36ec5fafd69ad7 100644 (file)
--- a/src/libserver/symcache/symcache_runtime.hxx
+++ b/src/libserver/symcache/symcache_runtime.hxx
@@ -1,5 +1,5 @@
 /*
- * Copyright 2023 Vsevolod Stakhov
+ * Copyright 2024 Vsevolod Stakhov
  *
  * Licensed under the Apache License, Version 2.0 (the "License");
  * you may not use this file except in compliance with the License.
@@ -46,10 +46,16 @@ struct cache_dynamic_item {
 static_assert(sizeof(cache_dynamic_item) == sizeof(std::uint64_t));
 static_assert(std::is_trivial_v<cache_dynamic_item>);
 
+
 class symcache_runtime {
        unsigned items_inflight;
+       enum class slow_status : std::uint8_t {
+               none = 0,
+               enabled = 1,
+               disabled = 2,
+       } slow_status;
+
        bool profile;
-       bool has_slow;
 
        double profile_start;
        double lim;
@@ -199,7 +205,9 @@ public:
        /* XXX: a helper to allow hiding internal implementation of the slow timer structure */
        auto unset_slow() -> void
        {
-               has_slow = false;
+               if (slow_status == slow_status::enabled) {
+                       slow_status = slow_status::disabled;
+               }
        }
 };