commit e3a552c: [Fix] Lot's of fixes in maps check logic

Vsevolod Stakhov vsevolod at highsecure.ru
Sun Oct 27 12:21:07 UTC 2019


Author: Vsevolod Stakhov
Date: 2019-10-27 12:19:50 +0000
URL: https://github.com/rspamd/rspamd/commit/e3a552c64ba7639f294edf24da0b062f7ca896ea (HEAD -> master)

[Fix] Lot's of fixes in maps check logic

---
 src/libutil/map.c         | 118 +++++++++++++++++++++++++++++++++++-----------
 src/libutil/map_private.h |   1 +
 src/rspamd_proxy.c        |   4 +-
 3 files changed, 94 insertions(+), 29 deletions(-)

diff --git a/src/libutil/map.c b/src/libutil/map.c
index f93eafb90..808b2a69a 100644
--- a/src/libutil/map.c
+++ b/src/libutil/map.c
@@ -43,13 +43,19 @@
 #define MAP_RELEASE(x, t) REF_RELEASE(x)
 #endif
 
+enum rspamd_map_periodic_opts {
+	RSPAMD_MAP_SCHEDULE_NORMAL = 0,
+	RSPAMD_MAP_SCHEDULE_ERROR = (1u << 0u),
+	RSPAMD_MAP_SCHEDULE_LOCKED = (1u << 1u),
+	RSPAMD_MAP_SCHEDULE_INIT = (1u << 2u),
+};
+
 static void free_http_cbdata_common (struct http_callback_data *cbd,
 									 gboolean plan_new);
 static void free_http_cbdata_dtor (gpointer p);
 static void free_http_cbdata (struct http_callback_data *cbd);
 static void rspamd_map_process_periodic (struct map_periodic_cbdata *cbd);
-static void rspamd_map_schedule_periodic (struct rspamd_map *map, gboolean locked,
-										  gboolean initial, gboolean errored);
+static void rspamd_map_schedule_periodic (struct rspamd_map *map, int how);
 static gboolean read_map_file_chunks (struct rspamd_map *map,
 									  struct map_cb_data *cbdata,
 									  const gchar *fname,
@@ -214,11 +220,7 @@ http_map_error (struct rspamd_http_connection *conn,
 				cbd->addr ? rspamd_inet_address_to_string_pretty (cbd->addr) : "",
 				err);
 
-		MAP_RETAIN (cbd->periodic, "periodic");
 		rspamd_map_process_periodic (cbd->periodic);
-		MAP_RELEASE (cbd->periodic, "periodic");
-		/* Detach periodic as rspamd_map_process_periodic will destroy it */
-		cbd->periodic = NULL;
 	}
 
 	MAP_RELEASE (cbd, "http_callback_data");
@@ -965,11 +967,13 @@ rspamd_map_periodic_dtor (struct map_periodic_cbdata *periodic)
 	}
 
 	if (periodic->locked) {
+		g_atomic_int_set (periodic->map->locked, 0);
+		msg_debug_map ("unlocked map %s", periodic->map->name);
+
 		if (!periodic->map->wrk->wanna_die) {
-			rspamd_map_schedule_periodic (periodic->map, FALSE, FALSE, FALSE);
+			rspamd_map_schedule_periodic (periodic->map,
+					RSPAMD_SYMBOL_RESULT_NORMAL);
 		}
-		g_atomic_int_set (periodic->map->locked, 0);
-		msg_debug_map ("unlocked map");
 	}
 
 	g_free (periodic);
@@ -988,10 +992,11 @@ rspamd_map_periodic_callback (struct ev_loop *loop, ev_timer *w, int revents)
 }
 
 static void
-rspamd_map_schedule_periodic (struct rspamd_map *map,
-		gboolean locked, gboolean initial, gboolean errored)
+rspamd_map_schedule_periodic (struct rspamd_map *map, int how)
 {
 	const gdouble error_mult = 20.0, lock_mult = 0.1;
+	static const gdouble min_timer_interval = 2.0;
+	const gchar *reason = "unknown reason";
 	gdouble jittered_sec;
 	gdouble timeout;
 	struct map_periodic_cbdata *cbd;
@@ -1001,49 +1006,83 @@ rspamd_map_schedule_periodic (struct rspamd_map *map,
 		return;
 	}
 
-	if (map->next_check != 0) {
+	if (map->non_trivial && map->next_check != 0) {
 		timeout = map->next_check - rspamd_get_calendar_ticks ();
 
 		if (timeout > 0 && timeout < map->poll_timeout) {
 			/* Early check case, jitter */
 			gdouble poll_timeout = map->poll_timeout;
 
-			if (errored) {
+			if (how & RSPAMD_MAP_SCHEDULE_ERROR) {
 				poll_timeout = map->poll_timeout * error_mult;
+				reason = "early active non-trivial check (after error)";
 			}
-			else if (locked) {
+			else if (how & RSPAMD_MAP_SCHEDULE_LOCKED) {
 				poll_timeout = map->poll_timeout * lock_mult;
+				reason = "early active non-trivial check (after being locked)";
+			}
+			else {
+				reason = "early active non-trivial check";
 			}
 
 			jittered_sec = MIN (timeout, poll_timeout);
+
 		}
 		else if (timeout <= 0) {
 			/* Data is already expired, need to check */
 			jittered_sec = 0.0;
+			reason = "expired non-trivial data";
 		}
 		else {
 			/* No need to check now, wait till next_check */
 			jittered_sec = timeout;
+			reason = "valid non-trivial data";
 		}
 	}
 	else {
 		timeout = map->poll_timeout;
 
-		if (initial) {
+		if (how & RSPAMD_MAP_SCHEDULE_INIT) {
 			timeout = 0.0;
+			reason = "init scheduled check";
 		}
 		else {
-			if (errored) {
+			if (how & RSPAMD_MAP_SCHEDULE_ERROR) {
 				timeout = map->poll_timeout * error_mult;
+				reason = "errored scheduled check";
 			}
-			else if (locked) {
+			else if (how & RSPAMD_MAP_SCHEDULE_LOCKED) {
 				timeout = map->poll_timeout * lock_mult;
+				reason = "locked scheduled check";
+			}
+			else {
+				reason = "normal scheduled check";
 			}
 		}
 
 		jittered_sec = rspamd_time_jitter (timeout, 0);
 	}
 
+	/* Now, we do some sanity checks for jittered seconds */
+	if (!(how & RSPAMD_MAP_SCHEDULE_INIT)) {
+		/* Never allow too low interval between timer checks, it is epxensive */
+		if (jittered_sec < min_timer_interval) {
+			jittered_sec = rspamd_time_jitter (min_timer_interval, 0);
+		}
+
+		if (map->non_trivial) {
+			/*
+			 * Even if we are reported that we need to reload cache often, we
+			 * still want to be sane in terms of events...
+			 */
+			if (jittered_sec < min_timer_interval * 2.0) {
+				if (map->nelts > 0) {
+					jittered_sec = min_timer_interval * 3.0;
+				}
+			}
+		}
+	}
+
 	cbd = g_malloc0 (sizeof (*cbd));
 	cbd->cbdata.state = 0;
 	cbd->cbdata.prev_data = *map->user_data;
@@ -1057,8 +1096,8 @@ rspamd_map_schedule_periodic (struct rspamd_map *map,
 	ev_timer_init (&cbd->ev, rspamd_map_periodic_callback, jittered_sec, 0.0);
 	ev_timer_start (map->event_loop, &cbd->ev);
 
-	msg_debug_map ("schedule new periodic event %p in %.2f seconds",
-			cbd, jittered_sec);
+	msg_debug_map ("schedule new periodic event %p in %.3f seconds for %s; reason: %s",
+			cbd, jittered_sec, map->name, reason);
 }
 
 static void
@@ -1071,6 +1110,9 @@ rspamd_map_dns_callback (struct rdns_reply *reply, void *arg)
 
 	map = cbd->map;
 
+	msg_debug_map ("got dns reply with code %s on stage %d",
+			rdns_strerror (reply->code), cbd->stage);
+
 	if (cbd->stage == http_map_terminated) {
 		MAP_RELEASE (cbd, "http_callback_data");
 		return;
@@ -1112,6 +1154,10 @@ rspamd_map_dns_callback (struct rdns_reply *reply, void *arg)
 			cbd->periodic->errored = 1;
 			rspamd_map_process_periodic (cbd->periodic);
 		}
+		else {
+			/* We have at least one address, so we can continue... */
+			cbd->stage = http_map_http_conn;
+		}
 	}
 
 	if (cbd->stage == http_map_http_conn && cbd->addrs->len > 0) {
@@ -1121,6 +1167,8 @@ rspamd_map_dns_callback (struct rdns_reply *reply, void *arg)
 		cbd->addr = (rspamd_inet_addr_t *)g_ptr_array_index (cbd->addrs,
 				selected_addr_idx);
 
+		msg_debug_map ("open http connection to %s",
+				rspamd_inet_address_to_string_pretty (cbd->addr));
 		cbd->conn = rspamd_http_connection_new_client (NULL,
 				NULL,
 				http_map_error,
@@ -1131,6 +1179,16 @@ rspamd_map_dns_callback (struct rdns_reply *reply, void *arg)
 		if (cbd->conn != NULL) {
 			write_http_request (cbd);
 		}
+		else {
+			cbd->periodic->errored = TRUE;
+			msg_err_map ("error reading %s(%s): "
+						 "connection with http server terminated incorrectly: %s",
+					cbd->bk->uri,
+					cbd->addr ? rspamd_inet_address_to_string_pretty (cbd->addr) : "",
+					strerror (errno));
+
+			rspamd_map_process_periodic (cbd->periodic);
+		}
 	}
 
 	MAP_RELEASE (cbd, "http_callback_data");
@@ -1795,28 +1853,30 @@ rspamd_map_process_periodic (struct map_periodic_cbdata *cbd)
 	if (!cbd->locked) {
 		if (!g_atomic_int_compare_and_exchange (cbd->map->locked, 0, 1)) {
 			msg_debug_map (
-					"don't try to reread map as it is locked by other process, "
-					"will reread it later");
-			rspamd_map_schedule_periodic (map, TRUE, FALSE, FALSE);
+					"don't try to reread map %s as it is locked by other process, "
+					"will reread it later", cbd->map->name);
+			rspamd_map_schedule_periodic (map, RSPAMD_MAP_SCHEDULE_LOCKED);
 			MAP_RELEASE (cbd, "periodic");
 
 			return;
 		}
 		else {
-			msg_debug_map ("locked map");
+			msg_debug_map ("locked map %s", cbd->map->name);
 			cbd->locked = TRUE;
 		}
 	}
 
 	if (cbd->errored) {
 		/* We should not check other backends if some backend has failed */
-		rspamd_map_schedule_periodic (cbd->map, FALSE, FALSE, TRUE);
+		rspamd_map_schedule_periodic (cbd->map, RSPAMD_MAP_SCHEDULE_ERROR);
 
 		if (cbd->locked) {
 			g_atomic_int_set (cbd->map->locked, 0);
+			cbd->locked = FALSE;
 		}
 
-		msg_debug_map ("unlocked map");
+		msg_debug_map ("unlocked map %s, refcount=%d", cbd->map->name,
+				cbd->ref.refcount);
 		MAP_RELEASE (cbd, "periodic");
 
 		return;
@@ -1897,7 +1957,7 @@ rspamd_map_on_stat (struct ev_loop *loop, ev_stat *w, int revents)
 				map->scheduled_check = NULL;
 			}
 
-			rspamd_map_schedule_periodic (map, FALSE, TRUE, FALSE);
+			rspamd_map_schedule_periodic (map, RSPAMD_MAP_SCHEDULE_INIT);
 		}
 	}
 }
@@ -1949,9 +2009,13 @@ rspamd_map_watch (struct rspamd_config *cfg,
 				data->st_ev.data = map;
 				ev_stat_start (event_loop, &data->st_ev);
 			}
+			else if ((bk->protocol == MAP_PROTO_HTTP ||
+					  bk->protocol == MAP_PROTO_HTTPS) && map->active_http) {
+				map->non_trivial = TRUE;
+			}
 		}
 
-		rspamd_map_schedule_periodic (map, FALSE, TRUE, FALSE);
+		rspamd_map_schedule_periodic (map, RSPAMD_MAP_SCHEDULE_INIT);
 
 		cur = g_list_next (cur);
 	}
diff --git a/src/libutil/map_private.h b/src/libutil/map_private.h
index adcdd9d98..c45f55f4b 100644
--- a/src/libutil/map_private.h
+++ b/src/libutil/map_private.h
@@ -156,6 +156,7 @@ struct rspamd_map {
 	gdouble poll_timeout;
 	time_t next_check;
 	gboolean active_http;
+	gboolean non_trivial; /* E.g. has http backends in active mode */
 	/* Shared lock for temporary disabling of map reading (e.g. when this map is written by UI) */
 	gint *locked;
 	gchar tag[MEMPOOL_UID_LEN];
diff --git a/src/rspamd_proxy.c b/src/rspamd_proxy.c
index 66ab623f8..a01a37612 100644
--- a/src/rspamd_proxy.c
+++ b/src/rspamd_proxy.c
@@ -2086,8 +2086,8 @@ proxy_milter_error_handler (gint fd,
 	struct rspamd_proxy_session *session = ud;
 
 	msg_info_session ("abnormally closing milter connection from: %s, "
-			"error: %s", rspamd_inet_address_to_string (session->client_addr),
-			err->message);
+			"error: %e", rspamd_inet_address_to_string (session->client_addr),
+			err);
 	/* Terminate session immediately */
 	proxy_backend_close_connection (session->master_conn);
 	REF_RELEASE (session);


More information about the Commits mailing list