diff --git a/src/common/logging.cpp b/src/common/logging.cpp index 5915cca862..d327966d97 100644 --- a/src/common/logging.cpp +++ b/src/common/logging.cpp @@ -54,6 +54,19 @@ struct Entry { namespace { +/// @brief A log entry. Log entries are store in a structured format to permit more varied output +/// formatting on different frontends, as well as facilitating filtering and aggregation. +struct Entry { + std::string_view thread_name; + std::string message; + std::chrono::microseconds timestamp; + Class log_class{}; + Level log_level{}; + const char* filename = nullptr; + const char* function = nullptr; + unsigned int line_num = 0; +}; + /// @brief Returns the name of the passed log class as a C-string. Subclasses are separated by periods /// instead of underscores as in the enumeration. /// @note GetClassName is a macro defined by Windows.h, grrr... @@ -90,7 +103,7 @@ std::string FormatLogMessage(const Entry& entry) noexcept { auto const time_fractional = uint32_t(entry.timestamp.count() % 1000000); auto const class_name = GetLogClassName(entry.log_class); auto const level_name = GetLevelName(entry.log_level); - return fmt::format("[{:4d}.{:06d}] {} <{}> {}:{}:{}: {}\n", time_seconds, time_fractional, class_name, level_name, entry.filename, entry.line_num, entry.function, entry.message); + return fmt::format("[{:4d}.{:06d}] {} <{}> ({}) {}:{}:{}: {}\n", time_seconds, time_fractional, class_name, level_name, entry.thread_name.data(), entry.filename, entry.line_num, entry.function, entry.message); } template @@ -156,7 +169,7 @@ struct Backend { }; /// @brief Formatting specifier (to use with printf) of the equivalent fmt::format() expression -#define CCB_PRINTF_FMT "[%4d.%06d] %s <%s> %s:%u:%s: %s" +#define CCB_PRINTF_FMT "[%4d.%06d] %s <%s> (eden:%s) %s:%u:%s: %s" /// @brief Instead of using fmt::format() just use the system's formatting capabilities directly struct DirectFormatArgs { @@ -199,7 +212,7 @@ struct ColorConsoleBackend final : public Backend { }()); SetConsoleTextAttribute(console_handle, color); auto const df = GetDirectFormatArgs(entry); - std::fprintf(stdout, CCB_PRINTF_FMT "\n", df.time_seconds, df.time_fractional, df.class_name, df.level_name, entry.filename, entry.line_num, entry.function, entry.message); + std::fprintf(stdout, CCB_PRINTF_FMT "\n", df.time_seconds, df.time_fractional, df.class_name, df.level_name, entry.thread_name.data(), entry.filename, entry.line_num, entry.function, entry.message); } } void Flush() noexcept override {} @@ -225,7 +238,7 @@ struct ColorConsoleBackend final : public Backend { // more restrictive, because take for example this simple prelude: // [ 50.872256] Config common/settings.cpp:142:LogSettings: char buffer[256]; - auto result = fmt::format_to_n(buffer, sizeof(buffer) - 1, "\x1b{}[{:4d}.{:06d}] {} <{}> {}:{}:{}: ", color_str, df.time_seconds, df.time_fractional, df.class_name, df.level_name, entry.filename, entry.line_num, entry.function, entry.message); + auto result = fmt::format_to_n(buffer, sizeof(buffer) - 1, "\x1b{}[{:4d}.{:06d}] {} <{}> {}:{}:{}: ", color_str, df.time_seconds, df.time_fractional, df.class_name, df.level_name, entry.thread_name.data(), entry.filename, entry.line_num, entry.function, entry.message); std::fwrite(buffer, 1, (std::min)(sizeof(buffer) - 1, result.size), stdout); std::fwrite(entry.message, 1, entry.message_len, stdout); std::fwrite("\x1b[0m\n", 1, sizeof("\x1b[0m\n"), stdout); @@ -329,7 +342,7 @@ struct LogcatBackend : public Backend { } }(); auto const df = GetDirectFormatArgs(entry); - __android_log_print(android_log_priority, "YuzuNative", CCB_PRINTF_FMT, df.time_seconds, df.time_fractional, df.class_name, df.level_name, entry.filename, entry.line_num, entry.function, entry.message); + __android_log_print(android_log_priority, "YuzuNative", CCB_PRINTF_FMT, df.time_seconds, df.time_fractional, df.class_name, df.level_name, entry.thread_name.data(), entry.filename, entry.line_num, entry.function, entry.message); } void Flush() noexcept override {} }; @@ -431,6 +444,7 @@ void FmtLogMessageImpl(Class log_class, Level log_level, const char* filename, u buffer[(std::min)(result.size, sizeof(buffer) - 1)] = '\0'; logging_instance->ForEachBackend([=](Backend& backend) { backend.Write(Entry{ + .thread_name = Common::GetCurrentThreadName(), .message = buffer, .message_len = (std::min)(result.size, sizeof(buffer) - 1), .timestamp = std::chrono::duration_cast(std::chrono::steady_clock::now() - logging_instance->time_origin), diff --git a/src/common/thread.cpp b/src/common/thread.cpp index 7b4dec3dce..49c48ef837 100644 --- a/src/common/thread.cpp +++ b/src/common/thread.cpp @@ -449,6 +449,13 @@ void RememberCurrentThreadNice(pid_t tid, s32 nice_value) { namespace Common { +// The use of TLS is justified as it is faster than using pthread_* functions +// and generally will be better long term... yeah %fs/%gs reloads aren't great +// but it's better than doing a potential call-stack-fuckery... +thread_local struct { + std::string name{}; +} per_thread_data = {}; + void SetCurrentThreadPriority(ThreadPriority new_priority) { #ifdef _WIN32 int windows_priority = [&]() { @@ -503,7 +510,7 @@ void SetCurrentThreadPriority(ThreadPriority new_priority) { #endif } -void SetCurrentThreadName(const char* name) { +void SetCurrentThreadName(const char* name) noexcept { #ifdef _MSC_VER // Sets the debugger-visible name of the current thread. if (auto pf = (decltype(&SetThreadDescription))(void*)GetProcAddress(GetModuleHandle(TEXT("KernelBase.dll")), "SetThreadDescription"); pf) @@ -537,6 +544,11 @@ void SetCurrentThreadName(const char* name) { #else pthread_setname_np(pthread_self(), name); #endif + per_thread_data.name = std::string{name}; +} + +std::string_view GetCurrentThreadName() noexcept { + return per_thread_data.name; } void SetCurrentThreadToPerformanceCores() { diff --git a/src/common/thread.h b/src/common/thread.h index 4a36295931..0d0df991db 100644 --- a/src/common/thread.h +++ b/src/common/thread.h @@ -106,7 +106,10 @@ enum class ThreadPlacement : u32 { }; void SetCurrentThreadPriority(ThreadPriority new_priority); -void SetCurrentThreadName(const char* name); + +void SetCurrentThreadName(const char* name) noexcept; +std::string_view GetCurrentThreadName() noexcept; + void SetCurrentThreadToPerformanceCores(); void SetCurrentThreadToEfficiencyCores(); void SetCurrentThreadToBackgroundWork();