counter ridiculous infolog spam

consecutive duplicated messages are now
filtered out before they enter any sink

rts/ExternalAI/SAIInterfaceCallbackImpl.cpp

@@ -174,7 +174,7 @@ EXPORT(void) aiInterfaceCallback_Log_log(int interfaceId, const char* const msg)
 EXPORT(void) aiInterfaceCallback_Log_logsl(int interfaceId, const char* section, int loglevel, const char* const msg) {
 	CHECK_INTERFACE_ID(interfaceId);
 
-	log_frontend_record(section, loglevel, "%s", msg);
+	log_frontend_record(loglevel, section, "%s", msg);
 }
 
 

rts/Game/UI/InfoConsole.cpp

@@ -165,8 +165,7 @@ int CInfoConsole::GetRawLines(std::deque<RawLine>& lines)
 }
 
 
-void CInfoConsole::RecordLogMessage(const std::string& section, int level,
-			const std::string& text)
+void CInfoConsole::RecordLogMessage(int level, const std::string& section, const std::string& text)
 {
 	std::lock_guard<spring::recursive_mutex> scoped_lock(infoConsoleMutex);
 

rts/Game/UI/InfoConsole.h

@@ -24,8 +24,7 @@ class CInfoConsole: public CInputReceiver, public CEventClient, public ILogSink
 	void Draw();
 	void PushNewLinesToEventHandler();
 
-	void RecordLogMessage(const std::string& section, int level,
-			const std::string& text);
+	void RecordLogMessage(int level, const std::string& section, const std::string& text) override;
 
 	bool WantsEvent(const std::string& eventName) {
 		return (eventName == "LastMessagePosition");

rts/Lua/LuaUnsyncedCtrl.cpp

@@ -2896,7 +2896,7 @@ int LuaUnsyncedCtrl::SetLogSectionFilterLevel(lua_State* L) {
 		}
 	}
 
-	log_frontend_register_runtime_section(luaL_checkstring(L, 1), logLevel);
+	log_frontend_register_runtime_section(logLevel, luaL_checkstring(L, 1));
 	return 0;
 }
 

rts/System/Log/Backend.cpp

@@ -1,12 +1,13 @@
 /* This file is part of the Spring engine (GPL v2 or later), see LICENSE.html */
 
-#include "Backend.h"
-
 #include <cstdio>
 #include <cstdarg>
+#include <cstring>
 #include <set>
 
-
+#include "Backend.h"
+#include "LogUtil.h"
+#include "System/maindefines.h"
 
 
 namespace {
@@ -21,50 +22,65 @@ namespace {
 	}
 }
 
+
 #ifdef __cplusplus
 extern "C" {
 #endif
 
-extern char* log_formatter_format(const char* section, int level, const char* fmt, va_list arguments);
+
+// note: no real point to TLS, sinks themselves are not thread-safe
+static _threadlocal log_record_t cur_record = {NULL, "", "", 0, 0};
+static _threadlocal log_record_t prv_record = {NULL, "", "", 0, 0};
+
+
+extern void log_formatter_format(log_record_t* log, va_list arguments);
 
 void log_backend_registerSink(log_sink_ptr sink) { log_formatter_getSinks().insert(sink); }
 void log_backend_unregisterSink(log_sink_ptr sink) { log_formatter_getSinks().erase(sink); }
 
 void log_backend_registerCleanup(log_cleanup_ptr cleanupFunc) { log_formatter_getCleanupFuncs().insert(cleanupFunc); }
 void log_backend_unregisterCleanup(log_cleanup_ptr cleanupFunc) { log_formatter_getCleanupFuncs().erase(cleanupFunc); }
 
+
 /**
  * @name logging_backend
  * ILog.h backend implementation.
  */
 ///@{
 
-/// Eventually formats and routes the record to all sinks
-void log_backend_record(const char* section, int level, const char* fmt, va_list arguments)
+// formats and routes the record to all sinks
+void log_backend_record(int level, const char* section, const char* fmt, va_list arguments)
 {
 	const std::set<log_sink_ptr>& sinks = log_formatter_getSinks();
 
-	if (sinks.empty()) {
-		static bool warned = false;
+	if (sinks.empty())
+		return;
+
+	cur_record.sec = section;
+	cur_record.fmt = fmt;
+	cur_record.lvl = level;
 
-		if (!warned) {
-			warned = true;
+	// format the record
+	log_formatter_format(&cur_record, arguments);
 
-			fprintf(stderr,
-				"\nWARNING: A log message was recorded, but no sink is registered."
-				"\n         (there will be no further warnings)\n\n");
-		}
-	} else {
-		// format the record
-		const char* record = log_formatter_format(section, level, fmt, arguments);
+	// check for duplicates after formatting; can not be
+	// done in log_frontend_record or log_filter_record
+	if (prv_record.msg != NULL && strcmp(cur_record.msg, prv_record.msg) == 0)
+		return;
 
-		// sink the record into each registered sink
-		for (auto si = sinks.begin(); si != sinks.end(); ++si) {
-			(*si)(section, level, record);
-		}
+	// sink the record into each registered sink
+	for (auto si = sinks.begin(); si != sinks.end(); ++si) {
+		(*si)(level, section, cur_record.msg);
+	}
 
-		delete[] record;
+	// reallocate buffer for copy if current is larger
+	if (cur_record.len > prv_record.len) {
+		delete[] prv_record.msg;
+		prv_record.msg = NULL;
+		prv_record.msg = new char[prv_record.len = cur_record.len];
 	}
+
+	strncpy(prv_record.msg, cur_record.msg, cur_record.len);
 }
 
 /// Passes on a cleanup request to all sinks
@@ -74,6 +90,9 @@ void log_backend_cleanup() {
 	for (auto si = cleanupFuncs.begin(); si != cleanupFuncs.end(); ++si) {
 		(*si)();
 	}
+
+	delete[] prv_record.msg; prv_record.msg = NULL; prv_record.len = 0;
+	delete[] cur_record.msg; cur_record.msg = NULL; cur_record.len = 0;
 }
 
 ///@}

rts/System/Log/Backend.h

@@ -18,8 +18,7 @@ extern "C" {
  */
 ///@{
 
-typedef void (*log_sink_ptr)(const char* section, int level,
-		const char* record);
+typedef void (*log_sink_ptr)(int level, const char* section, const char* record);
 
 /// Start routing log records to the supplied sink
 void log_backend_registerSink(log_sink_ptr sink);

rts/System/Log/ConsoleSink.cpp

@@ -34,8 +34,7 @@ void log_console_colorizedOutput(bool enable) {
 
 
 /// Records a log entry
-static void log_sink_record_console(const char* section, int level,
-		const char* record)
+static void log_sink_record_console(int level, const char* section, const char* record)
 {
 	char framePrefix[128] = {'\0'};
 	log_framePrefixer_createPrefix(framePrefix, sizeof(framePrefix));

rts/System/Log/DefaultFilter.cpp

@@ -24,10 +24,10 @@ extern "C" {
 #endif
 
 
-bool log_frontend_isEnabled(const char* section, int level);
+bool log_frontend_isEnabled(int level, const char* section);
 
 
-extern void log_backend_record(const char* section, int level, const char* fmt, va_list arguments);
+extern void log_backend_record(int level, const char* section, const char* fmt, va_list arguments);
 extern void log_backend_cleanup();
 
 
@@ -128,7 +128,7 @@ int log_filter_section_getMinLevel(const char* section)
 
 // called by LogOutput for each ENABLED section
 // also by LuaUnsyncedCtrl::SetLogSectionFilterLevel
-void log_filter_section_setMinLevel(const char* section, int level)
+void log_filter_section_setMinLevel(int level, const char* section)
 {
 	log_filter_checkCompileTimeMinLevel(level);
 
@@ -199,16 +199,16 @@ const char* log_filter_section_getRegisteredIndex(int index) {
 	return (*si);
 }
 
-static void log_filter_record(const char* section, int level, const char* fmt, va_list arguments)
+static void log_filter_record(int level, const char* section, const char* fmt, va_list arguments)
 {
 	assert(level > LOG_LEVEL_ALL);
 	assert(level < LOG_LEVEL_NONE);
 
-	if (!log_frontend_isEnabled(section, level))
+	if (!log_frontend_isEnabled(level, section))
 		return;
 
 	// format (and later store) the log record
-	log_backend_record(section, level, fmt, arguments);
+	log_backend_record(level, section, fmt, arguments);
 }
 
 
@@ -218,7 +218,7 @@ static void log_filter_record(const char* section, int level, const char* fmt, v
  */
 ///@{
 
-bool log_frontend_isEnabled(const char* section, int level) {
+bool log_frontend_isEnabled(int level, const char* section) {
 	if (level < log_filter_global_getMinLevel())
 		return false;
 	if (level < log_filter_section_getMinLevel(section))
@@ -239,23 +239,23 @@ void log_frontend_register_section(const char* section) {
 	}
 }
 
-void log_frontend_register_runtime_section(const char* section_cstr_tmp, int level) {
+void log_frontend_register_runtime_section(int level, const char* section_cstr_tmp) {
 	const char* section_cstr = log_filter_section_getSectionCString(section_cstr_tmp);
 
 	log_frontend_register_section(section_cstr);
-	log_filter_section_setMinLevel(section_cstr, level);
+	log_filter_section_setMinLevel(level, section_cstr);
 
 }
 
-void log_frontend_record(const char* section, int level, const char* fmt, ...)
+void log_frontend_record(int level, const char* section, const char* fmt, ...)
 {
 	assert(level > LOG_LEVEL_ALL);
 	assert(level < LOG_LEVEL_NONE);
 
 	// pass the log record on to the filter
 	va_list arguments;
 	va_start(arguments, fmt);
-	log_filter_record(section, level, fmt, arguments);
+	log_filter_record(level, section, fmt, arguments);
 	va_end(arguments);
 }
 

rts/System/Log/DefaultFilter.h

@@ -61,7 +61,7 @@ int log_filter_global_getMinLevel();
  * CAUTION: you may only use strings defined at compile-time.
  * @see #log_filter_section_getMinLevel
  */
-void log_filter_section_setMinLevel(const char* section, int level);
+void log_filter_section_setMinLevel(int level, const char* section);
 
 /**
  * Returns the minimum level to log for a certain section.