armsx/ARMSX3
0
0
Fork 0
mirror of https://github.com/ARMSX2/ARMSX3.git synced 2026-08-24 16:58:52 -07:00
Code Issues Packages Projects Releases Wiki Activity

Remove the Xillia 2 hang instrumentation

Browse Source 
Seven detectors over as many reproductions, none of which caught it. The
final one settles why: with cia sampled once a second, the guest threads are
found at a DIFFERENT address every time -- 0x011f63ac, 0x00278268, 0x008ac3a4,
0x0141512c -- so the best repeat count never exceeded 1.

The thread is not parked anywhere. It executes a great deal of varied guest
code at over 100% of a core while making no progress, consistent with
sys_ppu_thread_yield at ~100 million. A busy-wait that does real work each
iteration cannot be found by watching for something to stop, which is what
every one of these tried, in a different place each time.

What was learned and is worth keeping is recorded in the commits: frames keep
flipping throughout (so no frame-based check can see it), lock traffic never
ramps up because the hang precedes any workload, rsx::thread spins in
NV406E_SEMAPHORE_ACQUIRE, and PPU[0x1000000] burns 4.36s of CPU per 4s of wall
clock. The next attempt should start from a guest-side breakpoint or an
instruction trace, not from another liveness heuristic.

The structural fixes found along the way stay: on_frame_end no longer counts
forced frames as guest progress, and check_frame_stall dumps guest threads
rather than only reporting. Both are correct independently of this hunt.
This commit is contained in:
jpolo1224
2026-08-24 15:57:34 -04:00
parent cd1fd0e585
commit d65a603547
3 changed files with 0 additions and 217 deletions
Download Patch File Download Diff File Expand all files Collapse all files
rpcs3/Emu/Cell/lv2/lv2.cpp
-133
View File
@@ -7,8 +7,6 @@
#include "Emu/Cell/PPUFunction.h"
#include "Emu/Cell/PPUThread.h"
#include <unordered_map>
#include "Emu/Cell/SPUThread.h"
#include "Emu/Cell/ErrorCodes.h"
#include "sys_sync.h"
@@ -27,7 +25,6 @@
#include "sys_ppu_thread.h"
#include "sys_process.h"
#include "sys_prx.h"
#include "Emu/RSX/RSXThread.h"
#include "sys_rsx.h"
#include "sys_rwlock.h"
#include "sys_semaphore.h"
@@ -1252,136 +1249,6 @@ public:
// Hang watchdog. This thread is independent of the RSX thread, which is the whole
// point: a hang where the RSX spins inside a method handler starves the stall check
// that lives on it. Cheap -- two atomic loads and a clock read unless it fires.
// Spin detector.
//
// Five earlier attempts at catching this hang all keyed on something STOPPING --
// frames, then lock traffic -- and all missed it, because nothing stops. Measured on
// the hung device: PPU[0x1000000] burning 4.36s of CPU across 4s of wall clock, i.e.
// more than a full core, while rsx::thread spun on NV406E_SEMAPHORE_ACQUIRE. Tales of
// Xillia 2 white-screens when its Bandai logo is skipped, and the guest's main thread
// is not blocked at all -- it is in a tight guest-side wait loop, making no syscalls,
// producing no log output, and taking no locks. That is why a frame-based detector,
// a lock-based one, and a "no syscalls at all" one each saw nothing wrong.
//
// So look for the opposite of a stall: a thread that is RUNNING (no wait flag) whose
// cia has not left a small window. A spin loop is a handful of instructions branching
// to themselves; ordinary execution walks cia across the whole binary within a second.
// Threads parked in a syscall carry cpu_flag::wait and are skipped, so a normal idle
// game cannot trip this.
{
// Count how often a thread is found at the SAME cia, and DECAY on a miss
// rather than resetting.
//
// The range-window version reset on every excursion, and the report made that
// look like success: widest_range=0x0 does not mean an identical cia, it means
// the entry had just been reset, so lo==hi. The thread mostly sits in a small
// loop -- one sample caught it inside 0x500 -- and occasionally wanders far
// enough (a helper, a syscall handler) to blow any fixed window. Anything
// all-or-nothing therefore measured nothing.
//
// Decaying instead means an occasional excursion costs one point rather than all
// of them, so a thread parked at one address 90% of the time still accumulates,
// and a thread genuinely making progress still falls to zero.
struct spin_state { u32 cia; u32 hits; };
static std::unordered_map<u32, spin_state> s_spin;
static u32 s_dumps = 0;
static u32 s_worst = 0;
static u32 s_worst_cia = 0;
if (Emu.IsPaused() || Emu.IsStopped(true))
{
s_spin.clear();
s_dumps = 0;
s_worst = 0;
}
else
{
u32 worst = 0;
u32 worst_id = 0;
u32 worst_cia = 0;
idm::select<named_thread<ppu_thread>>([&](u32 id, ppu_thread& ppu)
{
// Parked in a syscall: skipped, not counted against. A thread that is
// only ever parked never accumulates hits, so idle cannot look like spin.
if (!ppu.state.load().none_of(cpu_flag::wait))
{
return;
}
const u32 cia = ppu.cia;
auto& st = s_spin[id];
if (st.hits == 0)
{
st.cia = cia;
}
if (cia == st.cia)
{
st.hits++;
}
else if (st.hits > 0)
{
st.hits--;
// Fully decayed: adopt wherever it is now as the new candidate.
if (st.hits == 0)
{
st.cia = cia;
}
}
if (st.hits > worst)
{
worst = st.hits;
worst_id = id;
worst_cia = st.cia;
}
}, idm::unlocked);
s_worst = worst;
s_worst_cia = worst_cia;
if ((worst == 30 || worst == 45) && s_dumps < 2)
{
s_dumps++;
ppu_log.error("PPU 0x%07x has been at cia=0x%08x for %u of the last "
"samples. Dumping guest threads.", worst_id, worst_cia, worst);
rsx::dump_guest_threads_now();
}
if (worst == 0)
{
s_dumps = 0;
}
}
if (i % 10 == 0)
{
// Report the widest range any tracked thread is covering. If this still does
// not fire, that number IS the answer -- it says how big the loop actually is
// and therefore what the threshold has to be, instead of costing another
// reproduction to find out.
ppu_log.notice("spin detector: tracked=%u best=%u@0x%08x dumps=%u",
static_cast<u32>(s_spin.size()), s_worst, s_worst_cia, s_dumps);
}
}
// IsStopped(TRUE), not the default.
//
// The default overload is `m_state <= system_state::stopping`, and the enum orders
// stopped, loading, stopping, running -- so it reports true while the game is
// LOADING. A hang during a load is precisely what this watches for (Tales of Xillia 2
// white-screens mid-load after its logos are skipped), so the plain guard skipped the
// watchdog on every tick of the exact case it exists for, and did it silently: no
// declined decision to see, just no call at all.
if (!Emu.IsPaused() && !Emu.IsStopped(true))
{
rsx::poll_frame_stall_watchdog();
}
const bool is_paused = Emu.IsPaused();
// Force-print all if paused
rpcs3/Emu/RSX/RSXThread.cpp
-77
View File
@@ -1433,83 +1433,6 @@ namespace rsx
// 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.
// Independent watchdog, called from a thread that is NOT the RSX thread.
//
// check_frame_stall() runs from do_local_task, on the RSX thread's own FIFO loop. That is
// fine for a guest-side hang with the RSX idle, and useless for the opposite case: Tales of
// Xillia 2 hangs with rsx::thread spinning at 100% CPU inside NV406E_SEMAPHORE_ACQUIRE,
// waiting on a guest semaphore the stopped guest will never write. Spinning inside a method
// handler it never returns to do_local_task, so the detector that would report the hang is
// starved by the hang itself. Measured on the device: +4.99s of thread CPU across 5s of wall
// clock, with guest mutex traffic at exactly zero for minutes.
//
// So the same condition is polled from the PPU syscall usage thread, which ticks once a
// second and keeps running regardless. This half only DUMPS -- the on-screen message and the
// native-UI flip stay on the RSX side, because the overlay is not safe to drive from here.
// Dump on demand, for a caller that has decided a hang is happening by its own means.
// The frame-based checks in this file cannot see a hang whose render loop keeps flipping.
void dump_guest_threads_now()
{
dump_guest_threads_stalled();
}
void poll_frame_stall_watchdog()
{
const u64 now = get_system_time();
// Say why this declined, once every 10s.
//
// Three attempts at this detector have now failed SILENTLY on a reproducible hang -- it
// disarmed itself, then it sat on the thread that was stuck, then it would not seed its
// own clock -- and each time the only evidence was an absence, which says nothing about
// which branch below won. Reporting the decision costs one line per ten seconds and turns
// the next failure into a fact instead of another guess.
{
static atomic_t<u64> s_last_report{0};
if (now - s_last_report >= 10'000'000)
{
s_last_report = now;
const u64 last = g_last_frame_time;
rsx_log.notice("stall watchdog: progr=%d last_frame=%llu age=%lldms dumps=%u",
g_progr_text ? 1 : 0, last,
last ? static_cast<s64>(now - last) / 1000 : -1, g_frame_stall_dumps.load());
}
}
// SEED the timestamp, do not merely bail on it.
//
// The RSX-side check sets g_last_frame_time here, which is what starts its clock. This
// half returned instead -- and since the case it exists for is an RSX thread too stuck to
// run that check, nothing ever seeded it, g_last_frame_time stayed zero, and the watchdog
// bailed on every tick forever. Blocked in exactly the scenario it was written for.
if (g_progr_text || !g_last_frame_time)
{
g_last_frame_time = now;
g_frame_stall_reported = false;
g_frame_stall_dumps = 0;
return;
}
if (now - g_last_frame_time < 30'000'000)
{
return;
}
// Shares the RSX side's counter and its two-sample budget, so the two paths can never
// produce four dumps between them.
if (const u32 taken = g_frame_stall_dumps; taken < 2)
{
g_frame_stall_dumps = taken + 1;
rsx_log.error("No frame presented in %us and the RSX thread is not polling: dumping "
"guest threads from the watchdog.", (now - g_last_frame_time) / 1'000'000);
dump_guest_threads_stalled();
}
}
static void dump_guest_threads_stalled()
{
std::string out;
rpcs3/Emu/RSX/RSXThread.h
-7
View File
@@ -38,13 +38,6 @@ extern rsx::frame_capture_data frame_capture;
namespace rsx
{
// Polled once a second from the PPU syscall usage thread. The RSX-side stall check cannot
// report a hang in which the RSX thread itself is spinning; see the definition.
void poll_frame_stall_watchdog();
// Dump every guest thread's state now. For a caller that detected a hang some other way --
// the frame-based checks cannot see one whose render loop is still flipping.
void dump_guest_threads_now();
class RSXDMAWriter;