From e5be93a9f811c91e93f70ffc4a4524ee2bc3ee6d Mon Sep 17 00:00:00 2001 From: Bram Matthys Date: Tue, 5 May 2026 18:59:50 +0200 Subject: [PATCH] Suppress high rate events via set::log-throttle (similar to Linux kernel) And ship with these by default (no need to copy this set block): set { log-throttle { CONNTHROTTLE_IPV6_LIMIT 100:60; MAXPERIP_LIMIT 100:60; }; }; You can do the same for other events, or even override existing ones, and use the special value "unlimited" to turn default set ratelimits off: set { log-throttle { CONNTHROTTLE_IPV6_LIMIT 50:60; MAXPERIP_LIMIT unlimited; }; }; Suggested in 2020 at https://bugs.unrealircd.org/view.php?id=5523 (and keeping it simple) --- include/dynconf.h | 10 +++ include/h.h | 33 ++++++- src/conf.c | 58 ++++++++++++ src/ircd.c | 2 + src/log.c | 219 ++++++++++++++++++++++++++++++++++++++++++++++ 5 files changed, 318 insertions(+), 4 deletions(-) diff --git a/include/dynconf.h b/include/dynconf.h index 27572dc9c..4385c2fa5 100644 --- a/include/dynconf.h +++ b/include/dynconf.h @@ -32,6 +32,15 @@ struct FloodSettings { long period[MAXFLOODOPTIONS]; }; +typedef struct LogThrottleConfig LogThrottleConfig; +struct LogThrottleConfig { + LogThrottleConfig *prev, *next; + char *event_id; /**< the event_id this policy applies to */ + int threshold; /**< per-window cap */ + int period; /**< window length in seconds */ + int unlimited; /**< if set, never throttle */ +}; + enum UHAllowed { UHALLOW_ALWAYS, UHALLOW_NOCHANS, UHALLOW_REJOIN, UHALLOW_NEVER }; struct ChMode { @@ -114,6 +123,7 @@ struct Configuration { int modes_on_join_set; char *level_on_join; FloodSettings *floodsettings; + LogThrottleConfig *log_throttle; int ident_connect_timeout; int ident_read_timeout; long default_bantime; diff --git a/include/h.h b/include/h.h index e3c239528..233707863 100644 --- a/include/h.h +++ b/include/h.h @@ -1422,11 +1422,29 @@ extern const char *log_type_valtostring(LogType v); * parameters explicitly, put log_data_source() at the beginning of the argument list * and then use non-portable ## __VA_ARGS__ for the remainder. */ -#define unreal_log(...) do { LogData *lds = log_data_source(__FILE__, __LINE__, __FUNCTION__); do_unreal_log(__VA_ARGS__, lds, NULL); log_data_free(lds); } while(0) -#define unreal_log_raw(...) do { LogData *lds = log_data_source(__FILE__, __LINE__, __FUNCTION__); do_unreal_log_raw(__VA_ARGS__, lds, NULL); log_data_free(lds); } while(0) +#define unreal_log(level, sys, id, ...) do { \ + if (!log_throttled((sys), (id))) { \ + LogData *lds = log_data_source(__FILE__, __LINE__, __FUNCTION__); \ + do_unreal_log((level), (sys), (id), __VA_ARGS__, lds, NULL); \ + log_data_free(lds); \ + } \ + } while(0) +#define unreal_log_raw(level, sys, id, ...) do { \ + if (!log_throttled((sys), (id))) { \ + LogData *lds = log_data_source(__FILE__, __LINE__, __FUNCTION__); \ + do_unreal_log_raw((level), (sys), (id), __VA_ARGS__, lds, NULL); \ + log_data_free(lds); \ + } \ + } while(0) #else -#define unreal_log(...) do_unreal_log(__VA_ARGS__, NULL) -#define unreal_log_raw(...) do_unreal_log_raw(__VA_ARGS__, NULL) +#define unreal_log(level, sys, id, ...) do { \ + if (!log_throttled((sys), (id))) \ + do_unreal_log((level), (sys), (id), __VA_ARGS__, NULL); \ + } while(0) +#define unreal_log_raw(level, sys, id, ...) do { \ + if (!log_throttled((sys), (id))) \ + do_unreal_log_raw((level), (sys), (id), __VA_ARGS__, NULL); \ + } while(0) #endif extern void do_unreal_log(LogLevel loglevel, const char *subsystem, const char *event_id, Client *client, const char *msg, ...) __attribute__((format(printf,5,0))); extern void do_unreal_log_raw(LogLevel loglevel, const char *subsystem, const char *event_id, Client *client, const char *msg, ...); @@ -1448,6 +1466,13 @@ extern void log_pre_rehash(void); extern int log_tests(void); extern void config_pre_run_log(void); extern void log_blocks_switchover(void); +extern void log_throttle_init(void); +extern int log_throttled(const char *subsystem, const char *event_id); +extern void log_throttle_rehash(void); +extern void free_log_throttle_config(LogThrottleConfig *c); +extern LogThrottleConfig *find_log_throttle_config(LogThrottleConfig *list, const char *event_id); +extern void add_log_throttle_config(LogThrottleConfig **list, const char *event_id, int threshold, int period, int unlimited); +extern EVENT(log_throttle_flush); extern void postconf_defaults_log_block(void); extern int valid_loglevel(int v); extern LogLevel log_level_stringtoval(const char *str); diff --git a/src/conf.c b/src/conf.c index 708491f3d..c1c430c5b 100644 --- a/src/conf.c +++ b/src/conf.c @@ -1811,6 +1811,9 @@ void free_iConf(Configuration *i) } i->floodsettings = NULL; + free_log_throttle_config(i->log_throttle); + i->log_throttle = NULL; + /* And zero out everything, too easy to make a mistake above. */ memset(i, 0, sizeof(Configuration)); } @@ -1895,6 +1898,9 @@ void config_setdefaultsettings(Configuration *i) config_parse_flood_generic("90:1000", i, "unknown-users", FLD_LAG_PENALTY); /* 90 bytes / 1000 msec */ config_parse_flood_generic("7:1500", i, "unknown-users", FLD_MULTILINE); /* max-lines=7, max-bytes=1500 */ + add_log_throttle_config(&i->log_throttle, "CONNTHROTTLE_IPV6_LIMIT", 100, 60, 0); + add_log_throttle_config(&i->log_throttle, "MAXPERIP_LIMIT", 100, 60, 0); + /* TLS options */ i->tls_options = safe_alloc(sizeof(TLSOptions)); snprintf(tmp, sizeof(tmp), "%s/tls/curl-ca-bundle.crt", CONFDIR); @@ -2921,6 +2927,7 @@ void config_switchover(void) memcpy(&iConf, &tempiConf, sizeof(iConf)); memset(&tempiConf, 0, sizeof(tempiConf)); log_blocks_switchover(); + log_throttle_rehash(); } /** Priority of config blocks during CONFIG_TEST stage */ @@ -8146,6 +8153,23 @@ int _conf_set(ConfigFile *conf, ConfigEntry *ce) } } } + else if (!strcmp(cep->name, "log-throttle")) + { + for (cepp = cep->items; cepp; cepp = cepp->next) + { + if (!cepp->name || !cepp->value) + continue; + if (!strcmp(cepp->value, "unlimited") || !strcmp(cepp->value, "max")) + { + add_log_throttle_config(&tempiConf.log_throttle, cepp->name, 0, 0, 1); + } else + { + int cnt = 0, period = 0; + config_parse_flood(cepp->value, &cnt, &period); + add_log_throttle_config(&tempiConf.log_throttle, cepp->name, cnt, period, 0); + } + } + } else if (!strcmp(cep->name, "options")) { for (cepp = cep->items; cepp; cepp = cepp->next) { if (!strcmp(cepp->name, "hide-ulines")) { @@ -9335,6 +9359,40 @@ int _test_set(ConfigFile *conf, ConfigEntry *ce) "https://www.unrealircd.org/docs/Anti-flood_settings"); } } + else if (!strcmp(cep->name, "log-throttle")) + { + for (cepp = cep->items; cepp; cepp = cepp->next) + { + int cnt = 0, period = 0; + if (!cepp->name) + continue; + if (!cepp->value) + { + config_error("%s:%i: set::log-throttle::%s: missing value " + "(need 'count:period' or 'unlimited')", + cepp->file->filename, cepp->line_number, cepp->name); + errors++; + continue; + } + if (!valid_event_id(cepp->name)) + { + config_error("%s:%i: set::log-throttle::%s: invalid event_id name " + "(must contain only uppercase A-Z, 0-9 and underscores)", + cepp->file->filename, cepp->line_number, cepp->name); + errors++; + continue; + } + if (!strcmp(cepp->value, "unlimited") || !strcmp(cepp->value, "max")) + continue; + if (!config_parse_flood(cepp->value, &cnt, &period) || (cnt < 1) || (period < 1)) + { + config_error("%s:%i: set::log-throttle::%s: invalid value '%s'. " + "Syntax is ':' (eg 100:60), or 'unlimited'", + cepp->file->filename, cepp->line_number, cepp->name, cepp->value); + errors++; + } + } + } else if (!strcmp(cep->name, "options")) { for (cepp = cep->items; cepp; cepp = cepp->next) { if (!strcmp(cepp->name, "hide-ulines")) diff --git a/src/ircd.c b/src/ircd.c index 046767c75..74b9b27ba 100644 --- a/src/ircd.c +++ b/src/ircd.c @@ -502,6 +502,7 @@ void SetupEvents(void) EventAdd(NULL, "detect_high_connection_rate", detect_high_connection_rate, NULL, 1000*DETECT_HIGH_CONNECTION_RATE_SAMPLE_TIME, 0); EventAdd(NULL, "central_spamfilter_download_evt", central_spamfilter_download_evt, NULL, 5000, 0); EventAdd(NULL, "update_known_user_cache_timer", update_known_user_cache_timer, NULL, 5000, 0); + EventAdd(NULL, "log_throttle_flush", log_throttle_flush, NULL, 5000, 0); } /** The main function. This will call SocketLoop() once the server is ready. */ @@ -545,6 +546,7 @@ int InitUnrealIRCd(int argc, char *argv[]) memset(&loop, 0, sizeof(loop)); init_hash(); + log_throttle_init(); SetupEvents(); diff --git a/src/log.c b/src/log.c index 0bf4b35d5..079988b18 100644 --- a/src/log.c +++ b/src/log.c @@ -31,6 +31,20 @@ #define show_event_console 0 #define MAXLOGLENGTH 16384 /**< Maximum length of a log entry (which may be multiple lines) */ +#define LOG_THROTTLE_TABLE_SIZE 256 + +typedef struct LogThrottleEntry LogThrottleEntry; +struct LogThrottleEntry { + LogThrottleEntry *next; /**< next entry in the same hash bucket */ + char *event_id; /**< the event_id this entry tracks */ + char *subsystem_last; /**< most recent subsystem seen, for the summary line */ + time_t window_start; /**< when the current window opened */ + int hits; /**< total events in the current window */ + int suppressed; /**< events beyond threshold in the current window */ + int threshold; /**< limit: number of events (per window cap) */ + int period; /**< limit: in what period (window length in seconds) */ + int unlimited; /**< if set, never throttle */ +}; /* Variables */ Log *logs[NUM_LOG_DESTINATIONS] = { NULL, NULL, NULL, NULL, NULL, NULL }; @@ -44,6 +58,9 @@ LogEntry *memory_log = NULL; /**< Log entries in memory (OLDEST entry) */ LogEntry *memory_log_tail = NULL; /**< Tail of log entries in memory (NEWEST entry) */ int memory_log_entries = 0; /**< Number of memory_log entries */ +static LogThrottleEntry *log_throttle_table[LOG_THROTTLE_TABLE_SIZE]; +static char log_throttle_siphashkey[SIPHASH_KEY_LENGTH]; + /* Forward declarations */ int log_sources_match(LogSource *logsource, LogLevel loglevel, const char *subsystem, const char *event_id, int matched_already); void do_unreal_log_internal(LogLevel loglevel, const char *subsystem, const char *event_id, Client *client, int expand_msg, const char *msg, va_list vl); @@ -1522,6 +1539,208 @@ void do_unreal_log_free_args(va_list vl) static int unreal_log_recursion_trap = 0; +static const char *log_throttle_subsystem_or(const LogThrottleEntry *e) +{ + return e->subsystem_last ? e->subsystem_last : "unknown"; +} + +LogThrottleConfig *find_log_throttle_config(LogThrottleConfig *list, const char *event_id) +{ + LogThrottleConfig *p; + for (p = list; p; p = p->next) + if (!strcmp(p->event_id, event_id)) + return p; + return NULL; +} + +/* Lookups walk head-first and the parser prepends after defaults are seeded, + * so admin overrides naturally win over defaults. + */ +void add_log_throttle_config(LogThrottleConfig **list, const char *event_id, + int threshold, int period, int unlimited) +{ + LogThrottleConfig *t = safe_alloc(sizeof(LogThrottleConfig)); + safe_strdup(t->event_id, event_id); + t->threshold = threshold; + t->period = period; + t->unlimited = unlimited; + AddListItem(t, *list); +} + +static int resolve_log_throttle_policy(const char *event_id, + int *threshold, int *period, int *unlimited) +{ + LogThrottleConfig *c = find_log_throttle_config(iConf.log_throttle, event_id); + if (!c) + return 0; + *unlimited = c->unlimited; + *threshold = c->threshold; + *period = c->period; + return 1; +} + +void log_throttle_init(void) +{ + siphash_generate_key(log_throttle_siphashkey); + memset(log_throttle_table, 0, sizeof(log_throttle_table)); +} + +static unsigned int hash_log_throttle_entry(const char *event_id) +{ + return (unsigned int)(siphash_nocase(event_id, log_throttle_siphashkey) + % LOG_THROTTLE_TABLE_SIZE); +} + +static LogThrottleEntry *find_log_throttle_entry(const char *event_id, unsigned int idx) +{ + LogThrottleEntry *e; + for (e = log_throttle_table[idx]; e; e = e->next) + if (!strcmp(e->event_id, event_id)) + return e; + return NULL; +} + +static LogThrottleEntry *add_log_throttle_entry(const char *event_id, const char *subsystem, + int threshold, int period, int unlimited, + unsigned int idx) +{ + LogThrottleEntry *e = safe_alloc(sizeof(LogThrottleEntry)); + safe_strdup(e->event_id, event_id); + if (subsystem) + safe_strdup(e->subsystem_last, subsystem); + e->threshold = threshold; + e->period = period; + e->unlimited = unlimited; + e->window_start = TStime(); + e->next = log_throttle_table[idx]; + log_throttle_table[idx] = e; + return e; +} + +static void emit_log_throttle_summary(LogThrottleEntry *e) +{ + int suppressed = e->suppressed; + int period = e->period; + + /* Reset BEFORE emitting so any re-entry sees a clean state. */ + e->hits = 0; + e->suppressed = 0; + e->window_start = TStime(); + + if (suppressed <= 0) + return; + + unreal_log(ULOG_INFO, "log", "LOG_RATE_LIMIT_SUMMARY", NULL, + "Suppressed $count log entries with event_id $throttled_event_id " + "(subsystem $throttled_subsystem) over the last $period seconds", + log_data_integer("count", suppressed), + log_data_string("throttled_event_id", e->event_id), + log_data_string("throttled_subsystem", log_throttle_subsystem_or(e)), + log_data_integer("period", period)); +} + +/* Returns 1 if this log line should be suppressed. + * On the suppressed branch the caller never evaluates its log_data_*() varargs. + */ +int log_throttled(const char *subsystem, const char *event_id) +{ + LogThrottleEntry *e; + unsigned int idx; + int threshold, period, unlimited; + + if (!event_id) + return 0; + /* The summary itself, and BUG_LOG_* meta-errors, must never be throttled. */ + if (!strcmp(event_id, "LOG_RATE_LIMIT_SUMMARY")) + return 0; + if (subsystem && !strcmp(subsystem, "log")) + return 0; + + idx = hash_log_throttle_entry(event_id); + e = find_log_throttle_entry(event_id, idx); + + if (!e) + { + if (!resolve_log_throttle_policy(event_id, &threshold, &period, &unlimited)) + return 0; + e = add_log_throttle_entry(event_id, subsystem, threshold, period, unlimited, idx); + e->hits = 1; + return 0; + } + + if (subsystem && (!e->subsystem_last || strcmp(e->subsystem_last, subsystem))) + safe_strdup(e->subsystem_last, subsystem); + + if (e->unlimited) + return 0; + + if (TStime() - e->window_start >= e->period) + emit_log_throttle_summary(e); /* no-op when suppressed==0 */ + + e->hits++; + if (e->hits <= e->threshold) + return 0; + + e->suppressed++; + return 1; +} + +/* Catches windows that closed silently (no further events to trigger lazy expiry). */ +EVENT(log_throttle_flush) +{ + int i; + time_t now = TStime(); + LogThrottleEntry *e; + + for (i = 0; i < LOG_THROTTLE_TABLE_SIZE; i++) + { + for (e = log_throttle_table[i]; e; e = e->next) + { + if (e->unlimited) + continue; + if (e->suppressed > 0 && now - e->window_start >= e->period) + emit_log_throttle_summary(e); + } + } +} + +/* Counters survive across rehash so suppression progress is not reset + * mid-attack; only threshold/period/unlimited are refreshed. + */ +void log_throttle_rehash(void) +{ + int i, threshold, period, unlimited; + LogThrottleEntry *e; + + for (i = 0; i < LOG_THROTTLE_TABLE_SIZE; i++) + { + for (e = log_throttle_table[i]; e; e = e->next) + { + if (resolve_log_throttle_policy(e->event_id, &threshold, &period, &unlimited)) + { + e->threshold = threshold; + e->period = period; + e->unlimited = unlimited; + } + else + { + e->unlimited = 1; + } + } + } +} + +void free_log_throttle_config(LogThrottleConfig *c) +{ + LogThrottleConfig *next; + for (; c; c = next) + { + next = c->next; + safe_free(c->event_id); + safe_free(c); + } +} + /* Logging function, called by the unreal_log() macro. */ void do_unreal_log(LogLevel loglevel, const char *subsystem, const char *event_id, Client *client, const char *msg, ...)