Logging: Add customizable logging backends and fmtlib based macros

* Change the logging backend to support multiple sinks through the
Backend Interface
* Add a new set of logging macros to use fmtlib instead.
* Qt: Compile as GUI application on windows to make the console hidden by
default. Add filter configuration and a button to open log location.
* SDL: Migrate to the new logging macros

src/common/logging/backend.cpp

@@ -4,16 +4,108 @@
 
 #include <algorithm>
 #include <array>
+#include <chrono>
 #include <cstdio>
+#include <future>
+#include <memory>
+#include <thread>
 #include "common/assert.h"
 #include "common/common_funcs.h" // snprintf compatibility define
 #include "common/logging/backend.h"
-#include "common/logging/filter.h"
 #include "common/logging/log.h"
 #include "common/logging/text_formatter.h"
+#include "common/string_util.h"
+#include "common/threadsafe_queue.h"
 
 namespace Log {
 
+/**
+ * Static state as a singleton.
+ */
+class Impl {
+public:
+    static Impl& Instance() {
+        static Impl backend;
+        return backend;
+    }
+
+    Impl(Impl const&) = delete;
+    const Impl& operator=(Impl const&) = delete;
+
+    Common::MPSCQueue<Log::Entry>& GetQueue() {
+        return message_queue;
+    }
+
+    void AddBackend(std::unique_ptr<Backend> backend) {
+        backends.push_back(std::move(backend));
+    }
+
+    void RemoveBackend(const std::string& backend_name) {
+        std::remove_if(backends.begin(), backends.end(),
+                       [&backend_name](const auto& i) { return i->GetName() == backend_name; });
+    }
+
+    const Filter& GetGlobalFilter() const {
+        return filter;
+    }
+
+    void SetGlobalFilter(const Filter& f) {
+        filter = f;
+    }
+
+    Backend* GetBackend(const std::string& backend_name) {
+        auto it = std::find_if(backends.begin(), backends.end(), [&backend_name](const auto& i) {
+            return i->GetName() == backend_name;
+        });
+        if (it == backends.end())
+            return nullptr;
+        return it->get();
+    }
+
+private:
+    Impl() : running(true) {
+        backend_thread = std::async(std::launch::async, [&] {
+            using namespace std::chrono_literals;
+            Entry entry;
+            while (running) {
+                if (!message_queue.Pop(entry)) {
+                    std::this_thread::sleep_for(1ms);
+                    continue;
+                }
+                for (const auto& backend : backends) {
+                    backend->Write(entry);
+                }
+            }
+        });
+    }
+    ~Impl() {
+        if (running) {
+            running = false;
+        }
+    }
+
+    std::atomic_bool running;
+    std::future<void> backend_thread;
+    std::vector<std::unique_ptr<Backend>> backends;
+    Common::MPSCQueue<Log::Entry> message_queue;
+    Filter filter;
+};
+
+void ConsoleBackend::Write(const Entry& entry) {
+    PrintMessage(entry);
+}
+
+void ColorConsoleBackend::Write(const Entry& entry) {
+    PrintColoredMessage(entry);
+}
+
+void FileBackend::Write(const Entry& entry) {
+    if (!file.IsOpen()) {
+        return;
+    }
+    file.WriteString(FormatLogMessage(entry) + "\n");
+}
+
 /// Macro listing all log classes. Code should define CLS and SUB as desired before invoking this.
 #define ALL_LOG_CLASSES()                                                                          \
     CLS(Log)                                                                                       \
@@ -113,45 +205,65 @@ const char* GetLevelName(Level log_level) {
 }
 
 Entry CreateEntry(Class log_class, Level log_level, const char* filename, unsigned int line_nr,
-                  const char* function, const char* format, va_list args) {
-    using std::chrono::steady_clock;
+                  const char* function, const std::string& message) {
     using std::chrono::duration_cast;
+    using std::chrono::steady_clock;
 
     static steady_clock::time_point time_origin = steady_clock::now();
 
-    std::array<char, 4 * 1024> formatting_buffer;
-
     Entry entry;
     entry.timestamp = duration_cast<std::chrono::microseconds>(steady_clock::now() - time_origin);
     entry.log_class = log_class;
     entry.log_level = log_level;
-
-    snprintf(formatting_buffer.data(), formatting_buffer.size(), "%s:%s:%u", filename, function,
-             line_nr);
-    entry.location = std::string(formatting_buffer.data());
-
-    vsnprintf(formatting_buffer.data(), formatting_buffer.size(), format, args);
-    entry.message = std::string(formatting_buffer.data());
+    entry.filename = std::string(Common::TrimSourcePath(filename));
+    entry.line_num = line_nr;
+    entry.function = std::string(function);
+    entry.message = message;
 
     return entry;
 }
 
-static Filter* filter = nullptr;
-
-void SetFilter(Filter* new_filter) {
-    filter = new_filter;
+void SetGlobalFilter(const Filter& filter) {
+    Impl::Instance().SetGlobalFilter(filter);
 }
 
-void LogMessage(Class log_class, Level log_level, const char* filename, unsigned int line_nr,
-                const char* function, const char* format, ...) {
-    if (filter != nullptr && !filter->CheckMessage(log_class, log_level))
-        return;
+void AddBackend(std::unique_ptr<Backend> backend) {
+    Impl::Instance().AddBackend(std::move(backend));
+}
 
+void RemoveBackend(const std::string& backend_name) {
+    Impl::Instance().RemoveBackend(backend_name);
+}
+
+Backend* GetBackend(const std::string& backend_name) {
+    return Impl::Instance().GetBackend(backend_name);
+}
+
+void LogMessage(Class log_class, Level log_level, const char* filename, unsigned int line_num,
+                const char* function, const char* format, ...) {
+    auto filter = Impl::Instance().GetGlobalFilter();
+    if (!filter.CheckMessage(log_class, log_level))
+        return;
+    std::array<char, 4 * 1024> formatting_buffer;
     va_list args;
     va_start(args, format);
-    Entry entry = CreateEntry(log_class, log_level, filename, line_nr, function, format, args);
+    vsnprintf(formatting_buffer.data(), formatting_buffer.size(), format, args);
     va_end(args);
+    Entry entry = CreateEntry(log_class, log_level, filename, line_num, function,
+                              std::string(formatting_buffer.data()));
 
-    PrintColoredMessage(entry);
+    Impl::Instance().GetQueue().Push(std::move(entry));
 }
+
+void FmtLogMessage(Class log_class, Level log_level, const char* filename, unsigned int line_num,
+                   const char* function, const char* format, fmt::ArgList args) {
+    auto filter = Impl::Instance().GetGlobalFilter();
+    if (!filter.CheckMessage(log_class, log_level))
+        return;
+
+    Entry entry =
+        CreateEntry(log_class, log_level, filename, line_num, function, fmt::format(format, args));
+
+    Impl::Instance().GetQueue().Push(std::move(entry));
 }
+} // namespace Log

src/common/logging/backend.h

@@ -6,8 +6,11 @@
 
 #include <chrono>
 #include <cstdarg>
+#include <memory>
 #include <string>
 #include <utility>
+#include "common/file_util.h"
+#include "common/logging/filter.h"
 #include "common/logging/log.h"
 
 namespace Log {
@@ -22,15 +25,80 @@ struct Entry {
     std::chrono::microseconds timestamp;
     Class log_class;
     Level log_level;
-    std::string location;
+    std::string filename;
+    unsigned int line_num;
+    std::string function;
     std::string message;
 
     Entry() = default;
     Entry(Entry&& o) = default;
 
     Entry& operator=(Entry&& o) = default;
+    Entry& operator=(const Entry& o) = default;
 };
 
+/**
+ * Interface for logging backends. As loggers can be created and removed at runtime, this can be
+ * used by a frontend for adding a custom logging backend as needed
+ */
+class Backend {
+public:
+    virtual ~Backend() = default;
+    virtual void SetFilter(const Filter& new_filter) {
+        filter = new_filter;
+    }
+    virtual const char* GetName() const = 0;
+    virtual void Write(const Entry& entry) = 0;
+
+private:
+    Filter filter;
+};
+
+/**
+ * Backend that writes to stderr without any color commands
+ */
+class ConsoleBackend : public Backend {
+public:
+    const char* GetName() const override {
+        return "console";
+    }
+    void Write(const Entry& entry) override;
+};
+
+/**
+ * Backend that writes to stderr and with color
+ */
+class ColorConsoleBackend : public Backend {
+public:
+    const char* GetName() const override {
+        return "color_console";
+    }
+    void Write(const Entry& entry) override;
+};
+
+/**
+ * Backend that writes to a file passed into the constructor
+ */
+class FileBackend : public Backend {
+public:
+    FileBackend(const std::string& filename) : file(filename, "w") {}
+
+    const char* GetName() const override {
+        return "file";
+    }
+
+    void Write(const Entry& entry) override;
+
+private:
+    FileUtil::IOFile file;
+};
+
+void AddBackend(std::unique_ptr<Backend> backend);
+
+void RemoveBackend(const std::string& backend_name);
+
+Backend* GetBackend(const std::string& backend_name);
+
 /**
  * Returns the name of the passed log class as a C-string. Subclasses are separated by periods
  * instead of underscores as in the enumeration.
@@ -44,7 +112,13 @@ const char* GetLevelName(Level log_level);
 
 /// Creates a log entry by formatting the given source location, and message.
 Entry CreateEntry(Class log_class, Level log_level, const char* filename, unsigned int line_nr,
-                  const char* function, const char* format, va_list args);
+                  const char* function, const char* format, const std::string& message);
 
-void SetFilter(Filter* filter);
-}
+/**
+ * The global filter will prevent any messages from even being processed if they are filtered. Each
+ * backend can have a filter, but if the level is lower than the global filter, the backend will
+ * never get the message
+ */
+void SetGlobalFilter(const Filter& filter);
+
+} // namespace Log

src/common/logging/filter.h

@@ -19,7 +19,7 @@ namespace Log {
 class Filter {
 public:
     /// Initializes the filter with all classes having `default_level` as the minimum level.
-    Filter(Level default_level);
+    Filter(Level default_level = Level::Info);
 
     /// Resets the filter so that all classes have `level` as the minimum displayed level.
     void ResetAll(Level level);
@@ -50,4 +50,4 @@ public:
 private:
     std::array<Level, (size_t)Class::Count> class_levels;
 };
-}
+} // namespace Log

src/common/logging/log.h

@@ -4,6 +4,7 @@
 
 #pragma once
 
+#include <fmt/format.h>
 #include "common/common_types.h"
 
 namespace Log {
@@ -98,7 +99,7 @@ enum class Class : ClassType {
 };
 
 /// Logs a message to the global logger.
-void LogMessage(Class log_class, Level log_level, const char* filename, unsigned int line_nr,
+void LogMessage(Class log_class, Level log_level, const char* filename, unsigned int line_num,
                 const char* function,
 #ifdef _MSC_VER
                 _Printf_format_string_
@@ -110,6 +111,12 @@ void LogMessage(Class log_class, Level log_level, const char* filename, unsigned
 #endif
     ;
 
+/// Logs a message to the global logger, this time with 100% moar fmtlib
+void FmtLogMessage(Class log_class, Level log_level, const char* filename, unsigned int line_num,
+                   const char* function, const char* format, fmt::ArgList);
+
+FMT_VARIADIC(void, FmtLogMessage, Class, Level, const char*, unsigned int, const char*, const char*)
+
 } // namespace Log
 
 #define LOG_GENERIC(log_class, log_level, ...)                                                     \
@@ -132,3 +139,28 @@ void LogMessage(Class log_class, Level log_level, const char* filename, unsigned
     LOG_GENERIC(::Log::Class::log_class, ::Log::Level::Error, __VA_ARGS__)
 #define LOG_CRITICAL(log_class, ...)                                                               \
     LOG_GENERIC(::Log::Class::log_class, ::Log::Level::Critical, __VA_ARGS__)
+
+// Define the fmt lib macros
+#ifdef _DEBUG
+#define NGLOG_TRACE(log_class, fmt, ...)                                                           \
+    ::Log::FmtLogMessage(::Log::Class::log_class, ::Log::Level::Trace, __FILE__, __LINE__,         \
+                         __func__, fmt, ##__VA_ARGS__)
+#else
+#define NGLOG_TRACE(log_class, fmt, ...) (void(0))
+#endif
+
+#define NGLOG_DEBUG(log_class, fmt, ...)                                                           \
+    ::Log::FmtLogMessage(::Log::Class::log_class, ::Log::Level::Debug, __FILE__, __LINE__,         \
+                         __func__, fmt, ##__VA_ARGS__)
+#define NGLOG_INFO(log_class, fmt, ...)                                                            \
+    ::Log::FmtLogMessage(::Log::Class::log_class, ::Log::Level::Info, __FILE__, __LINE__,          \
+                         __func__, fmt, ##__VA_ARGS__)
+#define NGLOG_WARNING(log_class, fmt, ...)                                                         \
+    ::Log::FmtLogMessage(::Log::Class::log_class, ::Log::Level::Warning, __FILE__, __LINE__,       \
+                         __func__, fmt, ##__VA_ARGS__)
+#define NGLOG_ERROR(log_class, fmt, ...)                                                           \
+    ::Log::FmtLogMessage(::Log::Class::log_class, ::Log::Level::Error, __FILE__, __LINE__,         \
+                         __func__, fmt, ##__VA_ARGS__)
+#define NGLOG_CRITICAL(log_class, fmt, ...)                                                        \
+    ::Log::FmtLogMessage(::Log::Class::log_class, ::Log::Level::Critical, __FILE__, __LINE__,      \
+                         __func__, fmt, ##__VA_ARGS__)

src/common/logging/text_formatter.cpp

@@ -18,50 +18,26 @@
 
 namespace Log {
 
-// TODO(bunnei): This should be moved to a generic path manipulation library
-const char* TrimSourcePath(const char* path, const char* root) {
-    const char* p = path;
-
-    while (*p != '\0') {
-        const char* next_slash = p;
-        while (*next_slash != '\0' && *next_slash != '/' && *next_slash != '\\') {
-            ++next_slash;
-        }
-
-        bool is_src = Common::ComparePartialString(p, next_slash, root);
-        p = next_slash;
-
-        if (*p != '\0') {
-            ++p;
-        }
-        if (is_src) {
-            path = p;
-        }
-    }
-    return path;
-}
-
-void FormatLogMessage(const Entry& entry, char* out_text, size_t text_len) {
+std::string FormatLogMessage(const Entry& entry) {
     unsigned int time_seconds = static_cast<unsigned int>(entry.timestamp.count() / 1000000);
     unsigned int time_fractional = static_cast<unsigned int>(entry.timestamp.count() % 1000000);
 
     const char* class_name = GetLogClassName(entry.log_class);
     const char* level_name = GetLevelName(entry.log_level);
 
-    snprintf(out_text, text_len, "[%4u.%06u] %s <%s> %s: %s", time_seconds, time_fractional,
-             class_name, level_name, TrimSourcePath(entry.location.c_str()), entry.message.c_str());
+    return fmt::format("[{:4d}.{:06d}] {} <{}> {}:{}:{}: {}", time_seconds, time_fractional,
+                       class_name, level_name, entry.filename, entry.function, entry.line_num,
+                       entry.message);
 }
 
 void PrintMessage(const Entry& entry) {
-    std::array<char, 4 * 1024> format_buffer;
-    FormatLogMessage(entry, format_buffer.data(), format_buffer.size());
-    fputs(format_buffer.data(), stderr);
-    fputc('\n', stderr);
+    auto str = FormatLogMessage(entry) + "\n";
+    fputs(str.c_str(), stderr);
 }
 
 void PrintColoredMessage(const Entry& entry) {
 #ifdef _WIN32
-    static HANDLE console_handle = GetStdHandle(STD_ERROR_HANDLE);
+    HANDLE console_handle = GetStdHandle(STD_ERROR_HANDLE);
 
     CONSOLE_SCREEN_BUFFER_INFO original_info = {0};
     GetConsoleScreenBufferInfo(console_handle, &original_info);
@@ -129,4 +105,4 @@ void PrintColoredMessage(const Entry& entry) {
 #undef ESC
 #endif
 }
-}
+} // namespace Log

src/common/logging/text_formatter.h

@@ -10,22 +10,10 @@ namespace Log {
 
 struct Entry;
 
-/**
- * Attempts to trim an arbitrary prefix from `path`, leaving only the part starting at `root`. It's
- * intended to be used to strip a system-specific build directory from the `__FILE__` macro,
- * leaving only the path relative to the sources root.
- *
- * @param path The input file path as a null-terminated string
- * @param root The name of the root source directory as a null-terminated string. Path up to and
- *             including the last occurrence of this name will be stripped
- * @return A pointer to the same string passed as `path`, but starting at the trimmed portion
- */
-const char* TrimSourcePath(const char* path, const char* root = "src");
-
 /// Formats a log entry into the provided text buffer.
-void FormatLogMessage(const Entry& entry, char* out_text, size_t text_len);
+std::string FormatLogMessage(const Entry& entry);
 /// Formats and prints a log entry to stderr.
 void PrintMessage(const Entry& entry);
 /// Prints the same message as `PrintMessage`, but colored acoording to the severity level.
 void PrintColoredMessage(const Entry& entry);
-}
+} // namespace Log