Server bans and Spamfilters now track how often they are hit and the time

of the last hit, eg in `STATS gline` for GLINEs. These counts happen on
each individual server and are not network-wide. This allows IRCOps to see
which entries never get any hits and can potentially be removed.
* Important exception: config-based spamfilters/bans lose their counters
  on `REHASH` and restart atm.
* For non-config TKLs, the hit count and last hit timestamp are preserved
  across reboots (via tkldb).
* Again, see *Developers and protocol* for the exact STATS field.

The spamfilter hits already existed but all the rest is new.

Suggested by BlackBishop in https://bugs.unrealircd.org/view.php?id=6304
(in particular, time of the last hit)

doc/RELEASE-NOTES.md

@@ -27,6 +27,15 @@ This is work in progress and may not always be a stable version.
     or later, especially the hubs. If there is one server in-between
     that is older, then TKL IDs don't propagate properly and the ID
     will be empty.
+* Server bans and Spamfilters now track how often they are hit and the time
+  of the last hit, eg in `STATS gline` for GLINEs. These counts happen on
+  each individual server and are not network-wide. This allows IRCOps to see
+  which entries never get any hits and can potentially be removed.
+  * Important exception: config-based spamfilters/bans lose their counters
+    on `REHASH` and restart.
+  * For non-config TKLs, the hit count and last hit timestamp are preserved
+    across reboots (via tkldb).
+  * Again, see *Developers and protocol* for the exact STATS field.
 
 ### Changes:
 * Spamfilter regexes now use more sensible defaults in terms of "max effort",
@@ -72,12 +81,14 @@ This is work in progress and may not always be a stable version.
   * `RPL_STATSSPAMF` (229) ends with `lasthit lasthit_except id :regex`
     (which comes right after `hits hits_except`, which was already there)
   * `RPL_STATSEXCEPTTKL` (230) ends with `id :reason`
-  * An absent id or spamfilter_id is sent as `-`. The hits/lasthit/lasthit_except
-    fields are reserved and currently always `0`; FIXME in later commit.
+  * An absent id or spamfilter_id is sent as `-`
+  * The hits/lasthit/lasthit_except show how often the TKL was hit and
+    the timestamp of the last hit (the usual, unix time), or 0 for never.
+    These counts are local to each server.
 * `banned_client()` has an extra parameter `const char *tklid` for the
    TKL ID (or NULL if none).
-* The tkldb database version is now 6260 and stores the id and spamfilter_id.
-  FIXME: also prepared for hit stats, so update this release note line in later commit.
+* The tkldb database version is now 6260 and stores the id, spamfilter_id and
+  the hit statistics (hit count and last-hit time per ban).
   Older databases still load. Downside: you cannot downgrade UnrealIRCd.
 * JSON for TKL entries (server logs and JSON-RPC) now includes `id`, and
   `spamfilter_id` for spamfilter-created server bans.

include/h.h

@@ -847,6 +847,7 @@ extern MODVAR void (*free_tkl)(TKL *tkl);
 extern MODVAR void (*tkl_del_line)(TKL *tkl);
 extern MODVAR void (*tkl_check_local_remove_shun)(TKL *tmp);
 extern MODVAR int (*find_tkline_match)(Client *cptr, int skip_soft);
+extern MODVAR void (*tkl_hit)(Client *client, TKL *tkl);
 extern MODVAR int (*find_shun)(Client *cptr);
 extern MODVAR int (*find_spamfilter_user)(Client *client, int flags);
 extern MODVAR TKL *(*find_qline)(Client *cptr, const char *nick, int *ishold);

include/modules.h

@@ -3055,6 +3055,7 @@ enum EfunctionType {
 	EFUNC_GET_CONNECTIONS_FROM_IP,
 	EFUNC_GET_FLOODPROT_CHANNEL_MAX_LINES,
 	EFUNC_FLOODPROT_CHECK_MULTILINE_BATCH,
+	EFUNC_TKL_HIT,
 };
 
 /* Module flags */

include/struct.h

@@ -1291,8 +1291,8 @@ struct Spamfilter {
 	char *tkl_reason; /**< Reason to use for bans placed by this spamfilter, escaped by unreal_encodespace(). */
 	time_t tkl_duration; /**< Duration of bans placed by this spamfilter */
 	char *id; /**< ID */
-	long long hits; /**< Spamfilter hits (except exempts) */
 	long long hits_except; /**< Spamfilter hits by exempt clients */
+	time_t lasthit_except; /**< When an exempt client last hit this spamfilter, or 0 if never */
 	SecurityGroup *except; /**< Don't run this spamfilter at all for these users (not counting towards hits_except btw) */
 	int input_conversion;	/**< How we should handle the input */
 	/** For overriding set::spamfilter::show-message-content-on-hit
@@ -1330,6 +1330,8 @@ struct TKL {
 	time_t expire_at; /**< When this entry will expire */
 	char id[TKLIDLEN]; /**< Unique ID: assigned (random, generated by originating server) or external (eg from services), or empty string if none */
 	char spamfilter_id[TKLIDLEN]; /**< For server bans created by a spamfilter: that spamfilter's id. Empty otherwise. */
+	long long hits; /**< Number of times this TKL was enforced (counted locally on this server) */
+	time_t lasthit; /**< When this TKL was last enforced, or 0 if never */
 	union {
 		Spamfilter *spamfilter;
 		ServerBan *serverban;

src/api-efunctions.c

@@ -73,6 +73,7 @@ TKL *(*tkl_add_banexception)(int type, const char *usermask, const char *hostmas
 void (*tkl_del_line)(TKL *tkl);
 void (*tkl_check_local_remove_shun)(TKL *tmp);
 int (*find_tkline_match)(Client *client, int skip_soft);
+void (*tkl_hit)(Client *client, TKL *tkl);
 int (*find_shun)(Client *client);
 int(*find_spamfilter_user)(Client *client, int flags);
 TKL *(*find_qline)(Client *client, const char *nick, int *ishold);
@@ -422,6 +423,7 @@ void efunctions_init(void)
 	efunc_init_function(EFUNC_TKL_DEL_LINE, tkl_del_line, NULL, 0);
 	efunc_init_function(EFUNC_TKL_CHECK_LOCAL_REMOVE_SHUN, tkl_check_local_remove_shun, NULL, 0);
 	efunc_init_function(EFUNC_FIND_TKLINE_MATCH, find_tkline_match, NULL, 0);
+	efunc_init_function(EFUNC_TKL_HIT, tkl_hit, NULL, 0);
 	efunc_init_function(EFUNC_FIND_SHUN, find_shun, NULL, 0);
 	efunc_init_function(EFUNC_FIND_SPAMFILTER_USER, find_spamfilter_user, NULL, 0);
 	efunc_init_function(EFUNC_FIND_QLINE, find_qline, NULL, 0);

src/json.c

@@ -596,11 +596,15 @@ void json_expand_tkl(json_t *root, const char *key, TKL *tkl, int detail)
 		json_object_set_new(j, "reason", json_string_unreal(tkl->ptr.serverban->reason));
 		if (tkl->spamfilter_id[0])
 			json_object_set_new(j, "spamfilter_id", json_string_unreal(tkl->spamfilter_id));
+		json_object_set_new(j, "hits", json_integer(tkl->hits));
+		json_object_set_new(j, "last_hit_at", json_timestamp(tkl->lasthit));
 	} else
 	if (TKLIsNameBan(tkl))
 	{
 		json_object_set_new(j, "name", json_string_unreal(tkl->ptr.nameban->name));
 		json_object_set_new(j, "reason", json_string_unreal(tkl->ptr.nameban->reason));
+		json_object_set_new(j, "hits", json_integer(tkl->hits));
+		json_object_set_new(j, "last_hit_at", json_timestamp(tkl->lasthit));
 	} else
 	if (TKLIsBanException(tkl))
 	{
@@ -627,8 +631,10 @@ void json_expand_tkl(json_t *root, const char *key, TKL *tkl, int detail)
 		json_object_set_new(j, "ban_duration_string", json_string_unreal(pretty_time_val_r(buf, sizeof(buf), tkl->ptr.spamfilter->tkl_duration)));
 		json_object_set_new(j, "spamfilter_targets", json_string_unreal(spamfilter_target_inttostring(tkl->ptr.spamfilter->target)));
 		json_object_set_new(j, "reason", json_string_unreal(unreal_decodespace(tkl->ptr.spamfilter->tkl_reason)));
-		json_object_set_new(j, "hits", json_integer(tkl->ptr.spamfilter->hits));
+		json_object_set_new(j, "hits", json_integer(tkl->hits));
+		json_object_set_new(j, "last_hit_at", json_timestamp(tkl->lasthit));
 		json_object_set_new(j, "hits_except", json_integer(tkl->ptr.spamfilter->hits_except));
+		json_object_set_new(j, "last_hit_except_at", json_timestamp(tkl->ptr.spamfilter->lasthit_except));
 	}
 }
 

src/modules/join.c

@@ -486,6 +486,7 @@ void _do_join(Client *client, int parc, const char *parv[])
 			}
 			if (!ValidatePermissionsForPath("immune:server-ban:deny-channel",client,NULL,NULL,NULL) && (tklban = find_qline(client, name, &ishold)))
 			{
+				tkl_hit(client, tklban);
 				sendnumeric(client, ERR_FORBIDDENCHANNEL, name, tklban->ptr.nameban->reason);
 				continue;
 			}

src/modules/nick.c

@@ -314,6 +314,7 @@ CMD_FUNC(cmd_nick_local)
 		}
 		if (!ValidatePermissionsForPath("immune:server-ban:ban-nick",client,NULL,NULL,nick))
 		{
+			tkl_hit(client, tklban);
 			add_fake_lag(client, 4000); /* lag them up */
 			sendnumeric(client, ERR_ERRONEUSNICKNAME, nick, tklban->ptr.nameban->reason);
 			unreal_log(ULOG_INFO, "nick", "QLINE_NICK_LOCAL_ATTEMPT", client,

src/modules/rpc/user.c

@@ -254,6 +254,7 @@ RPC_CALL_FUNC(rpc_user_set_nick)
 		/* Check other restrictions */
 		Client *check = find_user(newnick, NULL);
 		int ishold = 0;
+		TKL *tklban;
 
 		/* Check if in use by someone else (do allow case-changing) */
 		if (check && (acptr != check))
@@ -265,8 +266,9 @@ RPC_CALL_FUNC(rpc_user_set_nick)
 		// Can't really check for spamfilter here, since it assumes user is local
 
 		// But we can check q-lines...
-		if (find_qline(acptr, newnick, &ishold))
+		if ((tklban = find_qline(acptr, newnick, &ishold)))
 		{
+			tkl_hit(acptr, tklban);
 			rpc_error(client, request, JSON_RPC_ERROR_INVALID_NAME, "New nickname is forbidden by q-line");
 			return;
 		}

src/modules/tkl.c

@@ -55,6 +55,7 @@ CMD_FUNC(cmd_eline);
 CMD_FUNC(cmd_spaminfo);
 void cmd_tkl_line(Client *client, int parc, const char *parv[], char *type);
 int _tkl_hash(unsigned int c);
+void _tkl_hit(Client *client, TKL *tkl);
 char _tkl_typetochar(int type);
 int _tkl_chartotype(char c);
 char _tkl_configtypetochar(const char *name);
@@ -222,6 +223,7 @@ MOD_TEST()
 	EfunctionAddVoid(modinfo->handle, EFUNC_FREE_TKL, _free_tkl);
 	EfunctionAddVoid(modinfo->handle, EFUNC_TKL_CHECK_LOCAL_REMOVE_SHUN, _tkl_check_local_remove_shun);
 	EfunctionAdd(modinfo->handle, EFUNC_FIND_TKLINE_MATCH, _find_tkline_match);
+	EfunctionAddVoid(modinfo->handle, EFUNC_TKL_HIT, _tkl_hit);
 	EfunctionAdd(modinfo->handle, EFUNC_FIND_SHUN, _find_shun);
 	EfunctionAdd(modinfo->handle, EFUNC_FIND_SPAMFILTER_USER, _find_spamfilter_user);
 	EfunctionAddPVoid(modinfo->handle, EFUNC_FIND_QLINE, TO_PVOIDFUNC(_find_qline));
@@ -1497,6 +1499,16 @@ static const char *spamfilter_fallback_id(TKL *tkl)
 	return buf;
 }
 
+/** Called when a TKL is enforced against a client: bump its hit counter and
+ * remember when. Call this while 'client' is still valid (before the client is
+ * exited), so it stays safe if we later add a hook here.
+ */
+void _tkl_hit(Client *client, TKL *tkl)
+{
+	tkl->hits++;
+	tkl->lasthit = TStime();
+}
+
 /* Warn opers when a spamfilter regex could not finish (eg. it hit the
  * PCRE2 match or depth limit). The match is treated as no-match, so we
  * only warn and do not remove the spamfilter.
@@ -1523,7 +1535,10 @@ int tkl_ip_change(Client *client, const char *oldip)
 {
 	TKL *tkl;
 	if ((tkl = find_tkline_match_zap(client)))
+	{
+		tkl_hit(client, tkl);
 		banned_client(client, "Z-Lined", tkl->ptr.serverban->reason, tkl->id, (tkl->type & TKL_GLOBAL)?1:0, NO_EXIT_CLIENT);
+	}
 	return 0;
 }
 
@@ -1532,6 +1547,7 @@ int tkl_accept(Client *client)
 	TKL *tkl;
 	if ((tkl = find_tkline_match_zap(client)))
 	{
+		tkl_hit(client, tkl);
 		banned_client(client, "Z-Lined", tkl->ptr.serverban->reason, tkl->id, (tkl->type & TKL_GLOBAL)?1:0, NO_EXIT_CLIENT);
 		return 2; // TODO: HOOK_DENY_ALWAYS;
 	}
@@ -3916,6 +3932,7 @@ int _find_tkline_match(Client *client, int skip_soft)
 	if (tkl->type & TKL_KILL)
 	{
 		ircstats.is_ref++;
+		tkl_hit(client, tkl);
 		if (tkl->type & TKL_GLOBAL)
 			banned_client(client, "G-Lined", tkl->ptr.serverban->reason, tkl->id, 1, 0);
 		else
@@ -3925,6 +3942,7 @@ int _find_tkline_match(Client *client, int skip_soft)
 	if (tkl->type & TKL_ZAP)
 	{
 		ircstats.is_ref++;
+		tkl_hit(client, tkl);
 		banned_client(client, "Z-Lined", tkl->ptr.serverban->reason, tkl->id, (tkl->type & TKL_GLOBAL)?1:0, 0);
 		return 1; /* killed */
 	}
@@ -3967,6 +3985,7 @@ int _find_shun(Client *client)
 				/* Found match. Now check for exception... */
 				if (find_tkl_exception(TKL_SHUN, client))
 					return 0;
+				tkl_hit(client, tkl);
 				SetShunned(client);
 				return 1;
 			}
@@ -4337,7 +4356,7 @@ int tkl_stats_matcher(Client *client, int type, const char *para, TKLFlag *tklfl
 			{
 				sendnumeric(client, RPL_STATSGLINE, 'K', namevalue_nospaces(m),
 					   (tkl->expire_at != 0) ? (long long)(tkl->expire_at - TStime()) : 0,
-					   (long long)(TStime() - tkl->set_at), tkl->set_by, (long long)0, (long long)0, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
+					   (long long)(TStime() - tkl->set_at), tkl->set_by, tkl->hits, (long long)tkl->lasthit, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
 
 			}
 		} else {
@@ -4347,31 +4366,31 @@ int tkl_stats_matcher(Client *client, int type, const char *para, TKLFlag *tklfl
 			{
 				sendnumeric(client, RPL_STATSGLINE, 'G', uhost,
 					   (tkl->expire_at != 0) ? (long long)(tkl->expire_at - TStime()) : 0,
-					   (long long)(TStime() - tkl->set_at), tkl->set_by, (long long)0, (long long)0, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
+					   (long long)(TStime() - tkl->set_at), tkl->set_by, tkl->hits, (long long)tkl->lasthit, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
 			} else
 			if (tkl->type == (TKL_ZAP | TKL_GLOBAL))
 			{
 				sendnumeric(client, RPL_STATSGLINE, 'Z', uhost,
 					   (tkl->expire_at != 0) ? (long long)(tkl->expire_at - TStime()) : 0,
-					   (long long)(TStime() - tkl->set_at), tkl->set_by, (long long)0, (long long)0, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
+					   (long long)(TStime() - tkl->set_at), tkl->set_by, tkl->hits, (long long)tkl->lasthit, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
 			} else
 			if (tkl->type == (TKL_SHUN | TKL_GLOBAL))
 			{
 				sendnumeric(client, RPL_STATSGLINE, 's', uhost,
 					   (tkl->expire_at != 0) ? (long long)(tkl->expire_at - TStime()) : 0,
-					   (long long)(TStime() - tkl->set_at), tkl->set_by, (long long)0, (long long)0, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
+					   (long long)(TStime() - tkl->set_at), tkl->set_by, tkl->hits, (long long)tkl->lasthit, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
 			} else
 			if (tkl->type == (TKL_KILL))
 			{
 				sendnumeric(client, RPL_STATSGLINE, 'K', uhost,
 					   (tkl->expire_at != 0) ? (long long)(tkl->expire_at - TStime()) : 0,
-					   (long long)(TStime() - tkl->set_at), tkl->set_by, (long long)0, (long long)0, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
+					   (long long)(TStime() - tkl->set_at), tkl->set_by, tkl->hits, (long long)tkl->lasthit, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
 			} else
 			if (tkl->type == (TKL_ZAP))
 			{
 				sendnumeric(client, RPL_STATSGLINE, 'z', uhost,
 					   (tkl->expire_at != 0) ? (long long)(tkl->expire_at - TStime()) : 0,
-					   (long long)(TStime() - tkl->set_at), tkl->set_by, (long long)0, (long long)0, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
+					   (long long)(TStime() - tkl->set_at), tkl->set_by, tkl->hits, (long long)tkl->lasthit, spamfilter_id_str, id_str, tkl->ptr.serverban->reason);
 			}
 		}
 	} else
@@ -4387,10 +4406,10 @@ int tkl_stats_matcher(Client *client, int type, const char *para, TKLFlag *tklfl
 			(long long)tkl->ptr.spamfilter->tkl_duration,
 			tkl->ptr.spamfilter->tkl_reason,
 			tkl->set_by,
-			tkl->ptr.spamfilter->hits,
+			tkl->hits,
 			tkl->ptr.spamfilter->hits_except,
-			(long long)0,
-			(long long)0,
+			(long long)tkl->lasthit,
+			(long long)tkl->ptr.spamfilter->lasthit_except,
 			id_str,
 			tkl->ptr.spamfilter->match->str);
 		if (para && !strcasecmp(para, "del"))
@@ -4410,8 +4429,8 @@ int tkl_stats_matcher(Client *client, int type, const char *para, TKLFlag *tklfl
 		            (tkl->expire_at != 0) ? (long long)(tkl->expire_at - TStime()) : 0,
 		            (long long)(TStime() - tkl->set_at),
 		            tkl->set_by,
-		            (long long)0,
-		            (long long)0,
+		            tkl->hits,
+		            (long long)tkl->lasthit,
 		            id_str,
 		            tkl->ptr.nameban->reason);
 	} else
@@ -5760,9 +5779,10 @@ static void match_spamfilter_hit(Client *client, const char *str_in, const char
 	if (match_spamfilter_exempt(tkl, user_is_exempt_general, user_is_exempt_central))
 	{
 		tkl->ptr.spamfilter->hits_except++;
+		tkl->ptr.spamfilter->lasthit_except = TStime();
 	} else
 	{
-		tkl->ptr.spamfilter->hits++;
+		tkl_hit(client, tkl);
 		highest_action = highest_ban_action(tkl->ptr.spamfilter->action);
 		if (highest_action > BAN_ACT_SET)
 		{

src/modules/tkldb.c

@@ -404,12 +404,9 @@ int write_tkline(UnrealDB *db, const char *tmpfname, TKL *tkl)
 	W_SAFE(unrealdb_write_str(db, tkl->id));     /* since TKLDB_VERSION 6260 */
 	W_SAFE(unrealdb_write_str(db, tkl->spamfilter_id)); /* since TKLDB_VERSION 6260 */
 
-	/* Reserved hit-stat fields for all TKL types (since TKLDB_VERSION 6260):
-	 * hits, lasthit. Written as 0 for now; a later release will populate them
-	 * (for non-config TKLs).
-	 */
-	W_SAFE(unrealdb_write_int64(db, 0));
-	W_SAFE(unrealdb_write_int64(db, 0));
+	/* Hit-stat fields for all TKL types (since TKLDB_VERSION 6260): hits, lasthit. */
+	W_SAFE(unrealdb_write_int64(db, tkl->hits));
+	W_SAFE(unrealdb_write_int64(db, tkl->lasthit));
 
 	if (TKLIsServerBan(tkl))
 	{
@@ -455,11 +452,9 @@ int write_tkline(UnrealDB *db, const char *tmpfname, TKL *tkl)
 		W_SAFE(unrealdb_write_char(db, action));
 		W_SAFE(unrealdb_write_str(db, tkl->ptr.spamfilter->tkl_reason));
 		W_SAFE(unrealdb_write_int64(db, tkl->ptr.spamfilter->tkl_duration));
-		/* Reserved spamfilter-only hit-stat fields (since TKLDB_VERSION 6260):
-		 * hits_except, lasthit_except. Written as 0 for now.
-		 */
-		W_SAFE(unrealdb_write_int64(db, 0));
-		W_SAFE(unrealdb_write_int64(db, 0));
+		/* Spamfilter-only hit-stat fields (since TKLDB_VERSION 6260): hits_except, lasthit_except. */
+		W_SAFE(unrealdb_write_int64(db, tkl->ptr.spamfilter->hits_except));
+		W_SAFE(unrealdb_write_int64(db, tkl->ptr.spamfilter->lasthit_except));
 	}
 
 	return 1;
@@ -580,11 +575,11 @@ int read_tkldb(void)
 			R_SAFE(unrealdb_read_str(db, &str));
 			strlcpy(tkl->spamfilter_id, str, sizeof(tkl->spamfilter_id));
 			safe_free(str);
-			/* Reserved hit-stat fields for all TKL types (hits, lasthit).
-			 * Read and discarded for now; a later release will use them.
-			 */
+			/* Hit-stat fields for all TKL types (hits, lasthit). */
 			R_SAFE(unrealdb_read_int64(db, &v));
+			tkl->hits = v;
 			R_SAFE(unrealdb_read_int64(db, &v));
+			tkl->lasthit = v;
 		}
 
 		/* Save some CPU... if it's already expired then don't bother adding */
@@ -757,12 +752,13 @@ int read_tkldb(void)
 			R_SAFE(unrealdb_read_str(db, &tkl->ptr.spamfilter->tkl_reason));
 			R_SAFE(unrealdb_read_int64(db, &v));
 			tkl->ptr.spamfilter->tkl_duration = v;
-			/* Reserved spamfilter-only hit-stat fields (hits_except,
-			 * lasthit_except). Read and discarded for now. */
+			/* Spamfilter-only hit-stat fields (hits_except, lasthit_except). */
 			if (version >= 6260)
 			{
 				R_SAFE(unrealdb_read_int64(db, &v));
+				tkl->ptr.spamfilter->hits_except = v;
 				R_SAFE(unrealdb_read_int64(db, &v));
+				tkl->ptr.spamfilter->lasthit_except = v;
 			}
 
 			if (!do_not_add &&
@@ -813,6 +809,13 @@ int read_tkldb(void)
 		{
 			strlcpy(added->id, tkl->id, sizeof(added->id));
 			strlcpy(added->spamfilter_id, tkl->spamfilter_id, sizeof(added->spamfilter_id));
+			added->hits = tkl->hits;
+			added->lasthit = tkl->lasthit;
+			if (TKLIsSpamfilter(added))
+			{
+				added->ptr.spamfilter->hits_except = tkl->ptr.spamfilter->hits_except;
+				added->ptr.spamfilter->lasthit_except = tkl->ptr.spamfilter->lasthit_except;
+			}
 		}
 
 		if (!do_not_add)