commit d6b21b8: [Minor] Log events on forced timeout

[Vsevolod Stakhov]

Author: Vsevolod Stakhov
Date: 2021-12-27 18:45:43 +0000
URL: https://github.com/rspamd/rspamd/commit/d6b21b81428e45f009b1f42714342d68270cb8f9 (HEAD -> master)

[Minor] Log events on forced timeout

---
 src/libserver/async_session.c | 41 ++++++++++++++++++++++++++++++++---------
 src/libserver/async_session.h |  2 +-
 src/libserver/task.c          |  4 ++--
 3 files changed, 35 insertions(+), 12 deletions(-)

diff --git a/src/libserver/async_session.c b/src/libserver/async_session.c
index 057604447..f84b8aa5e 100644
--- a/src/libserver/async_session.c
+++ b/src/libserver/async_session.c
@@ -257,7 +257,7 @@ rspamd_session_destroy (struct rspamd_async_session *session)
 
 	if (!rspamd_session_blocked (session)) {
 		session->flags |= RSPAMD_SESSION_FLAG_DESTROYING;
-		rspamd_session_cleanup (session);
+		rspamd_session_cleanup (session, false);
 
 		if (session->cleanup != NULL) {
 			session->cleanup (session->user_data);
@@ -268,7 +268,7 @@ rspamd_session_destroy (struct rspamd_async_session *session)
 }
 
 void
-rspamd_session_cleanup (struct rspamd_async_session *session)
+rspamd_session_cleanup (struct rspamd_async_session *session, bool forced_cleanup)
 {
 	struct rspamd_async_event *ev;
 
@@ -285,15 +285,32 @@ rspamd_session_cleanup (struct rspamd_async_session *session)
 		int ret;
 
 		if (ev->fin != NULL) {
-			msg_debug_session ("removed event on destroy: %p, subsystem: %s",
-					ev->user_data,
-					ev->subsystem);
+			if (forced_cleanup) {
+				msg_info_session ("forced removed event on destroy: %p, subsystem: %s, scheduled from: %s",
+						ev->user_data,
+						ev->subsystem,
+						ev->loc);
+			}
+			else {
+				msg_debug_session("removed event on destroy: %p, subsystem: %s",
+						ev->user_data,
+						ev->subsystem);
+			}
 			ev->fin (ev->user_data);
 		}
 		else {
-			msg_debug_session ("NOT removed event on destroy - uncancellable: %p, subsystem: %s",
-					ev->user_data,
-					ev->subsystem);
+			if (forced_cleanup) {
+				msg_info_session ("NOT forced removed event on destroy - uncancellable: "
+								  "%p, subsystem: %s, scheduled from: %s",
+						ev->user_data,
+						ev->subsystem,
+						ev->loc);
+			}
+			else {
+				msg_debug_session("NOT removed event on destroy - uncancellable: %p, subsystem: %s",
+						ev->user_data,
+						ev->subsystem);
+			}
 			/* Assume an event is uncancellable, move it to a new hash table */
 			kh_put (rspamd_events_hash, uncancellable_events, ev, &ret);
 		}
@@ -301,7 +318,13 @@ rspamd_session_cleanup (struct rspamd_async_session *session)
 
 	kh_destroy (rspamd_events_hash, session->events);
 	session->events = uncancellable_events;
-	msg_debug_session ("pending %d uncancellable events", kh_size (uncancellable_events));
+	if (forced_cleanup) {
+		msg_info_session ("pending %d uncancellable events", kh_size (uncancellable_events));
+	}
+	else {
+		msg_debug_session ("pending %d uncancellable events", kh_size (uncancellable_events));
+	}
+
 	session->flags &= ~RSPAMD_SESSION_FLAG_CLEANUP;
 }
 
diff --git a/src/libserver/async_session.h b/src/libserver/async_session.h
index ad79769e9..5dc4a3b84 100644
--- a/src/libserver/async_session.h
+++ b/src/libserver/async_session.h
@@ -83,7 +83,7 @@ gboolean rspamd_session_destroy (struct rspamd_async_session *session);
 /**
  * Try to remove all events pending
  */
-void rspamd_session_cleanup (struct rspamd_async_session *session);
+void rspamd_session_cleanup (struct rspamd_async_session *session, bool forced_cleanup);
 
 /**
  * Returns mempool associated with async session
diff --git a/src/libserver/task.c b/src/libserver/task.c
index c9f3fb627..fa97d67a5 100644
--- a/src/libserver/task.c
+++ b/src/libserver/task.c
@@ -1911,7 +1911,7 @@ rspamd_task_timeout (EV_P_ ev_timer *w, int revents)
 
 		ev_timer_again (EV_A_ w);
 		task->processed_stages |= RSPAMD_TASK_STAGE_FILTERS;
-		rspamd_session_cleanup (task->s);
+		rspamd_session_cleanup (task->s, true);
 		rspamd_task_process (task, RSPAMD_TASK_PROCESS_ALL);
 		rspamd_session_pending (task->s);
 	}
@@ -1940,7 +1940,7 @@ rspamd_task_timeout (EV_P_ ev_timer *w, int revents)
 
 		ev_timer_stop (EV_A_ w);
 		task->processed_stages |= RSPAMD_TASK_STAGE_DONE;
-		rspamd_session_cleanup (task->s);
+		rspamd_session_cleanup (task->s, true);
 		rspamd_task_process (task, RSPAMD_TASK_PROCESS_ALL);
 		rspamd_session_pending (task->s);
 	}