From 5eb3d64ed02fc6de74be5ff4c4df2c06dbdd8bb3 Mon Sep 17 00:00:00 2001 From: jpolo1224 Date: Mon, 10 Aug 2026 15:49:20 -0400 Subject: [PATCH] Name where each guest thread is parked when frames stop The RSX-side stall report says what the RSX is doing, which on every hang chased so far has been idling while the guest waits -- and nothing said which guest thread or what it was in. The syscall stats name the syscall without the caller, and a thread that has not started reads from /proc exactly like one that is blocked. One line per PPU thread with its name, state, PC and current function, on the same condition and cadence as the RSX report. Reads the id map unlocked on purpose: this runs on the RSX thread, and taking that lock to diagnose a hang would add the kind of dependency being diagnosed. --- rpcs3/Emu/RSX/RSXThread.cpp | 35 +++++++++++++++++++++++++++++++++- rpcs3/Emu/RSX/rsx_profiler.cpp | 16 +++++++++------- rpcs3/Emu/RSX/rsx_profiler.h | 6 ++++-- 3 files changed, 47 insertions(+), 10 deletions(-) diff --git a/rpcs3/Emu/RSX/RSXThread.cpp b/rpcs3/Emu/RSX/RSXThread.cpp index 1e70c69fc..3ec6d50ec 100644 --- a/rpcs3/Emu/RSX/RSXThread.cpp +++ b/rpcs3/Emu/RSX/RSXThread.cpp @@ -1304,6 +1304,33 @@ namespace rsx return t + timestamp_subvalue; } + // Say where every guest thread is parked once frames have stopped arriving. + // + // A hang with the RSX idle is a guest-side wait, and nothing named the thread or the place. + // The syscall stats report sys_timer_usleep without saying who called it, /proc shows a + // thread that never started as indistinguishable from one that is blocked, and the RSX + // profiler only covers this side of the boundary. Name, state, PC and the function each + // PPU is in separate all of those. + // + // idm::unlocked deliberately: this runs on the RSX thread, and taking the id lock here to + // diagnose a hang would add exactly the kind of dependency being diagnosed. A torn read of + // a diagnostic line costs nothing. + static void dump_guest_threads_stalled() + { + std::string out; + + idm::select>([&out](u32 id, ppu_thread& ppu) + { + const auto func = ppu.current_function ? ppu.current_function : ppu.last_function; + + fmt::append(out, "\n PPU 0x%07x '%s': state=%s cia=0x%08x %s func='%s'", + id, *ppu.ppu_tname.load(), ppu.state.load(), ppu.cia, + ppu.current_function ? "in" : "last", func ? func : ""); + }, idm::unlocked); + + rsx_log.error("Guest PPU threads while no frame has completed:%s", out); + } + void thread::do_local_task(FIFO::state state) { // Arm and poll from here as well as on_frame_end. Both of those run only once a frame @@ -1311,7 +1338,13 @@ namespace rsx // and silent -- and that is the case where what the RSX thread is looping in is the // whole question. Both calls return immediately once armed and are rate-limited. prof::set_enabled(g_cfg.video.rsx_profiler.get()); - prof::poll_stall(); + + // Both halves on the same condition. Every hang chased so far has been the guest + // waiting while the RSX idles, and only the RSX half was ever visible. + if (prof::poll_stall()) [[unlikely]] + { + dump_guest_threads_stalled(); + } m_eng_interrupt_mask.clear(rsx::backend_interrupt); diff --git a/rpcs3/Emu/RSX/rsx_profiler.cpp b/rpcs3/Emu/RSX/rsx_profiler.cpp index e5169f8ba..a5edb131a 100644 --- a/rpcs3/Emu/RSX/rsx_profiler.cpp +++ b/rpcs3/Emu/RSX/rsx_profiler.cpp @@ -266,31 +266,31 @@ namespace rsx::prof // the case worth instrumenting: a boot that never presents, where the compile has finished // and the thread is looping somewhere without consuming. Called from do_local_task, which // the FIFO loop reaches whether or not frames advance. - void poll_stall() + bool poll_stall() { if (!g_enabled.load(std::memory_order_relaxed)) [[likely]] { - return; + return false; } // Only the thread the buckets are armed against; anyone else's clock is meaningless. if (current_thread_token() != g_owner_thread) { - return; + return false; } const u64 freq = utils::get_tsc_freq(); if (!freq) { - return; + return false; } const u64 now = utils::get_tsc(); if (now - g_last_stall_check < freq * 5) { - return; + return false; } g_last_stall_check = now; @@ -300,19 +300,21 @@ namespace rsx::prof // Frames are still arriving, so tick_frame is doing the reporting. g_stall_frames = g_acc.frames; g_stall_started = now; - return; + return false; } if (!g_stall_started) { g_stall_started = now; - return; + return false; } prof_log.error("RSX has not finished a frame in %.1fs; current bucket '%s', in it for %.2fs", static_cast(now - g_stall_started) / static_cast(freq), name_of(g_current), static_cast(now - g_last_switch) / static_cast(freq)); + + return true; } void dump_and_reset() diff --git a/rpcs3/Emu/RSX/rsx_profiler.h b/rpcs3/Emu/RSX/rsx_profiler.h index 50e40fc2a..c47d52c01 100644 --- a/rpcs3/Emu/RSX/rsx_profiler.h +++ b/rpcs3/Emu/RSX/rsx_profiler.h @@ -506,8 +506,10 @@ namespace rsx::prof void dump_and_reset(); /** Report the bucket the RSX thread is stuck in when frames have stopped arriving. - * Rate-limited internally; safe to call from the FIFO loop. */ - void poll_stall(); + * Rate-limited internally; safe to call from the FIFO loop. + * Returns true on the calls that actually reported, so a caller can attach its own + * diagnosis to the same condition without repeating the rate limit. */ + bool poll_stall(); void set_enabled(bool enabled); inline bool enabled() { return g_enabled.load(std::memory_order_relaxed); }