commit 7ae4d09: [Minor] Improve logging in lambdas

[Vsevolod Stakhov]

Author: Vsevolod Stakhov
Date: 2022-05-14 12:07:03 +0100
URL: https://github.com/rspamd/rspamd/commit/7ae4d091ce49880128879da792c063db1a395290

[Minor] Improve logging in lambdas

---
 src/libserver/logger.h                       |  8 ++++++++
 src/libserver/symcache/symcache_internal.hxx |  4 ++++
 src/libserver/symcache/symcache_runtime.cxx  | 17 +++++++++--------
 3 files changed, 21 insertions(+), 8 deletions(-)

diff --git a/src/libserver/logger.h b/src/libserver/logger.h
index ae3ea4694..35792e68e 100644
--- a/src/libserver/logger.h
+++ b/src/libserver/logger.h
@@ -290,6 +290,10 @@ extern guint rspamd_task_log_id;
         task->task_pool->tag.tagname, task->task_pool->tag.uid, \
         RSPAMD_LOG_FUNC, \
         __VA_ARGS__)
+#define msg_err_task_lambda(...) rspamd_default_log_function (G_LOG_LEVEL_CRITICAL, \
+        task->task_pool->tag.tagname, task->task_pool->tag.uid, \
+        log_func, \
+        __VA_ARGS__)
 #define msg_warn_task(...)   rspamd_default_log_function (G_LOG_LEVEL_WARNING, \
         task->task_pool->tag.tagname, task->task_pool->tag.uid, \
         RSPAMD_LOG_FUNC, \
@@ -310,6 +314,10 @@ extern guint rspamd_task_log_id;
         rspamd_task_log_id, "task", task->task_pool->tag.uid, \
         RSPAMD_LOG_FUNC, \
         __VA_ARGS__)
+#define msg_debug_task_lambda(...)  rspamd_conditional_debug_fast (NULL,  task->from_addr, \
+        rspamd_task_log_id, "task", task->task_pool->tag.uid, \
+        log_func, \
+        __VA_ARGS__)
 #define msg_err_task_encrypted(...) rspamd_default_log_function (G_LOG_LEVEL_CRITICAL|RSPAMD_LOG_ENCRYPTED, \
         task->task_pool->tag.tagname, task->task_pool->tag.uid, \
         RSPAMD_LOG_FUNC, \
diff --git a/src/libserver/symcache/symcache_internal.hxx b/src/libserver/symcache/symcache_internal.hxx
index 00c0d4d8b..84ae8de7f 100644
--- a/src/libserver/symcache/symcache_internal.hxx
+++ b/src/libserver/symcache/symcache_internal.hxx
@@ -64,6 +64,10 @@
         ::rspamd::symcache::rspamd_symcache_log_id, "symcache", task->task_pool->tag.uid, \
         RSPAMD_LOG_FUNC, \
         __VA_ARGS__)
+#define msg_debug_cache_task_lambda(...)  rspamd_conditional_debug_fast (NULL, NULL, \
+        ::rspamd::symcache::rspamd_symcache_log_id, "symcache", task->task_pool->tag.uid, \
+        log_func, \
+        __VA_ARGS__)
 
 struct lua_State;
 
diff --git a/src/libserver/symcache/symcache_runtime.cxx b/src/libserver/symcache/symcache_runtime.cxx
index 788a36ec9..1bcebbdc7 100644
--- a/src/libserver/symcache/symcache_runtime.cxx
+++ b/src/libserver/symcache/symcache_runtime.cxx
@@ -532,10 +532,11 @@ auto symcache_runtime::check_item_deps(struct rspamd_task *task, symcache &cache
 									   cache_dynamic_item *dyn_item, bool check_only) -> bool
 {
 	constexpr const auto max_recursion = 20;
+	auto log_func = RSPAMD_LOG_FUNC;
 
 	auto inner_functor = [&](int recursion, cache_item *item, cache_dynamic_item *dyn_item, auto rec_functor) -> bool {
 		if (recursion > max_recursion) {
-			msg_err_task ("cyclic dependencies: maximum check level %ud exceed when "
+			msg_err_task_lambda("cyclic dependencies: maximum check level %ud exceed when "
 						  "checking dependencies for %s", max_recursion, item->symbol.c_str());
 
 			return true;
@@ -546,7 +547,7 @@ auto symcache_runtime::check_item_deps(struct rspamd_task *task, symcache &cache
 		for (const auto &dep: item->deps) {
 			if (!dep.item) {
 				/* Assume invalid deps as done */
-				msg_debug_cache_task("symbol %d(%s) has invalid dependencies on %d(%s)",
+				msg_debug_cache_task_lambda("symbol %d(%s) has invalid dependencies on %d(%s)",
 						item->id, item->symbol.c_str(), dep.id, dep.sym.c_str());
 				continue;
 			}
@@ -563,26 +564,26 @@ auto symcache_runtime::check_item_deps(struct rspamd_task *task, symcache &cache
 								rec_functor)) {
 
 							ret = false;
-							msg_debug_cache_task("delayed dependency %d(%s) for "
+							msg_debug_cache_task_lambda("delayed dependency %d(%s) for "
 												 "symbol %d(%s)",
 									dep.id, dep.sym.c_str(), item->id, item->symbol.c_str());
 						}
 						else if (!process_symbol(task, cache, dep.item.get(), dep_dyn_item)) {
 							/* Now started, but has events pending */
 							ret = false;
-							msg_debug_cache_task("started check of %d(%s) symbol "
+							msg_debug_cache_task_lambda("started check of %d(%s) symbol "
 												 "as dep for "
 												 "%d(%s)",
 									dep.id, dep.sym.c_str(), item->id, item->symbol.c_str());
 						}
 						else {
-							msg_debug_cache_task("dependency %d(%s) for symbol %d(%s) is "
+							msg_debug_cache_task_lambda("dependency %d(%s) for symbol %d(%s) is "
 												 "already processed",
 									dep.id, dep.sym.c_str(), item->id, item->symbol.c_str());
 						}
 					}
 					else {
-						msg_debug_cache_task("dependency %d(%s) for symbol %d(%s) "
+						msg_debug_cache_task_lambda("dependency %d(%s) for symbol %d(%s) "
 											 "cannot be started now",
 								dep.id, dep.sym.c_str(), item->id, item->symbol.c_str());
 						ret = false;
@@ -590,14 +591,14 @@ auto symcache_runtime::check_item_deps(struct rspamd_task *task, symcache &cache
 				}
 				else {
 					/* Started but not finished */
-					msg_debug_cache_task("dependency %d(%s) for symbol %d(%s) is "
+					msg_debug_cache_task_lambda("dependency %d(%s) for symbol %d(%s) is "
 										 "still executing",
 							dep.id, dep.sym.c_str(), item->id, item->symbol.c_str());
 					ret = false;
 				}
 			}
 			else {
-				msg_debug_cache_task("dependency %d(%s) for symbol %d(%s) is already "
+				msg_debug_cache_task_lambda("dependency %d(%s) for symbol %d(%s) is already "
 									 "checked",
 						dep.id, dep.sym.c_str(), item->id, item->symbol.c_str());
 			}