Compare commits

..

2 Commits

Author SHA1 Message Date
lizzie a225ffa385 ah yes how to forget the time i messed up a merge 2026-08-29 06:51:09 +00:00
lizzie 1dd159d414 [common/logging] Add thread names
Signed-off-by: lizzie <lizzie@eden-emu.dev>
2026-08-29 06:34:33 +00:00
11 changed files with 42 additions and 79 deletions
+9 -8
View File
@@ -38,10 +38,12 @@
#include "common/bounded_threadsafe_queue.h"
namespace Common::Log {
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;
char const* message = nullptr;
size_t message_len = 0;
std::chrono::microseconds timestamp;
@@ -49,11 +51,9 @@ struct Entry {
Level log_level{};
const char* filename = nullptr;
const char* function = nullptr;
uint32_t line_num = 0;
unsigned int line_num = 0;
};
namespace {
/// @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 +90,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 <typename It>
@@ -156,7 +156,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 +199,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 +225,7 @@ struct ColorConsoleBackend final : public Backend {
// more restrictive, because take for example this simple prelude:
// [ 50.872256] Config <Info> 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 +329,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 +431,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::microseconds>(std::chrono::steady_clock::now() - logging_instance->time_origin),
+13 -1
View File
@@ -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() {
+4 -1
View File
@@ -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();
+6 -34
View File
@@ -4,7 +4,6 @@
#include <array>
#include <atomic>
#include <memory>
#include <unordered_map>
#include <utility>
#include "game_settings.h"
@@ -249,30 +248,12 @@ struct System::Impl {
}
}
void NotifyNVDECChannelOpen(u64 process_id) {
std::scoped_lock lock{nvdec_active_mutex};
++nvdec_active_channels[process_id];
}
void NotifyNVDECChannelClose(u64 process_id) {
std::scoped_lock lock{nvdec_active_mutex};
const auto it = nvdec_active_channels.find(process_id);
if (it == nvdec_active_channels.end()) {
return;
}
if (--it->second == 0) {
nvdec_active_channels.erase(it);
}
void SetNVDECActive(bool is_nvdec_active) {
nvdec_active = is_nvdec_active;
}
bool GetNVDECActive() {
std::scoped_lock lock{nvdec_active_mutex};
return !nvdec_active_channels.empty();
}
bool IsNVDECActiveForProcess(u64 process_id) {
std::scoped_lock lock{nvdec_active_mutex};
return nvdec_active_channels.contains(process_id);
return nvdec_active;
}
void InitializeDebugger(System& system, u16 port) {
@@ -524,8 +505,6 @@ struct System::Impl {
mutable std::mutex suspend_guard;
std::mutex general_channel_mutex;
std::mutex nvdec_active_mutex;
std::unordered_map<u64, u32> nvdec_active_channels;
std::atomic_bool is_paused{};
std::atomic_bool is_shutting_down{};
std::atomic_bool is_powered_on{};
@@ -533,6 +512,7 @@ struct System::Impl {
bool extended_memory_layout : 1 = false;
bool exit_locked : 1 = false;
bool exit_requested : 1 = false;
bool nvdec_active : 1 = false;
void EnsureGeneralChannelInitialized(System& system) {
if (!general_channel_event) {
@@ -596,22 +576,14 @@ void System::UnstallApplication() {
impl->UnstallApplication();
}
void System::NotifyNVDECChannelOpen(u64 process_id) {
impl->NotifyNVDECChannelOpen(process_id);
}
void System::NotifyNVDECChannelClose(u64 process_id) {
impl->NotifyNVDECChannelClose(process_id);
void System::SetNVDECActive(bool is_nvdec_active) {
impl->SetNVDECActive(is_nvdec_active);
}
bool System::GetNVDECActive() {
return impl->GetNVDECActive();
}
bool System::IsNVDECActiveForProcess(u64 process_id) {
return impl->IsNVDECActiveForProcess(process_id);
}
void System::InitializeDebugger() {
impl->InitializeDebugger(*this, Settings::values.gdbstub_port.GetValue());
}
+1 -3
View File
@@ -191,10 +191,8 @@ public:
std::unique_lock<std::mutex> StallApplication();
void UnstallApplication();
void NotifyNVDECChannelOpen(u64 process_id);
void NotifyNVDECChannelClose(u64 process_id);
void SetNVDECActive(bool is_nvdec_active);
[[nodiscard]] bool GetNVDECActive();
[[nodiscard]] bool IsNVDECActiveForProcess(u64 process_id);
/**
* Initialize the debugger.
+2 -2
View File
@@ -1216,7 +1216,7 @@ Result KServerSession::ReceiveRequest(KernelCore& kernel, uintptr_t server_messa
}
Result KServerSession::SendReply(KernelCore& kernel, uintptr_t server_message, uintptr_t server_buffer_size,
KPhysicalAddress server_message_paddr, bool is_hle, bool session_closed) {
KPhysicalAddress server_message_paddr, bool is_hle) {
// Lock the session.
KScopedLightLock lk{m_lock};
@@ -1248,7 +1248,7 @@ Result KServerSession::SendReply(KernelCore& kernel, uintptr_t server_message, u
KEvent* event = request->GetEvent();
// Check whether we're closed.
const bool closed = (client_thread == nullptr || m_parent->IsClientClosed() || session_closed);
const bool closed = (client_thread == nullptr || m_parent->IsClientClosed());
Result result = ResultSuccess;
if (!closed) {
+3 -3
View File
@@ -54,14 +54,14 @@ public:
Result OnRequest(KernelCore& kernel, KSessionRequest* request);
Result SendReply(KernelCore& kernel, uintptr_t server_message, uintptr_t server_buffer_size,
KPhysicalAddress server_message_paddr, bool is_hle = false, bool session_closed = false);
KPhysicalAddress server_message_paddr, bool is_hle = false);
Result ReceiveRequest(KernelCore& kernel, uintptr_t server_message, uintptr_t server_buffer_size,
KPhysicalAddress server_message_paddr,
std::shared_ptr<Service::HLERequestContext>* out_context = nullptr,
std::weak_ptr<Service::SessionRequestManager> manager = {});
Result SendReplyHLE(KernelCore& kernel, bool session_closed = false) {
R_RETURN(this->SendReply(kernel, 0, 0, 0, true, session_closed));
Result SendReplyHLE(KernelCore& kernel) {
R_RETURN(this->SendReply(kernel, 0, 0, 0, true));
}
Result ReceiveRequestHLE(KernelCore& kernel, std::shared_ptr<Service::HLERequestContext>* out_context,
@@ -8,7 +8,6 @@
#include "common/assert.h"
#include "common/logging.h"
#include "core/core.h"
#include "core/hle/kernel/k_process.h"
#include "core/hle/service/nvdrv/core/container.h"
#include "core/hle/service/nvdrv/devices/ioctl_serialization.h"
#include "core/hle/service/nvdrv/devices/nvhost_nvdec.h"
@@ -72,23 +71,17 @@ NvResult nvhost_nvdec::Ioctl3(DeviceFD fd, Ioctl command, std::span<const u8> in
void nvhost_nvdec::OnOpen(NvCore::SessionId session_id, DeviceFD fd) {
LOG_INFO(Service_NVDRV, "NVDEC video stream started");
system.SetNVDECActive(true);
sessions[fd] = session_id;
if (const auto* session = core.GetSession(session_id);
session != nullptr && session->process != nullptr) {
system.NotifyNVDECChannelOpen(session->process->GetId());
}
host1x.StartDevice(fd, Tegra::Host1x::ChannelType::NvDec, channel_syncpoint);
}
void nvhost_nvdec::OnClose(DeviceFD fd) {
LOG_INFO(Service_NVDRV, "NVDEC video stream ended");
host1x.StopDevice(fd, Tegra::Host1x::ChannelType::NvDec);
system.SetNVDECActive(false);
auto it = sessions.find(fd);
if (it != sessions.end()) {
if (const auto* session = core.GetSession(it->second);
session != nullptr && session->process != nullptr) {
system.NotifyNVDECChannelClose(session->process->GetId());
}
sessions.erase(it);
}
}
+1 -1
View File
@@ -393,7 +393,7 @@ Result ServerManager::CompleteSyncRequest(Session* session) {
}
// Send the reply.
res = server_session->SendReplyHLE(m_system.Kernel(), service_res == IPC::ResultSessionClosed);
res = server_session->SendReplyHLE(m_system.Kernel());
// If the session has been closed, we're done.
if (res == Kernel::ResultSessionClosed || service_res == IPC::ResultSessionClosed) {
+1 -15
View File
@@ -4,16 +4,12 @@
// SPDX-FileCopyrightText: Copyright 2018 yuzu Emulator Project
// SPDX-License-Identifier: GPL-2.0-or-later
#include <chrono>
#include <fmt/ranges.h>
#include <string_view>
#include <thread>
#include "common/assert.h"
#include "common/logging.h"
#include "common/settings.h"
#include "core/core.h"
#include "core/hle/ipc.h"
#include "core/hle/kernel/k_process.h"
#include "core/hle/kernel/kernel.h"
#include "core/hle/service/ipc_helpers.h"
#include "core/hle/service/service.h"
@@ -37,7 +33,6 @@ ServiceFrameworkBase::ServiceFrameworkBase(Core::System& system_, const char* se
: SessionRequestHandler(system_.Kernel(), service_name_)
, system{system_}
, service_name{service_name_}
, is_i_storage{std::string_view{service_name_} == "IStorage"}
, handler_invoker{handler_invoker_}
, max_sessions{max_sessions_}
{}
@@ -82,22 +77,13 @@ void ServiceFrameworkBase::ReportUnimplementedFunction(HLERequestContext& ctx,
}
void ServiceFrameworkBase::InvokeRequest(HLERequestContext& ctx) {
const auto command = ctx.GetCommand();
auto it = handlers.find(command);
const bool is_cmd_read = command == 0;
auto it = handlers.find(ctx.GetCommand());
FunctionInfoBase const* info = it == handlers.end() ? nullptr : &it->second;
if (info == nullptr || info->handler_callback == nullptr)
return ReportUnimplementedFunction(ctx, info);
LOG_TRACE(Service, "{}", MakeFunctionString(info->name, GetServiceName(), ctx.CommandBuffer()));
handler_invoker(this, info->handler_callback, ctx);
if (is_i_storage && is_cmd_read) {
const auto* const process = ctx.GetThread().GetOwnerProcess();
if (process != nullptr && system.IsNVDECActiveForProcess(process->GetId())) {
std::this_thread::sleep_for(std::chrono::microseconds{600});
}
}
}
void ServiceFrameworkBase::InvokeRequestTipc(HLERequestContext& ctx) {
-2
View File
@@ -107,8 +107,6 @@ protected:
Core::System& system;
/// Identifier string used to connect to the service.
const char* service_name;
/// Whether this is the IStorage service.
const bool is_i_storage;
/// Function used to safely up-cast pointers to the derived class before invoking a handler.
InvokerFn* handler_invoker;
/// Maximum number of concurrent sessions that this service can handle.