From: Frank Lahm Date: Sun, 19 Sep 2010 15:27:53 +0000 (+0200) Subject: log flooding prevention X-Git-Url: https://arthur.barton.de/cgi-bin/gitweb.cgi?p=netatalk.git;a=commitdiff_plain;h=308bdcf282961837e3132356b243ccd154b43b0d log flooding prevention --- diff --git a/libatalk/util/logger.c b/libatalk/util/logger.c index ecaced07..1b3e9a2f 100644 --- a/libatalk/util/logger.c +++ b/libatalk/util/logger.c @@ -91,6 +91,17 @@ UAM_MODULE_EXPORT logtype_conf_t type_configs[logtype_end_of_list_marker] = { DEFAULT_LOG_CONFIG /* logtype_uams */ }; +/* We use this in order to track the last n log messages in order to prevent flooding */ +#define LOG_FLOODING_MAXCOUNT 10 /* this controls after how many consecutive messages we force a + "repeated x times" message */ +#define LOG_FLOODING_ARRAY_SIZE 3 /* this contols how many messages in flow we track */ +struct log_flood_entry { + int count; + unsigned int hash; +}; +static struct log_flood_entry log_flood_array[LOG_FLOODING_ARRAY_SIZE]; +static int log_flood_entries; + /* These are used by the LOG macro to store __FILE__ and __LINE__ */ static const char *log_src_filename; static int log_src_linenumber; @@ -110,6 +121,20 @@ static const unsigned int num_loglevel_strings = COUNT_ARRAY(arr_loglevel_string Internal function definitions ========================================================================= */ +/* Hash a log message */ +static unsigned int hash_message(const char *message) +{ + const char *p = message; + unsigned int hash = 0, i = 7; + + while (*p) { + hash += *p * i; + i++; + p++; + } + return hash; +} + /* * If filename == NULL its for syslog logging, otherwise its for file-logging. * "unsetuplog" calls with loglevel == NULL. @@ -493,7 +518,7 @@ void make_log_entry(enum loglevels loglevel, enum logtypes logtype, if (fd < 0) { /* no where to send the output, give up */ - return; + goto exit; } /* Initialise the Messages */ @@ -512,6 +537,67 @@ void make_log_entry(enum loglevels loglevel, enum logtypes logtype, temp_buffer[len+1] = 0; } + /* Prevent flooding: hash the message and check if we got the same one recently */ + int hash = hash_message(temp_buffer); + + /* Search for the same message by hash */ + for (int i = log_flood_entries - 1; i >= 0; i--) { + if (log_flood_array[i].hash == hash) { + + /* found same message */ + log_flood_array[i].count++; + + /* Check if that message has reached LOG_FLOODING_MAXCOUNT */ + if (log_flood_array[i].count >= LOG_FLOODING_MAXCOUNT) { + /* yes, log it and remove from array */ + + /* reusing log_details_buffer */ + sprintf(log_details_buffer, "message repeated %i times: ", log_flood_array[i].count); + iov[0].iov_base = log_details_buffer; + iov[0].iov_len = strlen(log_details_buffer); + iov[1].iov_base = temp_buffer; + iov[1].iov_len = strlen(temp_buffer); + + /* Write "message repeated x times: ..." to log */ + writev( fd, iov, 2); + + if ((i + 1) == LOG_FLOODING_ARRAY_SIZE) { + /* last array element, just decrement count */ + log_flood_entries--; + goto exit; + } + /* move array elements down */ + for (int j = i + 1; j != LOG_FLOODING_ARRAY_SIZE ; j++) + log_flood_array[j-1] = log_flood_array[j]; + log_flood_entries--; + } + goto exit; + } /* if */ + } /* for */ + + /* No matching message found, add this message to array*/ + if (log_flood_entries == LOG_FLOODING_ARRAY_SIZE) { + /* array is full, discard oldest entry printing "message repeated..." if count > 1 */ + if (log_flood_array[0].count > 1) { + /* reusing log_details_buffer */ + sprintf(log_details_buffer, "message repeated %i times: ", log_flood_array[0].count); + iov[0].iov_base = log_details_buffer; + iov[0].iov_len = strlen(log_details_buffer); + iov[1].iov_base = temp_buffer; + iov[1].iov_len = strlen(temp_buffer); + + /* Write "message repeated x times: ..." to log */ + writev( fd, iov, 2); + } + for (int i = 1; i < LOG_FLOODING_ARRAY_SIZE; i++) { + log_flood_array[i-1] = log_flood_array[i]; + } + log_flood_entries--; + } + log_flood_array[log_flood_entries-1].count = 1; + log_flood_array[log_flood_entries-1].hash = hash; + log_flood_entries++; + if ( ! log_config.console) { generate_message_details(log_details_buffer, sizeof(log_details_buffer), type_configs[logtype].set ? @@ -529,6 +615,7 @@ void make_log_entry(enum loglevels loglevel, enum logtypes logtype, write(fd, temp_buffer, strlen(temp_buffer)); } +exit: inlog = 0; } diff --git a/libatalk/util/test/logger_test.c b/libatalk/util/test/logger_test.c index 97323a39..cd00dbf9 100644 --- a/libatalk/util/test/logger_test.c +++ b/libatalk/util/test/logger_test.c @@ -35,6 +35,39 @@ int main(int argc, char *argv[]) LOG(log_maxdebug, logtype_dsi, "This should still log."); + /* flooding prevention check */ + LOG(log_debug, logtype_default, "Flooding 12x1"); + for (int i = 0; i < 12; i++) { + LOG(log_error, logtype_default, "flooding 12x1 1"); + } + + LOG(log_debug, logtype_default, "============="); + LOG(log_debug, logtype_default, "Flooding 12x3"); + for (int i = 0; i < 12; i++) { + LOG(log_error, logtype_default, "flooding 12x3 1"); + LOG(log_error, logtype_default, "flooding 12x3 2"); + LOG(log_error, logtype_default, "flooding 12x3 3"); + } + + LOG(log_debug, logtype_default, "============="); + LOG(log_debug, logtype_default, "Flooding 12x4"); + for (int i = 0; i < 12; i++) { + LOG(log_error, logtype_default, "flooding 12x4 1"); + LOG(log_error, logtype_default, "flooding 12x4 2"); + LOG(log_error, logtype_default, "flooding 12x4 3"); + LOG(log_error, logtype_default, "flooding 12x4 4"); + } + + LOG(log_debug, logtype_default, "============="); + LOG(log_debug, logtype_default, "Flooding 12x5"); + for (int i = 0; i < 12; i++) { + LOG(log_error, logtype_default, "flooding 12x5 1"); + LOG(log_error, logtype_default, "flooding 12x5 2"); + LOG(log_error, logtype_default, "flooding 12x5 3"); + LOG(log_error, logtype_default, "flooding 12x5 4"); + LOG(log_error, logtype_default, "flooding 12x5 5"); + } + return 0; }