How to measure where the Virtual Jaguar libretro core actually spends time.
Investigating a report from tvOS, Android or a console port? Start with On-device profiling. Everything else in this guide is host-side (macOS/Linux, Instruments/
perf/sample) and cannot reach a device you can't attach a profiler to. Context for the wider effort: #509.
The core registers eight timing counters through
RETRO_ENVIRONMENT_GET_PERF_INTERFACE, and RetroArch renders them in its own
UI on every platform including tvOS. This is the only route that measures the
device that is actually slow.
Nothing to build: it ships in release builds and is inert until a frontend offers the interface.
- In RetroArch, Settings → Frontend → Performance Counters → On (older builds: Settings → Logging → Performance Counters).
- Load content, play the part that is slow, then quit the core — totals are also written to the RetroArch log at unload, which is usually easier to retrieve off a locked-down device than reading them off the TV.
- Settings → Logging → Log Verbosity → On if you want the log copy.
Both were found by reading RetroArch's runloop.c, and neither announces
itself — the failure looks like a working run.
1. perfcnt_enable is mandatory, and off means zero, not "off".
runloop_performance_counter_register() -- NEVER gated
core_performance_counter_start/stop() -- gated on perfcnt_enable
runloop_perf_log() -- returns early if disabled
Registration always succeeds, so the core sets vjPerfActive = 1, every
probe fires, and every counter stays at zero. A capture taken with the
setting off is indistinguishable from a core whose instrumentation is
broken. Set it in the menu, or put perfcnt_enable = "true" in
retroarch.cfg — the scripts below do the latter.
Corollary for shipping builds: under RetroArch the core's fast path is
not the "never-taken branch" described in perf_iface.h. RetroArch
accepts the interface even with counters disabled, so vjPerfActive is 1
and each probe makes a real indirect call that returns immediately. That is
~2,000 such calls per frame — negligible at slice granularity, but it is not
zero, and it is only zero on frontends that actually decline env 28.
2. The log prints an AVERAGE, not a total.
#define PERF_LOG_FMT "[PERF] Avg (%s): %llu ticks, %llu runs.\n"Total ticks = avg × runs. This matters more than it sounds: the blitter is
few calls that are individually expensive and the GPU is very many cheap
ones, so ranking by the printed figure inverts the exact comparison the
counters exist to make. On yarc.j64 the blitter's average is ~32× the
GPU's while its total is ~4× smaller.
Two scripts drive the whole loop and share one report parser, so the iOS/tvOS and Raspberry Pi paths print the same table.
# iOS / tvOS, through your own RetroArch checkout
test/tools/device_perf.sh doctor # devices + build id
test/tools/device_perf.sh build tvos # + build-identity assert
test/tools/device_perf.sh install tvos -d "Bedroom" # sign, inject, deploy
test/tools/device_perf.sh cfg -d "Bedroom" # perfcnt_enable=true
test/tools/device_perf.sh capture -d "Bedroom" # prints the manual step
test/tools/device_perf.sh pull -d "Bedroom" -o run.log
test/tools/device_perf.sh report run.log --json run.json# Raspberry Pi (or any Linux ARM box you can ssh to)
test/tools/rpi_perf.sh build --arch aarch64 # container; artefacts only
test/tools/rpi_perf.sh doctor pi@raspberrypi.local # real-hardware gate
test/tools/rpi_perf.sh deploy pi@raspberrypi.local
test/tools/rpi_perf.sh profile pi@raspberrypi.local --frames 1800rpi_perf.sh runs perf_iface_witness on the Pi rather than RetroArch — it
is a complete env-28 frontend in a single file, so it needs no frontend,
no GUI and no config, and trap 1 above cannot apply to it.
It will refuse to report timings from emulated hardware. bench and
profile both gate on doctor, which requires a Raspberry Pi
/proc/device-tree/model and a non-virtualised
systemd-detect-virt. An aarch64 container on your Mac will build the core
happily and produce entirely meaningless numbers; the gate exists because
the dangerous outcome is not a wrong number, it is a confident one.
| Counter | What it brackets |
|---|---|
vj_m68k_slice |
One 68K slice from the event loop |
vj_gpu_exec |
All GPU RISC execution, every entry path |
vj_dsp_exec |
All DSP RISC execution, every entry path |
vj_gpu_sync |
The part of vj_gpu_exec pulled in by a 68K bus access |
vj_dsp_sync |
The part of vj_dsp_exec pulled in by a 68K bus access |
vj_op_halfline |
One Object Processor halfline render |
vj_blitter |
One blit, whichever engine is selected |
vj_dac_mix |
One frame of audio mixing |
These do not sum to frame time and are not a pie chart. The Jaguar's processors do not run in disjoint phases, and two nestings are real:
- A 68K access into GPU/DSP local RAM runs RISC cycles inline via
GPUSyncToM68K()/DSPSyncToM68K(), sovj_m68k_slicecontains RISC time. - The Object Processor runs the GPU inline from a halfline callback, so
vj_op_halflinecontains GPU time.
vj_gpu_sync / vj_dsp_sync exist to make the first one measurable rather
than merely disclosed. To decompose:
real 68K work ~= vj_m68k_slice - vj_gpu_sync - vj_dsp_sync
slice-driven GPU ~= vj_gpu_exec - vj_gpu_sync
vj_gpu_exec and vj_dsp_exec need no correction — every path that runs RISC
cycles goes through them.
Enabling the counters costs time. vj_gpu_exec alone brackets ~1,700
calls per frame, each taking two clock reads. Use the numbers for relative
attribution between subsystems, not as an absolute frame budget, and don't
compare a counters-on session against a counters-off one for total speed.
It cannot perturb the emulation. The instrumentation touches no emulated
state — test/tools/perf_iface_witness asserts that the framebuffer is
byte-identical with counters on and off, so a capture is measuring the same
machine you were playing.
From perf_iface_witness on yarc.j64, 120 frames — the ordering is the
point, not the absolute numbers:
vj_gpu_exec calls=201045 total=475217000 <- dominates
vj_blitter calls=1433 total=100466000 <- few calls, expensive each
vj_op_halfline calls=31440 total=26878000
vj_m68k_slice calls=200390 total=6772000 <- small
vj_dsp_exec calls=200390 total=4333000
vj_dac_mix calls=120 total=14000
vj_gpu_sync calls=0 total=0 <- this title never syncs
vj_dsp_sync calls=0 total=0
Benchmark-ROM caveat (#533).
yarc.j64is an amplifier, not a benchmark: 73.3% of its GPU time isjr(a spin loop) and its DSP share is ~0.08%, so a DSP or blitter change measures as "no effect" on it. The #532 GPU hoist scored −4.33% on yarc against −3.77% on jagniccc — same change, and the gap is that bias. Use yarc to make a GPU-loop effect visible; never to size one. The figures on this page taken on yarc are still valid for what they measured, but are not a whole-core picture.
make benchmarknow defaults tojagniccc.j64@ 900 frames with a 300-frame warmup — the warmup matters, because jagniccc is still in BIOS boot (zero GPU-interpreter instructions) at 90 frames. Usetest/tools/ir_ab.sh --profileto check any ROM/window before trusting it.
Add a slot to the enum in src/core/perf_iface.h,
an identifier to vjperf_idents[], and a VJP_ENTER/VJP_LEAVE pair at the
site. Read the placement rule in that header first — the probe goes after
a function's top-of-function guards, and there must be no return between
ENTER and LEAVE, or the slot leaks its nesting depth and silently measures
nothing for the rest of the session. perf_iface_witness gates that.
Wall-clock baseline you can run on every commit:
make benchmark # default: jagniccc.j64, 900 frames, 300 warmup
make benchmark BENCH_ROM=test/roms/yarc.j64 # GPU-loop amplifier -- see the caveat below
make benchmark BENCH_FRAMES=3000 # longer run (smoother numbers)
make benchmark BENCH_BLITTER=accurate # A/B against the "accurate" path. Measured
# on arm64 (#511): fast is never slower, and
# ~2.2x faster in blit-heavy scenes despite
# being scalar while accurate is NEON.
make benchmark BENCH_ROM=test/roms/private/Atari\ Karts.jagReports Frames/sec, Time/frame, total wall time. Boots the core via dlopen, runs N frames headless (no video presentation, no audio output), so you measure pure emulator work.
Use it as a delta: capture baseline before your change, run again after. Don't trust absolute numbers across hosts (CPU, thermals, scheduler, big.LITTLE pinning). Do trust same-host commit-to-commit deltas.
The harness lives at
test/tools/test_benchmark.c. Read it if you want to measure something specific (per-subsystem timing, only-DSP, etc.) — it's <400 lines.
make benchmark and opt_ab.sh measure wall time, so they need a quiet host — and that dependency has produced two wrong answers. #515 measured -O3 at +12.5% sequentially and −11.7% interleaved from the same two binaries, minutes apart; #520's timing phase was blocked outright (load 19.08 on 12 cores) and never ran.
ir_ab.sh sidesteps the problem by counting work instead of timing it. The emulator is deterministic, so a fixed ROM and frame count is a fixed number of instructions, and valgrind --tool=cachegrind counts exactly that in simulation — bit-identical run to run. It needs no privileges (unlike perf stat, which hosted CI runners lock down), so it works on a busy dev box and on a free GitHub runner.
test/tools/ir_ab.sh 'OPT_LEVEL=-O2' 'OPT_LEVEL=-O3' # flag flip (opt_ab.sh's convention)
test/tools/ir_ab.sh --ref libretro/develop HEAD # source change / PR vs base
test/tools/ir_ab.sh --selftest # instrument check: Ir must be IDENTICAL
IR_ROM=test/roms/yarc.j64 test/tools/ir_ab.sh --profile # where does this ROM's Ir go?No valgrind on the host? On macOS the script re-execs itself inside a Linux container (podman or docker) automatically; only $WORK and the ROM cross the boundary.
Deliberately no load-average gate. opt_ab.sh refuses above one load per core and is right to — it measures a clock. Ir does not depend on how busy the machine is, and that is the entire point. Don't add one back.
| property | how | result |
|---|---|---|
| Determinism | same source both arms (--selftest) |
Ir identical: 1,633,893,288 twice. I1/D1/LL miss counts identical too. |
| Sensitivity | throwaway commit adding one volatile increment per emulated GPU opcode |
+1.815% (+159,337,672 Ir), correctly signed |
The sensitivity control is the one that matters: an instrument that has never shown it can detect a change will report "no change" forever and look perfectly healthy. It also calibrates the tool — the added waste is ~3 instructions per GPU opcode, putting yarc@90 at roughly 53.1 million GPU opcodes, which turns later deltas into per-instruction arithmetic rather than percentages. (Treat that as a calibration figure, not an exact count: 159,337,672 / 3 is not an integer, so the per-opcode cost is not exactly 3 on every path — the compiler is free to fold the increment differently depending on surrounding code.)
Ir is not wall time. It models neither branch prediction nor ILP nor real cache behaviour (the simulated D1/LL columns close only part of that gap). A change can legitimately raise Ir and still be faster (inlining, unrolling), and removing dependent loads helps latency more than it helps instruction count — so a small Ir delta there understates the win. This is a gate and a regression detector; wall-clock confirmation still belongs on real hardware.
Absolute Ir is architecture-specific — an arm64 container and an x86_64 runner disagree by construction. Only the within-run A/B delta means anything. The Ir denominator also includes the measuring harness (frame_hash_ab's own hashing is ~4.4% of total on the default workload), so an ir_ab percentage is a share of emulator plus instrument, not directly comparable to a sampling profiler's "% of process time".
--profile gives per-function Ir for one workload with no source changes and no sampling bias. Measured:
| workload | GPU interp | DSP interp | blitter | 68K | total Ir |
|---|---|---|---|---|---|
jagniccc.j64 @ 90 |
0% | 0% | 0% | ~38% | 1.6e9 |
jagniccc.j64 @ 300 |
38.6% | 22.3% | 7.1% | ~5.9% | 19.5e9 |
jagniccc.j64 @ 600 |
40.2% | 23.7% | 10.3% | ~2% | 52.3e9 |
yarc.j64 @ 90 |
71.2% | 0.08% | 17.5% | ~0% | 8.8e9 |
jagniccc.j64 is the Jaguar port of Leonard/Oxygene's NICCC 2000 ST demo (test/vendor/JaguarDemos/jagniccc2000), and it renders on the GPU with the 68K parked in stop #$2000 — but only after its boot window. At 90 frames it is still in BIOS boot and executes zero GPU-interpreter instructions, which is exactly the shape of an inert gate. At 300 it reaches the steady-state mix, which is why that is the default here and in CI.
yarc.j64 is the GPU amplifier, but note #533's point: its opcode mix is jr-heavy, so per-instruction loop overhead is an unusually large share of its GPU time and a loop-bookkeeping change scores high on it relative to a real game. Use it to make a GPU-loop effect visible, not to size it.
.github/workflows/ir-ab.yml runs the A/B on PRs touching src/tom/gpu.c, src/tom/blitter.c, src/tom/op.c, src/jerry/dsp.c, src/m68000/** or the Makefiles, and reports the delta as a job summary. Because the variance is zero the flagging threshold is tight (0.5%), but the job is advisory, not blocking — see "what Ir is not" above. Flip IR_GATE: '1' if that policy ever changes.
Instruments (Time Profiler) is the easiest way to get a flame graph on macOS.
The wrapper at scripts/profile-mac.sh builds the core, runs the benchmark
under xctrace, and writes a .trace bundle you can open in Instruments:
scripts/profile-mac.sh # default: Time Profiler, accurate blitter
scripts/profile-mac.sh --template "CPU Counters" # PMU: cycles, instructions, branch misses
scripts/profile-mac.sh --rom test/roms/yarc.j64 --open # auto-open the traceManual invocation if you'd rather attach to a running process:
make benchmark BENCH_FRAMES=6000 BENCH_WARMUP=120 &
BENCH_PID=$!
xcrun xctrace record --template "Time Profiler" --attach $BENCH_PID --output bench.trace --time-limit 30s
open bench.traceThe default symbolication is good — you'll see OPProcessFixedBitmap, BlitterMidsummer2, DSPExec etc. as top hot frames if they're slow.
For a quick text dump without the GUI:
sample $BENCH_PID 5 -file /tmp/sample.txt
# 5-second sample. Read /tmp/sample.txt for collapsed call stacks.Sampling profilers tell you where time goes; counters tell you how often
something happens. When you want exact iteration counts (e.g., "did my
fast-path actually skip the inner loop?"), use the perf_counters system in
src/core/perf_counters.h.
make benchmark BENCH_PROFILE=1 BENCH_BLITTER=accurate BENCH_FRAMES=300
# ...
# [perf] counter dump:
# [perf] blitter_phrase_writes 3034993
# [perf] blitter_phrase_reads 931821
# [perf] blitter_inner_io 3966814
# [perf] blitter_inner 4131151
# [perf] blitter_outer 337722
# [perf] blitter_calls 131628The macros are zero-overhead when BENCH_PROFILE is undefined (default
build) — every PERF_INC becomes ((void)0), every PERF_COUNTER
becomes a typedef. Use them freely in hot paths to instrument
hypotheses.
Adding a counter:
#include "perf_counters.h"
PERF_COUNTER(my_event); /* file scope */
void hot(void) {
PERF_INC(my_event); /* in-loop */
PERF_ADD(my_event, n); /* batch */
}The harness (test/tools/test_benchmark.c) calls
perf_counters_dump(stderr) at exit; counter values appear right
before the BENCHMARK RESULTS block.
When to reach for this vs. Time Profiler:
| Question | Tool |
|---|---|
| "Where are we spending cycles?" | xctrace Time Profiler |
| "How many times does the inner loop run per frame?" | BENCH_PROFILE=1 |
| "What fraction of inner iterations are no-ops?" | BENCH_PROFILE=1 |
| "Are we hitting L1 / branch-mispredicting?" | xctrace CPU Counters |
| "Did this optimization change behavior, not just timing?" | BENCH_PROFILE=1 (deltas in counts) |
sudo apt install -y linux-tools-common linux-tools-generic
git clone https://github.com/brendangregg/FlameGraph /tmp/flamegraph
make benchmark BENCH_FRAMES=6000 BENCH_WARMUP=120 &
BENCH_PID=$!
perf record -F 999 -g -p $BENCH_PID -- sleep 30
perf script | /tmp/flamegraph/stackcollapse-perf.pl | /tmp/flamegraph/flamegraph.pl > flame.svg
open flame.svg-F 999 = 999 Hz sample rate (avoid 1000 Hz lockstep aliasing with display refresh). -g = capture call graphs.
Suspicious-by-default places when something gets slow:
| Subsystem | File | Notes |
|---|---|---|
| Object Processor (sprites, bitmaps) | src/tom/op.c |
OPProcessFixedBitmap, OPProcessScaledBitmap, OPDiscoverObjects. Dominant on heavy-OP scenes (Wolf3D, Tempest 2000). |
| Blitter | src/tom/blitter.c, blitter_mmio.c, blitter_simd_*.c |
Two paths: fast (blitter_generic, the upstream-derived path) and accurate (BlitterMidsummer2). SIMD (blitter_simd_{sse2,neon,scalar}.c) is currently wired only into the accurate blitter's pixel kernel — see issue #124 for the plan to widen SIMD coverage. |
| 68K | src/m68000/cpuemu.c |
Machine-generated UAE. ~1.8 MB of source. If this is hot, there's not much to do beyond JIT (out of scope). |
| GPU (RISC, 26.6 MHz) | src/tom/gpu.c |
GPUExec per-instruction. Hot when game uses GPU heavily (most do). |
| DSP (RISC, audio) | src/jerry/dsp.c |
DSPExec per-instruction. See src/jerry/dsp_acc40.h for the 40-bit MAC. |
| Frame loop | src/core/jaguar.c |
JaguarExecuteNew is the event-driven driver. If the event queue is hot, look at src/core/event.c. |
The blitter has three implementations, selected at build time via BLITTER_SIMD:
make BLITTER_SIMD=neon -j4 && make benchmark # ARM
make BLITTER_SIMD=sse2 -j4 && make benchmark # x86_64
make BLITTER_SIMD=scalar -j4 && make benchmark # portable fallbackAuto-detection picks NEON on aarch64 / SSE2 on x86_64 / scalar elsewhere (see Makefile.common). Force the scalar build to verify SIMD is actually winning — when the gap closes, your bottleneck moved elsewhere.
| Goal | Flags |
|---|---|
| Production perf | make (default; -O2 -DNDEBUG -ffast-math -fomit-frame-pointer) |
| Profiling (good symbols, near-prod perf) | make RELEASE_DEBUG_INFO=1 (-O2 -g). Strips later if shipping. |
| Sanitizers | make CC="clang -fsanitize=address,undefined -O1 -g" (catches bugs, halves perf) |
| Coverage | make COVERAGE=1 (-O0 -g --coverage). Don't profile this — coverage instrumentation overhead is ~3× and not representative. |
| Debug stepping | make DEBUG=1 (-O0 -g) |
The core is event-driven, not cycle-accurate (docs/source-layout.md covers the rationale). JaguarExecuteNew runs the 68K to the next event, then GPU, then fires callbacks. Don't expect cycle-counter results to match real hardware — measure wall-clock instead.
If you do need cycle-level inspection:
# Linux: cycles + instructions per loop iteration
perf stat -e cycles,instructions,branches,branch-misses ./test/tools/test_benchmark ./virtualjaguar_libretro.so test/roms/yarc.j64 600
# macOS: Instruments has a "CPU Counters" template
xcrun xctrace record --template "CPU Counters" --launch -- ./test/tools/test_benchmark ...If make benchmark shows a regression after your change:
- Run twice — check for noise. Same-host runs typically vary <2%. >5% delta is real signal.
- Bisect by commit:
git bisect start HEAD <known-good-commit>, mark good/bad withmake benchmarkresults until you isolate the offender. - Check both blitters (
BENCH_BLITTER=fastvsaccurate) — sometimes a regression only shows on one path. - Profile, don't guess — the bottleneck is rarely where you'd expect on this codebase.
CLAUDE.md— hardware model + repo layoutdocs/source-layout.md— file-by-file source tourdocs/emulation-bug-hunt-todos.md— known performance / accuracy follow-upstest/tools/test_benchmark.c— the harness itself