// Copyright 2014 Citra Emulator Project // Licensed under GPLv2 or any later version // Refer to the license.txt file included. #include #include #include #include #include #ifdef _WIN32 #include // For OutputDebugStringW #endif #if defined(__linux__) && defined(__GNUG__) && !defined(__clang__) #define BOOST_STACKTRACE_USE_BACKTRACE #include #undef BOOST_STACKTRACE_USE_BACKTRACE #include #define YUZU_LINUX_GCC_BACKTRACE #endif #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(FS::RemoveFile(old_filename)); static_cast(FS::RenameFile(filename, old_filename)); file = std::make_unique(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 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; #ifdef YUZU_LINUX_GCC_BACKTRACE [[noreturn]] void SleepForever() { while (true) { pause(); } } #endif /** * Static state as a singleton. */ class Impl { public: static Impl& Instance() { if (!instance) { 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(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; } 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(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(); } })} { #ifdef YUZU_LINUX_GCC_BACKTRACE int waker_pipefd[2]; int done_printing_pipefd[2]; if (pipe2(waker_pipefd, O_CLOEXEC) || pipe2(done_printing_pipefd, O_CLOEXEC)) { abort(); } backtrace_thread_waker_fd = waker_pipefd[1]; backtrace_done_printing_fd = done_printing_pipefd[0]; std::thread([this, wait_fd = waker_pipefd[0], done_fd = done_printing_pipefd[1]] { Common::SetCurrentThreadName("yuzu:Crash"); for (u8 ignore = 0; read(wait_fd, &ignore, 1) != 1;) ; const int sig = received_signal; if (sig <= 0) { abort(); } StopBackendThread(); const auto signal_entry = CreateEntry(Class::Log, Level::Critical, "?", 0, "?", fmt::vformat("Received signal {}", fmt::make_format_args(sig))); ForEachBackend([&signal_entry](Backend& backend) { backend.EnableForStacktrace(); backend.Write(signal_entry); }); const auto backtrace = boost::stacktrace::stacktrace::from_dump(backtrace_storage.data(), 4096); for (const auto& frame : backtrace.as_vector()) { auto line = boost::stacktrace::detail::to_string(&frame, 1); if (line.empty()) { abort(); } line.pop_back(); // Remove newline const auto frame_entry = CreateEntry(Class::Log, Level::Critical, "?", 0, "?", line); ForEachBackend([&frame_entry](Backend& backend) { backend.Write(frame_entry); }); } using namespace std::literals; const auto rip_entry = CreateEntry(Class::Log, Level::Critical, "?", 0, "?", "RIP"s); ForEachBackend([&rip_entry](Backend& backend) { backend.Write(rip_entry); backend.Flush(); }); for (const u8 anything = 0; write(done_fd, &anything, 1) != 1;) ; // Abort on original thread to help debugging SleepForever(); }).detach(); signal(SIGSEGV, &HandleSignal); signal(SIGABRT, &HandleSignal); #endif } ~Impl() { #ifdef YUZU_LINUX_GCC_BACKTRACE if (int zero_or_ignore = 0; !received_signal.compare_exchange_strong(zero_or_ignore, SIGKILL)) { SleepForever(); } #endif StopBackendThread(); } void StopBackendThread() { Entry stop_entry{}; stop_entry.final_entry = true; message_queue.Push(stop_entry); backend_thread.join(); } Entry CreateEntry(Class log_class, Level log_level, const char* filename, unsigned int line_nr, const char* function, std::string message) const { using std::chrono::duration_cast; using std::chrono::microseconds; using std::chrono::steady_clock; return { .timestamp = duration_cast(steady_clock::now() - time_origin), .log_class = log_class, .log_level = log_level, .filename = filename, .line_num = line_nr, .function = function, .message = std::move(message), .final_entry = false, }; } void ForEachBackend(auto lambda) { lambda(static_cast(debugger_backend)); lambda(static_cast(color_console_backend)); lambda(static_cast(file_backend)); } static void Deleter(Impl* ptr) { delete ptr; } #ifdef YUZU_LINUX_GCC_BACKTRACE [[noreturn]] static void HandleSignal(int sig) { signal(SIGABRT, SIG_DFL); signal(SIGSEGV, SIG_DFL); if (sig <= 0) { abort(); } instance->InstanceHandleSignal(sig); } [[noreturn]] void InstanceHandleSignal(int sig) { if (int zero_or_ignore = 0; !received_signal.compare_exchange_strong(zero_or_ignore, sig)) { if (received_signal == SIGKILL) { abort(); } SleepForever(); } // Don't restart like boost suggests. We want to append to the log file and not lose dynamic // symbols. This may segfault if it unwinds outside C/C++ code but we'll just have to fall // back to core dumps. boost::stacktrace::safe_dump_to(backtrace_storage.data(), 4096); std::atomic_thread_fence(std::memory_order_seq_cst); for (const int anything = 0; write(backtrace_thread_waker_fd, &anything, 1) != 1;) ; for (u8 ignore = 0; read(backtrace_done_printing_fd, &ignore, 1) != 1;) ; abort(); } #endif static inline std::unique_ptr instance{nullptr, Deleter}; Filter filter; DebuggerBackend debugger_backend{}; ColorConsoleBackend color_console_backend{}; FileBackend file_backend; std::thread backend_thread; MPSCQueue message_queue{}; std::chrono::steady_clock::time_point time_origin{std::chrono::steady_clock::now()}; #ifdef YUZU_LINUX_GCC_BACKTRACE std::atomic_int received_signal{0}; std::array backtrace_storage{}; int backtrace_thread_waker_fd; int backtrace_done_printing_fd; #endif }; } // namespace void Initialize() { Impl::Initialize(); } void DisableLoggingInTests() { initialization_in_progress_suppress_logging = true; } void SetGlobalFilter(const Filter& filter) { Impl::Instance().SetGlobalFilter(filter); } 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) { if (!initialization_in_progress_suppress_logging) { Impl::Instance().PushEntry(log_class, log_level, filename, line_num, function, fmt::vformat(format, args)); } } } // namespace Common::Log