From: Vsevolod Stakhov <vsevolod@highsecure.ru>
Date: Mon, 29 Feb 2016 15:18:39 +0000 (+0000)
Subject: [Feature] Add lockless logging
X-Git-Tag: 1.2.0~142
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=2cbece2248e8a90b7a71319ae59b638b36ced6df;p=thirdparty%2Frspamd.git

[Feature] Add lockless logging

Sometimes, it is needed to turn off logging mutex to avoid recursive
mutex obtaining. It is especially useful to do it within children wait
code in the main processes dispatcher.
---

diff --git a/src/libutil/logger.c b/src/libutil/logger.c
index 56f7822a5e..e6c1881133 100644
--- a/src/libutil/logger.c
+++ b/src/libutil/logger.c
@@ -48,6 +48,7 @@ struct rspamd_logger_s {
 	gboolean enabled;
 	gboolean is_debug;
 	gboolean throttling;
+	gboolean no_lock;
 	time_t throttling_time;
 	sig_atomic_t do_reopen_log;
 	enum rspamd_log_type type;
@@ -69,6 +70,18 @@ static const gchar lf_chr = '\n';
 
 static rspamd_logger_t *default_logger = NULL;
 
+#define RSPAMD_LOGGER_LOCK(l) do {				\
+	if ((l) != NULL && !(l)->no_lock) {			\
+		rspamd_mempool_lock_mutex ((l)->mtx);	\
+	}											\
+} while (0)
+
+#define RSPAMD_LOGGER_UNLOCK(l) do {			\
+	if ((l) != NULL && !(l)->no_lock) {			\
+		rspamd_mempool_unlock_mutex ((l)->mtx);	\
+	}											\
+} while (0)
+
 
 static void
 		syslog_log_function (const gchar *log_domain, const gchar *module,
@@ -456,14 +469,14 @@ rspamd_common_logv (rspamd_logger_t *rspamd_log, GLogLevelFlags log_level,
 	else {
 		if (rspamd_logger_need_log (rspamd_log, log_level, module)) {
 			rspamd_vsnprintf (logbuf, sizeof (logbuf), fmt, args);
-			rspamd_mempool_lock_mutex (rspamd_log->mtx);
+			RSPAMD_LOGGER_LOCK (rspamd_log);
 			rspamd_log->log_func (NULL, module, id,
 					function,
 					log_level,
 					logbuf,
 					FALSE,
 					rspamd_log);
-			rspamd_mempool_unlock_mutex (rspamd_log->mtx);
+			RSPAMD_LOGGER_UNLOCK (rspamd_log);
 		}
 
 		switch (log_level) {
@@ -918,7 +931,8 @@ rspamd_conditional_debug (rspamd_logger_t *rspamd_log,
 				return;
 			}
 		}
-		rspamd_mempool_lock_mutex (rspamd_log->mtx);
+
+		RSPAMD_LOGGER_LOCK (rspamd_log);
 		va_start (vp, fmt);
 		end = rspamd_vsnprintf (logbuf, sizeof (logbuf), fmt, vp);
 		*end = '\0';
@@ -929,7 +943,7 @@ rspamd_conditional_debug (rspamd_logger_t *rspamd_log,
 				logbuf,
 				TRUE,
 				rspamd_log);
-		rspamd_mempool_unlock_mutex (rspamd_log->mtx);
+		RSPAMD_LOGGER_UNLOCK (rspamd_log);
 	}
 }
 
@@ -946,14 +960,14 @@ rspamd_glib_log_function (const gchar *log_domain,
 
 	if (rspamd_log->enabled &&
 			rspamd_logger_need_log (rspamd_log, log_level, NULL)) {
-		rspamd_mempool_lock_mutex (rspamd_log->mtx);
+		RSPAMD_LOGGER_LOCK (rspamd_log);
 		rspamd_log->log_func (log_domain, "glib", NULL,
 				NULL,
 				log_level,
 				message,
 				FALSE,
 				rspamd_log);
-		rspamd_mempool_unlock_mutex (rspamd_log->mtx);
+		RSPAMD_LOGGER_UNLOCK (rspamd_log);
 	}
 }
 
@@ -992,3 +1006,19 @@ rspamd_log_counters (rspamd_logger_t *logger)
 
 	return NULL;
 }
+
+void
+rspamd_log_nolock (rspamd_logger_t *logger)
+{
+	if (logger) {
+		logger->no_lock = TRUE;
+	}
+}
+
+void
+rspamd_log_lock (rspamd_logger_t *logger)
+{
+	if (logger) {
+		logger->no_lock = FALSE;
+	}
+}
diff --git a/src/libutil/logger.h b/src/libutil/logger.h
index 7bf8307c83..2523efad32 100644
--- a/src/libutil/logger.h
+++ b/src/libutil/logger.h
@@ -123,6 +123,16 @@ void rspamd_log_debug (rspamd_logger_t *logger);
  */
 void rspamd_log_nodebug (rspamd_logger_t *logger);
 
+/**
+ * Turn off locking on logger (useful to avoid races)
+ */
+void rspamd_log_nolock (rspamd_logger_t *logger);
+
+/**
+ * Turn on locking to avoid log output mix
+ */
+void rspamd_log_lock (rspamd_logger_t *logger);
+
 /**
  * Return array of counters (4 numbers):
  * 0 - errors
diff --git a/src/rspamd.c b/src/rspamd.c
index 8ff95cd7aa..cada080b90 100644
--- a/src/rspamd.c
+++ b/src/rspamd.c
@@ -821,6 +821,9 @@ rspamd_cld_handler (gint signo, short what, gpointer arg)
 	struct rspamd_worker *cur;
 	pid_t wrk;
 
+	/* Turn off locking for logger */
+	rspamd_log_nolock (rspamd_main->logger);
+
 	msg_debug_main ("catch SIGCHLD signal, finding terminated worker");
 	/* Remove dead child form children list */
 	wrk = waitpid (0, &res, 0);
@@ -891,6 +894,8 @@ rspamd_cld_handler (gint signo, short what, gpointer arg)
 			}
 		}
 	}
+
+	rspamd_log_lock (rspamd_main->logger);
 }
 
 static void