diff options
| author | smiRaphi <neogt404@gmail.com> | 2026-04-06 19:17:43 +0200 |
|---|---|---|
| committer | crueter <crueter@eden-emu.dev> | 2026-04-06 19:17:43 +0200 |
| commit | d99a8c65ccfdd7dcf9ff80a8aac0ff8109998c47 (patch) | |
| tree | 746451ef3d83d7266d767af5aadfb5db2a2ad575 /src/core/hle/kernel | |
| parent | 876884e783c1cd6604ce840684605295427c600f (diff) | |
[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 <Info> 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 <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: Thread)
[ 9.707791] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: [SF-Internal]
[ 9.707827] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString:
[ 9.708202] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: Stack trace:
[ 9.708880] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866B5170 (unknown)
[ 9.708911] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866B42BC (unknown)
[ 9.708916] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866B4AEC (unknown)
[ 9.708919] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866B2F20 (unknown)
[ 9.708922] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866B19BC (unknown)
[ 9.708925] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x0000000086875C64 (unknown)
[ 9.708927] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000868752E0 (unknown)
[ 9.708929] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x0000000086874C1C (unknown)
[ 9.708932] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866FBD1C (unknown)
[ 9.708944] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x00000000866FBDCC (unknown)
[ 9.708967] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString:
[ 9.709035] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: Related modules:
[ 9.709061] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: base size name/path
[ 9.709349] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString: 0x000000008665D000 0x0000000000E50000 nnSdkEn
[ 9.709431] Debug.Emulated <Info> core\hle\kernel\svc\svc_debug_string.cpp:17:OutputDebugString:
```
Into:
```
[ 5.895512] Debug.Emulated <Info> 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 <crueter@eden-emu.dev>
Co-authored-by: smiRaphi <neogt404@gmail.com>
Co-committed-by: smiRaphi <neogt404@gmail.com>
Diffstat (limited to 'src/core/hle/kernel')
| -rw-r--r-- | src/core/hle/kernel/svc/svc_debug_string.cpp | 73 |
1 files 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 <condition_variable> +#include <mutex> +#include <thread> + #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<std::thread> 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<std::thread>(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 |
