widelands-dev team mailing list archive

[Paul Pogonyshev <pogonyshev@xxxxxxxxx>]

Paul Pogonyshev has proposed merging lp:~doublep/widelands/improved-logging into lp:widelands.

Requested reviews:
  Widelands Developers (widelands-dev)

For more details, see:
https://code.launchpad.net/~doublep/widelands/improved-logging/+merge/153200

This change improves logging by Widelands in that it becomes configurable at runtime, i.e. without compiling anything. Open file ~/.widelands/config and add a section like this:

[log]
default=printed
SurfaceCache=silenced

Now Widelands will no longer print any messages from surface caching module. Likewise can go for other messages, but this commit only changes surface_cache.cc, as a proof of concept. However, changes needed are very simple:
 
-	log("SurfaceCache: inserted %s, now using %.2f mb.\n", hash.c_str(), used_memory_ / 1048576.0);
+	log2("SurfaceCache", "inserted %s, now using %.2f mb.\n", hash.c_str(), used_memory_ / 1048576.0);

The idea is to keep logging and selectively limit it to messages you are interested in at the moment. So, categories can be added later as needed. A good strategy for developer would be to silence everything and only enable one or two selected categories.
-- 
https://code.launchpad.net/~doublep/widelands/improved-logging/+merge/153200
Your team Widelands Developers is requested to review the proposed merge of lp:~doublep/widelands/improved-logging into lp:widelands.

=== modified file 'src/graphic/surface_cache.cc'
--- src/graphic/surface_cache.cc	2013-03-01 18:36:40 +0000
+++ src/graphic/surface_cache.cc	2013-03-13 17:21:25 +0000
@@ -93,7 +93,7 @@
 	used_memory_ += surface_size;
 	map_.insert(make_pair(hash, new Entry(surf, it)));
 
-	log("SurfaceCache: inserted %s, now using %.2f mb.\n", hash.c_str(), used_memory_ / 1048576.0);
+	log2("SurfaceCache", "inserted %s, now using %.2f mb.\n", hash.c_str(), used_memory_ / 1048576.0);
 	return surf;
 }
 

=== modified file 'src/log.cc'
--- src/log.cc	2012-02-15 21:25:34 +0000
+++ src/log.cc	2013-03-13 17:21:25 +0000
@@ -20,25 +20,106 @@
 #include "log.h"
 
 #include "io/dedicated_log.h"
+#include "profile/profile.h"
 
 #include <cstdarg>
 #include <cstdio>
 #include <iostream>
+#include <set>
+
+#include <boost/scoped_ptr.hpp>
+
 
 extern std::ostream & wout;
 
 bool g_verbose = false;
 
-void log(const char * const fmt, ...) {
-	char buffer[2048];
-	va_list va;
-
-	va_start(va, fmt);
-	vsnprintf(buffer, sizeof(buffer), fmt, va);
-	va_end(va);
-
-	wout << buffer;
-	wout.flush();
+
+namespace
+{
+	const std::string  empty_category;
+
+	struct Settings
+	{
+		bool                    silenced_by_default;
+		std::set <std::string>  exceptions;
+
+		Settings (Section& config)
+		{
+			silenced_by_default = is_silenced (config.get_string ("default"), false);
+			while (Section::Value* value = config.get_next_val ()) {
+				int  silenced = is_silenced (value->get_string ());
+				if (silenced != -1 && silenced == !silenced_by_default) {
+					if (strcmp (value->get_name (), "empty_category") == 0)
+						exceptions.insert (empty_category);
+					else
+						exceptions.insert (value->get_name ());
+				}
+			}
+		}
+
+		static int is_silenced (const char* value, int default_value = -1)
+		{
+			if (value && strcasecmp (value, "silenced") == 0)
+				return true;
+			if (value && strcasecmp (value, "printed") == 0)
+				return false;
+			return default_value;
+		}
+	};
+
+	boost::scoped_ptr <Settings>  settings;
+
+
+	void do_log2 (const std::string& category, const char* format, va_list args)
+	{
+		if (settings) {
+			bool  exceptional = (settings->exceptions.find (category) != settings->exceptions.end ());
+			if (settings->silenced_by_default ? !exceptional : exceptional)
+				return;
+		}
+
+		char  buffer[2048];
+		char* write_at = buffer;
+
+		if (!category.empty ())
+			write_at += snprintf (write_at, sizeof (buffer), "%s: ", category.c_str ());
+
+		vsnprintf (write_at, buffer + sizeof(buffer) - write_at, format, args);
+
+		wout << buffer;
+		wout.flush();
+	}
+}
+
+
+void log (const char* format, ...)
+{
+	va_list  args;
+	va_start (args, format);
+	do_log2 (empty_category, format, args);
+	va_end (args);
+}
+
+/**
+ *  Log a formatted message with specified category (a free-form string).  Categories can
+ *  be silenced or printed, so you can concentrate on output from certain modules without
+ *  recompiling anything.
+ *
+ *  To fine tune output, open file '~/.widelands/config' and add/edit log section, e.g.:
+ *
+ *  [log]
+ *  default=silenced
+ *  my_module=printed
+ *
+ *  This will silence all log messages except those in category 'my_module'.
+ */
+void log2 (const std::string& category, const char* format, ...)
+{
+	va_list  args;
+	va_start (args, format);
+	do_log2 (category, format, args);
+	va_end (args);
 }
 
 
@@ -56,3 +137,9 @@
 	wout << buffer;
 	wout.flush();
 }
+
+
+void initialize_log (Section& config)
+{
+	settings.reset (new Settings (config));
+}

=== modified file 'src/log.h'
--- src/log.h	2013-01-25 12:09:49 +0000
+++ src/log.h	2013-03-13 17:21:25 +0000
@@ -20,6 +20,8 @@
 #ifndef LOG_H
 #define LOG_H
 
+#include <string>
+
 #ifdef __GNUC__
 #define PRINTF_FORMAT(b, c) __attribute__ ((__format__ (__printf__, b, c)))
 #else
@@ -47,13 +49,22 @@
 // Informational messages that can aid in debugging
 #define ALIVE() log("Alive in %s line %i\n", __FILE__, __LINE__)
 
+
+struct Section;
+
+
 // Print a formatted log messages to wout.
 // wout is either std::cout or specified logfile.
 void log(const char *, ...) PRINTF_FORMAT(1, 2);
 
+void log2(const std::string& category, const char* format, ...) PRINTF_FORMAT(2, 3);
+
 void dedicatedlog(const char *, ...) PRINTF_FORMAT(1, 2);
 
 
+void initialize_log (Section& config);
+
+
 extern bool g_verbose;
 
 #endif

=== modified file 'src/wlapplication.cc'
--- src/wlapplication.cc	2013-03-08 14:17:14 +0000
+++ src/wlapplication.cc	2013-03-13 17:21:25 +0000
@@ -861,6 +861,9 @@
 	g_options.read("config", "global");
 	Section & s = g_options.pull_section("global");
 
+	// Initialize logging first, so that any further processing can use it.
+	initialize_log (g_options.pull_section ("log"));
+
 	//then parse the commandline - overwrites conffile settings
 	handle_commandline_parameters();