logging: Simplify and make thread-safe

This simplifies the logging system.

This also fixes some lost messages on startup.

The simplification is simple. I removed unused functions and moved most things in the .h to the .cpp. I replaced the unnecessary linked list with its contents laid out as three member variables. Anything that went through the linked list now directly accesses the backends. Generic functions are replaced with those for each specific use case and there aren't many. This change increases coupling but we gain back more KISS and encapsulation.

With those changes it was easy to make it thread-safe. I just removed the mutex and turned a boolean atomic. I was planning to use this thread-safety in my next PR about stacktraces. It was actually async-signal-safety at first but I ended up using a different approach. Anyway getting rid of the linked list is important for that because have the list of backends constantly changing complicates things.

src/common/logging/backend.cpp

@@ -2,13 +2,9 @@
 // Licensed under GPLv2 or any later version
 // Refer to the license.txt file included.
 
-#include <algorithm>
 #include <atomic>
 #include <chrono>
 #include <climits>
-#include <condition_variable>
-#include <memory>
-#include <mutex>
 #include <thread>
 #include <vector>
 
@@ -16,28 +12,173 @@
 #include <windows.h> // For OutputDebugStringW
 #endif
 
-#include "common/assert.h"
 #include "common/fs/file.h"
 #include "common/fs/fs.h"
+#include "common/fs/fs_paths.h"
+#include "common/fs/path_util.h"
 #include "common/literals.h"
 
 #include "common/logging/backend.h"
 #include "common/logging/log.h"
 #include "common/logging/text_formatter.h"
 #include "common/settings.h"
+#ifdef _WIN32
 #include "common/string_util.h"
+#endif
 #include "common/threadsafe_queue.h"
 
 namespace Common::Log {
 
+namespace {
+
+/**
+ * Interface for logging backends.
+ */
+class Backend {
+public:
+    virtual ~Backend() = default;
+
+    virtual void Write(const Entry& entry) = 0;
+
+    virtual void EnableForStacktrace() = 0;
+
+    virtual void Flush() = 0;
+};
+
+/**
+ * Backend that writes to stderr and with color
+ */
+class ColorConsoleBackend final : public Backend {
+public:
+    explicit ColorConsoleBackend() = default;
+
+    ~ColorConsoleBackend() override = default;
+
+    void Write(const Entry& entry) override {
+        if (enabled.load(std::memory_order_relaxed)) {
+            PrintColoredMessage(entry);
+        }
+    }
+
+    void Flush() override {
+        // stderr shouldn't be buffered
+    }
+
+    void EnableForStacktrace() override {
+        enabled = true;
+    }
+
+    void SetEnabled(bool enabled_) {
+        enabled = enabled_;
+    }
+
+private:
+    std::atomic_bool enabled{false};
+};
+
+/**
+ * Backend that writes to a file passed into the constructor
+ */
+class FileBackend final : public Backend {
+public:
+    explicit FileBackend(const std::filesystem::path& filename) {
+        auto old_filename = filename;
+        old_filename += ".old.txt";
+
+        // Existence checks are done within the functions themselves.
+        // We don't particularly care if these succeed or not.
+        static_cast<void>(FS::RemoveFile(old_filename));
+        static_cast<void>(FS::RenameFile(filename, old_filename));
+
+        file = std::make_unique<FS::IOFile>(filename, FS::FileAccessMode::Write,
+                                            FS::FileType::TextFile);
+    }
+
+    ~FileBackend() override = default;
+
+    void Write(const Entry& entry) override {
+        if (!enabled) {
+            return;
+        }
+
+        bytes_written += file->WriteString(FormatLogMessage(entry).append(1, '\n'));
+
+        using namespace Common::Literals;
+        // Prevent logs from exceeding a set maximum size in the event that log entries are spammed.
+        const auto write_limit = Settings::values.extended_logging ? 1_GiB : 100_MiB;
+        const bool write_limit_exceeded = bytes_written > write_limit;
+        if (entry.log_level >= Level::Error || write_limit_exceeded) {
+            if (write_limit_exceeded) {
+                // Stop writing after the write limit is exceeded.
+                // Don't close the file so we can print a stacktrace if necessary
+                enabled = false;
+            }
+            file->Flush();
+        }
+    }
+
+    void Flush() override {
+        file->Flush();
+    }
+
+    void EnableForStacktrace() override {
+        enabled = true;
+        bytes_written = 0;
+    }
+
+private:
+    std::unique_ptr<FS::IOFile> file;
+    bool enabled = true;
+    std::size_t bytes_written = 0;
+};
+
+/**
+ * Backend that writes to Visual Studio's output window
+ */
+class DebuggerBackend final : public Backend {
+public:
+    explicit DebuggerBackend() = default;
+
+    ~DebuggerBackend() override = default;
+
+    void Write(const Entry& entry) override {
+#ifdef _WIN32
+        ::OutputDebugStringW(UTF8ToUTF16W(FormatLogMessage(entry).append(1, '\n')).c_str());
+#endif
+    }
+
+    void Flush() override {}
+
+    void EnableForStacktrace() override {}
+};
+
+bool initialization_in_progress_suppress_logging = false;
+
 /**
  * Static state as a singleton.
  */
 class Impl {
 public:
     static Impl& Instance() {
-        static Impl backend;
+        if (!instance) {
-        return backend;
+            abort();
+        }
+        return *instance;
+    }
+
+    static void Initialize() {
+        if (instance) {
+            abort();
+        }
+        using namespace Common::FS;
+        initialization_in_progress_suppress_logging = true;
+        const auto& log_dir = GetYuzuPath(YuzuPath::LogDir);
+        void(CreateDir(log_dir));
+        Filter filter;
+        filter.ParseFilterString(Settings::values.log_filter.GetValue());
+        instance = std::unique_ptr<Impl, decltype(&Deleter)>(new Impl(log_dir / LOG_FILE, filter),
+                                                             Deleter);
+        initialization_in_progress_suppress_logging = false;
     }
 
     Impl(const Impl&) = delete;
@@ -46,74 +187,54 @@ public:
     Impl(Impl&&) = delete;
     Impl& operator=(Impl&&) = delete;
 
-    void PushEntry(Class log_class, Level log_level, const char* filename, unsigned int line_num,
-                   const char* function, std::string message) {
-        message_queue.Push(
-            CreateEntry(log_class, log_level, filename, line_num, function, std::move(message)));
-    }
-
-    void AddBackend(std::unique_ptr<Backend> backend) {
-        std::lock_guard lock{writing_mutex};
-        backends.push_back(std::move(backend));
-    }
-
-    void RemoveBackend(std::string_view backend_name) {
-        std::lock_guard lock{writing_mutex};
-
-        std::erase_if(backends, [&backend_name](const auto& backend) {
-            return backend_name == backend->GetName();
-        });
-    }
-
-    const Filter& GetGlobalFilter() const {
-        return filter;
-    }
-
     void SetGlobalFilter(const Filter& f) {
         filter = f;
     }
 
-    Backend* GetBackend(std::string_view backend_name) {
+    void SetColorConsoleBackendEnabled(bool enabled) {
-        const auto it =
+        color_console_backend.SetEnabled(enabled);
-            std::find_if(backends.begin(), backends.end(),
+    }
-                         [&backend_name](const auto& i) { return backend_name == i->GetName(); });
+
-        if (it == backends.end())
+    void PushEntry(Class log_class, Level log_level, const char* filename, unsigned int line_num,
-            return nullptr;
+                   const char* function, std::string message) {
-        return it->get();
+        if (!filter.CheckMessage(log_class, log_level))
+            return;
+        const Entry& entry =
+            CreateEntry(log_class, log_level, filename, line_num, function, std::move(message));
+        message_queue.Push(entry);
     }
 
 private:
-    Impl() {
+    Impl(const std::filesystem::path& file_backend_filename, const Filter& filter_)
-        backend_thread = std::thread([&] {
+        : filter{filter_}, file_backend{file_backend_filename}, backend_thread{std::thread([this] {
+              Common::SetCurrentThreadName("yuzu:Log");
               Entry entry;
-            auto write_logs = [&](Entry& e) {
+              const auto write_logs = [this, &entry]() {
-                std::lock_guard lock{writing_mutex};
+                  ForEachBackend([&entry](Backend& backend) { backend.Write(entry); });
-                for (const auto& backend : backends) {
-                    backend->Write(e);
-                }
               };
               while (true) {
                   entry = message_queue.PopWait();
                   if (entry.final_entry) {
                       break;
                   }
-                write_logs(entry);
+                  write_logs();
               }
-
               // Drain the logging queue. Only writes out up to MAX_LOGS_TO_WRITE to prevent a
               // case where a system is repeatedly spamming logs even on close.
-            const int MAX_LOGS_TO_WRITE = filter.IsDebug() ? INT_MAX : 100;
+              int max_logs_to_write = filter.IsDebug() ? INT_MAX : 100;
-            int logs_written = 0;
+              while (max_logs_to_write-- && message_queue.Pop(entry)) {
-            while (logs_written++ < MAX_LOGS_TO_WRITE && message_queue.Pop(entry)) {
+                  write_logs();
-                write_logs(entry);
-            }
-        });
               }
+          })} {}
 
     ~Impl() {
-        Entry entry;
+        StopBackendThread();
-        entry.final_entry = true;
+    }
-        message_queue.Push(entry);
+
+    void StopBackendThread() {
+        Entry stop_entry{};
+        stop_entry.final_entry = true;
+        message_queue.Push(stop_entry);
         backend_thread.join();
     }
 
@@ -135,100 +256,51 @@ private:
         };
     }
 
-    std::mutex writing_mutex;
+    void ForEachBackend(auto lambda) {
-    std::thread backend_thread;
+        lambda(static_cast<Backend&>(debugger_backend));
-    std::vector<std::unique_ptr<Backend>> backends;
+        lambda(static_cast<Backend&>(color_console_backend));
-    MPSCQueue<Entry> message_queue;
+        lambda(static_cast<Backend&>(file_backend));
+    }
+
+    static void Deleter(Impl* ptr) {
+        delete ptr;
+    }
+
+    static inline std::unique_ptr<Impl, decltype(&Deleter)> instance{nullptr, Deleter};
+
     Filter filter;
+    DebuggerBackend debugger_backend{};
+    ColorConsoleBackend color_console_backend{};
+    FileBackend file_backend;
+
+    std::thread backend_thread;
+    MPSCQueue<Entry> message_queue{};
     std::chrono::steady_clock::time_point time_origin{std::chrono::steady_clock::now()};
 };
+} // namespace
 
-ConsoleBackend::~ConsoleBackend() = default;
+void Initialize() {
-
+    Impl::Initialize();
-void ConsoleBackend::Write(const Entry& entry) {
-    PrintMessage(entry);
 }
 
-ColorConsoleBackend::~ColorConsoleBackend() = default;
+void DisableLoggingInTests() {
-
+    initialization_in_progress_suppress_logging = true;
-void ColorConsoleBackend::Write(const Entry& entry) {
-    PrintColoredMessage(entry);
-}
-
-FileBackend::FileBackend(const std::filesystem::path& filename) {
-    auto old_filename = filename;
-    old_filename += ".old.txt";
-
-    // Existence checks are done within the functions themselves.
-    // We don't particularly care if these succeed or not.
-    FS::RemoveFile(old_filename);
-    void(FS::RenameFile(filename, old_filename));
-
-    file =
-        std::make_unique<FS::IOFile>(filename, FS::FileAccessMode::Write, FS::FileType::TextFile);
-}
-
-FileBackend::~FileBackend() = default;
-
-void FileBackend::Write(const Entry& entry) {
-    if (!file->IsOpen()) {
-        return;
-    }
-
-    using namespace Common::Literals;
-    // Prevent logs from exceeding a set maximum size in the event that log entries are spammed.
-    constexpr std::size_t MAX_BYTES_WRITTEN = 100_MiB;
-    constexpr std::size_t MAX_BYTES_WRITTEN_EXTENDED = 1_GiB;
-
-    const bool write_limit_exceeded =
-        bytes_written > MAX_BYTES_WRITTEN_EXTENDED ||
-        (bytes_written > MAX_BYTES_WRITTEN && !Settings::values.extended_logging);
-
-    // Close the file after the write limit is exceeded.
-    if (write_limit_exceeded) {
-        file->Close();
-        return;
-    }
-
-    bytes_written += file->WriteString(FormatLogMessage(entry).append(1, '\n'));
-    if (entry.log_level >= Level::Error) {
-        file->Flush();
-    }
-}
-
-DebuggerBackend::~DebuggerBackend() = default;
-
-void DebuggerBackend::Write(const Entry& entry) {
-#ifdef _WIN32
-    ::OutputDebugStringW(UTF8ToUTF16W(FormatLogMessage(entry).append(1, '\n')).c_str());
-#endif
 }
 
 void SetGlobalFilter(const Filter& filter) {
     Impl::Instance().SetGlobalFilter(filter);
 }
 
-void AddBackend(std::unique_ptr<Backend> backend) {
+void SetColorConsoleBackendEnabled(bool enabled) {
-    Impl::Instance().AddBackend(std::move(backend));
+    Impl::Instance().SetColorConsoleBackendEnabled(enabled);
-}
-
-void RemoveBackend(std::string_view backend_name) {
-    Impl::Instance().RemoveBackend(backend_name);
-}
-
-Backend* GetBackend(std::string_view backend_name) {
-    return Impl::Instance().GetBackend(backend_name);
 }
 
 void FmtLogMessageImpl(Class log_class, Level log_level, const char* filename,
                        unsigned int line_num, const char* function, const char* format,
                        const fmt::format_args& args) {
-    auto& instance = Impl::Instance();
+    if (!initialization_in_progress_suppress_logging) {
-    const auto& filter = instance.GetGlobalFilter();
+        Impl::Instance().PushEntry(log_class, log_level, filename, line_num, function,
-    if (!filter.CheckMessage(log_class, log_level))
-        return;
-
-    instance.PushEntry(log_class, log_level, filename, line_num, function,
                                    fmt::vformat(format, args));
     }
+}
 } // namespace Common::Log

src/common/logging/backend.h

@@ -5,120 +5,21 @@
 #pragma once
 
 #include <filesystem>
-#include <memory>
-#include <string>
-#include <string_view>
 #include "common/logging/filter.h"
-#include "common/logging/log.h"
-
-namespace Common::FS {
-class IOFile;
-}
 
 namespace Common::Log {
 
 class Filter;
 
-/**
+/// Initializes the logging system. This should be the first thing called in main.
- * Interface for logging backends. As loggers can be created and removed at runtime, this can be
+void Initialize();
- * 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) {
+void DisableLoggingInTests();
-        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
+ * The global filter will prevent any messages from even being processed if they are filtered.
- */
-class ConsoleBackend : public Backend {
-public:
-    ~ConsoleBackend() override;
-
-    static const char* Name() {
-        return "console";
-    }
-    const char* GetName() const override {
-        return Name();
-    }
-    void Write(const Entry& entry) override;
-};
-
-/**
- * Backend that writes to stderr and with color
- */
-class ColorConsoleBackend : public Backend {
-public:
-    ~ColorConsoleBackend() override;
-
-    static const char* Name() {
-        return "color_console";
-    }
-
-    const char* GetName() const override {
-        return Name();
-    }
-    void Write(const Entry& entry) override;
-};
-
-/**
- * Backend that writes to a file passed into the constructor
- */
-class FileBackend : public Backend {
-public:
-    explicit FileBackend(const std::filesystem::path& filename);
-    ~FileBackend() override;
-
-    static const char* Name() {
-        return "file";
-    }
-
-    const char* GetName() const override {
-        return Name();
-    }
-
-    void Write(const Entry& entry) override;
-
-private:
-    std::unique_ptr<FS::IOFile> file;
-    std::size_t bytes_written = 0;
-};
-
-/**
- * Backend that writes to Visual Studio's output window
- */
-class DebuggerBackend : public Backend {
-public:
-    ~DebuggerBackend() override;
-
-    static const char* Name() {
-        return "debugger";
-    }
-    const char* GetName() const override {
-        return Name();
-    }
-    void Write(const Entry& entry) override;
-};
-
-void AddBackend(std::unique_ptr<Backend> backend);
-
-void RemoveBackend(std::string_view backend_name);
-
-Backend* GetBackend(std::string_view backend_name);
-
-/**
- * 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);
+
+void SetColorConsoleBackendEnabled(bool enabled);
 } // namespace Common::Log

src/core/core.cpp

@@ -84,8 +84,6 @@ FileSys::StorageId GetStorageIdForFrontendSlot(
 
 } // Anonymous namespace
 
-/*static*/ System System::s_instance;
-
 FileSys::VirtualFile GetGameFileFromPath(const FileSys::VirtualFilesystem& vfs,
                                          const std::string& path) {
     // To account for split 00+01+etc files.
@@ -425,6 +423,13 @@ struct System::Impl {
 System::System() : impl{std::make_unique<Impl>(*this)} {}
 System::~System() = default;
 
+void System::InitializeGlobalInstance() {
+    if (s_instance) {
+        abort();
+    }
+    s_instance = std::unique_ptr<System>(new System);
+}
+
 CpuManager& System::GetCpuManager() {
     return impl->cpu_manager;
 }

src/core/core.h

@@ -121,8 +121,13 @@ public:
      * @returns Reference to the instance of the System singleton class.
      */
     [[deprecated("Use of the global system instance is deprecated")]] static System& GetInstance() {
-        return s_instance;
+        if (!s_instance) {
+            abort();
         }
+        return *s_instance;
+    }
+
+    static void InitializeGlobalInstance();
 
     /// Enumeration representing the return values of the System Initialize and Load process.
     enum class ResultStatus : u32 {
@@ -396,7 +401,7 @@ private:
     struct Impl;
     std::unique_ptr<Impl> impl;
 
-    static System s_instance;
+    inline static std::unique_ptr<System> s_instance{};
 };
 
 } // namespace Core

src/tests/common/param_package.cpp

@@ -4,11 +4,13 @@
 
 #include <catch2/catch.hpp>
 #include <math.h>
+#include "common/logging/backend.h"
 #include "common/param_package.h"
 
 namespace Common {
 
 TEST_CASE("ParamPackage", "[common]") {
+    Common::Log::DisableLoggingInTests();
     ParamPackage original{
         {"abc", "xyz"},
         {"def", "42"},

src/yuzu/debugger/console.cpp

@@ -21,6 +21,7 @@ void ToggleConsole() {
         console_shown = UISettings::values.show_console.GetValue();
     }
 
+    using namespace Common::Log;
 #if defined(_WIN32) && !defined(_DEBUG)
     FILE* temp;
     if (UISettings::values.show_console) {
@@ -29,24 +30,20 @@ void ToggleConsole() {
             freopen_s(&temp, "CONIN$", "r", stdin);
             freopen_s(&temp, "CONOUT$", "w", stdout);
             freopen_s(&temp, "CONOUT$", "w", stderr);
-            Common::Log::AddBackend(std::make_unique<Common::Log::ColorConsoleBackend>());
+            SetColorConsoleBackendEnabled(true);
         }
     } else {
         if (FreeConsole()) {
             // In order to close the console, we have to also detach the streams on it.
             // Just redirect them to NUL if there is no console window
-            Common::Log::RemoveBackend(Common::Log::ColorConsoleBackend::Name());
+            SetColorConsoleBackendEnabled(false);
             freopen_s(&temp, "NUL", "r", stdin);
             freopen_s(&temp, "NUL", "w", stdout);
             freopen_s(&temp, "NUL", "w", stderr);
         }
     }
 #else
-    if (UISettings::values.show_console) {
+    SetColorConsoleBackendEnabled(UISettings::values.show_console.GetValue());
-        Common::Log::AddBackend(std::make_unique<Common::Log::ColorConsoleBackend>());
-    } else {
-        Common::Log::RemoveBackend(Common::Log::ColorConsoleBackend::Name());
-    }
 #endif
 }
 } // namespace Debugger

src/yuzu/main.cpp

@@ -175,21 +175,6 @@ void GMainWindow::ShowTelemetryCallout() {
 
 const int GMainWindow::max_recent_files_item;
 
-static void InitializeLogging() {
-    using namespace Common;
-
-    Log::Filter log_filter;
-    log_filter.ParseFilterString(Settings::values.log_filter.GetValue());
-    Log::SetGlobalFilter(log_filter);
-
-    const auto log_dir = FS::GetYuzuPath(FS::YuzuPath::LogDir);
-    void(FS::CreateDir(log_dir));
-    Log::AddBackend(std::make_unique<Log::FileBackend>(log_dir / LOG_FILE));
-#ifdef _WIN32
-    Log::AddBackend(std::make_unique<Log::DebuggerBackend>());
-#endif
-}
-
 static void RemoveCachedContents() {
     const auto cache_dir = Common::FS::GetYuzuPath(Common::FS::YuzuPath::CacheDir);
     const auto offline_fonts = cache_dir / "fonts";
@@ -207,8 +192,6 @@ GMainWindow::GMainWindow()
     : input_subsystem{std::make_shared<InputCommon::InputSubsystem>()},
       config{std::make_unique<Config>()}, vfs{std::make_shared<FileSys::RealVfsFilesystem>()},
       provider{std::make_unique<FileSys::ManualContentProvider>()} {
-    InitializeLogging();
-
     LoadTranslation();
 
     setAcceptDrops(true);
@@ -3398,6 +3381,7 @@ void GMainWindow::SetDiscordEnabled([[maybe_unused]] bool state) {
 #endif
 
 int main(int argc, char* argv[]) {
+    Common::Log::Initialize();
     Common::DetachedTasks detached_tasks;
     MicroProfileOnThreadCreate("Frontend");
     SCOPE_EXIT({ MicroProfileShutdown(); });
@@ -3437,6 +3421,7 @@ int main(int argc, char* argv[]) {
     // generating shaders
     setlocale(LC_ALL, "C");
 
+    Core::System::InitializeGlobalInstance();
     GMainWindow main_window;
     // After settings have been loaded by GMainWindow, apply the filter
     main_window.show();

src/yuzu_cmd/yuzu.cpp

@@ -74,31 +74,14 @@ static void PrintVersion() {
     std::cout << "yuzu " << Common::g_scm_branch << " " << Common::g_scm_desc << std::endl;
 }
 
-static void InitializeLogging() {
-    using namespace Common;
-
-    Log::Filter log_filter(Log::Level::Debug);
-    log_filter.ParseFilterString(static_cast<std::string>(Settings::values.log_filter));
-    Log::SetGlobalFilter(log_filter);
-
-    Log::AddBackend(std::make_unique<Log::ColorConsoleBackend>());
-
-    const auto& log_dir = FS::GetYuzuPath(FS::YuzuPath::LogDir);
-    void(FS::CreateDir(log_dir));
-    Log::AddBackend(std::make_unique<Log::FileBackend>(log_dir / LOG_FILE));
-#ifdef _WIN32
-    Log::AddBackend(std::make_unique<Log::DebuggerBackend>());
-#endif
-}
-
 /// Application entry point
 int main(int argc, char** argv) {
+    Common::Log::Initialize();
+    Common::Log::SetColorConsoleBackendEnabled(true);
     Common::DetachedTasks detached_tasks;
     Config config;
 
     int option_index = 0;
-
-    InitializeLogging();
 #ifdef _WIN32
     int argc_w;
     auto argv_w = CommandLineToArgvW(GetCommandLineW(), &argc_w);
@@ -163,6 +146,7 @@ int main(int argc, char** argv) {
         return -1;
     }
 
+    Core::System::InitializeGlobalInstance();
     auto& system{Core::System::GetInstance()};
     InputCommon::InputSubsystem input_subsystem;