Last iteration left two candidates for why trace_gpu_stream produced no
file: the CLI flag not reaching the cvar, or BeginTracing failing
silently. Neither. Following the code instead of guessing:
BeginTracing only sets trace_state_ = kStreaming ("Streaming starts on
the next primary buffer execute"). The file is opened later, in
ExecutePrimaryBuffer, inside
#if XE_ENABLE_TRACE_WRITER_INSTRUMENTATION == 1
and trace_writer.h defines that as 0 under NDEBUG, 1 otherwise -- the
trace writer exists only in debug builds.
Confirmed against the binaries, with a control. The format string
"{:08X}_stream.xtr" lives only inside that guard:
build/bin/Linux/Release/xenia_canary 0 occurrences
build/bin/Linux/Debug/xenia_canary 1 occurrence
/sylph-home/re/canary-build/.../Release/... 0 <- what run-canary uses
The debug binary is the control: it proves the test finds the string when
it is present, so the release zero means something.
So trace_gpu_stream is a no-op in this container's emulator -- the cvar
parses, BeginTracing runs, and nothing can open a file. The kill -9 was
not the cause either, though it would have destroyed a trace had one
existed.
The route exists but is not cheap: a debug build with the writer compiled
in sits at build/bin/Linux/Debug/xenia_canary, 253 MB against Release's
18 MB, so a much slower boot plus a trace of every GPU packet on a disk
at 95%. Recorded as available rather than attempted -- what it would
confirm, the DC_LUT write, is already a well-supported inference, and the
cost is out of proportion to the gain.
METHOD: a cvar existing does not mean the feature is compiled in; and
test a compile-time gate against the binary, with a control.
Tried to turn the gamma-ramp inference into a direct observation.
canary's trace_gpu_stream records gamma ramps as their own command type
(kGammaRamp, index 11 in TraceCommandType), so a boot trace should show
the write. Two bounded runs produced NO trace file at all -- nothing under
the prefix, no .xtr anywhere, no scratch/gpu/.
Bounded deliberately: the disk is at 95% (50 GiB free) and a trace of all
GPU packets during boot includes video decode, so the runner carried its
own watchdog that killed the emulator the moment output passed a 2 GiB
cap. It never fired -- there was nothing to cap -- and disk stayed at 95%
throughout. Bounding from inside cost nothing and removed any need to
gamble on how coarsely I could poll.
What the attempt did establish. BeginTracing() runs at GPU init when the
cvar is set (graphics_system.cc:237), but EndTracing() runs only from
GraphicsSystem::Shutdown() -- so the kill -9 this session has used
routinely can never finalise a trace. The second run was stopped with
SIGTERM and exited cleanly; still no file, so that is not the whole
story. Two candidates remain unseparated: the CLI flag not reaching the
cvar, or BeginTracing failing silently. The next run removes the
ambiguity by setting trace_gpu_stream in the config FILE instead.
And a trap I nearly fell into. The startup config dump showed
trace_gpu_stream = false after I passed --trace_gpu_stream=true, which
reads as "flag ignored". It is not evidence either way: the gamma run
passed --log_mask=12 --log_level=3, its dump printed log_mask = 0 and
log_level = 2, and Kernel Debug logging was demonstrably ON -- that run
is where VdGetCurrentDisplayGamma was captured. The dump reflects the
config file and can neither confirm nor refute a command-line override.
(It does not undo the earlier user_language conclusion: absence of a NAME
from the dump still shows a cvar is unregistered.)
The gamma-ramp write therefore remains an inference, unchanged.
Three earlier "the title never appears" claims came from instruments
later found broken -- a stale pixel oracle, a 41 s sampling interval, a
freezing stream. This one carries its own evidence.
title_probe_xchecked.py restarts its capture stream every 30 s AND prints
its reading beside an independent `import` grab every 60 s:
1851 frames in 560.2 s = 3.30 fps
cross-checks 9, disagreements 1
max glyph 0
t= 62s stream 6.05 | import 0.07 disagree (a fade, logos mid-transition)
t=123s stream 7.40 | import 7.49 agree
t=183s stream 8.18 | import 8.29 agree
t=243s stream 0.23 | import 0.10 agree
t=311s stream 89.68 | import 89.51 agree
t=371s stream 80.97 | import 81.58 agree
t=426s stream 117.43 | import 117.72 agree
t=487s stream 77.71 | import 76.25 agree
t=546s stream 70.43 | import 70.55 agree
Eight of nine agree within 2%, fps held at 3.30 with no collapse to 1.60,
and the surface moved through dark and bright phases. So the frames were
live: over 560 continuous seconds from launch, sampled 3.3 times a
second, the interactive title's green (A) plate never appears while the
game renders throughout. The final frame correlates 0.0145 / -0.0047 /
0.0102 with our title / main menu / EXTRAS renders -- attract-movie
content, not a UI screen.
Why remains unknown. live-title-press-a.png with its 753 glyph pixels
proves the title was reachable from this container on 2026-08-28, and
clearing the shader cache fixed the black surface but not this.
The two emulator-side questions (gamma control, 8AX vs ptbase) are
therefore blocked on a characterised failure rather than a suspicion.
Neither blocks the five menu screens, so I am returning to static work;
the probe is committed for whoever picks it up.
METHOD: a probe that cross-checks itself turns "no result" into a result.
Cross-checked the instrument built last iteration against an independent
grabber while both watched the same screen, and it fails.
A single long-lived ffmpeg x11grab stream degrades and then freezes:
862 frames in 540.1 s = 1.60 fps (it starts at 3.98)
t=450/480/510/540 s: surface mean 5.21, identical every time
At that same moment `import` read surface mean 125.65, and a freshly
started ffmpeg stream read 122.43 -- agreeing with import to 3%. So the
acquisition was broken, not the analysis: the stream replayed a stale
frame while the screen was 24x brighter.
That withdraws last iteration's headline. "2391 frames over 600 s from
t=0, max glyph 0" cannot distinguish "the title never appeared" from "the
stream froze early and repeated one frame 2391 times". Its 3.98 fps was
measured over the first 20 s, before the degradation. Sample count is not
coverage unless the samples are known independent.
Fixed: the stream is now torn down and restarted every 30 s. Startup is
~0.3 s, cheap against the title's window, and it guarantees live frames.
Separately, the cache hypothesis was tested and is SUPPORTED. cache,
cache0, cache1, cache_host moved aside (to /tmp/xenia-cache-aside, not
deleted) and the surface renders again: import reads mean 54.8 and 68.6
with 100% non-black warm content, against 0.07 and 0.08% non-black in the
black run; 773 of 862 probe frames had >2% non-black. One run each side
and many kill -9s before the black one, so it is supported, not proven --
the old caches are kept for reproduction.
Still no title, but that number now comes from a stalling probe and
establishes nothing either way.
METHOD: validating a probe on static images tests its analysis, not its
acquisition -- cross-check against an independent grabber during a run.
The named experiment was to attach the fast probe at t=0 so the boot
title could not be missed. Done, default config, English:
2391 frames in 600.4 s = 3.98 fps; max glyph 0; hits 0
Ten minutes sampled four times a second FROM LAUNCH, no green-(A) glyph.
So "the plate only shows in an early boot window I keep missing" is mine
and refuted -- the third explanation refuted in three iterations.
Then the check that should have come first. Splitting the raw root grab
into bands:
y 0- 44 (GTK menu bar) 100.00% non-black mean 210.50
y 45-719 (game surface) 0.08% non-black mean 0.07
The game is rendering black, reproducibly across back-to-back samples,
while the guest is alive and polling input (XamInputGetKeystrokeEx past
1201 calls) and MEM-WATCH keeps reporting. The crop and every pixel
oracle were correct; there was nothing on the surface to detect.
What this does NOT do is retroactively explain the earlier failures, and
claiming so would be the fourth over-reach in a row. Those runs had
content: run 2 sampled mean 33.1, run 3's classifier measured real
frame-to-frame rmse, the gamma_type=0 run measured mean 122.8. The
failure mode CHANGED over the session; black is the newest and worst.
Hypothesis for the regression, untested: canary's shader/pipeline cache
is 47 MB and was last written 23:49 on Aug 28, during the failed runs,
and this session has kill -9'd the emulator repeatedly. The test is to
move cache* aside and boot again -- one line and one run, not done.
Two METHOD lines: ask whether the screen is drawing anything before
explaining why a feature of it is missing; and a newly found fault does
not retroactively explain older failures.
Last iteration I blamed four failed runs on the probe sampling every
~41 s, slower than the title screen lasts, and withdrew three earlier
conclusions on that basis. Building the fix tested the claim and killed
it.
The speedup is real and control-verified. One long-lived ffmpeg x11grab
stream, raw RGB, glyph counted in numpy -- no per-sample process startup,
no PNG encode, no convert -crop:
wrapper `screenshot` 3.98 s per sample (emulator running)
import -window root -> PPM 1.20 s
long-lived x11grab stream 0.29 s 13.7x
The counter is byte-identical to is_title.py: 753 on the committed title
capture, 327 on the main menu.
Pointed at a running game it says the opposite of what I expected:
332 frames in 85.3 s = 3.89 fps; max glyph 0
1674 frames in 420.0 s = 3.99 fps; max glyph 0
1674 consecutive samples over seven unbroken minutes, four per second,
zero green-(A) pixels. Sampling rate was a real defect that happened not
to be the cause.
So "neither locale reaches the interactive title without a pad press" --
withdrawn last iteration for want of evidence -- is reinstated, now as a
dense measurement, with its reach stated: a MID-RUN window only, silent
about the boot title.
Leading hypothesis, unconfirmed: the PRESS (A) plate appears only in the
boot title window and the attract loop's title carries none, which is
exactly what title_states_capture.sh was written to test. The experiment
is to start the fast probe from t=0 rather than attach to a run already
in progress.
METHOD: fixing the instrument is how you test the explanation that blamed
it -- a plausible mechanism is a hypothesis, and the fix is its
experiment, not its proof.
Four consecutive runs failed to reach the interactive title, across two
locales, two launch paths and two display-gamma settings. I attributed it
in turn to a stale oracle, to the locale, and to the attract loop. It was
none of those.
one `screenshot` call, emulator running: 10.8 s
one `screenshot` call, emulator killed: 0.117 s
92x, measured at a 1-minute load average of 1.80 -- so it is contention
with the emulator through the X server, not background load.
skip_intro.sh takes two grabs per iteration plus a numpy import, giving a
median sampling interval of 41 s in the last run (38/82/41/20/30/30/35/
47/46/45/44/43/21/19). The title lasts "a few seconds" before the attract
loop reclaims it -- wait_title.sh's own header says so. The harness was
sampling slower than the event it was waiting for. That also explains why
runs at 16:43-18:05 the same day succeeded.
Withdrawn as CAUSES, though the observations stand: "the JP run never
reaches the interactive title", "neither locale reaches it without a pad
press", and "the game sat in the attract loop for 604 s". The English
control did control for locale -- it just shared the same defect.
Also recorded: I set kernel_display_gamma_type = 0 for the gamma control
run, which brightens the frame (mid-attract mean 122.8 vs 52.5/82.8 at
type 2) -- and skip_intro classifies movie-vs-static on an ABSOLUTE rmse
threshold, so the gamma change biased the very classifier the run
depended on. Changing a display setting and a capture behaviour in one
run confounds both. Config restored to type 2.
The fix is not applied: make the probe cheap enough to outpace the title
window (small region, no convert round trip, one long-lived process).
Every remaining emulator-side question is waiting on that.
