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.
author: yzct12345 <87620833+yzct12345@users.noreply.github.com> 2021-08-13 18:39:45 +0000
committer: GitHub <noreply@github.com> 2021-08-13 18:39:45 +0000
commit: 001675dced1b7b751d1db4f0d6490776c613df2f (patch)
tree: 151923c90c42bdcede2581ddf6b56768bfcafc01 /src/common/logging/backend.cpp
parent: 71d8d84b59ae6e1cfad37d70e6ea7d61001326f3 (diff)
1 files changed, 211 insertions, 139 deletions
diff --git a/src/common/logging/backend.cpp b/src/common/logging/backend.cpp
index 61dddab3f5..13edda9c9f 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
author	yzct12345 <87620833+yzct12345@users.noreply.github.com>	2021-08-13 18:39:45 +0000
committer	GitHub <noreply@github.com>	2021-08-13 18:39:45 +0000
commit	001675dced1b7b751d1db4f0d6490776c613df2f (patch)
tree	151923c90c42bdcede2581ddf6b56768bfcafc01 /src/common/logging/backend.cpp
parent	71d8d84b59ae6e1cfad37d70e6ea7d61001326f3 (diff)