Those two are 7.4 ms a frame in Arkham City, a fifth of it, and the GPU side of
the same work is 0.76 ms, so it is host work. Each handler does several unrelated
things and nothing separates them: a read barrier that can force a readback, the
memory copy the transfer exists to perform, and in the blit engine a software
scale through ffmpeg for the cases the GPU path does not take.
Scope the three. The scale is scoped inside convert_scale_image rather than at
its four call sites in the blit engine, and only the RSX thread is ever reported,
so calls from elsewhere cost nothing to cover.
Also let a scope be closed early, so a region ending part-way through a function
does not need a block introduced purely to place a brace.
The name table is keyed by register index, and both method reports passed the
byte offset. A lookup therefore matched whichever unrelated method happened to
have that value as its enum, so the costliest entry in Arkham City came out as
NV4097_SET_CONTEXT_DMA_VERTEX_B, which has no handler and cannot cost anything.
It was NV406E_SEMAPHORE_ACQUIRE: the RSX waiting for the guest to signal, which
is the one entry in that list that is supposed to block and the one that should
not be optimised.
A wrong name is worse than none here. The hex fallback was right the whole time
and is left as the byte offset, which is what a reader looks up.
The handler bodies are 60% of the RSX thread in Arkham City and the dispatch
machinery around them is 3.5%, so the question is which handlers. The method
histogram cannot answer it: it counts calls, and the busiest method may be a
register write while a rare one does the work.
Keep the interval the dispatch site already measures. It brackets the call with
two counter reads to fill the method_call bucket and then throws the difference
away; billing it to the method's slot as well costs one add.
Inclusive of whatever the handler calls into, including scopes that charge
themselves elsewhere. For ranking handlers that is the useful reading, and the
per-bucket totals stay exclusive as they were.
Arkham City spends 38.5 ms a frame in FIFO decode, 58% of the RSX thread, at
164 ns a dispatch. Sonic manages 45 ns on the same loop, the same decode and the
same counters, so the difference is in what the handlers do rather than in the
dispatch. Nothing separates the two: fifo_decode encloses the whole loop, so it
holds every handler body as well as the machinery around them.
The two handlers already scoped, transform program and transform constant,
measure 0.02 and 0.06 ms here, which rules them out and leaves the rest of the
mix unaccounted for.
Wrap the handler call. This is the only per-dispatch scope in the profiler and an
earlier attempt at one measured mostly itself; it is affordable here because it
brackets a call rather than a loop iteration, and handlers carrying their own
scope still attribute inward. It costs a few percent of the bucket it splits, so
the split is the number to read, not the total.
Booting a second game without restarting the app builds a new RSX thread.
set_enabled is the only thing that binds the profiler to a thread, and it
early-returns when the setting has not changed, so it stayed bound to the
previous game's thread. Every scope then failed its owner check, nothing
switched buckets, and the whole window was charged to whichever bucket happened
to be current.
That prints as "FIFO decode 100.0%", which is indistinguishable from a genuine
finding about a command-bound title, and was briefly read as one.
Notice the change per frame and re-bind, dropping the accumulated window and the
per-pass counters: they belong to a thread that is gone, and keeping them would
blend two games into one report.
The include list came over from ARMSX2 and names sstates, memcards, gamesettings,
cheats and snaps. None of those exist here, so a backup collected a few kilobytes
of controller profiles, reported success, and left every save behind. Nothing
warned: skipping an absent folder silently is right for an optional one and wrong
for a list aimed at a different emulator.
Name RPCS3's paths instead. The part that matters is config/dev_hdd0/home, which
holds save data, trophies and licences, and is the only thing in here that cannot
be rebuilt or re-downloaded. Save states, input configs and patches come along.
Installed titles are left out on purpose, along with firmware and dev_hdd1: a PKG
reinstalls and a PUP reinstalls, a save does not, and that is the line this list
is drawn on. Including them would have taken the archive from tens of megabytes
to nearly five hundred on the device this was sized against.
The description on the screen said memory cards and artwork too, so the one place
a user could have noticed agreed with the bug.
Everything measured so far describes what a draw contains: vertices, pixels,
shader length, subdraws, barriers. By all of them pass six should be the
cheapest of the expensive passes, and it is the dearest by a factor of seven.
An occlusion query is none of those things. On a tiler it makes the visibility
stream resolve, it costs the same whatever the framebuffer size, and no counter
here would show it. That matches every property this pass has: indifferent to a
sixteen fold cut in pixels, indifferent to tiling being switched off, no
barriers, one subdraw per draw, shorter shaders than the passes it dwarfs.
ZCULL is active, and emit_geometry opens a query whenever the command buffer
carries the occlusion flag. Count them where they open.
Installing a .rap never worked at all. The package screen routed licences to
installKey, whose RAP branch works out the content id by decrypting the game's
EBOOT, so it needs a game path, and the only caller passed an empty one. Every
attempt died at "Failed to fetch NPDRM of SELF". A RAP's filename is the content
id it unlocks, which is why RPCS3 desktop's InstallFileInExData simply copies the
file into exdata. That is what this does now, lower case extension included,
because unself.cpp searches for it that way.
Picking a game together with its licence could not work either. The installer
routed on file count rather than file kind, so any multi file selection went to
installSplitPkg, whose first act is to reject anything that is not a .pkg part.
Multiple selection has been allowed since split packages landed, so the obvious
thing to do was the one thing guaranteed to fail. The selection is split by kind
now, packages first, since a licence unlocks content the package has to have
written already.
Both failures showed the same generic "Install failed. The file may be encrypted,
incomplete or not a PS3 package", which reads as a bad file rather than a bug in
the app. The reason the native side already reported now reaches the screen.
A licence-locked title also looked like any other until it refused to boot. The
core works that flag out by attempting decrypt_self on the EBOOT, but the library
never asked it. The scan asks now, and a locked game gets a badge on its cover, an
Install licence entry in its context menu, and a prompt instead of a doomed boot
from every launch path: the library cards, the context menu, the controller, and
the settings screen's Play button.
Boot failures were silent besides. Rpcs3Bridge.boot threw away BootGame's return
code and MainActivityRuntime dropped runVMThread's result, so a failed boot was
indistinguishable from a game that started and exited immediately. Both are
reported now, which is how I found the licence problem in the first place.
External intents and launcher shortcuts are not covered, because externalGameInfo
builds a fresh GameInfo where locked defaults to false. Those still fall back to
the boot failure message.
Uninstalling only ever removed dev_hdd0/game/<TITLEID>, so the title's compiled
code and shader cache stayed on disk forever. On my device that was between 7 and
58 MB per title, and one of those caches belonged to a game I had already removed.
I made it a checkbox on the existing confirmation rather than doing it silently,
defaulted on, which is how RPCS3 desktop's own remove dialog treats caches. The
row is hidden when there is no cache, and it shows the measured size so you can
see what you are freeing. The size is measured off the main thread because a cache
directory holds hundreds of files and this runs while the dialog is opening.
The cache goes only after the native uninstall reports success, since dropping the
cache for a title that is still installed would just cost a recompile. The title
id is validated before the recursive delete: it comes from a directory listing,
but a path separator or a dot dot in it would resolve outside the per title
folder, so anything that is not a single plain segment is refused.
Save data, trophies and licences are deliberately left alone. Those belong to the
user rather than to the install, and desktop does not offer to remove them either.
A session ended in a fatal VK_ERROR_OUT_OF_DEVICE_MEMORY, the first in any log
here. On this GPU that is system memory, and the device had two gigabytes free
of seven with the emulator holding most of the rest.
Two frames in flight is what makes the CPU and the GPU overlap, and it is also a
second frame's worth of resources alive before anything retires them. That trade
is worth making at rest and not worth making into a crash on a handheld sharing
memory with everything else.
Fall back to the single frame this used to run with when the memory load is
above low. Slower, and slower is recoverable.
Shader length settled that pass six is not the game's workload: it has the
shortest shaders of the expensive passes, a quarter of the vertices of a pass
that costs a seventh as much, no barriers, and no reaction to resolution or to
tiling being switched off. Every quantity measured so far says it should be
cheap, and it takes nine milliseconds.
The draw count is the one that has been lying. It counts clauses, and a clause
is expanded over its subranges, so a single entry can become thousands of draws.
Batching them through VK_EXT_multi_draw, which this device does support, saves
our command overhead and changes nothing about how many the GPU processes.
Count them at every submission site. Thousands of tiny draws at a fixed cost
each is the last shape that fits, and nothing else measured would reveal it.
Pass six costs about 26 times what pass eight does per vertex: 123 draws and 68
thousand vertices for 9.15 ms against 532 draws and 253 thousand vertices for
1.26 ms. It has no barriers, does not care about resolution, and does not change
when TU_DEBUG=sysmem takes tiling and binning out of the picture entirely. The
only thing left that behaves that way is the shader.
Record vertex and fragment ucode length per pass. This decides whether there is
a bug here at all, which nothing measured so far can: shaders genuinely that
much longer are the game's own workload and there is nothing to fix, while
comparable ones mean something is happening to those draws that should not be.
The previous commit read driver_env.txt before the log file was opened, so the
one thing worth knowing -- whether the option was applied -- was written into a
listener that did not exist yet and then thrown away when the log rotated.
Move the read to just after the log file is created and report each option by
reading it back rather than echoing what was meant to be set. There is no other
honest confirmation available: /proc/<pid>/environ is the snapshot taken at exec
and never reflects a runtime setenv, and Mesa's own logging goes to stderr,
which Android discards. Still long before any Vulkan instance exists, which is
the only ordering Mesa cares about.
This device needs Turnip; the stock Adreno driver does not render the game at
all. Turnip is steered by environment variables such as TU_DEBUG, and the usual
way to set one on Android, the wrap.<package> property, is ignored on a user
build. It can be set and read back while never reaching the process, which makes
a flag that never applied look exactly like a flag that made no difference. That
is how the first attempt at this measured stock Turnip twice and called it a
result.
Read NAME=VALUE lines from <root>/driver_env.txt during initialize, before any
Vulkan instance exists, since Mesa caches each option the first time it is read.
A missing file does nothing, which is the normal case.
Picking a scale and launching a game still rendered at native. The previous
attempt read the launch-time write from ps3.resolutionScale, which turns out to
be the wrong end of it: that field has no writer anywhere in the UI, so it holds
its default of 100 permanently.
applyTo pushed that default onto Video@@Resolution Scale, the same node the
upscale multiplier writes, and applyTo runs after the launch path, so the orphan
won every time. Changing the scale in game appeared to work only because nothing
calls applyTo again afterwards.
Emit the node from upscaleFloat instead, which is what the preset grid, the
custom percentage slider and the in-game overlay all write, using the same
conversion and clamp as the other writer so the two cannot disagree. Restores
the launch-time call to the multiplier it always used.
Picking a resolution scale and then launching a game ran at native. The UI kept
showing the chosen value, the config held the default, and changing it in game
worked, which made it look like the setting was not saving.
Both settings write the same native node. applyTo writes the PS3 percentage to
Video@@Resolution Scale, and renderUpscalemultiplier writes the ARMSX2-lineage
multiplier times a hundred to the same place, from the launch path, after
applyTo. So the last writer won and it was the one carrying a default of 1.0.
Changing the value in game appeared to work only because nothing writes the node
again afterwards.
Drive the launch-time write from the PS3 setting so the two agree. Same node,
one owner.
Pass six spends 9.8 ms on 44 draws and 33 thousand vertices at ordinary
resolution, which is 300 ns a vertex. That is not vertex work, and the 2048
square shadow map next to it costs under a quarter of a millisecond with twice
the geometry, so it is not target size either. What is left is the GPU being
serialised inside the pass.
texture_barrier keeps the pass open on Android and issues a by-region
self dependency instead, which was the right trade against a tile store and
reload. But that barrier still makes a tiler resolve the tile and fetch it back,
and one per draw would cost about what pass six is costing. Nothing counts them.
Count barriers issued while a pass is open, per pass, and how many came from a
cyclic reference. If pass six shows one per draw the mechanism is named; if it
shows none, the serialisation is somewhere else and this rules out the obvious
candidate cheaply.
Two passes hold 69% of GPU time and one of them, pass six, costs 76us a draw
against 2.4us in pass eight while holding 7% of the frame's draws. Rendering at
quarter resolution changed nothing, so it is not fragment work, and the ordinal
on its own says nothing about what the pass is for.
Record the render target size and the vertex count per pass alongside the draw
count. Size names the pass in the game's terms, since a shadow map, a reflection
and the main scene do not share dimensions. Vertices per draw separates a lot of
geometry from a lot of cost per vertex, which is the question the timing cannot
answer and which decides what a fix would even look like.
Rendering at a quarter resolution changed the GPU time not at all, which rules
out fill rate, fragment shading and tile traffic in one measurement, since all
three scale with pixels. What is left inside the passes is geometry, binning and
per-draw cost. It also retires the tile bandwidth theory the previous two
attempts were built on: that traffic would have fallen sixteen fold.
So the draw total needs splitting, and the timer already measures each pass
individually and only reports the sum. Report the distribution instead, keyed by
the pass ordinal within the frame: the frame structure is stable, so pass N is
the same logical pass each time, which is what makes it something to act on.
Count draws per pass alongside it, on the same ordinal. A pass that is expensive
holding few draws is expensive per draw; one holding most of the frame's draws
is carrying the geometry. Same milliseconds, opposite fixes.
Reporting only. No new timestamps and nothing recorded that was not already
being measured.
vkCmdClearAttachments needs the pass open, and the pass opens with LOAD_OP_LOAD,
so clearing a target reads the whole framebuffer into tile memory and then
throws it away. LOAD_OP_CLEAR skips the read. On a tiler that read is the whole
attachment every time, and this title runs about thirty passes a frame at 720p
with colour and depth.
Taken only when the clear covers the entire render area and no pass is already
open. A partial clear is not a load op, and ending an open pass to change its
load ops would store the framebuffer in order to discard it, which costs more
than it saves. Colour is all attachments or none, since a load op applies to the
attachment as a whole. Depth and stencil get separate bits because clearing one
and keeping the other is common.
Whether an open instance can serve a request now compares the key with the clear
bits masked off rather than the pass pointer. Load ops do not affect render pass
compatibility, so the two variants are interchangeable for an open instance and
for the pipelines inside it; comparing pointers would have ended the instance to
begin an equivalent one, paying the store and reload this is meant to avoid and
discarding the clear on the way. Callers that pass no key keep the old pointer
comparison.
The collector had gathered eight frames in five thousand flips and its ring was
parked on slot zero with every slot unreset and empty. All of that follows from
one thing: the frame region was opened at device init and in flush_command_queue
only, and this title takes that path roughly never, so the region opened once at
boot, closed on the first submit and was never opened again.
Everything else depends on it. The slot's query range is reset when the frame
region opens, the ring only advances past a slot once something in it has
completed, and collection refuses a slot that was never reset. So a timer that
initialised cleanly and logged its tick period produced no report for an entire
session, which reads the same as a GPU with nothing to do.
Open it where the primary command buffer is actually begun for the next frame.
The GPU timer initialises, reports its tick period, and then never produces a
report: eighteen RSX profiles came and went in one session against zero GPU
profiles. Collection has several preconditions and the report only prints once
three hundred frames have been gathered, so a collector stuck on any of them
prints nothing at all, which reads exactly like a GPU that is idle.
Log the collector's state periodically while it has nothing, with the slot
flags, the open regions and the drop count, so the precondition that is not
being met can be read instead of guessed at.
Also stop recording anything but the frame region into a slot that still needs
its reset. Writing a timestamp into a range that has not been reset is invalid,
and the reset only happens when the frame region opens, so a render pass that
begins first -- the ones flip() runs after next_frame has already rotated the
slot -- was writing into stale queries.
The GPU timer measures the whole frame, readbacks, blits and uploads, and the
one region it names but never records is draw. So the split it exists to provide
has been missing exactly where it matters: with the RSX thread no longer waiting
on a fence, the Adreno sits at 99% busy at its top clock and nothing says how
much of that is drawing the game.
Bracket the render pass at the only place one actually starts, not at the
wrapper, which early-outs when the same pass and framebuffer are already bound.
Roughly thirty passes a frame, comfortably inside the per-frame event cap.
Both timestamps sit outside the pass rather than inside it. On a tiler the load
at the start and the store at the end are the expensive part, and timing from
within would exclude the cost worth knowing about.
Take the command buffer by const reference, which is what the render pass
helpers hold and what the conversion operator already permits.