Merge pull request #6869 from yzct12345/shiny-logs-in-the-fireplace

logging: Simplify and make thread-safe

1 files changed, 211 insertions, 139 deletions

diff --git a/src/common/logging/backend.cpp b/src/common/logging/backend.cpp
index 61dddab3f..13edda9c9 100644
--- a/src/common/logging/backend.cpp
+++ b/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,104 +12,229 @@
 #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 {
+
 /**
- * Static state as a singleton.
+ * Interface for logging backends.
  */
-class Impl {
+class Backend {
 public:
-    static Impl& Instance() {
-        static Impl backend;
-        return backend;
+    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);
+        }
     }
 
-    Impl(const Impl&) = delete;
-    Impl& operator=(const Impl&) = delete;
+    void Flush() override {
+        // stderr shouldn't be buffered
+    }
 
-    Impl(Impl&&) = delete;
-    Impl& operator=(Impl&&) = delete;
+    void EnableForStacktrace() override {
+        enabled = true;
+    }
 
-    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 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;
     }
 
-    void AddBackend(std::unique_ptr<Backend> backend) {
-        std::lock_guard lock{writing_mutex};
-        backends.push_back(std::move(backend));
+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 RemoveBackend(std::string_view backend_name) {
-        std::lock_guard lock{writing_mutex};
+    void Flush() override {}
+
+    void EnableForStacktrace() override {}
+};
+
+bool initialization_in_progress_suppress_logging = false;
 
-        std::erase_if(backends, [&backend_name](const auto& backend) {
-            return backend_name == backend->GetName();
-        });
+/**
+ * Static state as a singleton.
+ */
+class Impl {
+public:
+    static Impl& Instance() {
+        if (!instance) {
+            abort();
+        }
+        return *instance;
     }
 
-    const Filter& GetGlobalFilter() const {
-        return filter;
+    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;
+    Impl& operator=(const Impl&) = delete;
+
+    Impl(Impl&&) = delete;
+    Impl& operator=(Impl&&) = delete;
+
     void SetGlobalFilter(const Filter& f) {
         filter = f;
     }
 
-    Backend* GetBackend(std::string_view backend_name) {
-        const auto it =
-            std::find_if(backends.begin(), backends.end(),
-                         [&backend_name](const auto& i) { return backend_name == i->GetName(); });
-        if (it == backends.end())
-            return nullptr;
-        return it->get();
+    void SetColorConsoleBackendEnabled(bool enabled) {
+        color_console_backend.SetEnabled(enabled);
+    }
+
+    void PushEntry(Class log_class, Level log_level, const char* filename, unsigned int line_num,
+                   const char* function, std::string message) {
+        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() {
-        backend_thread = std::thread([&] {
-            Entry entry;
-            auto write_logs = [&](Entry& e) {
-                std::lock_guard lock{writing_mutex};
-                for (const auto& backend : backends) {
-                    backend->Write(e);
-                }
-            };
-            while (true) {
-                entry = message_queue.PopWait();
-                if (entry.final_entry) {
-                    break;
-                }
-                write_logs(entry);
-            }
+    Impl(const std::filesystem::path& file_backend_filename, const Filter& filter_)
+        : filter{filter_}, file_backend{file_backend_filename}, backend_thread{std::thread([this] {
+              Common::SetCurrentThreadName("yuzu:Log");
+              Entry entry;
+              const auto write_logs = [this, &entry]() {
+                  ForEachBackend([&entry](Backend& backend) { backend.Write(entry); });
+              };
+              while (true) {
+                  entry = message_queue.PopWait();
+                  if (entry.final_entry) {
+                      break;
+                  }
+                  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.
+              int max_logs_to_write = filter.IsDebug() ? INT_MAX : 100;
+              while (max_logs_to_write-- && message_queue.Pop(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 logs_written = 0;
-            while (logs_written++ < MAX_LOGS_TO_WRITE && message_queue.Pop(entry)) {
-                write_logs(entry);
-            }
-        });
+    ~Impl() {
+        StopBackendThread();
     }
 
-    ~Impl() {
-        Entry entry;
-        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;
-    std::thread backend_thread;
-    std::vector<std::unique_ptr<Backend>> backends;
-    MPSCQueue<Entry> message_queue;
-    Filter filter;
-    std::chrono::steady_clock::time_point time_origin{std::chrono::steady_clock::now()};
-};
-
-ConsoleBackend::~ConsoleBackend() = default;
-
-void ConsoleBackend::Write(const Entry& entry) {
-    PrintMessage(entry);
-}
-
-ColorConsoleBackend::~ColorConsoleBackend() = default;
-
-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 ForEachBackend(auto lambda) {
+        lambda(static_cast<Backend&>(debugger_backend));
+        lambda(static_cast<Backend&>(color_console_backend));
+        lambda(static_cast<Backend&>(file_backend));
+    }
 
-void FileBackend::Write(const Entry& entry) {
-    if (!file->IsOpen()) {
-        return;
+    static void Deleter(Impl* ptr) {
+        delete ptr;
     }
 
-    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;
+    static inline std::unique_ptr<Impl, decltype(&Deleter)> instance{nullptr, Deleter};
 
-    const bool write_limit_exceeded =
-        bytes_written > MAX_BYTES_WRITTEN_EXTENDED ||
-        (bytes_written > MAX_BYTES_WRITTEN && !Settings::values.extended_logging);
+    Filter filter;
+    DebuggerBackend debugger_backend{};
+    ColorConsoleBackend color_console_backend{};
+    FileBackend file_backend;
 
-    // Close the file after the write limit is exceeded.
-    if (write_limit_exceeded) {
-        file->Close();
-        return;
-    }
+    std::thread backend_thread;
+    MPSCQueue<Entry> message_queue{};
+    std::chrono::steady_clock::time_point time_origin{std::chrono::steady_clock::now()};
+};
+} // namespace
 
-    bytes_written += file->WriteString(FormatLogMessage(entry).append(1, '\n'));
-    if (entry.log_level >= Level::Error) {
-        file->Flush();
-    }
+void Initialize() {
+    Impl::Initialize();
 }
 
-DebuggerBackend::~DebuggerBackend() = default;
-
-void DebuggerBackend::Write(const Entry& entry) {
-#ifdef _WIN32
-    ::OutputDebugStringW(UTF8ToUTF16W(FormatLogMessage(entry).append(1, '\n')).c_str());
-#endif
+void DisableLoggingInTests() {
+    initialization_in_progress_suppress_logging = true;
 }
 
 void SetGlobalFilter(const Filter& filter) {
     Impl::Instance().SetGlobalFilter(filter);
 }
 
-void AddBackend(std::unique_ptr<Backend> backend) {
-    Impl::Instance().AddBackend(std::move(backend));
-}
-
-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 SetColorConsoleBackendEnabled(bool enabled) {
+    Impl::Instance().SetColorConsoleBackendEnabled(enabled);
 }
 
 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();
-    const auto& filter = instance.GetGlobalFilter();
-    if (!filter.CheckMessage(log_class, log_level))
-        return;
-
-    instance.PushEntry(log_class, log_level, filename, line_num, function,
-                       fmt::vformat(format, args));
+    if (!initialization_in_progress_suppress_logging) {
+        Impl::Instance().PushEntry(log_class, log_level, filename, line_num, function,
+                                   fmt::vformat(format, args));
+    }
 }
 } // namespace Common::Log