The 1 KiB base+offset window measured nothing. On the hung device it reported
tracked=1 longest=0s: one running thread, whose cia left the window every
second, so the window reset on every tick and the counter never advanced past
zero. The loop is wider than a handful of instructions -- it polls and calls
helpers -- which the previous shape could not represent at all.
Track the RANGE cia has covered instead, and allow 64 KiB of it. A polling
loop that calls helpers stays within tens of KiB; ordinary execution covers
megabytes in a second.
The state line now reports the widest range being tracked. If this still does
not fire, that number is itself the answer -- it says how large the loop
really is, and therefore what the threshold must be, instead of costing
another reproduction to find out.
Five earlier attempts at catching this hang keyed on something STOPPING --
frames, then lock traffic -- and every one missed it, because nothing stops.
Measured on the hung device: PPU[0x1000000] burning 4.36s of CPU across 4s of
wall clock, 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 sits in a
tight guest-side wait loop, making no syscalls, taking no locks and writing no
log lines. A frame-based detector saw frames still flipping, a lock-based one
saw a peak of 10 locks/sec to fall from, and neither was wrong about what it
measured. They were measuring the wrong thing.
So look for the opposite of a stall: a thread that is RUNNING -- no
cpu_flag::wait, meaning not parked in a syscall -- whose cia has not left a
1 KiB window for 30 seconds. A spin loop is a few instructions branching to
themselves; ordinary execution walks cia across the binary many times a
second. Threads waiting in a syscall are skipped, so an idle game cannot trip
it.
Dumps twice, 15s apart, so the second shows whether cia moved at all between
them, and reports its own state every 10s: threads tracked, longest spin,
dumps taken.
Two corrections to the previous attempt, both measured rather than reasoned.
Including _sys_lwmutex_lock broke it. That counter keeps climbing straight
through the hang at a flat ~375 per 10s -- the idle loops take lightweight
mutexes -- so the 'unchanged' test re-armed on every tick and the detector
never fired. sys_mutex_lock alone froze outright, at 22.
And 'exactly zero' only fits Xillia 2. Kane & Lynch collapsed from ~200,000
per 10s to ~300, which is just as dead and never reaches zero. So the test is
now relative: remember the busiest rate this game has reached, decay it
slowly, and call it a hang when the current rate stays under a fiftieth of
that for 30 seconds. A title that has never been busy has no peak to fall from
and cannot trip it; the 5000/s floor sits far below every busy rate measured
(20,000+) and far above anything idle.
The syscall code is resolved by name from g_ppu_syscall_table once, rather
than hardcoded, so it cannot silently come to mean a different syscall.
Also logs its own state every 10s -- rate, peak, quiet seconds, dumps taken.
Five attempts at detecting this hang have now failed, every one of them
silently, and each cost a reproduction to discover. The detector reporting
what it sees is worth more than the detector being clever.
The frame-based check cannot see this class of hang at all. Tales of Xillia 2
white-screens with its RENDER loop still running: it submits real, non-forced
flips every ~10ms forever, so 'no frame presented' is never true while the
game logic behind them is dead. Measured on device -- g_last_frame_time was
9-12ms old on every sample taken across the hang. Four fixes to the
frame-based detector were all fixing the wrong instrument.
What actually stops is lock traffic. Both hangs seen so far -- Xillia 2's
white screen and Kane & Lynch's freeze -- show mutex acquisition at exactly
zero for minutes while sys_timer_usleep and sys_event_queue_receive continue
at flat, identical rates, which is idle service loops and nothing else. Both
games were taking 100k+ locks per 10s until the moment they stopped.
Polled from the PPU syscall usage thread, which already holds the counters and
is independent of both the RSX thread and the guest. Bounded the same way as
the other path: two dumps, the second 15s after the first so a cia that has
not moved between them is distinguishable from slow progress, re-armed only
when lock traffic resumes.
The watchdog was called under !Emu.IsPaused() && !Emu.IsStopped(). The
default IsStopped() overload is m_state <= system_state::stopping, and the
enum orders stopped, loading, stopping, running -- so it reports true for a
game that is LOADING.
A hang during a load is exactly what this watches for. Tales of Xillia 2
white-screens mid-load once its logos are skipped, so the guard skipped the
watchdog on every tick of the precise case it exists for, and skipped it
silently: not a declined decision anyone could read, just no call at all.
Nine minutes of held white screen produced no output whatsoever.
Use IsStopped(true), which is the fully-stopped test.
Also log the watchdog's decision once every 10s -- progress flag, last frame
timestamp, its age, dumps taken. Three attempts at this detector have failed
silently on a reproducible hang; the only evidence each time was an absence,
which cannot say which branch won. One line per ten seconds makes the next
failure a fact rather than another guess.
poll_frame_stall_watchdog returned early when g_last_frame_time was zero,
where the RSX-side check seeds it -- and seeding is what starts the clock.
Since the whole reason the watchdog exists is an RSX thread too stuck to run
that check, nothing ever seeded it: the value stayed zero and the watchdog
bailed on every tick forever, blocked in exactly the scenario it was written
for.
Reproduced on Tales of Xillia 2: white screen held for nearly nine minutes,
guest mutex traffic zero throughout, and not one dump.
check_frame_stall() runs from do_local_task, on the RSX thread's own FIFO
loop. That works for a guest-side hang with the RSX idle -- every hang chased
so far -- and is useless for the opposite case, where the RSX thread is the
one stuck. It never returns to do_local_task, so the detector that would
report the hang is starved by the hang.
Tales of Xillia 2 (BLUS31397) is exactly that. Reproduced on device: guest
mutex traffic at zero for minutes while sys_event_queue_receive and
sys_timer_usleep tick at flat identical rates, rsx::thread accumulating 4.99s
of CPU per 5s of wall clock, and NV406E_SEMAPHORE_ACQUIRE its costliest method
at 1.59ms a call. The RSX is spinning on a guest semaphore the stopped guest
will never write, and nothing reported any of it.
The same condition is now polled once a second from the PPU syscall usage
thread, which is independent and keeps running. That 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 another thread. Both share one dump budget
so they cannot produce four dumps between them.
check_frame_stall() arms native-UI flipping when it reports a stall, so the
guest has something on screen while it is hung. Those synthetic flips reach
flip(), which finds nothing queued and calls on_frame_end(buffer, true), and
on_frame_end refreshed g_last_frame_time unconditionally. So the first hang of
a session switched on a flip source that then refreshed the timestamp forever,
and no later hang in that session could be detected at all.
Only a frame the guest actually produced counts as guest progress now.
Found on Tales of Xillia 2 (BLUS31397), which reproduces the same white screen
as Xillia 1: a stall was reported at 0:29:06, that game was closed, another was
booted, and when it hung 90 seconds later nothing fired. Guest mutex traffic
sat at exactly zero for over two minutes -- sys_event_queue_receive and
sys_timer_usleep continuing at flat, identical rates every interval, which is
idle service loops and nothing else -- while VKGSRender::flip kept running and
the detector kept believing frames were landing.
That is the one case this was written for: a hang where something still flips
looks perfectly healthy to a detector that only watches frames.
A callback the backend cannot fill completely is a hole in the output: the
device asked for N frames, the emulator did not have them, and the gap is
filled by repeating the last sample. That is what crackling IS, and nothing
counted it. The buffer-level report samples every ten seconds while a starved
callback lasts milliseconds, so every transient underrun passed between
samples unseen -- a Call of Duty: World at War capture shows a perfectly
healthy buffer (queued 22.7-48ms against a 36.7ms target, never near dry)
through a session where the audio was audibly breaking up.
Counted in AudioBackend rather than per backend so Cubeb and Oboe report the
same number the same way, one count per starved callback rather than per
padded frame -- the audible event is the gap, and its length is already
implied by how much of the callback had to be invented.
Reported on the existing audio line as a delta since the previous one, not a
running total: what matters is whether the output is breaking up now, and a
total from a rough patch minutes ago hides that.
There was exactly one previous log: RPCSX.log became RPCSX.old.log and the
previous old was deleted. That loses the capture reliably, because of how
people send it -- play, stop, relaunch the app to reach the file, and the
relaunch rotates the wanted session into .old; relaunch once more, to find it
or to share it or because the launcher restored the app, and it is gone.
Three captures have been lost this way (#87, #91, and the Call of Duty audio
one). In two of them what arrived was a 47-line log ending before the game had
booted, which is the replacement session rather than the one played.
Two defences, because generations alone would not have saved those:
1. A session that produced almost nothing does not get a slot. The logs that
did the damage were boot-only -- a few KB, stopping within a second of
launch -- and pushing one of those down the chain is what evicted the real
capture. Below the threshold the file is discarded instead. A session with
'Silence All Logs' on still writes far more than this (~190 KB for a
29-minute one), so that setting does not trip it.
2. Three generations instead of one, so an ordinary mistake costs nothing.
Ported from ARMSX2. Android has no supported API for SoC temperatures --
HardwarePropertiesManager is gated behind the signature-level DEVICE_POWER --
so the only route is the thermal sysfs, which is readable without permission
on essentially every device but is not a contract: zone count, order, naming
and even the unit are all vendor-specific. So the app discovers zones once by
name, tolerates every failure by having no reading, and never displays a value
it could not actually read. A device that exposes nothing shows nothing, which
is a normal outcome rather than an error.
The core cannot read these and should not learn how, so the app pushes them in
through _rpcsx_setThermals into atomics beside the overlay. The overlay line is
appended after the detail-level switch, the same way the frame generation line
is, so all four levels get it without their format strings and positional
arguments having to agree.
The sentinel is -1000.0f on both sides. ARMSX2 spells the Kotlin half
Float.MIN_VALUE, which in Kotlin is the smallest POSITIVE float (1.4e-45) and
so arrives as a real temperature of 0 degrees rather than as absent; worth
correcting there too.
Default on, poll interval configurable 1-5s (default 2s) since sensor overhead
was the concern raised when this was asked for. No realtime option: a
temperature that moves slower than a second is not worth the syscalls.
It stays a feature -- the hotkey, the touch button and the OSD indicator are
untouched -- it just no longer occupies a tile in either panel.
Removing it also repairs the Session grid's controller dispatch, which was
broken. EmulationMenuViewModel indexes three things by the same number: the
grid in SessionPane, actionCount(), and activateSelection(). Fast-forward sat
at index 1 in the grid and had no entry in activateSelection, so every index
from 1 up dispatched to its neighbour -- a pad press on Fast Forward restarted
the game, Restart swapped the disc, Swap Disc closed the game, and Close could
not be activated at all. actionCount had been corrected to 5 to let the pad
reach the last tile, which made the misalignment reachable rather than fixing
it. With the tile gone the grid is resume/restart/swap/close, exactly what
activateSelection already dispatched, and actionCount goes to 4.
Touch users are unaffected: the grid is tapped by index through onSelect, so
it was always correct there. This only ever misfired for a controller.
Upstream bc22df8ba skips waking waiters after a SUCCESSFUL conditional store
when the SPU sits at pc 0x11e4 with the SPURS control block reserved, unless
byte 0x73 of that block shows this thread going running->idle. It is a
throughput optimisation: SPURS kernels store to that block constantly and
waking every waiter each time is a thundering herd.
Both constants are assumptions about one specific SPURS kernel build. 0x11e4
is a guest code address and 0x73 an offset inside the guest's control block,
and SPURS ships in many versions across titles. On a kernel whose layout
differs, the running->idle test reads the wrong byte, answers no forever, and
the store succeeds while every waiter stays asleep -- reported by nothing.
Tales of Xillia (BLUS31006) hangs with all five graphics SPUs reserving that
block, each suppressing ~100,000 notifications, ~4.85M conditional stores at
a 16.5% failure rate. Its SPURS kernel then executes its own HALT at
pc=0x00f00: r16 & r17 = 0x40000000, two workload masks that must be disjoint
both claiming workload bit 30. The group never joins, no frame is ever
presented again, and every PPU thread parks.
Whether the missed wakeups cause that inconsistency or merely accompany it is
NOT established. What is established is that notifying is correct and
suppressing is the optimisation, so the optimisation goes. Expect a
throughput cost on SPURS-heavy titles; it is measurable and revertable.
The counter is kept, now recording how often the heuristic would have
suppressed, so that cost shows up in a log instead of being guessed at.
The stall report picked its detailed SPU by raddr == spurs_addr -- a kernel
waiting on its own control block, i.e. an IDLE one -- on the assumption that
every kernel parks at the same pc so any of them would do. Tales of Xillia
is the counter-example: one graphics kernel executed a guest HALT and sits
stopped at pc=0x00f00 while the other four idle normally at 0x011a8, so the
rule picked an idle SPU. The only thread in the process with anything to say
printed no registers at all.
A stopped, halted or exited SPU now wins outright, chosen in a pass before
the walk. Nothing else in a SPURS group stops on its own, so if one has, it
is why the group never joined and the rest are only waiting on it.
Also dump all 128 GPRs rather than the first 16. Xillia's assertion is a
validity check over r12/r16/r17/r19/r33/r34, so the sixteen that were printed
did not include a single operand of the test the log had just disassembled.
jpolo1224