Skip to content

fix(vk): RX_VK_FRAME_LOG writes its frame times in a headless run too - #2354

Merged
hckrman101 merged 2 commits into
NotRexed:mainfrom
mooki000:fix/vk-frame-log-headless
Nov 11, 2026
Merged

hckrman101 merged 2 commits into
NotRexed:mainfrom
mooki000:fix/vk-frame-log-headless

Conversation

@mooki000

@mooki000 mooki000 commented Nov 11, 2026 •

Copy link
Copy Markdown
Contributor

What this is for: frame times from headless runs, the kind scripted tests and measurements use. RX_VK_FRAME_LOG=<csv> ("A CSV line per present: frame, seconds, frame time in ms", docs/development.md) writes nothing in a headless run (HOS_HEADLESS): the file is never even created. Fixes #2353. What is measured: on Linux (RTX 4090, NVIDIA 615.78.08) a headless run with the change wrote 6480 lines over 108.9 s, and its first interval equals the game's own present trace of the same run; none of 23 headless runs of main left a file; a game-free test that fails on main; the whole of the checks. Not measured: a windowed run with the change (that path calls the same code at the same place as before), Windows game runtime, AMD, the Steam Deck under gamescope.

What changed

  • gpu/vk/vk_replay.cpp: the writer was only in present_out, after vkQueuePresentKHR. Without a window a present
    copies the picture into the offscreen image and do_present returns before present_image, so it never got there.
    The writer is now frame_log_present(), unchanged (same file, header, columns and flush every 60 lines), called
    where it was and at the end of a headless do_present, once the copy into the offscreen image is submitted.
  • Frame generation is off without a window (framegen_on), so a headless run writes one line per game frame, as a
    window does without frame generation.
  • The times are the same steady clock as before. A headless run has no swapchain to wait on, so they show the game's
    and the replay's pace without the display's (V-Sync, the compositor).
  • tests/test_frame_log_headless.py (game-free): compiles the actual frame_log_present and checks its CSV header, sequence numbers, elapsed/interval times, and disabled output. It does not infer execution from call-site spelling.
  • docs/development.md: documents headless CPU intervals and the absence of swapchain/display waits.

How it was tested

Latest refresh, 2026-11-11: head e3119ce0 on 47ed9f14, including the merged #2397 Windows ASTC fixture repair. The present_native_pq conflict was resolved by retaining main’s moved declaration and this PR’s logger. The compiled CSV writer passes with GCC and Clang. No new game run or full local suite was made for this refresh; Source-regression CI now passes on this head: both Windows and both Ubuntu shards.

RTX 4090, NVIDIA 615.78.08, Arch Linux; headless (HOS_HEADLESS=1, the log says vk: no window: presents render offscreen (1920x1080)), from a fresh profile, no input, 120 s, muted, RX_VK_FRAME_LOG and HOS_PRESENT_TRACE set.

  • Main: none of 23 such headless runs left a frame log (the switch was set in every one).

  • With this change: frames.csv holds the header and 6480 lines, frames 0 to 6479 over 108.9 s, times rising from 0;
    the frame times average 16.80 ms (59.5 fps; the last 30 s 59.9 fps) with the game at its 60 cap through the intro
    movie and the title screen (pictures of the run looked at). The game's own present trace of the same run has the
    same first interval (43.28 ms) and 6432 presents over 108.1 s. (Not a frame-rate claim: other work ran beside it.)

  • That run was of this change on main bdfe09c (commit 7da36252). Rebased onto 49f75dc the change is the same apart from one blank line. Added 2026-11-11 16:27 UTC: the rebased build (cc36308 on 49f75dc, hookshot v2.1.0-rc.3-54-gcc363089) ran the same way, 150 s: frames.csv holds the header and 5880 lines, frames 0 to 5879 over 98.4 s, times rising from 0; its first interval (32.909 ms) equals the game's own present trace of that run (32,908,677 ns); no FATAL or device-lost line, no driver line in the kernel log. (Load average 22 falling to 9: not a frame-rate claim.)

  • Updated 2026-11-11: rebased onto 7759a6f3, head 5ce5970f. fix(vk): recover presentation after surface loss #1995 changed present_out to return bool; the old test pinned its full signature. The source-text call-site assertions are removed rather than repinned. The compiled writer check passes with GCC 16.2.1 and Clang 23.1.3: PASS: frame log CSV header, sequence, elapsed/interval times, and disabled output. Against main it fails because main has no extracted frame_log_present helper; that is not a headless integration test. Headless integration evidence is the two older game runs above.

  • On 5ce5970f, tests/run_all.py: 385 passed, 2 failed, 10 skipped in 141 s. test_updater_asset_digest.py cannot resolve the .NET 8 reference packs on this machine. nx2/test_texture_phi_dominance.py had a compiler killed by SIGKILL; its narrow rerun alone passed (1 passed, 0 failed, 0 skipped in 20 s). No second full suite was run.

  • Earlier suite on cc363089 (load 57 to 113), python -I -B tests/run_all.py: 362 passed, 3 failed, 10 skipped in 193 s (linux, 32 at once). Two of the failures are this machine's and fail on main as well, each with a pull request of its own: tests/test_updater_asset_digest.py (only a .NET 10 SDK here, test: the updater digest check runs where only a later .NET SDK is installed #2294) and tests/test_wayland_libdecor_hint.py (Clang 23, test: the Wayland libdecor fixture builds with Clang 23 (-Wunused-but-set-global) #2290). The third, tests/test_display_pointer.py, failed under that load at reads > 0 (its reader thread had made no read yet when the check ended) and passes when run alone (3 of 3, at load 55).

Added 2026-11-11: Windows part 2/2 passes tests/test_frame_log_headless.py. The job fails only on the unrelated ASTC fixture’s scanf deprecation, fixed by #2397, which has now merged and is included in the latest refresh. This is Windows coverage of the compiled writer, not a game run.

Not tested

  • No new game build/run after the subsequent rebases, including 47ed9f14; the game runs above name their earlier heads. The renderer patch remains the same; fix(vk): recover presentation after surface loss #1995's surface-loss return stays before the existing window log position.
  • A windowed run of this branch: the window's path calls the same function at the same place as before; not run here.
  • Windows game runtime, AMD, the Steam Deck under gamescope (the switch's first use).

Risks

  • A windowed run writes exactly what it wrote: the same function is called at the same place in present_out.
  • A headless line is written when the offscreen copy is submitted, not when a display shows it: there is no display. Its times are the game's and the replay's pace. Nobody should read them as presentation times, which the description of the switch does not promise either.
  • The file is opened at the first present, as before; a run without the switch pays one getenv at its first present and a null check after that.

Overlaps

Updated 2026-11-11 after the refresh: 49 open PRs touch one of this branch’s three files; one additional text conflict was reported, and its hunk was read.

Assisted-by: Claude Opus 5.5
Co-Authored-By: Claude Opus 5.5 noreply@anthropic.com

Assisted-by: GPT-6 Astra
Co-Authored-By: GPT-6 Astra noreply@openai.com

@mooki000

Copy link
Copy Markdown
Contributor Author

Rebased onto 7759a6f3, now 5ce5970f. #1995 changed present_out to return bool; I removed the test’s source-text call-site assertions instead of pinning the new signature. The compiled CSV writer checks still pass with GCC and Clang. The renderer patch is unchanged, including the window log’s position after the surface-loss early return.

Full suite: 385 passed, 2 failed, 10 skipped. One failure is this machine’s missing .NET 8 packs; the other was a SIGKILL during a shader fixture compile, and its isolated rerun passed. The description now distinguishes that writer check from the earlier headless game runs. No new game run or Windows run after this rebase.

@mooki000

Copy link
Copy Markdown
Contributor Author

The Windows part 2/2 job is red, but tests/test_frame_log_headless.py passes there. Its only failure is tests/test_native_astc_texture_count.py: the Windows CRT’s scanf deprecation under -Werror, already fixed by the approved #2397 (not merged yet). This job used main 7759a6f3, before that fix.

Job log. This adds Windows coverage of the compiled frame-log writer, not a Windows game run. No frame-log source change is needed for this failure.

@hckrman101 hckrman101 left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good. The writer is moved unchanged into frame_log_present(), and the windowed call in present_out sits at the same spot as before (after the #1995 surface-loss return). The new call in do_present is guarded by dev.offscreen, so only a headless run takes it. That also means a normal run only gains a function call, and without the switch it pays the same one-time getenv and then a null check.

Timing source: it is the same steady_clock as before. With no swapchain the numbers are CPU intervals after the offscreen copy is submitted. The PR describes this plainly, and its first interval matched HOS_PRESENT_TRACE in the headless runs it reports. Frame generation is off headless, so it is one line per game frame, which the PR says too.

The test compiles the real function and checks the header, sequence, times and the unset case. It runs without a dump and is declared with RUN_ALL_ARGS. Windows part 2/2 is red only on the ASTC scanf deprecation that #2397 fixes, and this test passes there.

Nit, not for this PR: the fopen of the log path is narrow, so a non-ASCII path on Windows goes through the ANSI code page. That was already the case before this change, and a debug switch fed a path by a script is a minor spot for it.

Not run here: I only read the diff and the head file, so the game runs are the author's.

@mooki000

Copy link
Copy Markdown
Contributor Author

Thanks for the review. I’ve recorded the inherited narrow-path issue on Windows separately; it is unchanged and outside this patch. The Windows writer-test pass and the #2397 dependency are now in the description.

mooki000 and others added 2 commits November 11, 2026 13:52
RX_VK_FRAME_LOG (docs/development.md: "A CSV line per present") was written only in present_out, after
vkQueuePresentKHR. Without a window (HOS_HEADLESS) a present copies the picture into the offscreen image and returns
before present_image, so a headless run, the kind a scripted test or a measurement runs, left no file at all.

The writer is now frame_log_present(), called where it was and at the end of a headless present, after the copy into
the offscreen image is submitted. Frame generation is off without a window, so every game frame is one line, as with
a window. The times are the same CPU clock as before; a headless run has no swapchain to wait on, so they show the
game's and the replay's pace without the display's.

tests/test_frame_log_headless.py compiles the actual frame_log_present with RX_VK_FRAME_LOG set and checks that both
ends of a present call it.

Assisted-by: Claude Opus 5.5
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Remove the call-site spelling assertions rather than pinning a changed present_out return type. Retain the compiled CSV writer behavior check; headless call-path evidence remains in the reported game runs. Document the headless clock semantics.

Assisted-by: Claude Opus 5.5
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Assisted-by: GPT-6 Astra
Co-Authored-By: GPT-6 Astra <noreply@openai.com>
@mooki000
mooki000 force-pushed the fix/vk-frame-log-headless branch from 5ce5970 to e3119ce Compare November 11, 2026 20:05
@mooki000

mooki000 commented Nov 11, 2026 •

Copy link
Copy Markdown
Contributor Author

#2397 has merged. Rebased onto 47ed9f14, now e3119ce0, so the Windows checks include that repair. Kept main’s moved HDR declaration and the unchanged frame-log writer; its compiled check passes with GCC and Clang. No new game run or full local suite for this refresh; the description keeps the earlier evidence tied to its tested heads.

Update 2026-11-11: the refreshed source-regression workflow is green on e3119ce0: both Windows and both Ubuntu shards pass. This is game-free CI evidence, not a new game run.

@Joey-Magnus Joey-Magnus left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The rebases since approval only moved code. The frame-log writer is the same function, and the new call in do_present only runs with dev.offscreen, where present_out is never reached, so the two call sites can't both write. The test compiles the real function and passes on both platforms.

@hckrman101
hckrman101 merged commit 60a4b84 into NotRexed:main Nov 11, 2026
13 checks passed
@jspenaq

jspenaq commented Nov 12, 2026

Copy link
Copy Markdown

Independent validation: Steam Deck LCD / AMD RADV (headless)

I independently tested a backport of #2354 onto the v2.1.0 release tag on a Steam Deck LCD.

Environment

  • Steam Deck LCD, SteamOS 3.9.5
  • AMD Van Gogh, Mesa RADV 26.2.0-devel
  • Vulkan 1.4.350
  • Linux x86-64; Vulkan backend rebuilt with Clang 23.1.5
  • Headless execution (HOS_HEADLESS=1, RX_VK_PRECOMPILE=0)

Results

  • The rebuilt hookshot_vk.so loaded successfully, passed the API 14 initialization check, and initialized RADV.
  • With RX_VK_FRAME_LOG enabled: 1,020 valid CSV rows, frame IDs 0–1019, consecutive with no gaps or duplicates, non-decreasing timestamps, and no invalid frametimes.
  • The CSV contained the expected frame,time_s,frametime_ms header.
  • With RX_VK_FRAME_LOG unset: the renderer continued producing presents, but no CSV was created.
  • No Vulkan device loss, GPU reset, or OOM was observed in either run.
  • The original v2.1.0 installation remained unchanged; testing used an isolated copy.

Scope: This validates the backported headless path on Steam Deck hardware. It is not a test of the exact merged main build, the windowed/gamescope path, or comparative performance.

Thanks for the fix!!

@mooki000

Copy link
Copy Markdown
Contributor Author

Thanks @jspenaq for checking both enabled and disabled logging on your Steam Deck LCD/RADV backport, including the 1,020 valid CSV rows. That adds real Deck coverage of the headless path on v2.1.0, while keeping the exact merged-main build and windowed/gamescope path separate and untested by those runs.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

RX_VK_FRAME_LOG writes nothing in a headless run (HOS_HEADLESS)

4 participants