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); }