From d99a8c65ccfdd7dcf9ff80a8aac0ff8109998c47 Mon Sep 17 00:00:00 2001 From: smiRaphi Date: Mon, 6 Apr 2026 19:17:43 +0200 Subject: [PATCH] [hle/kernel] Fix OutputDebugString formatting (#3744) Fixes the debug outputs by buffering it, should not effect any normal game as the flush thread only get's created once the function has actually been called. Turning it from: ``` [ 9.707449] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: SDK Assertion Failure: 'hipc::ResultSessionClosed::Includes(result)' in CloseClientSessionHandleSafely() at pid=81, tid=76(Main [ 9.707642] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: Thread) [ 9.707791] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: [SF-Internal] [ 9.707827] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: [ 9.708202] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: Stack trace: [ 9.708880] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866B5170 (unknown) [ 9.708911] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866B42BC (unknown) [ 9.708916] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866B4AEC (unknown) [ 9.708919] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866B2F20 (unknown) [ 9.708922] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866B19BC (unknown) [ 9.708925] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x0000000086875C64 (unknown) [ 9.708927] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000868752E0 (unknown) [ 9.708929] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x0000000086874C1C (unknown) [ 9.708932] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866FBD1C (unknown) [ 9.708944] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866FBDCC (unknown) [ 9.708967] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: [ 9.709035] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: Related modules: [ 9.709061] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: base size name/path [ 9.709349] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x000000008665D000 0x0000000000E50000 nnSdkEn [ 9.709431] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: ``` Into: ``` [ 5.895512] Debug.Emulated core\hle\kernel\svc\svc_debug_string.cpp:47:FlushDbgLoop: SDK Assertion Failure: 'hipc::ResultSessionClosed::Includes(result)' in CloseClientSessionHandleSafely() at pid=81, tid=76(MainThread) [SF-Internal] Stack trace: 0x00000000866B5170 (unknown) 0x00000000866B42BC (unknown) 0x00000000866B4AEC (unknown) 0x00000000866B2F20 (unknown) 0x00000000866B19BC (unknown) 0x0000000086875C64 (unknown) 0x00000000868752E0 (unknown) 0x0000000086874C1C (unknown) 0x00000000866FBD1C (unknown) 0x00000000866FBDCC (unknown) Related modules: base size name/path 0x000000008665D000 0x0000000000E50000 nnSdkEn ``` Reviewed-on: https://git.eden-emu.dev/eden-emu/eden/pulls/3744 Reviewed-by: crueter Co-authored-by: smiRaphi Co-committed-by: smiRaphi --- src/core/hle/kernel/svc/svc_debug_string.cpp | 73 +++++++++++++++++++- 1 file changed, 70 insertions(+), 3 deletions(-) diff --git a/src/core/hle/kernel/svc/svc_debug_string.cpp b/src/core/hle/kernel/svc/svc_debug_string.cpp index 00b65429be..92cc334a81 100644 --- a/src/core/hle/kernel/svc/svc_debug_string.cpp +++ b/src/core/hle/kernel/svc/svc_debug_string.cpp @@ -1,6 +1,13 @@ +// SPDX-FileCopyrightText: Copyright 2026 Eden Emulator Project +// SPDX-License-Identifier: GPL-3.0-or-later + // SPDX-FileCopyrightText: Copyright 2023 yuzu Emulator Project // SPDX-License-Identifier: GPL-2.0-or-later +#include +#include +#include + #include "core/core.h" #include "core/hle/kernel/k_thread.h" #include "core/hle/kernel/svc.h" @@ -8,14 +15,62 @@ namespace Kernel::Svc { +constexpr auto MAX_MSG_TIME = std::chrono::milliseconds(250); +const auto MAX_MSG_SIZE = 0x1000; + +static std::string msg_buffer; +static std::mutex msg_mutex; +static std::condition_variable msg_cv; +static std::chrono::steady_clock::time_point last_msg_time; +static bool worker_running = true; +static std::unique_ptr flush_thread; +static std::once_flag start_flag; + +static void FlushDbgLoop() { + while (true) { + std::unique_lock lock(msg_mutex); + + msg_cv.wait(lock, [] { return !msg_buffer.empty() || !worker_running; }); + if (!worker_running && msg_buffer.empty()) break; + + auto timeout = last_msg_time + MAX_MSG_TIME; + bool woke_early = msg_cv.wait_until(lock, timeout, [] { + return msg_buffer.size() >= MAX_MSG_SIZE || !worker_running; + }); + + if (!woke_early || msg_buffer.size() >= MAX_MSG_SIZE || !worker_running) { + if (!msg_buffer.empty()) { + // Remove trailing newline as LOG_INFO adds that anyways + if (msg_buffer.back() == '\n') + msg_buffer.pop_back(); + + LOG_INFO(Debug_Emulated, "\n{}", msg_buffer); + msg_buffer.clear(); + } + if (!worker_running) break; + } + } +} + /// Used to output a message on a debug hardware unit - does nothing on a retail unit Result OutputDebugString(Core::System& system, u64 address, u64 len) { R_SUCCEED_IF(len == 0); - std::string str(len, '\0'); - GetCurrentMemory(system.Kernel()).ReadBlock(address, str.data(), str.size()); - LOG_INFO(Debug_Emulated, "{}", str); + // Only start the thread the very first time this function is called + std::call_once(start_flag, [] { + flush_thread = std::make_unique(FlushDbgLoop); + }); + { + std::lock_guard lock(msg_mutex); + const auto old_size = msg_buffer.size(); + msg_buffer.resize(old_size + len); + GetCurrentMemory(system.Kernel()).ReadBlock(address, msg_buffer.data() + old_size, len); + + last_msg_time = std::chrono::steady_clock::now(); + } + + msg_cv.notify_one(); R_SUCCEED(); } @@ -27,4 +82,16 @@ Result OutputDebugString64From32(Core::System& system, uint32_t debug_str, uint3 R_RETURN(OutputDebugString(system, debug_str, len)); } +struct BufferAutoFlush { + ~BufferAutoFlush() { + { + std::lock_guard lock(msg_mutex); + worker_running = false; + } + msg_cv.notify_all(); + if (flush_thread && flush_thread->joinable()) flush_thread->join(); + } +}; +static BufferAutoFlush auto_flusher; + } // namespace Kernel::Svc