diff options
Diffstat (limited to 'src/common/logging/backend.cpp')
| -rw-r--r-- | src/common/logging/backend.cpp | 352 |
1 files changed, 213 insertions, 139 deletions
diff --git a/src/common/logging/backend.cpp b/src/common/logging/backend.cpp index 61dddab3f..e40d117d6 100644 --- a/src/common/logging/backend.cpp +++ b/src/common/logging/backend.cpp | |||
| @@ -2,13 +2,10 @@ | |||
| 2 | // Licensed under GPLv2 or any later version | 2 | // Licensed under GPLv2 or any later version |
| 3 | // Refer to the license.txt file included. | 3 | // Refer to the license.txt file included. |
| 4 | 4 | ||
| 5 | #include <algorithm> | ||
| 6 | #include <atomic> | 5 | #include <atomic> |
| 7 | #include <chrono> | 6 | #include <chrono> |
| 8 | #include <climits> | 7 | #include <climits> |
| 9 | #include <condition_variable> | 8 | #include <exception> |
| 10 | #include <memory> | ||
| 11 | #include <mutex> | ||
| 12 | #include <thread> | 9 | #include <thread> |
| 13 | #include <vector> | 10 | #include <vector> |
| 14 | 11 | ||
| @@ -16,104 +13,230 @@ | |||
| 16 | #include <windows.h> // For OutputDebugStringW | 13 | #include <windows.h> // For OutputDebugStringW |
| 17 | #endif | 14 | #endif |
| 18 | 15 | ||
| 19 | #include "common/assert.h" | ||
| 20 | #include "common/fs/file.h" | 16 | #include "common/fs/file.h" |
| 21 | #include "common/fs/fs.h" | 17 | #include "common/fs/fs.h" |
| 18 | #include "common/fs/fs_paths.h" | ||
| 19 | #include "common/fs/path_util.h" | ||
| 22 | #include "common/literals.h" | 20 | #include "common/literals.h" |
| 21 | #include "common/thread.h" | ||
| 23 | 22 | ||
| 24 | #include "common/logging/backend.h" | 23 | #include "common/logging/backend.h" |
| 25 | #include "common/logging/log.h" | 24 | #include "common/logging/log.h" |
| 26 | #include "common/logging/text_formatter.h" | 25 | #include "common/logging/text_formatter.h" |
| 27 | #include "common/settings.h" | 26 | #include "common/settings.h" |
| 27 | #ifdef _WIN32 | ||
| 28 | #include "common/string_util.h" | 28 | #include "common/string_util.h" |
| 29 | #endif | ||
| 29 | #include "common/threadsafe_queue.h" | 30 | #include "common/threadsafe_queue.h" |
| 30 | 31 | ||
| 31 | namespace Common::Log { | 32 | namespace Common::Log { |
| 32 | 33 | ||
| 34 | namespace { | ||
| 35 | |||
| 33 | /** | 36 | /** |
| 34 | * Static state as a singleton. | 37 | * Interface for logging backends. |
| 35 | */ | 38 | */ |
| 36 | class Impl { | 39 | class Backend { |
| 37 | public: | 40 | public: |
| 38 | static Impl& Instance() { | 41 | virtual ~Backend() = default; |
| 39 | static Impl backend; | 42 | |
| 40 | return backend; | 43 | virtual void Write(const Entry& entry) = 0; |
| 44 | |||
| 45 | virtual void EnableForStacktrace() = 0; | ||
| 46 | |||
| 47 | virtual void Flush() = 0; | ||
| 48 | }; | ||
| 49 | |||
| 50 | /** | ||
| 51 | * Backend that writes to stderr and with color | ||
| 52 | */ | ||
| 53 | class ColorConsoleBackend final : public Backend { | ||
| 54 | public: | ||
| 55 | explicit ColorConsoleBackend() = default; | ||
| 56 | |||
| 57 | ~ColorConsoleBackend() override = default; | ||
| 58 | |||
| 59 | void Write(const Entry& entry) override { | ||
| 60 | if (enabled.load(std::memory_order_relaxed)) { | ||
| 61 | PrintColoredMessage(entry); | ||
| 62 | } | ||
| 41 | } | 63 | } |
| 42 | 64 | ||
| 43 | Impl(const Impl&) = delete; | 65 | void Flush() override { |
| 44 | Impl& operator=(const Impl&) = delete; | 66 | // stderr shouldn't be buffered |
| 67 | } | ||
| 45 | 68 | ||
| 46 | Impl(Impl&&) = delete; | 69 | void EnableForStacktrace() override { |
| 47 | Impl& operator=(Impl&&) = delete; | 70 | enabled = true; |
| 71 | } | ||
| 48 | 72 | ||
| 49 | void PushEntry(Class log_class, Level log_level, const char* filename, unsigned int line_num, | 73 | void SetEnabled(bool enabled_) { |
| 50 | const char* function, std::string message) { | 74 | enabled = enabled_; |
| 51 | message_queue.Push( | 75 | } |
| 52 | CreateEntry(log_class, log_level, filename, line_num, function, std::move(message))); | 76 | |
| 77 | private: | ||
| 78 | std::atomic_bool enabled{false}; | ||
| 79 | }; | ||
| 80 | |||
| 81 | /** | ||
| 82 | * Backend that writes to a file passed into the constructor | ||
| 83 | */ | ||
| 84 | class FileBackend final : public Backend { | ||
| 85 | public: | ||
| 86 | explicit FileBackend(const std::filesystem::path& filename) { | ||
| 87 | auto old_filename = filename; | ||
| 88 | old_filename += ".old.txt"; | ||
| 89 | |||
| 90 | // Existence checks are done within the functions themselves. | ||
| 91 | // We don't particularly care if these succeed or not. | ||
| 92 | static_cast<void>(FS::RemoveFile(old_filename)); | ||
| 93 | static_cast<void>(FS::RenameFile(filename, old_filename)); | ||
| 94 | |||
| 95 | file = std::make_unique<FS::IOFile>(filename, FS::FileAccessMode::Write, | ||
| 96 | FS::FileType::TextFile); | ||
| 97 | } | ||
| 98 | |||
| 99 | ~FileBackend() override = default; | ||
| 100 | |||
| 101 | void Write(const Entry& entry) override { | ||
| 102 | if (!enabled) { | ||
| 103 | return; | ||
| 104 | } | ||
| 105 | |||
| 106 | bytes_written += file->WriteString(FormatLogMessage(entry).append(1, '\n')); | ||
| 107 | |||
| 108 | using namespace Common::Literals; | ||
| 109 | // Prevent logs from exceeding a set maximum size in the event that log entries are spammed. | ||
| 110 | const auto write_limit = Settings::values.extended_logging ? 1_GiB : 100_MiB; | ||
| 111 | const bool write_limit_exceeded = bytes_written > write_limit; | ||
| 112 | if (entry.log_level >= Level::Error || write_limit_exceeded) { | ||
| 113 | if (write_limit_exceeded) { | ||
| 114 | // Stop writing after the write limit is exceeded. | ||
| 115 | // Don't close the file so we can print a stacktrace if necessary | ||
| 116 | enabled = false; | ||
| 117 | } | ||
| 118 | file->Flush(); | ||
| 119 | } | ||
| 120 | } | ||
| 121 | |||
| 122 | void Flush() override { | ||
| 123 | file->Flush(); | ||
| 124 | } | ||
| 125 | |||
| 126 | void EnableForStacktrace() override { | ||
| 127 | enabled = true; | ||
| 128 | bytes_written = 0; | ||
| 53 | } | 129 | } |
| 54 | 130 | ||
| 55 | void AddBackend(std::unique_ptr<Backend> backend) { | 131 | private: |
| 56 | std::lock_guard lock{writing_mutex}; | 132 | std::unique_ptr<FS::IOFile> file; |
| 57 | backends.push_back(std::move(backend)); | 133 | bool enabled = true; |
| 134 | std::size_t bytes_written = 0; | ||
| 135 | }; | ||
| 136 | |||
| 137 | /** | ||
| 138 | * Backend that writes to Visual Studio's output window | ||
| 139 | */ | ||
| 140 | class DebuggerBackend final : public Backend { | ||
| 141 | public: | ||
| 142 | explicit DebuggerBackend() = default; | ||
| 143 | |||
| 144 | ~DebuggerBackend() override = default; | ||
| 145 | |||
| 146 | void Write(const Entry& entry) override { | ||
| 147 | #ifdef _WIN32 | ||
| 148 | ::OutputDebugStringW(UTF8ToUTF16W(FormatLogMessage(entry).append(1, '\n')).c_str()); | ||
| 149 | #endif | ||
| 58 | } | 150 | } |
| 59 | 151 | ||
| 60 | void RemoveBackend(std::string_view backend_name) { | 152 | void Flush() override {} |
| 61 | std::lock_guard lock{writing_mutex}; | 153 | |
| 154 | void EnableForStacktrace() override {} | ||
| 155 | }; | ||
| 156 | |||
| 157 | bool initialization_in_progress_suppress_logging = true; | ||
| 62 | 158 | ||
| 63 | std::erase_if(backends, [&backend_name](const auto& backend) { | 159 | /** |
| 64 | return backend_name == backend->GetName(); | 160 | * Static state as a singleton. |
| 65 | }); | 161 | */ |
| 162 | class Impl { | ||
| 163 | public: | ||
| 164 | static Impl& Instance() { | ||
| 165 | if (!instance) { | ||
| 166 | throw std::runtime_error("Using Logging instance before its initialization"); | ||
| 167 | } | ||
| 168 | return *instance; | ||
| 66 | } | 169 | } |
| 67 | 170 | ||
| 68 | const Filter& GetGlobalFilter() const { | 171 | static void Initialize() { |
| 69 | return filter; | 172 | if (instance) { |
| 173 | LOG_WARNING(Log, "Reinitializing logging backend"); | ||
| 174 | return; | ||
| 175 | } | ||
| 176 | using namespace Common::FS; | ||
| 177 | const auto& log_dir = GetYuzuPath(YuzuPath::LogDir); | ||
| 178 | void(CreateDir(log_dir)); | ||
| 179 | Filter filter; | ||
| 180 | filter.ParseFilterString(Settings::values.log_filter.GetValue()); | ||
| 181 | instance = std::unique_ptr<Impl, decltype(&Deleter)>(new Impl(log_dir / LOG_FILE, filter), | ||
| 182 | Deleter); | ||
| 183 | initialization_in_progress_suppress_logging = false; | ||
| 70 | } | 184 | } |
| 71 | 185 | ||
| 186 | Impl(const Impl&) = delete; | ||
| 187 | Impl& operator=(const Impl&) = delete; | ||
| 188 | |||
| 189 | Impl(Impl&&) = delete; | ||
| 190 | Impl& operator=(Impl&&) = delete; | ||
| 191 | |||
| 72 | void SetGlobalFilter(const Filter& f) { | 192 | void SetGlobalFilter(const Filter& f) { |
| 73 | filter = f; | 193 | filter = f; |
| 74 | } | 194 | } |
| 75 | 195 | ||
| 76 | Backend* GetBackend(std::string_view backend_name) { | 196 | void SetColorConsoleBackendEnabled(bool enabled) { |
| 77 | const auto it = | 197 | color_console_backend.SetEnabled(enabled); |
| 78 | std::find_if(backends.begin(), backends.end(), | 198 | } |
| 79 | [&backend_name](const auto& i) { return backend_name == i->GetName(); }); | 199 | |
| 80 | if (it == backends.end()) | 200 | void PushEntry(Class log_class, Level log_level, const char* filename, unsigned int line_num, |
| 81 | return nullptr; | 201 | const char* function, std::string message) { |
| 82 | return it->get(); | 202 | if (!filter.CheckMessage(log_class, log_level)) |
| 203 | return; | ||
| 204 | const Entry& entry = | ||
| 205 | CreateEntry(log_class, log_level, filename, line_num, function, std::move(message)); | ||
| 206 | message_queue.Push(entry); | ||
| 83 | } | 207 | } |
| 84 | 208 | ||
| 85 | private: | 209 | private: |
| 86 | Impl() { | 210 | Impl(const std::filesystem::path& file_backend_filename, const Filter& filter_) |
| 87 | backend_thread = std::thread([&] { | 211 | : filter{filter_}, file_backend{file_backend_filename}, backend_thread{std::thread([this] { |
| 88 | Entry entry; | 212 | Common::SetCurrentThreadName("yuzu:Log"); |
| 89 | auto write_logs = [&](Entry& e) { | 213 | Entry entry; |
| 90 | std::lock_guard lock{writing_mutex}; | 214 | const auto write_logs = [this, &entry]() { |
| 91 | for (const auto& backend : backends) { | 215 | ForEachBackend([&entry](Backend& backend) { backend.Write(entry); }); |
| 92 | backend->Write(e); | 216 | }; |
| 93 | } | 217 | while (true) { |
| 94 | }; | 218 | entry = message_queue.PopWait(); |
| 95 | while (true) { | 219 | if (entry.final_entry) { |
| 96 | entry = message_queue.PopWait(); | 220 | break; |
| 97 | if (entry.final_entry) { | 221 | } |
| 98 | break; | 222 | write_logs(); |
| 99 | } | 223 | } |
| 100 | write_logs(entry); | 224 | // Drain the logging queue. Only writes out up to MAX_LOGS_TO_WRITE to prevent a |
| 101 | } | 225 | // case where a system is repeatedly spamming logs even on close. |
| 226 | int max_logs_to_write = filter.IsDebug() ? INT_MAX : 100; | ||
| 227 | while (max_logs_to_write-- && message_queue.Pop(entry)) { | ||
| 228 | write_logs(); | ||
| 229 | } | ||
| 230 | })} {} | ||
| 102 | 231 | ||
| 103 | // Drain the logging queue. Only writes out up to MAX_LOGS_TO_WRITE to prevent a | 232 | ~Impl() { |
| 104 | // case where a system is repeatedly spamming logs even on close. | 233 | StopBackendThread(); |
| 105 | const int MAX_LOGS_TO_WRITE = filter.IsDebug() ? INT_MAX : 100; | ||
| 106 | int logs_written = 0; | ||
| 107 | while (logs_written++ < MAX_LOGS_TO_WRITE && message_queue.Pop(entry)) { | ||
| 108 | write_logs(entry); | ||
| 109 | } | ||
| 110 | }); | ||
| 111 | } | 234 | } |
| 112 | 235 | ||
| 113 | ~Impl() { | 236 | void StopBackendThread() { |
| 114 | Entry entry; | 237 | Entry stop_entry{}; |
| 115 | entry.final_entry = true; | 238 | stop_entry.final_entry = true; |
| 116 | message_queue.Push(entry); | 239 | message_queue.Push(stop_entry); |
| 117 | backend_thread.join(); | 240 | backend_thread.join(); |
| 118 | } | 241 | } |
| 119 | 242 | ||
| @@ -135,100 +258,51 @@ private: | |||
| 135 | }; | 258 | }; |
| 136 | } | 259 | } |
| 137 | 260 | ||
| 138 | std::mutex writing_mutex; | 261 | void ForEachBackend(auto lambda) { |
| 139 | std::thread backend_thread; | 262 | lambda(static_cast<Backend&>(debugger_backend)); |
| 140 | std::vector<std::unique_ptr<Backend>> backends; | 263 | lambda(static_cast<Backend&>(color_console_backend)); |
| 141 | MPSCQueue<Entry> message_queue; | 264 | lambda(static_cast<Backend&>(file_backend)); |
| 142 | Filter filter; | 265 | } |
| 143 | std::chrono::steady_clock::time_point time_origin{std::chrono::steady_clock::now()}; | ||
| 144 | }; | ||
| 145 | |||
| 146 | ConsoleBackend::~ConsoleBackend() = default; | ||
| 147 | |||
| 148 | void ConsoleBackend::Write(const Entry& entry) { | ||
| 149 | PrintMessage(entry); | ||
| 150 | } | ||
| 151 | |||
| 152 | ColorConsoleBackend::~ColorConsoleBackend() = default; | ||
| 153 | |||
| 154 | void ColorConsoleBackend::Write(const Entry& entry) { | ||
| 155 | PrintColoredMessage(entry); | ||
| 156 | } | ||
| 157 | |||
| 158 | FileBackend::FileBackend(const std::filesystem::path& filename) { | ||
| 159 | auto old_filename = filename; | ||
| 160 | old_filename += ".old.txt"; | ||
| 161 | |||
| 162 | // Existence checks are done within the functions themselves. | ||
| 163 | // We don't particularly care if these succeed or not. | ||
| 164 | FS::RemoveFile(old_filename); | ||
| 165 | void(FS::RenameFile(filename, old_filename)); | ||
| 166 | |||
| 167 | file = | ||
| 168 | std::make_unique<FS::IOFile>(filename, FS::FileAccessMode::Write, FS::FileType::TextFile); | ||
| 169 | } | ||
| 170 | |||
| 171 | FileBackend::~FileBackend() = default; | ||
| 172 | 266 | ||
| 173 | void FileBackend::Write(const Entry& entry) { | 267 | static void Deleter(Impl* ptr) { |
| 174 | if (!file->IsOpen()) { | 268 | delete ptr; |
| 175 | return; | ||
| 176 | } | 269 | } |
| 177 | 270 | ||
| 178 | using namespace Common::Literals; | 271 | static inline std::unique_ptr<Impl, decltype(&Deleter)> instance{nullptr, Deleter}; |
| 179 | // Prevent logs from exceeding a set maximum size in the event that log entries are spammed. | ||
| 180 | constexpr std::size_t MAX_BYTES_WRITTEN = 100_MiB; | ||
| 181 | constexpr std::size_t MAX_BYTES_WRITTEN_EXTENDED = 1_GiB; | ||
| 182 | 272 | ||
| 183 | const bool write_limit_exceeded = | 273 | Filter filter; |
| 184 | bytes_written > MAX_BYTES_WRITTEN_EXTENDED || | 274 | DebuggerBackend debugger_backend{}; |
| 185 | (bytes_written > MAX_BYTES_WRITTEN && !Settings::values.extended_logging); | 275 | ColorConsoleBackend color_console_backend{}; |
| 276 | FileBackend file_backend; | ||
| 186 | 277 | ||
| 187 | // Close the file after the write limit is exceeded. | 278 | std::thread backend_thread; |
| 188 | if (write_limit_exceeded) { | 279 | MPSCQueue<Entry> message_queue{}; |
| 189 | file->Close(); | 280 | std::chrono::steady_clock::time_point time_origin{std::chrono::steady_clock::now()}; |
| 190 | return; | 281 | }; |
| 191 | } | 282 | } // namespace |
| 192 | 283 | ||
| 193 | bytes_written += file->WriteString(FormatLogMessage(entry).append(1, '\n')); | 284 | void Initialize() { |
| 194 | if (entry.log_level >= Level::Error) { | 285 | Impl::Initialize(); |
| 195 | file->Flush(); | ||
| 196 | } | ||
| 197 | } | 286 | } |
| 198 | 287 | ||
| 199 | DebuggerBackend::~DebuggerBackend() = default; | 288 | void DisableLoggingInTests() { |
| 200 | 289 | initialization_in_progress_suppress_logging = true; | |
| 201 | void DebuggerBackend::Write(const Entry& entry) { | ||
| 202 | #ifdef _WIN32 | ||
| 203 | ::OutputDebugStringW(UTF8ToUTF16W(FormatLogMessage(entry).append(1, '\n')).c_str()); | ||
| 204 | #endif | ||
| 205 | } | 290 | } |
| 206 | 291 | ||
| 207 | void SetGlobalFilter(const Filter& filter) { | 292 | void SetGlobalFilter(const Filter& filter) { |
| 208 | Impl::Instance().SetGlobalFilter(filter); | 293 | Impl::Instance().SetGlobalFilter(filter); |
| 209 | } | 294 | } |
| 210 | 295 | ||
| 211 | void AddBackend(std::unique_ptr<Backend> backend) { | 296 | void SetColorConsoleBackendEnabled(bool enabled) { |
| 212 | Impl::Instance().AddBackend(std::move(backend)); | 297 | Impl::Instance().SetColorConsoleBackendEnabled(enabled); |
| 213 | } | ||
| 214 | |||
| 215 | void RemoveBackend(std::string_view backend_name) { | ||
| 216 | Impl::Instance().RemoveBackend(backend_name); | ||
| 217 | } | ||
| 218 | |||
| 219 | Backend* GetBackend(std::string_view backend_name) { | ||
| 220 | return Impl::Instance().GetBackend(backend_name); | ||
| 221 | } | 298 | } |
| 222 | 299 | ||
| 223 | void FmtLogMessageImpl(Class log_class, Level log_level, const char* filename, | 300 | void FmtLogMessageImpl(Class log_class, Level log_level, const char* filename, |
| 224 | unsigned int line_num, const char* function, const char* format, | 301 | unsigned int line_num, const char* function, const char* format, |
| 225 | const fmt::format_args& args) { | 302 | const fmt::format_args& args) { |
| 226 | auto& instance = Impl::Instance(); | 303 | if (!initialization_in_progress_suppress_logging) { |
| 227 | const auto& filter = instance.GetGlobalFilter(); | 304 | Impl::Instance().PushEntry(log_class, log_level, filename, line_num, function, |
| 228 | if (!filter.CheckMessage(log_class, log_level)) | 305 | fmt::vformat(format, args)); |
| 229 | return; | 306 | } |
| 230 | |||
| 231 | instance.PushEntry(log_class, log_level, filename, line_num, function, | ||
| 232 | fmt::vformat(format, args)); | ||
| 233 | } | 307 | } |
| 234 | } // namespace Common::Log | 308 | } // namespace Common::Log |