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