log/windows: Add our own stdout/stderr redirection on Windows

This replaces SDL 1.2's built-in stdout/stderr redirection, which writes
the log file to the process working directory (usually an
admin-restricted location) instead of a more accessible user-writable
location.

My approach combines stdout and stderr into a single log file which
includes the process id and timestamp in its filename in order to
accomodate multiple instances and (coming later) log rotation. The log
file is created in the user's temporary directory defined by Windows,
and then relocated to the game user data dir as soon as it is set-up the
first time, placed in the Windows-specific logs/ subdir.

The most pressing issues this solves are the lack of built-in
stdout/stderr redirection in SDL 2's SDL2main.lib entry point, and
Unicode path issues with SDL 1.2 (bug #22897). Additionally, it allows
us to not have to rely on UAC virtualization anymore; this is arguably
far more important because it has been known to break on occasion (e.g.
<http://r.wesnoth.org/t42970>), and starting with version 1.13.2 we want
to declare Windows Vista - 10 compatibility in our side-by-side manifest
(see commit e119f4071f).

Currently missing features coming later:

 * Log rotation (otherwise the logs/ dir may grow forever)
 * wesnothd support (although the code is already required to be linked
   into wesnothd due to it being required by the FS API)
 * Integration with the version info dialog

projectfiles/CodeBlocks/wesnoth.cbp

@@ -868,12 +868,15 @@
 		<Unit filename="../../src/leader_scroll_dialog.cpp" />
 		<Unit filename="../../src/leader_scroll_dialog.hpp" />
 		<Unit filename="../../src/lexical_cast.hpp" />
+		<Unit filename="../../src/libc_error.hpp" />
 		<Unit filename="../../src/loadscreen.cpp" />
 		<Unit filename="../../src/loadscreen.hpp" />
 		<Unit filename="../../src/lobby_preferences.cpp" />
 		<Unit filename="../../src/lobby_preferences.hpp" />
 		<Unit filename="../../src/log.cpp" />
 		<Unit filename="../../src/log.hpp" />
+		<Unit filename="../../src/log_windows.cpp" />
+		<Unit filename="../../src/log_windows.hpp" />
 		<Unit filename="../../src/lua/lapi.h" />
 		<Unit filename="../../src/lua/lauxlib.h" />
 		<Unit filename="../../src/lua/lcode.h" />

projectfiles/CodeBlocks/wesnothd.cbp

@@ -70,10 +70,13 @@
 		<Unit filename="../../src/gettext.hpp" />
 		<Unit filename="../../src/gettext_boost.cpp" />
 		<Unit filename="../../src/global.hpp" />
+		<Unit filename="../../src/libc_error.hpp" />
 		<Unit filename="../../src/loadscreen.hpp" />
 		<Unit filename="../../src/loadscreen_empty.cpp" />
 		<Unit filename="../../src/log.cpp" />
 		<Unit filename="../../src/log.hpp" />
+		<Unit filename="../../src/log_windows.cpp" />
+		<Unit filename="../../src/log_windows.hpp" />
 		<Unit filename="../../src/map.hpp" />
 		<Unit filename="../../src/mt_rng.cpp" />
 		<Unit filename="../../src/mt_rng.hpp" />

src/CMakeLists.txt

@@ -288,6 +288,12 @@ else()
 	)
 endif()
 
+if(WIN32)
+	set(libwesnoth-core_STAT_SRC
+		${libwesnoth-core_STAT_SRC}
+		log_windows.cpp
+	)
+
 # a 'lib' is automatically set in front when creating the library (as in the filename)
 # internal reference is the name given here
 add_library(wesnoth-core ${LIBRARY_TYPE} EXCLUDE_FROM_ALL ${libwesnoth-core_STAT_SRC})

src/SConscript

@@ -69,6 +69,11 @@ libwesnoth_core_sources.extend([
     filesystem_env.Object("filesystem_boost.cpp")
 ])
 
+if env["PLATFORM"] == "win32":
+    libwesnoth_core_sources.extend([
+        filesystem_env.Object("log_windows.cpp")
+    ])
+
 if env["libintl"]:
     libwesnoth_core_sources.extend([
         filesystem_env.Object("gettext.cpp")

src/filesystem_boost.cpp

@@ -34,7 +34,10 @@
 using boost::uintmax_t;
 
 #ifdef _WIN32
+#include "log_windows.hpp"
+
 #include <boost/locale.hpp>
+
 #include <windows.h>
 #include <shlobj.h>
 #endif /* !_WIN32 */
@@ -478,6 +481,10 @@ static void setup_user_data_dir()
 	create_directory_if_missing(user_data_dir / "data" / "add-ons");
 	create_directory_if_missing(user_data_dir / "saves");
 	create_directory_if_missing(user_data_dir / "persist");
+
+#ifdef _WIN32
+	lg::finish_log_file_setup();
+#endif
 }
 
 #ifdef _WIN32

src/libc_error.hpp

@@ -0,0 +1,42 @@
+/*
+   By Ignacio Riquelme Morelle <shadowm2006@gmail.com>
+   Part of the Battle for Wesnoth Project http://www.wesnoth.org/
+
+   The contents of this file are placed in the public domain.
+ */
+
+#include <cerrno>
+#include <cstring>
+#include <string>
+
+#ifndef LIBC_ERROR_HPP_INCLUDED
+#define LIBC_ERROR_HPP_INCLUDED
+
+/**
+ * Exception type used to propagate C runtime errors across functions.
+ */
+class libc_error
+{
+public:
+	libc_error(): e_(errno), msg_(strerror(e_))
+	{
+	}
+
+	/** Returns the value of @a errno at the time the exception was thrown. */
+	int num() const
+	{
+		return e_;
+	}
+
+	/** Returns an explanatory string describing the runtime error. */
+	const std::string& desc() const
+	{
+		return msg_;
+	}
+
+private:
+	int e_;
+	std::string msg_;
+};
+
+#endif

src/log_windows.cpp

@@ -0,0 +1,344 @@
+/*
+   Copyright (C) 2015 by Ignacio Riquelme Morelle <shadowm2006@gmail.com>
+   Part of the Battle for Wesnoth Project http://www.wesnoth.org/
+
+   This program is free software; you can redistribute it and/or modify
+   it under the terms of the GNU General Public License as published by
+   the Free Software Foundation; either version 2 of the License, or
+   (at your option) any later version.
+   This program is distributed in the hope that it will be useful,
+   but WITHOUT ANY WARRANTY.
+
+   See the COPYING file for more details.
+*/
+
+#include "log_windows.hpp"
+
+#include "filesystem.hpp"
+#include "libc_error.hpp"
+#include "log.hpp"
+#include "serialization/unicode.hpp"
+
+#include <cstdio>
+#include <ctime>
+
+#include <boost/noncopyable.hpp>
+#include <boost/scoped_ptr.hpp>
+
+#ifndef UNICODE
+#define UNICODE
+#endif
+
+#define WIN32_LEAN_AND_MEAN
+#define _WIN32_WINNT 0x0501 // XP and later
+
+#include <windows.h>
+
+#if 1
+static lg::log_domain log_setup("logsetup");
+#define ERR_LS LOG_STREAM(err,   log_setup)
+#define WRN_LS LOG_STREAM(warn,  log_setup)
+#define LOG_LS LOG_STREAM(info,  log_setup)
+#define DBG_LS LOG_STREAM(debug, log_setup)
+
+#else
+
+std::stringstream foo;
+#define ERR_LS foo
+#define WRN_LS foo
+#define LOG_LS foo
+#define DBG_LS foo
+
+#endif
+
+namespace lg
+{
+
+namespace
+{
+
+/**
+ * Generates a "unique" log file name.
+ *
+ * This is really not guaranteed to be unique, but it's close enough, since
+ * the odds of having multiple Wesnoth instances spawn with the same PID within
+ * a second span are close to zero.
+ */
+std::string unique_log_filename()
+{
+	std::ostringstream o;
+
+	o << "wesnoth-";
+
+	const time_t cur = time(NULL);
+	const tm* const lt = localtime(&cur);
+
+	if(lt) {
+		char ts_buf[128] = { 0 };
+		strftime(ts_buf, 128, "%Y%m%d-%H%M%S-", lt);
+		o << ts_buf;
+	}
+
+	o << GetCurrentProcessId() << ".log";
+
+	return o.str();
+}
+
+/**
+ * Returns the path to a system-defined temporary files dir.
+ */
+std::string temp_dir()
+{
+	wchar_t tmpdir[MAX_PATH + 1];
+
+	if(GetTempPath(MAX_PATH + 1, tmpdir) == 0) {
+		return ".";
+	}
+
+	return unicode_cast<std::string>(std::wstring(tmpdir));
+}
+
+/**
+ * Display an alert box to warn about log initialization errors, and exit.
+ */
+void log_init_panic(const std::string& msg)
+{
+	ERR_LS << "Log initialization panic call: " << msg << '\n';
+
+	const std::string full_msg = msg + "\n\n" + "This may indicate an issue with your Wesnoth launch configuration. If the problem persists, contact the development team for technical support, including the full contents of this message (copy with CTRL+C).";
+
+	// It may not be useful to write to stderr at this point, so warn the user
+	// in a failsafe fashion via Windows UI API.
+	MessageBox(NULL,
+			   unicode_cast<std::wstring>(full_msg).c_str(),
+			   L"Battle for Wesnoth",
+			   MB_ICONEXCLAMATION | MB_OK);
+
+	// It may seem excessive to quit over something like this, but it's a good
+	// indicator of possible configuration issues with the user data dir that
+	// may cause much weirder symptoms later (see http://r.wesnoth.org/t42970
+	// for an example).
+	exit(1);
+}
+
+/**
+ * Display an alert box to warn about log initialization errors, and exit.
+ */
+void log_init_panic(const libc_error& e,
+					const std::string& new_log_path,
+					const std::string& old_log_path = std::string())
+{
+	std::ostringstream msg;
+
+	if(old_log_path.empty()) {
+		msg << "Early log initialization failed.";
+	} else {
+		msg << "Log relocation failed.";
+	}
+
+	msg << "\n\n"
+		<< "Runtime error: " << e.desc() << " (" << e.num() << ")\n"
+		<< "New log file path: " << new_log_path << '\n'
+		<< "Old log file path: ";
+
+	if(old_log_path.empty()) {
+		msg << "Log file path: " << new_log_path << '\n';
+	} else {
+		msg << "New log file path: " << new_log_path << '\n'
+			<< "Old log file path: ";
+	}
+
+	log_init_panic(msg.str());
+}
+
+/**
+ * Singleton class that deals with the intricacies of log file redirection.
+ */
+class log_file_manager : private boost::noncopyable
+{
+public:
+	log_file_manager();
+
+	/**
+	 * Returns the path to the current log file.
+	 */
+	std::string log_file_path() const;
+
+	/**
+	 * Moves the log file to a new directory.
+	 *
+	 * This causes the associated streams to closed momentarily in order to be
+	 * able to move the log file, because Windows does not allow move/rename
+	 * operations on currently-open files.
+	 *
+	 * @param log_dir        Log directory path.
+	 *
+	 * @throw libc_error     If the log file cannot be opened or relocated.
+	 */
+	void move_log_file(const std::string& log_dir);
+
+private:
+	std::string fn_;
+	std::string cur_path_;
+
+	enum STREAM_ID {
+		STREAM_STDOUT = 1,
+		STREAM_STDERR = 2
+	};
+
+	/**
+	 * Opens the log file for the current session in the specified directory.
+	 *
+	 * @param file_path      Log file path.
+	 * @param truncate       Whether to truncate an existing log file or append
+	 *                       to it instead.
+	 *
+	 * @throw libc_error     If the log file cannot be opened.
+	 */
+	void open_log_file(const std::string& file_path,
+					   bool truncate);
+
+	/**
+	 * Takes care of any tasks required for redirecting a log stream.
+	 *
+	 * @param file_path      Log file path.
+	 * @param stream         Stream identifier.
+	 * @param truncate       Whether to truncate an existing log file or append
+	 *                       to it instead.
+	 *
+	 * @throw libc_error     If the log file cannot be opened.
+	 *
+	 * @note This does not set cur_path_ to the new path.
+	 */
+	void do_redirect_single_stream(const std::string& file_path,
+								   STREAM_ID stream,
+								   bool truncate);
+};
+
+log_file_manager::log_file_manager()
+	: fn_(unique_log_filename())
+	, cur_path_()
+{
+	DBG_LS << "Early init message\n";
+
+	//
+	// We use the Windows temp dir on startup,
+	//
+	const std::string new_path = temp_dir() + "/" + fn_;
+
+	try {
+		open_log_file(new_path, true);
+	} catch(const libc_error& e) {
+		log_init_panic(e, new_path, cur_path_);
+	}
+
+	LOG_LS << "Opened log file at " << new_path << '\n';
+}
+
+std::string log_file_manager::log_file_path() const
+{
+	return cur_path_;
+}
+
+void log_file_manager::move_log_file(const std::string& log_dir)
+{
+	const std::string new_path = log_dir + "/" + fn_;
+
+	try {
+		if(!cur_path_.empty()) {
+			const std::string old_path = cur_path_;
+
+			// Need to close files before moving or renaming. This will replace
+			// cur_path_ with NUL, hence the backup above.
+			open_log_file("NUL", false);
+
+			if(rename(old_path.c_str(), new_path.c_str()) != 0) {
+				throw libc_error();
+			}
+		}
+
+		// Reopen.
+		open_log_file(new_path, false);
+	} catch(const libc_error& e) {
+		log_init_panic(e, new_path, cur_path_);
+	}
+
+	LOG_LS << "Moved log file to " << new_path << '\n';
+}
+
+void log_file_manager::open_log_file(const std::string& file_path, bool truncate)
+{
+	do_redirect_single_stream(file_path, STREAM_STDERR, truncate);
+	do_redirect_single_stream(file_path, STREAM_STDOUT, false);
+
+	cur_path_ = file_path;
+}
+
+void log_file_manager::do_redirect_single_stream(const std::string& file_path,
+												 log_file_manager::STREAM_ID stream,
+												 bool truncate)
+{
+	DBG_LS << stream << ' ' << cur_path_ << " -> " << file_path << " [side A]\n";
+
+	FILE* crts = stream == STREAM_STDERR ? stderr : stdout;
+	std::ostream& cxxs = stream == STREAM_STDERR ? std::cerr : std::cout;
+
+	fflush(crts);
+	cxxs.flush();
+
+	if(!freopen(file_path.c_str(), (truncate ? "w" : "a"), crts))
+	{
+		throw libc_error();
+	}
+
+	//setbuf(crts, NULL);
+
+	DBG_LS << stream << ' ' << cur_path_ << " -> " << file_path << " [side B]\n";
+}
+
+boost::scoped_ptr<log_file_manager> lfm;
+
+} // end anonymous namespace
+
+std::string log_file_path()
+{
+	if(lfm) {
+		return lfm->log_file_path();
+	}
+
+	return "";
+}
+
+void early_log_file_setup()
+{
+	if(lfm) {
+		return;
+	}
+
+	lfm.reset(new log_file_manager());
+}
+
+void finish_log_file_setup()
+{
+	// Make sure the LFM is actually set up just in case.
+	early_log_file_setup();
+
+	static bool setup_complete = false;
+
+	if(setup_complete) {
+		ERR_LS << "finish_log_file_setup() called more than once!\n";
+		return;
+	}
+
+	const std::string log_dir = filesystem::get_user_data_dir() + "/logs";
+	if(!filesystem::file_exists(log_dir) && !filesystem::make_directory(log_dir)) {
+		log_init_panic(std::string("Could not create logs directory at ") +
+					   log_dir + ".");
+	}
+
+	lfm->move_log_file(log_dir);
+
+	setup_complete = true;
+}
+
+} // end namespace lg

src/log_windows.hpp

@@ -0,0 +1,73 @@
+/*
+   Copyright (C) 2015 by Ignacio Riquelme Morelle <shadowm2006@gmail.com>
+   Part of the Battle for Wesnoth Project http://www.wesnoth.org/
+
+   This program is free software; you can redistribute it and/or modify
+   it under the terms of the GNU General Public License as published by
+   the Free Software Foundation; either version 2 of the License, or
+   (at your option) any later version.
+   This program is distributed in the hope that it will be useful,
+   but WITHOUT ANY WARRANTY.
+
+   See the COPYING file for more details.
+*/
+
+#ifndef DESKTOP_WINDOWS_LOG_HPP_INCLUDED
+#define DESKTOP_WINDOWS_LOG_HPP_INCLUDED
+
+#include <string>
+
+/**
+ * @file
+ * Log file control routines for Windows.
+ *
+ * During static object initialization, stdout and stderr are redirected to a
+ * uniquely-named log file located in the user's temporary directory as defined
+ * by the platform (e.g. C:/Users/username/AppData/Local/Temp/wesnoth-XXXX.log).
+ * Later, a request may be issued to relocate the log file to a more permanent
+ * and user-accessible location (such as the Wesnoth user data directory).
+ *
+ * Because Wesnoth is normally built with the GUI subsystem option, there is no
+ * console on startup and thus no way to see stdout/stderr output. Since
+ * version 1.13.1, we can allocate a console during initialization when started
+ * with the --wconsole option, but that is a somewhat clunky hack that does not
+ * help with post mortem debugging.
+ *
+ * SDL 1.2 used to redirect stdout and stderr to stdout.txt and stderr.txt in
+ * the process working directory automatically, but this approach too had its
+ * own shortcomings by assuming the pwd was writable by the process (or in Vista
+ * and later versions, requiring UAC virtualization to be enabled).
+ */
+
+namespace lg
+{
+
+/**
+ * Returns the path to the current log file.
+ *
+ * An empty string is returned if the log file has not been set up yet or it
+ * was disabled (e.g. by --wconsole).
+ */
+std::string log_file_path();
+
+/**
+ * Sets up the initial temporary log file.
+ *
+ * This has to be done on demand (preferably as early as possible) from a
+ * function rather than during static initialization, otherwise things go
+ * horribly wrong as soon as we try to use the logging facilities internally
+ * for debug messages.
+ */
+void early_log_file_setup();
+
+/**
+ * Relocates the stdout+stderr log file to the user data directory.
+ *
+ * This function exits the process if something goes wrong (including calling
+ * it when the user data directory isn't known yet).
+ */
+void finish_log_file_setup();
+
+}
+
+#endif

src/wesnoth.cpp

@@ -63,6 +63,7 @@
 
 #ifdef _WIN32
 #include "desktop/windows_console.hpp"
+#include "log_windows.hpp"
 #endif // _WIN32
 
 #include <SDL.h>                        // for SDL_Init, SDL_INIT_TIMER
@@ -909,6 +910,8 @@ int main(int argc, char** argv)
 #endif
 #endif //_OPENMP
 #ifdef _WIN32
+	lg::early_log_file_setup();
+
 	(void)argc;
 	(void)argv;