* Improve logging system:

  - do not write many repeated messages to log
  - add process name to log line
* Small fixes to FreeBSD port and to start script as we have xml version now
* Reconfig modules while rereading config file

6 files changed, 146 insertions, 36 deletions

diff --git a/freebsd/port/Makefile b/freebsd/port/Makefile
index 668d8d8d4..d75fc40e4 100644
--- a/freebsd/port/Makefile
+++ b/freebsd/port/Makefile
@@ -6,7 +6,7 @@
 #
 
 PORTNAME=		rspamd
-PORTVERSION=	0.2.9
+PORTVERSION=	0.3.0
 CATEGORIES=		mail
 MASTER_SITES=	SF/${PORTNAME}/${PORTNAME}/${PORTNAME}-${PORTVERSION}
 
@@ -27,7 +27,6 @@ USE_PERL5=		yes
 
 OPTIONS=		RSPAMD_GPERF "Enable google perf-tools profiling" off \
 				RSPAMD_JUDY "Enable judy arrays usage for performance" off \
-				RSPAMD_LUA	"Enable lua plugins support in rspamd" on \
 				RSPAMD_OPTFLAGS "Turn on compiler optimizations" off \
 				RSPAMD_REDIRECTOR "Install HTTP redirector" off \
 				RSPAMD_STATIC "Build static version of rspamd" off
@@ -47,13 +46,8 @@ LIB_DEPENDS+=	profiler.0:${PORTSDIR}/devel/google-perftools
 LIB_DEPENDS+=	Judy:${PORTSDIR}/devel/judy
 .endif
 
-.if defined(WITH_RSPAMD_LUA)
 USE_LUA=	5.1-
 PLIST_SUB+=		LUA=""
-.else
-CMAKE_ARGS+=	-DENABLE_LUA=OFF
-PLIST_SUB+=		LUA="@comment"
-.endif
 
 .if defined(WITH_RSPAMD_OPTFLAGS)
 CMAKE_ARGS+=	-DENABLE_OPTIMIZATION=ON
diff --git a/freebsd/rspamd.sh.in b/freebsd/rspamd.sh.in
index 5bb3a5cc2..42e82f140 100755
--- a/freebsd/rspamd.sh.in
+++ b/freebsd/rspamd.sh.in
@@ -41,6 +41,6 @@ extra_commands="reload configtest"
 sig_reload="USR1"
 
 command="$procname"
-command_args="-u ${rspamd_user} -g ${rspamd_group} -c @CMAKE_INSTALL_PREFIX@/etc/rspamd.conf"
+command_args="-u ${rspamd_user} -g ${rspamd_group} -c @CMAKE_INSTALL_PREFIX@/etc/rspamd.xml"
 
 run_rc_command "$1"
diff --git a/src/logger.c b/src/logger.c
index 0d8daa75f..72bb9da73 100644
--- a/src/logger.c
+++ b/src/logger.c
@@ -29,12 +29,36 @@
 #include "main.h"
 #include "map.h"
 
+/* How much message should be repeated before it is count to be repeated one */
+#define REPEATS_MIN 3
+#define REPEATS_MAX 300
 
 #ifdef RSPAMD_MAIN
 sig_atomic_t                    do_reopen_log = 0;
 #endif
 
-rspamd_logger_t *rspamd_log;
+typedef struct rspamd_logger_s {
+	rspamd_log_func_t        log_func;
+	struct config_file		*cfg;
+	struct {
+		uint32_t size;
+		uint32_t used;
+		u_char *buf;
+	}                        io_buf;
+	int                      fd;
+	gboolean                 is_buffered;
+	gboolean                 enabled;
+	enum rspamd_log_type     type;
+	pid_t                    pid;
+	enum process_type		 process_type;
+	radix_tree_t            *debug_ip;
+	uint32_t                 last_line_cksum;
+	uint32_t                 repeats;
+	gchar                   *saved_message;
+	gchar                   *saved_function;
+} rspamd_logger_t;
+
+rspamd_logger_t *rspamd_log = NULL;
 
 static const char lf_chr = '\n';
 
@@ -47,6 +71,23 @@ file_log_function (const gchar * log_domain, const gchar *function,
 					GLogLevelFlags log_level, const gchar * message, 
 					gboolean forced, gpointer arg);
 
+static inline uint32_t
+rspamd_log_calculate_cksum (const gchar *message, size_t mlen)
+{
+	const gchar                    *bp = message;
+	const gchar                    *be = bp + mlen;
+	uint32_t                        hval = 0;
+
+    while (bp < be) {
+		hval += (hval<<1) + (hval<<4) + (hval<<7) + (hval<<8) + (hval<<24);
+		hval ^= (uint32_t)*bp++;
+    }
+
+    /* return our new hash value */
+    return hval;
+	
+}
+
 static void
 direct_write_log_line (void *data, int count, gboolean is_iov)
 {
@@ -115,6 +156,7 @@ open_log (void)
 void
 close_log (void)
 {
+	char            tmpbuf[256];
 	flush_log_buf ();
 
 	switch (rspamd_log->type) {
@@ -126,6 +168,21 @@ close_log (void)
 		break;
 	case RSPAMD_LOG_FILE:
 		if (rspamd_log->enabled) {
+			if (rspamd_log->repeats > REPEATS_MIN) {
+				snprintf (tmpbuf, sizeof (tmpbuf), "Last message repeated %u times", rspamd_log->repeats);
+				rspamd_log->repeats = 0;
+				if (rspamd_log->saved_message) {
+					file_log_function (NULL, rspamd_log->saved_function, rspamd_log->cfg->log_level, rspamd_log->saved_message, TRUE, NULL);
+					g_free (rspamd_log->saved_message);
+					g_free (rspamd_log->saved_function);
+					rspamd_log->saved_message = NULL;
+					rspamd_log->saved_function = NULL;
+				}	
+				/* It is safe to use temporary buffer here as it is not static */
+				file_log_function (NULL, __FUNCTION__, rspamd_log->cfg->log_level, tmpbuf, TRUE, NULL);
+				return;
+			}
+
 			if (fsync (rspamd_log->fd) == -1) {
 				msg_err ("error syncing log file: %s", strerror (errno));
 			}
@@ -138,7 +195,7 @@ close_log (void)
 }
 
 void
-rspamd_set_logger (enum rspamd_log_type type, struct config_file *cfg)
+rspamd_set_logger (enum rspamd_log_type type, enum process_type ptype, struct config_file *cfg)
 {
 	char                          **strvec, *p, *err;
 	int                             num, i, k;
@@ -152,6 +209,7 @@ rspamd_set_logger (enum rspamd_log_type type, struct config_file *cfg)
 
 	rspamd_log->type = type;
 	rspamd_log->pid = getpid ();
+	rspamd_log->process_type = ptype;
 
 	switch (type) {
 		case RSPAMD_LOG_CONSOLE:
@@ -225,9 +283,10 @@ reopen_log (void)
 }
 
 void
-update_log_pid (void)
+update_log_pid (enum process_type ptype)
 {
 	rspamd_log->pid = getpid ();
+	rspamd_log->process_type = ptype;
 }
 
 void
@@ -358,6 +417,9 @@ file_log_function (const gchar * log_domain, const gchar *function, GLogLevelFla
 	struct tm                      *tms;
 	struct iovec                    iov[3];
 	int                             r;
+	uint32_t                        cksum;
+	size_t                          mlen;
+	const char                     *cptype = NULL;
 
 	if (! rspamd_log->enabled) {
 		return;
@@ -369,20 +431,85 @@ file_log_function (const gchar * log_domain, const gchar *function, GLogLevelFla
 #endif
 
 	if (forced || log_level <= rspamd_log->cfg->log_level) {
+		/* Check repeats */
+		mlen = strlen (message);
+		cksum = rspamd_log_calculate_cksum (message, mlen);
+		if (cksum == rspamd_log->last_line_cksum) {
+			rspamd_log->repeats ++;
+			if (rspamd_log->repeats > REPEATS_MIN && rspamd_log->repeats < REPEATS_MAX) {
+				/* Do not log anything */
+				if (rspamd_log->saved_message == 0) {
+					rspamd_log->saved_message = g_strdup (message);
+					rspamd_log->saved_function = g_strdup (function);
+				}
+				return;
+			}
+			else if (rspamd_log->repeats > REPEATS_MAX) {
+				snprintf (tmpbuf, sizeof (tmpbuf), "Last message repeated %u times", rspamd_log->repeats);
+				rspamd_log->repeats = 0;
+				/* It is safe to use temporary buffer here as it is not static */
+				if (rspamd_log->saved_message) {
+					file_log_function (log_domain, rspamd_log->saved_function, log_level, rspamd_log->saved_message, forced, arg);
+				}	
+				file_log_function (log_domain, __FUNCTION__, log_level, tmpbuf, forced, arg);
+				file_log_function (log_domain, function, log_level, message, forced, arg);
+				rspamd_log->repeats = REPEATS_MIN + 1;
+				return;
+			}
+		}
+		else {
+			rspamd_log->last_line_cksum = cksum;
+			if (rspamd_log->repeats > REPEATS_MIN) {
+				snprintf (tmpbuf, sizeof (tmpbuf), "Last message repeated %u times", rspamd_log->repeats);
+				rspamd_log->repeats = 0;
+				if (rspamd_log->saved_message) {
+					file_log_function (log_domain, rspamd_log->saved_function, log_level, rspamd_log->saved_message, forced, arg);
+					g_free (rspamd_log->saved_message);
+					g_free (rspamd_log->saved_function);
+					rspamd_log->saved_message = NULL;
+					rspamd_log->saved_function = NULL;
+				}	
+				file_log_function (log_domain, __FUNCTION__, log_level, tmpbuf, forced, arg);
+				/* It is safe to use temporary buffer here as it is not static */
+				file_log_function (log_domain, function, log_level, message, forced, arg);
+				return;
+			}
+			else {
+				rspamd_log->repeats = 0;
+			}
+		}
+
 		now = time (NULL);
 		tms = localtime (&now);
 
 		strftime (timebuf, sizeof (timebuf), "%b %d %H:%M:%S", tms);
+		switch (rspamd_log->process_type) {
+			case TYPE_MAIN:
+				cptype = "main";
+				break;
+			case TYPE_WORKER:
+				cptype = "worker";
+				break;
+			case TYPE_CONTROLLER:
+				cptype = "controller";
+				break;
+			case TYPE_LMTP:
+				cptype = "lmtp";
+				break;
+			case TYPE_FUZZY:
+				cptype = "fuzzy";
+				break;
+		}
 		if (function == NULL) {
-			r = rspamd_snprintf (tmpbuf, sizeof (tmpbuf), "#%P: %s rspamd ", rspamd_log->pid, timebuf);
+			r = rspamd_snprintf (tmpbuf, sizeof (tmpbuf), "#%P(%s): %s rspamd ", rspamd_log->pid, cptype, timebuf);
 		}
 		else {
-			r = rspamd_snprintf (tmpbuf, sizeof (tmpbuf), "#%P: %s rspamd %s: ", rspamd_log->pid, timebuf, function);
+			r = rspamd_snprintf (tmpbuf, sizeof (tmpbuf), "#%P(%s): %s rspamd %s: ", rspamd_log->pid, cptype, timebuf, function);
 		}
 		iov[0].iov_base = tmpbuf;
 		iov[0].iov_len = r;
 		iov[1].iov_base = (void *)message;
-		iov[1].iov_len = strlen (message);
+		iov[1].iov_len = mlen;
 		iov[2].iov_base = (void *)&lf_chr;
 		iov[2].iov_len = 1;
 		
diff --git a/src/logger.h b/src/logger.h
index e86901cfc..c923b25ed 100644
--- a/src/logger.h
+++ b/src/logger.h
@@ -5,30 +5,17 @@
 #include "cfg_file.h"
 #include "radix.h"
 
+/* Forwarded declaration */
+enum process_type;
+
 typedef void (*rspamd_log_func_t)(const gchar * log_domain, const gchar *function,
 								  GLogLevelFlags log_level, const gchar * message, 
 								  gboolean forced, gpointer arg);
 
-typedef struct rspamd_logger_s {
-	rspamd_log_func_t        log_func;
-	struct config_file		*cfg;
-	struct {
-		uint32_t size;
-		uint32_t used;
-		u_char *buf;
-	}                        io_buf;
-	int                      fd;
-	gboolean                 is_buffered;
-	gboolean                 enabled;
-	enum rspamd_log_type     type;
-	pid_t                    pid;
-	radix_tree_t            *debug_ip;
-} rspamd_logger_t;
-
 /**
  * Init logger
  */
-void rspamd_set_logger (enum rspamd_log_type type, struct config_file *cfg);
+void rspamd_set_logger (enum rspamd_log_type type, enum process_type ptype, struct config_file *cfg);
 /**
  * Open log file or initialize other structures
  */
@@ -44,7 +31,7 @@ int reopen_log (void);
 /**
  * Set log pid
  */
-void update_log_pid (void);
+void update_log_pid (enum process_type ptype);
 
 /**
  * Flush log buffer for some types of logging
diff --git a/src/main.c b/src/main.c
index 123a69940..522af5736 100644
--- a/src/main.c
+++ b/src/main.c
@@ -236,7 +236,7 @@ drop_priv (struct config_file *cfg)
 static void
 config_logger (struct rspamd_main *rspamd, gboolean is_fatal)
 {
-	rspamd_set_logger (rspamd->cfg->log_type, rspamd->cfg);
+	rspamd_set_logger (rspamd->cfg->log_type, RSPAMD_MAIN, rspamd->cfg);
 	if (open_log () == -1) {
 		if (is_fatal) {
 			fprintf (stderr, "Fatal error, cannot open logfile, exiting\n");
@@ -284,7 +284,7 @@ reread_config (struct rspamd_main *rspamd)
 			while (l) {
 				filt = l->data;
 				if (filt->module) {
-					(void)filt->module->module_config_func (rspamd->cfg);
+					(void)filt->module->module_reconfig_func (rspamd->cfg);
 				}
 				l = g_list_next (l);
 			}
@@ -336,7 +336,7 @@ fork_worker (struct rspamd_main *rspamd, struct worker_conf *cf)
 		switch (cur->pid) {
 		case 0:
 			/* Update pid for logging */
-			update_log_pid ();
+			update_log_pid (cf->type);
 			/* Drop privilleges */
 			drop_priv (rspamd->cfg);
 			/* Set limits */
@@ -781,7 +781,7 @@ main (int argc, char **argv, char **env)
 #endif
 
 	/* First set logger to console logger */
-	rspamd_set_logger (RSPAMD_LOG_CONSOLE, rspamd->cfg);
+	rspamd_set_logger (RSPAMD_LOG_CONSOLE, RSPAMD_MAIN, rspamd->cfg);
 	(void)open_log ();
 	g_log_set_default_handler (rspamd_glib_log_function, rspamd->cfg);
 
diff --git a/src/plugins/fuzzy_check.c b/src/plugins/fuzzy_check.c
index bb66d1037..aa2b788ff 100644
--- a/src/plugins/fuzzy_check.c
+++ b/src/plugins/fuzzy_check.c
@@ -283,6 +283,8 @@ int
 fuzzy_check_module_reconfig (struct config_file *cfg)
 {
 	memory_pool_delete (fuzzy_module_ctx->fuzzy_pool);
+	fuzzy_module_ctx->servers = NULL;
+	fuzzy_module_ctx->servers_num = 0;
 	fuzzy_module_ctx->fuzzy_pool = memory_pool_new (memory_pool_get_size ());
 
 	return fuzzy_check_module_config (cfg);