Skip to content

perf(libkernel): end short sleeps when the GPU or a flip completes - #6658

Merged
oneandonlydean merged 15 commits into
boykopovar:mainfrom
nicolasabosch:perf/gpu-wake-sleeps
Oct 20, 2026
Merged

oneandonlydean merged 15 commits into
boykopovar:mainfrom
nicolasabosch:perf/gpu-wake-sleeps

Conversation

@nicolasabosch

@nicolasabosch nicolasabosch commented Oct 16, 2026 •

Copy link
Copy Markdown
Contributor

What

A sceKernelUsleep, usleep, nanosleep or sceKernelNanosleep of 1 ms or less now returns as soon as one of these happens:

  • the AGC driver sees a GPU batch complete (a thread per recorder waits on its timeline semaphore),
  • the driver runs a batch's completion actions,
  • VideoOut completes a flip.

Titles that poll a GPU label or the flip status between short sleeps no longer sleep out the rest of each 1 ms. SuperTuxKart's GL layer is one: it spins 200 us, then calls sceKernelUsleep(1000) until its marker lands, about 35 times per frame in the menu.

Limits that keep the console behaviour for everything else:

  • Sleeps over 1 ms are never shortened, so a frame limiter can wake at most 1 ms early per sleep.
  • A thread returns early at most 8 times in a run of back-to-back sleeps. The run restarts when the thread submits AGC work, or when it did not sleep for at least the requested time since its last sleep. A loop that counts sleeps to time out still sleeps all but 8 of them in full (STK's GL layer exits after 2000 sleeps of 1 ms).
  • On Windows a sleep under 50 us, or any sleep with APS5_COARSE_TIMED_WAITS set, takes the same path as on main.
  • APS5_NO_SLEEP_WAKE=1 keeps every sleep in full.

The early return is recorded in technical debt (libkernel, Functional).

Tested

Windows 11 Pro 10.0.26300, Intel i9-14900HX, 32 GB, NVIDIA GeForce RTX 4070 Laptop GPU (driver 616.92), 1920x1080 window.

Captured as the Performance report form describes:

  • APS5_TRACE_SECONDS only, no redirected log, warm caches.
  • main 43a2abaf7 and this branch 876ad540f (main merged in) built from clean checkouts and alternated in one session, same relinked executable.
title, scene main p50 / p90 ms this PR p50 / p90 ms
SuperTuxKart PPSA69421, main menu, run 1 53.3 / 57.6 32.1 / 33.9
SuperTuxKart PPSA69421, main menu, run 2 53.6 / 56.6 30.2 / 31.9
SuperTuxKart PPSA69421, kart selection 319.2 / 328.6 163.2 / 172.6
DOOM homebrew, demo loop, run 1 (earlier base 31cbb55d7) 16.68 / 17.29 16.68 / 17.16
DOOM homebrew, demo loop, run 2 (earlier base 31cbb55d7) 16.70 / 18.53 16.68 / 17.06

Other kart-selection runs of this branch gave 150.5 ms p50 (one more run) and, in an earlier session on main 31cbb55d7, 187.5 against 324.6 ms. One further run of the branch did not reach that scene and is not counted. DOOM was measured on the earlier base and not repeated; it paces itself at 60 Hz and its GPU time per present did not change.

In the STK menu the guest no longer waits out its 1 ms sleeps: in the trace, a batch's cycle drops from about 1.7 ms to about 0.9 ms.

ctest -j 16 (Windows, mingw) on this branch: 1689 of 1691 pass. agc_driver_pass_input_hazard fails the same way on main 43a2abaf7 without this change (3 of 3 runs). conversion_diagnostics timed out under the parallel run and passes alone (3 of 3). agc_driver_preparation_scope_settle and agc_driver_bda_device, which failed in earlier runs, are explained by main failing or timing out the same way (7 of 144 and 3 of 3 runs).

New test: guest_sleep_wake.

Validation layers (this change only, not compared with main): this branch with main dbac9fa15b61 merged in, built Release on the same machine and GPU, ctest -V -R 'sleep_wake|agc_driver_flip' with VK_INSTANCE_LAYERS=VK_LAYER_KHRONOS_validation, ANYPS5_NO_SHADER_CACHE=1 and ANYPS5_REQUIRE_VULKAN=1. 5 of 5 pass (agc_driver_flip, agc_driver_flip_stores_small_results, agc_driver_flip_compute, guest_sleep_wake, guest_sleep_wake_coarse); the log has no VUID- line and no was not found but was requested by env var VK_INSTANCE_LAYERS. The same run on main was not done, so the no-new-VUID comparison with main is not made.

Review of the Windows wake event: a wake that lands after a sleep stopped waiting left the per-thread event signalled, and the next sleep on that thread could spin its whole length. Measured on this machine with a 1000-run loop (a wake during a 300 us sleep, then a 1 ms sleep timed in thread cycles): without ResetEvent 65, 102 and 173 of 1000 of those second sleeps burned over 800 us of CPU; with the fix 3, 2 and 2. The same loop with no earlier wake gave 0 of 1000 in both. The fix is in SleepNanosUnlessChanged.

Linux and macOS take the condition-variable path in TimedWait::SleepNanosUnlessChanged. @jotitadev validated it on Linux in this review (Ubuntu 26.04, i7-8700, GCC 15.2): guest_sleep_wake passes 100/100 alone and 120/120 with 12 and 24 parallel copies, and aborts with APS5_NO_SLEEP_WAKE=1. That run was before the Windows fix above, which does not touch the Linux path. The GPU progress watcher and the flip wake were not run on Linux. macOS was not run.

Summary lines, traces and trace_digest.py output for every capture: https://github.com/nicolasabosch/AnyPS5/releases/tag/perf-evidence-gpu-wake-sleeps (files final-* are the captures in the table; the earlier session's are unprefixed).

Summary lines

STK main menu, main 43a2abaf7:

{"commit":"43a2abaf7753","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_DIR":"<path>","APS5_TRACE_SECONDS":"40:10"},"gpu":"NVIDIA GeForce RTX 4070 Laptop GPU","driver":"NVIDIA 616.92","os":"Windows 10.0.26300","resolution":"1920x1080","window":{"spec":"seconds 40:10","first_present":401,"ms":10013.889},"presents":184,"frame_ms":{"p50":53.331,"p90":57.606,"p99":77.508,"max":79.033},"gpu_busy_ms_per_present":1.516,"worker_busy_pct":{"queue worker 0x0":2.686},"top_phases_ms_per_frame":{"Graphics.Draw":4.919,"Graphics.Draw.draw_and_resource_release":4.756,"Vulkan.DrawFromRecipe":1.597,"Graphics.DrawWithRecipe":1.590,"Graphics.DrawWithRecipe.draw_and_resource_release":1.586,"Driver.Packet":1.438,"Driver.Packet.draw":1.092,"Driver.Draw":1.064},"trace_dropped":false,"trace":"aps5-trace-43a2abaf7753-4132.json.gz"}

STK main menu, this branch 876ad540f:

{"commit":"876ad540ff5c","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_DIR":"<path>","APS5_TRACE_SECONDS":"40:10"},"gpu":"NVIDIA GeForce RTX 4070 Laptop GPU","driver":"NVIDIA 616.92","os":"Windows 10.0.26300","resolution":"1920x1080","window":{"spec":"seconds 40:10","first_present":851,"ms":10029.038},"presents":310,"frame_ms":{"p50":32.141,"p90":33.898,"p99":39.566,"max":40.269},"gpu_busy_ms_per_present":1.124,"worker_busy_pct":{"queue worker 0x0":3.924},"top_phases_ms_per_frame":{"Graphics.Draw":4.743,"Graphics.Draw.draw_and_resource_release":4.587,"Vulkan.DrawFromRecipe":1.515,"Graphics.DrawWithRecipe":1.508,"Graphics.DrawWithRecipe.draw_and_resource_release":1.505,"Driver.Packet":1.248,"Driver.Packet.draw":0.951,"Driver.Draw":0.925},"trace_dropped":false,"trace":"aps5-trace-876ad540ff5c-40272.json.gz"}

STK kart selection, main:

{"commit":"43a2abaf7753","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_DIR":"<path>","APS5_TRACE_SECONDS":"70:10"},"gpu":"NVIDIA GeForce RTX 4070 Laptop GPU","driver":"NVIDIA 616.92","os":"Windows 10.0.26300","resolution":"1920x1080","window":{"spec":"seconds 70:10","first_present":411,"ms":10253.988},"presents":32,"frame_ms":{"p50":319.174,"p90":328.618,"p99":343.988,"max":343.988},"gpu_busy_ms_per_present":18.050,"worker_busy_pct":{"queue worker 0x0":2.420},"top_phases_ms_per_frame":{"Vulkan.DrawFromRecipe":20.167,"Graphics.DrawWithRecipe":20.066,"Graphics.DrawWithRecipe.draw_and_resource_release":19.708,"Graphics.Draw":17.411,"Graphics.Draw.draw_and_resource_release":14.140,"Driver.Packet":7.386,"Recorder.Submit":5.801,"Driver.Packet.draw":5.363},"trace_dropped":false,"trace":"aps5-trace-43a2abaf7753-5624.json.gz"}

STK kart selection, this branch:

{"commit":"876ad540ff5c","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_DIR":"<path>","APS5_TRACE_SECONDS":"70:10"},"gpu":"NVIDIA GeForce RTX 4070 Laptop GPU","driver":"NVIDIA 616.92","os":"Windows 10.0.26300","resolution":"1920x1080","window":{"spec":"seconds 70:10","first_present":708,"ms":10030.452},"presents":62,"frame_ms":{"p50":163.165,"p90":172.619,"p99":191.444,"max":191.444},"gpu_busy_ms_per_present":12.149,"worker_busy_pct":{"queue worker 0x0":4.686},"top_phases_ms_per_frame":{"Vulkan.DrawFromRecipe":20.087,"Graphics.DrawWithRecipe":19.992,"Graphics.DrawWithRecipe.draw_and_resource_release":19.643,"Graphics.Draw":15.843,"Graphics.Draw.draw_and_resource_release":12.864,"Driver.Packet":7.202,"Recorder.Submit":5.692,"Driver.Packet.draw":5.256},"trace_dropped":false,"trace":"aps5-trace-876ad540ff5c-39480.json.gz"}
tools/trace_digest.py, STK main menu, main

seconds 40:10 from present 401: 184 presents, frame p50 53.3 / p90 57.6 / p99 77.5 / max 79.0 ms, GPU busy 1.5 ms per present
NVIDIA GeForce RTX 4070 Laptop GPU, NVIDIA 616.92, Windows 10.0.26300, 1920x1080, commit 43a2aba, dropped: no

{"commit":"43a2abaf7753","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_DIR":"<path>","APS5_TRACE_SECONDS":"40:10"},"gpu":"NVIDIA GeForce RTX 4070 Laptop GPU","driver":"NVIDIA 616.92","os":"Windows 10.0.26300","resolution":"1920x1080","window":{"spec":"seconds 40:10","first_present":401,"ms":10013.889},"presents":184,"frame_ms":{"p50":53.331,"p90":57.606,"p99":77.508,"max":79.033},"gpu_busy_ms_per_present":1.516,"worker_busy_pct":{"queue worker 0x0":2.686},"top_phases_ms_per_frame":{"Graphics.Draw":4.919,"Graphics.Draw.draw_and_resource_release":4.756,"Vulkan.DrawFromRecipe":1.597,"Graphics.DrawWithRecipe":1.59,"Graphics.DrawWithRecipe.draw_and_resource_release":1.586,"Driver.Packet":1.438,"Driver.Packet.draw":1.092,"Driver.Draw":1.064},"trace_dropped":false,"trace":"aps5-trace-43a2abaf7753-4132.json.gz"}

Slowest frames (largest slices inside each, inclusive)

  • present 401: 79.0 ms at 0 ms: Driver.WorkerWait (queue worker 0x0) 76.8, Driver.WorkerWait.idle_and_completion_poll (queue worker 0x0) 76.7, batch (gpu) 5.5, Graphics.Draw (draw committer) 5.0
  • present 402: 77.5 ms at 79 ms: Driver.WorkerWait (queue worker 0x0) 75.9, Driver.WorkerWait.idle_and_completion_poll (queue worker 0x0) 75.8, Graphics.Draw (draw committer) 4.9, Graphics.Draw.draw_and_resource_release (draw committer) 4.7
  • present 403: 69.9 ms at 157 ms: Driver.WorkerWait (queue worker 0x0) 68.1, Driver.WorkerWait.idle_and_completion_poll (queue worker 0x0) 68.0, batch (gpu) 6.4, Graphics.Draw (draw committer) 5.5
  • present 488: 65.9 ms at 4792 ms: Driver.WorkerWait (queue worker 0x0) 64.2, Driver.WorkerWait.idle_and_completion_poll (queue worker 0x0) 64.1, Graphics.Draw (draw committer) 6.0, Graphics.Draw.draw_and_resource_release (draw committer) 5.9
  • present 404: 65.7 ms at 226 ms: Driver.WorkerWait (queue worker 0x0) 63.8, Driver.WorkerWait.idle_and_completion_poll (queue worker 0x0) 63.7, Graphics.Draw (draw committer) 5.2, Graphics.Draw.draw_and_resource_release (draw committer) 5.0

Threads (ms per frame)

thread busy wait untraced in slices < 20 us largest
title 0.0 (0 %) 0.0 (0 %) 54.4 0.2 Recorder.Sync 0.0
queue worker 0x0 1.0 (2 %) 52.8 (97 %) 0.7 2.2 Driver.Packet 1.0, Driver.EndSubmission 0.0
draw committer 6.8 (13 %) 0.3 (1 %) 47.3 0.5 Graphics.Draw 4.9, Vulkan.DrawFromRecipe 1.6
presenter 0.6 (1 %) 0.1 (0 %) 53.8 0.1 VideoOut.Flip 0.7, Driver.Present 0.0
gpu 1.5 (3 %) 0.0 (0 %) 52.9 0.0 batch 1.5

Largest slices (ms per frame, inclusive, all threads): Driver.WorkerWait 52.8, Driver.WorkerWait.idle_and_completion_poll 52.7, Graphics.Draw 4.9, Graphics.Draw.draw_and_resource_release 4.8, Vulkan.DrawFromRecipe 1.6, Graphics.DrawWithRecipe 1.6, Graphics.DrawWithRecipe.draw_and_resource_release 1.6, batch 1.5, Driver.Packet 1.0, Driver.Packet.draw 0.9

Longest waits

  • Driver.WorkerWait (queue worker 0x0) 5.0 ms at 4682 ms, present 486
  • Driver.WorkerWait (queue worker 0x0) 4.7 ms at 9088 ms, present 567
  • Driver.WorkerWait (queue worker 0x0) 4.4 ms at 158 ms, present 403
  • Driver.WorkerWait (queue worker 0x0) 4.3 ms at 2528 ms, present 445
  • Driver.WorkerWait (queue worker 0x0) 3.7 ms at 58 ms, present 401
  • Driver.WorkerWait (queue worker 0x0) 3.7 ms at 84 ms, present 402
  • Driver.WorkerWait (queue worker 0x0) 3.6 ms at 163 ms, present 403
  • Driver.WorkerWait (queue worker 0x0) 3.5 ms at 55 ms, present 401
  • Driver.WorkerWait (queue worker 0x0) 3.5 ms at 5 ms, present 401
  • Driver.WorkerWait (queue worker 0x0) 3.4 ms at 80 ms, present 402

Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)

  • batch 68: 3.0 ms at 159 ms, present 403: GPU no ranges; recorded by Graphics.Draw (draw committer) 0.1, Graphics.Draw.draw_and_resource_release (draw committer) 0.1, Recorder.Submit (draw committer) 0.0
  • batch 3: 2.1 ms at 6 ms, present 401: GPU no ranges; recorded by Vulkan.DrawFromRecipe (draw committer) 0.2, Graphics.DrawWithRecipe (draw committer) 0.1, Graphics.DrawWithRecipe.draw_and_resource_release (draw committer) 0.1, Recorder.Submit (draw committer) 0.0
  • batch 69: 1.8 ms at 163 ms, present 403: GPU no ranges; recorded by Vulkan.DrawFromRecipe (draw committer) 0.2, Graphics.DrawWithRecipe (draw committer) 0.2, Graphics.DrawWithRecipe.draw_and_resource_release (draw committer) 0.2, Recorder.Submit (draw committer) 0.0
  • batch 35: 1.3 ms at 82 ms, present 402: GPU no ranges; recorded by Graphics.Draw (draw committer) 0.1, Graphics.Draw.draw_and_resource_release (draw committer) 0.1, Recorder.Submit (draw committer) 0.0
  • batch 2: 1.3 ms at 3 ms, present 401: GPU no ranges; recorded by Graphics.Draw (draw committer) 0.1, Graphics.Draw.draw_and_resource_release (draw committer) 0.1, Recorder.Submit (draw committer) 0.0
tools/trace_digest.py, STK main menu, this branch

seconds 40:10 from present 851: 310 presents, frame p50 32.1 / p90 33.9 / p99 39.6 / max 40.3 ms, GPU busy 1.1 ms per present
NVIDIA GeForce RTX 4070 Laptop GPU, NVIDIA 616.92, Windows 10.0.26300, 1920x1080, commit 876ad54, dropped: no

{"commit":"876ad540ff5c","dirty":false,"env":{"APS5_PAD_INPUT_FILE":"<path>","APS5_TRACE_DIR":"<path>","APS5_TRACE_SECONDS":"40:10"},"gpu":"NVIDIA GeForce RTX 4070 Laptop GPU","driver":"NVIDIA 616.92","os":"Windows 10.0.26300","resolution":"1920x1080","window":{"spec":"seconds 40:10","first_present":851,"ms":10029.038},"presents":310,"frame_ms":{"p50":32.141,"p90":33.898,"p99":39.566,"max":40.269},"gpu_busy_ms_per_present":1.124,"worker_busy_pct":{"queue worker 0x0":3.924},"top_phases_ms_per_frame":{"Graphics.Draw":4.743,"Graphics.Draw.draw_and_resource_release":4.587,"Vulkan.DrawFromRecipe":1.515,"Graphics.DrawWithRecipe":1.508,"Graphics.DrawWithRecipe.draw_and_resource_release":1.505,"Driver.Packet":1.248,"Driver.Packet.draw":0.951,"Driver.Draw":0.925},"trace_dropped":false,"trace":"aps5-trace-876ad540ff5c-40272.json.gz"}

Slowest frames (largest slices inside each, inclusive)

  • present 1154: 40.3 ms at 9771 ms: Driver.WorkerWait (queue worker 0x0) 38.5, Driver.WorkerWait.idle_and_completion_poll (queue worker 0x0) 38.5, Graphics.Draw (draw committer) 5.2, Graphics.Draw.draw_and_resource_release (draw committer) 4.9
  • present 1155: 39.8 ms at 9811 ms: Driver.WorkerWait (queue worker 0x0) 38.1, Driver.WorkerWait.idle_and_completion_poll (queue worker 0x0) 38.1, Graphics.Draw (draw committer) 4.7, Graphics.Draw.draw_and_resource_release (draw committer) 4.5
  • present 1153: 39.7 ms at 9731 ms: Driver.WorkerWait (queue worker 0x0) 38.0, Driver.WorkerWait.idle_and_completion_poll (queue worker 0x0) 37.9, Graphics.Draw (draw committer) 4.9, Graphics.Draw.draw_and_resource_release (draw committer) 4.7
  • present 1156: 39.6 ms at 9851 ms: Driver.WorkerWait (queue worker 0x0) 38.1, Driver.WorkerWait.idle_and_completion_poll (queue worker 0x0) 38.0, Graphics.Draw (draw committer) 4.9, Graphics.Draw.draw_and_resource_release (draw committer) 4.7
  • present 1157: 38.4 ms at 9891 ms: Driver.WorkerWait (queue worker 0x0) 37.0, Driver.WorkerWait.idle_and_completion_poll (queue worker 0x0) 37.0, Graphics.Draw (draw committer) 4.9, Graphics.Draw.draw_and_resource_release (draw committer) 4.8

Threads (ms per frame)

thread busy wait untraced in slices < 20 us largest
title 0.0 (0 %) 0.0 (0 %) 32.3 0.1 Recorder.Sync 0.0
queue worker 0x0 0.8 (2 %) 30.9 (96 %) 0.7 2.1 Driver.Packet 0.8, Driver.EndSubmission 0.0
draw committer 6.6 (20 %) 0.4 (1 %) 25.4 0.5 Graphics.Draw 4.7, Vulkan.DrawFromRecipe 1.5
presenter 0.6 (2 %) 0.0 (0 %) 31.7 0.1 VideoOut.Flip 0.6, Driver.Present 0.0
gpu 1.1 (3 %) 0.0 (0 %) 31.2 0.0 batch 1.1

Largest slices (ms per frame, inclusive, all threads): Driver.WorkerWait 30.9, Driver.WorkerWait.idle_and_completion_poll 30.8, Graphics.Draw 4.7, Graphics.Draw.draw_and_resource_release 4.6, Vulkan.DrawFromRecipe 1.5, Graphics.DrawWithRecipe 1.5, Graphics.DrawWithRecipe.draw_and_resource_release 1.5, batch 1.1, Driver.Packet 0.8, Driver.Packet.draw 0.8

Longest waits

  • Driver.WorkerWait (queue worker 0x0) 2.6 ms at 7965 ms, present 1099
  • Driver.WorkerWait (queue worker 0x0) 2.5 ms at 3960 ms, present 974
  • Driver.WorkerWait (queue worker 0x0) 2.4 ms at 1958 ms, present 911
  • Driver.WorkerWait (queue worker 0x0) 2.3 ms at 9760 ms, present 1153
  • Driver.WorkerWait (queue worker 0x0) 2.3 ms at 9814 ms, present 1155
  • Driver.WorkerWait (queue worker 0x0) 2.2 ms at 9869 ms, present 1156
  • Driver.WorkerWait (queue worker 0x0) 2.1 ms at 9967 ms, present 1159
  • Driver.WorkerWait (queue worker 0x0) 2.1 ms at 1605 ms, present 901
  • Driver.WorkerWait (queue worker 0x0) 2.0 ms at 9749 ms, present 1153
  • Driver.WorkerWait (queue worker 0x0) 2.0 ms at 8966 ms, present 1130

Largest GPU batches (GPU ranges inside, and the CPU slices that recorded each, inclusive)

  • batch 9012: 0.1 ms at 8767 ms, present 1124: GPU no ranges; recorded by Vulkan.DrawFromRecipe (draw committer) 0.1, Graphics.DrawWithRecipe (draw committer) 0.1, Graphics.DrawWithRecipe.draw_and_resource_release (draw committer) 0.1, Recorder.Submit (draw committer) 0.0
  • batch 695: 0.1 ms at 674 ms, present 872: GPU no ranges; recorded by Graphics.Draw (draw committer) 0.1, Graphics.Draw.draw_and_resource_release (draw committer) 0.1
  • batch 728: 0.1 ms at 707 ms, present 873: GPU no ranges; recorded by Graphics.Draw (draw committer) 0.1, Graphics.Draw.draw_and_resource_release (draw committer) 0.1
  • batch 596: 0.1 ms at 574 ms, present 869: GPU no ranges; recorded by Graphics.Draw (draw committer) 0.3, Graphics.Draw.draw_and_resource_release (draw committer) 0.2
  • batch 761: 0.1 ms at 740 ms, present 874: GPU no ranges; recorded by Graphics.Draw (draw committer) 0.1, Graphics.Draw.draw_and_resource_release (draw committer) 0.1

Checklist

  • Based on current main; no other open PR implements the same functions
  • One topic per PR; follow-ups go in a new PR
  • No comments in code except technical debt
  • Unimplemented paths throw (NotImplemented_nid_no_patch); silent stubs are listed under Silent stubs in their library's technical debt file
  • No notes, investigation .md files or images added to the repository (attach them to this PR)
  • New third-party code is a submodule built from source
  • Generic behaviour, not specific to one title
  • Depends on: none
  • Unblocks: none
  • GPUs tested: NVIDIA GeForce RTX 4070 Laptop GPU, driver 616.92, Windows 11 Pro 10.0.26300
  • AI-assisted: yes

🤖 Generated with Claude Code

A sleep of 1 ms or less returns once the AGC driver sees a GPU batch
complete (a thread waits on the recorder's timeline semaphore), runs a
batch's completion actions, or VideoOut completes a flip. A thread
returns early at most 8 times in a run of back-to-back sleeps; the run
restarts when the thread submits AGC work or did not sleep for the
requested time. APS5_NO_SLEEP_WAKE=1 keeps every sleep in full.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@github-actions

github-actions Bot commented Oct 16, 2026 •

Copy link
Copy Markdown

Other open pull requests touch the same code. Merging one will break the other, or both implement the same thing. If this one builds on them, list them in Depends on.

Pull request Conflicting files (lines on main) Same exports Same new files
PR 8487 core/libs/prx/libkernel/CMakeLists.txt L738

Some comparisons could not be completed because a pull request conflicts with the base branch. Review these shared files manually before concluding that there is no overlap.

Pull request Shared files not compared
PR 674 core/libs/prx/libSceVideoOut/src/VideoOutDriver.cpp
PR 4040 core/libs/prx/libSceAgcDriver/Execution/src/Driver/EntryPoints.cpp
PR 4630 docs/dev/debt/libkernel.md
PR 4972 core/libs/prx/libkernel/CMakeLists.txt
PR 5021 core/libs/prx/libSceVideoOut/src/VideoOutDriver.cpp
core/libs/prx/libkernel/CMakeLists.txt
core/libs/prx/libkernel/Time/Time.cpp
core/libs/prx/libkernel/Time/TimedWait.cpp
docs/dev/debt/libkernel.md
PR 5431 core/libs/prx/libSceAgcDriver/Graphics/include/Recorder.hpp
core/libs/prx/libSceAgcDriver/Graphics/src/Recorder.cpp
docs/dev/ENVIRONMENT.md
PR 5609 core/libs/prx/libSceAgcDriver/Graphics/include/Recorder.hpp
core/libs/prx/libSceAgcDriver/Graphics/src/Recorder.cpp
PR 6044 core/libs/prx/libkernel/CMakeLists.txt
PR 6149 docs/dev/debt/libkernel.md
PR 6185 core/libs/prx/libSceAgcDriver/Graphics/include/Recorder.hpp
core/libs/prx/libSceAgcDriver/Graphics/src/Recorder.cpp
PR 6186 core/libs/prx/libSceAgcDriver/Graphics/include/Recorder.hpp
core/libs/prx/libSceAgcDriver/Graphics/src/Recorder.cpp
PR 6188 core/libs/prx/libSceAgcDriver/Graphics/include/Recorder.hpp
core/libs/prx/libSceAgcDriver/Graphics/src/Recorder.cpp
PR 6226 core/libs/prx/libkernel/CMakeLists.txt
PR 6469 core/libs/prx/libkernel/CMakeLists.txt
docs/dev/debt/libkernel.md
PR 6519 docs/dev/debt/libkernel.md
PR 6539 core/libs/prx/libSceAgcDriver/Graphics/include/Recorder.hpp
core/libs/prx/libSceAgcDriver/Graphics/src/Recorder.cpp
PR 6636 docs/dev/ENVIRONMENT.md
PR 6682 core/libs/prx/libSceAgcDriver/Graphics/src/Recorder.cpp
PR 6740 docs/dev/debt/libkernel.md
PR 6747 core/libs/prx/libSceAgcDriver/Execution/src/Driver/EntryPoints.cpp
PR 6946 core/libs/prx/libSceAgcDriver/Graphics/src/Recorder.cpp
docs/dev/ENVIRONMENT.md
PR 6947 core/libs/prx/libSceAgcDriver/Graphics/include/Recorder.hpp
core/libs/prx/libSceAgcDriver/Graphics/src/Recorder.cpp
docs/dev/ENVIRONMENT.md
PR 6977 core/libs/prx/libSceAgcDriver/Execution/src/Driver/EntryPoints.cpp
core/libs/prx/libkernel/CMakeLists.txt
docs/dev/debt/libkernel.md
PR 7049 docs/dev/debt/libkernel.md
PR 7088 docs/dev/debt/libkernel.md
PR 7105 docs/dev/debt/libkernel.md
PR 7121 docs/dev/debt/libkernel.md
PR 7149 docs/dev/debt/libkernel.md
PR 7192 core/libs/prx/libkernel/CMakeLists.txt
docs/dev/debt/libkernel.md
PR 7201 core/libs/prx/libSceVideoOut/src/VideoOutDriver.cpp
core/libs/prx/libkernel/CMakeLists.txt
core/libs/prx/libkernel/Time/Time.cpp
core/libs/prx/libkernel/Time/TimedWait.cpp
PR 7411 docs/dev/ENVIRONMENT.md
PR 7484 docs/dev/ENVIRONMENT.md
PR 7509 docs/dev/debt/libkernel.md
PR 7530 docs/dev/debt/libkernel.md
PR 7604 docs/dev/ENVIRONMENT.md
PR 7642 core/libs/prx/libSceAgcDriver/Graphics/include/Recorder.hpp
core/libs/prx/libSceAgcDriver/Graphics/src/Recorder.cpp
docs/dev/ENVIRONMENT.md
PR 7653 docs/dev/debt/libkernel.md
PR 7922 docs/dev/ENVIRONMENT.md
PR 8004 docs/dev/ENVIRONMENT.md
PR 8077 docs/dev/ENVIRONMENT.md
PR 8206 docs/dev/ENVIRONMENT.md
PR 8255 docs/dev/debt/libkernel.md
PR 8539 docs/dev/debt/libkernel.md

… other PRs change

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@nicolasabosch

Copy link
Copy Markdown
Contributor Author

Moved the SleepWake.hpp include in Recorder.cpp and the libkernel debt entry (now at the end of Functional) off the lines #6360 and #6586 change; both now merge cleanly with this branch (checked with git merge-tree). The other listed PRs already conflict with main and share files only, not the same functions, so none is a dependency.

🤖 Addressed by Claude Code

@jotitadev jotitadev 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.

Linux run of the condition-variable path in TimedWait::SleepNanosUnlessChanged, which the description lists as not run. Validated at 82dd28619 fast-forwarded onto main 5d9dcc42d; the current head 6ce90a728 only moves the SleepWake.hpp include in Recorder.cpp and the debt entry, no code change.

Machine: Ubuntu 26.04, Intel i7-8700 (6C/12T), GCC 15.2, full build, Release, BUILD_TESTING=ON.

  • Builds clean, including the new guest_sleep_wake target.
  • guest_sleep_wake passes on Linux: 100/100 runs alone, 120/120 with 12 copies in parallel and 120/120 with 24 copies in parallel (2x the logical CPUs).
  • The test does catch a missing wake: with APS5_NO_SLEEP_WAKE=1 it aborts.
  • Non-GPU suite (ctest -E "^agc|gpu|vulkan|video_out" -j12): 649/651; the only failures are file_writer_binary and file_writer_text, which also fail on main on this machine (648/650). guest_nanosleep passes.

Not covered here: the GPU progress watcher in Recorder.cpp and the VideoOut flip wake (no AGC/VideoOut tests or titles were run).

Written with AI assistance (Claude Code). I ran the builds and tests above on my machine.

@nicolasabosch

Copy link
Copy Markdown
Contributor Author

Thanks @jotitadev for the Linux run. I added it to the description, with what it doesn't cover (GPU progress watcher, flip wake, macOS).

@parl0v

parl0v commented Oct 16, 2026

Copy link
Copy Markdown
Contributor

Data point: RTX 3060 12 GB (NVIDIA 617.42), i5-12400F, Windows 10 19045, MinGW GCC Release. Minecraft Dungeons II (PPSA16064 01.100.100), title screen, no input, 200 s rows, APS5_PROFILE_DRAW=1 APS5_PROFILE_GPU=1; main 93e54ce vs main + this PR, interleaved with three other PRs in one batch, two rounds. FPS is the mean of the last 10 [present] windows, GPU busy and idle gaps per frame over the last 8.

libs FPS GPU busy idle gaps
main 6.61 / 6.61 104 / 105 ms 46 / 46 ms
+ this PR (6ce90a7) 6.67 / 6.60 105 / 106 ms 46 / 46 ms

Neutral on this scene (mean +0.4 %, within the row spread); no regression. 0 fatal.

AI-assisted: yes (Claude Code)

@github-actions github-actions Bot added the needs rebase Conflicts with main, rebase needed label Oct 16, 2026
@Dripl1x

Dripl1x commented Oct 16, 2026 •

Copy link
Copy Markdown
Contributor

Additional Windows test on Ryzen 7 5800H, 64 GiB RAM, RTX 3070 Laptop 8 GiB (NVIDIA 617.42), Windows 11 Pro 26H2 (build 26300.9550; NT 10.0).

I repeated the SuperTuxKart PPSA69421 comparison without the other local optimizations: clean main 5d9dcc42d2ec5401aebd089028b8d4d7410a77b4 versus that base with only this PR (6ce90a72864ec5a08e2101b0f14ecccb3793d7f4). All 12 changed source files were checked against the PR's Git blob hashes.

Startup/tutorial prompt over the main menu, 1920×1080 internal rendering. Same executable and shared warm shader cache, music/SFX disabled on both sides, normal flip pacing, no host-import-disabling switches. Both measured windows stayed foreground in the same maximized window, client area 2560×1369. No builds or GPU tests ran during the captures.

Each title run was limited to 35 seconds; the table uses the late APS5_TRACE_SECONDS=22:8 interval, without redirected console logs:

Runtime Mean FPS p50 / p90 / p99, ms
Clean main 9.98 99.858 / 103.047 / 105.129
Main + only #6658 15.90 62.289 / 65.992 / 75.486

The separately sampled last ~8 seconds also agreed in direction: 9.81 versus 15.67 FPS. Loaded library SHA256s were verified; both traces report trace_dropped=false. Neither title process exited early; both were stopped intentionally. This is one short pair in the startup/menu scene, not racing gameplay or a general FPS claim.

All 7 directly related sleep/import checks passed, including guest_sleep_wake, guest_nanosleep and precise_wait. The expanded selection passed 12/13; agc_driver_depth_fast_clear_submit segfaulted, but the same test also segfaulted on the exact clean-main control, so this run does not establish a regression from this PR. The full repository test suite was not run.

AI-assisted: yes. The builds, tests and measurements above were executed locally.

@github-actions github-actions Bot added perf Performance change perf numbers missing perf pull request without a before and after summary line labels Oct 18, 2026
@github-actions

Copy link
Copy Markdown

This pull request is labeled perf, so it needs the summary line of a capture on main and one with the change, from the same title, scene and machine, as the Performance report form asks. Please paste both aps5-summary.jsonl lines, attach the two traces and add the output of tools/trace_digest.py.

@github-actions github-actions Bot removed perf numbers missing perf pull request without a before and after summary line needs rebase Conflicts with main, rebase needed labels Oct 18, 2026
@oneandonlydean oneandonlydean self-assigned this Oct 19, 2026
@oneandonlydean

Copy link
Copy Markdown
Collaborator

@nicolasabosch thanks, this reads well, and the menu gain reproducing on three machines (one AMD) is convincing. One Windows fix before merge: the per-thread auto-reset wake event isn't reset when the sleeper registers. A wake that arrives after the wait has returned but before Unregister, which is common when completions are frequent, leaves it signalled. The next short sleep on that thread then returns from its wait at once, sees no counter change, and busy-spins in YieldProcessor for its whole length. A ResetEvent(waiter->wake) right after registering, before the counter check in SleepNanosUnlessChanged (TimedWait.cpp), fixes it.

Two smaller points, no change needed unless you prefer: on Windows the new path skips APS5_COARSE_TIMED_WAITS for sleeps of 1 ms or less, and sleeps under 50 µs now spin to the deadline where main did one SwitchToThread.

… coarse and sub-50 us sleeps as before

A wake set after the previous wait returned left the per-thread
auto-reset event signalled, so the next short sleep returned from its
wait at once and spun to its deadline. With APS5_COARSE_TIMED_WAITS or
a request under 50 us the sleep now takes TimedWait::SleepNanos as on
main.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@nicolasabosch

Copy link
Copy Markdown
Contributor Author

@oneandonlydean thanks, you're right. Fixed in 09093bf: SleepNanosUnlessChanged now calls ResetEvent(waiter->wake) after the thread registers and before it checks the counter, so a wake left over from the previous sleep no longer ends the next wait (a wake that arrives in between still changes the counter, which the check sees). I also took the two smaller points: on Windows a sleep under 50 us, or any sleep with APS5_COARSE_TIMED_WAITS set, goes through TimedWait::SleepNanos as on main.

Checked: the 12 sleep and timer tests (guest_sleep_wake, guest_nanosleep, cancellation, nested-sleep and clock tests) pass 3/3. SuperTuxKart main menu with the fix on the measured base 39ddb3585: p50 27.2 and 30.4 ms vs 30.9 and 29.1 ms without it, so no change in the gain. That check is on the old base because current main c4c2b3aa7 aborts this title at startup (Thread destructor callback is already registered), with or without this PR.

🤖 Addressed by Claude Code

@nicolasabosch

Copy link
Copy Markdown
Contributor Author

@oneandonlydean follow-up with what I measured, since my earlier reply fixed this without reproducing it first.

The stale event (Windows). Reproduced before keeping the fix. Loop of 1000 rounds: a wake lands 150 us into a 300 us sleep (which spins, so nothing consumes the event), then a 1 ms sleep is timed in thread cycles (QueryThreadCycleTime). Without the ResetEvent, 65, 102 and 173 of 1000 of those second sleeps burned over 800 us of CPU; with it (09093bfa2), 3, 2 and 2. The same loop with no earlier wake gave 0 of 1000 either way. A first version of my measurement used a wake that fell inside the wait, which the auto-reset event consumes, so it showed no difference; I discarded it. This is a measurement script, not a committed test: a CPU-time threshold would be flaky on shared CI runners.

(a) APS5_COARSE_TIMED_WAITS. You were right, the new path ignored it. Changed: with coarse waits set, SleepNanosUnlessChanged now calls SleepNanos as on main, so such a sleep is never ended early. I did not measure a case with coarse waits set beyond guest_sleep_wake and guest_nanosleep passing with APS5_COARSE_TIMED_WAITS=1... correction: guest_sleep_wake aborts with that variable set, because the test expects the early return, so that combination is not covered by a passing test.

(b) Sleeps under 50 us. Also changed: they take SleepNanos (one SwitchToThread) as on main. I did not measure what the spin cost there; I restored main's behaviour because I had no number showing the spin was wanted.

Tests: precise_wait, guest_sleep_wake, guest_nanosleep, the cancellation, nested-sleep, clock and timed-wait tests pass on the merged head 876ad540f. Full ctest there: 1689 of 1691; the two failures are agc_driver_pass_input_hazard (fails the same on main 43a2abaf7, 3 of 3) and a conversion_diagnostics timeout under load (passes alone 3 of 3). SuperTuxKart main menu, main 43a2abaf7 vs this branch: p50 53.3 / 53.6 vs 32.1 / 30.2 ms; kart selection 319 vs 163 ms. The description has the summary lines and the traces are in the release.

🤖 Addressed by Claude Code

nicolasabosch and others added 2 commits October 19, 2026 12:44
With APS5_COARSE_TIMED_WAITS set a sleep is never ended early.

Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
@nicolasabosch

Copy link
Copy Markdown
Contributor Author

Correction to my previous comment: its point (a) was garbled. The accurate version:

(a) APS5_COARSE_TIMED_WAITS. You were right, the new path ignored it. Changed in 09093bfa2: with coarse waits set, SleepNanosUnlessChanged calls SleepNanos as on main, so such a sleep is never ended early. When I checked this, guest_sleep_wake aborted with that variable set, because the test expected the early return. The test now has a coarse variant (guest_sleep_wake_coarse, commit 447b744dd) that runs the same binary with APS5_COARSE_TIMED_WAITS=1 and checks that 12 sleeps with a waker running all last their full length. Both variants pass 3 of 3 here. I did not check that the coarse variant fails without the Coarse() check.

The rest of the previous comment stands (stale-event measurement, (b), test and benchmark numbers). The branch is now at 843084a9d (main merged in); the sleep, cancellation and timer tests pass on it, and the STK numbers in the description were taken on main 43a2abaf7.

🤖 Addressed by Claude Code

@oneandonlydean

Copy link
Copy Markdown
Collaborator

Thanks for the ResetEvent fix and for restoring the coarse and sub-50 µs paths. Those look right.

The new guest_sleep_wake_coarse fails on Linux CI: Subprocess aborted after 0.51 s (run 39321993940), and it fails every time. APS5_COARSE_TIMED_WAITS is a Windows-only switch. TimedWait::Coarse() only reads it under _WIN32, and the new if (Coarse() || nanos < YIELD_BELOW_NANOS) check in SleepNanosUnlessChanged is inside #ifdef _WIN32. On Linux, the condition-variable branch still ends the sleep when completions changes. So CoarseWaitsKeepEverySleepFull sees early returns and its Require(Usleep(...) >= 1000us) aborts.

The code behaves correctly here. On Linux, Coarse() is always true, so gating the wake on it would switch the feature off there. The test is what needs to change. Could you register guest_sleep_wake_coarse only inside if(WIN32), or have the coarse branch of main return 77 when it isn't built for _WIN32?

APS5_COARSE_TIMED_WAITS is read under _WIN32 only; on Linux the condition
variable path always ends a sleep when a completion arrives.

Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
@nicolasabosch

Copy link
Copy Markdown
Contributor Author

@oneandonlydean you're right, and thanks for the diagnosis: I registered guest_sleep_wake_coarse for every platform, but APS5_COARSE_TIMED_WAITS is read only under _WIN32, so on Linux the test asserted something the code does not do. Fixed in 60d5149ef: the test is registered only inside if(WIN32), and the coarse branch of main in the test file is under #ifdef _WIN32 as well, so setting the variable on another platform runs the normal test. No change to TimedWait.cpp; gating the wake on Coarse() would switch it off on Linux, as you say. On Windows both guest_sleep_wake and guest_sleep_wake_coarse pass 3 of 3 here. I cannot run Linux, so the Linux CI run of this commit is the check.

🤖 Addressed by Claude Code

@github-actions github-actions Bot added the needs rebase Conflicts with main, rebase needed label Oct 20, 2026
@CPritch

CPritch commented Oct 20, 2026

Copy link
Copy Markdown
Contributor

Ran this on GTA V (PPSA04263 01.010.002), Linux 7.2.8-zen1-2-zen, NVIDIA GeForce RTX 5060 Laptop GPU, NVIDIA 615.71.09, Graphics Mode Performance, the Story prologue after Resume Story, with no input.
main eaa5c92 against main eaa5c92 + #6658 at 60d5149, same machine and session, two runs each in the order A B A B, window frames 3500:700, caches warm, APS5_TRACE_EVENTS=4194304 (BUILD.md's remedy for full trace buffers), no other APS5_TRACE_* or APS5_PROFILE_* switch, log not redirected. The harness navigates the menus from frame dumps in boot and load to present 3300 (APS5_DUMP_FRAMES=110, every 30 presents), which stop before the window.
Frame p50: main 79.8, 80.6 ms, with #6658 81.3, 81.8 ms (+1.3 ms, +1.7 %). GPU busy per present: 64.4 and 64.9 ms.
Not tested: other scenes, Fidelity mode, other GPUs.
Written with AI assistance (Claude Code); measured on the machine above.

Summary lines (main, then the PR):
{"commit":"eaa5c9238687","dirty":false,"env":{"APS5_DUMP_FRAMES":"110","APS5_DUMP_FRAMES_EVERY":"30","APS5_NO_PAD_INPUT":"1","APS5_PAD_INPUT_FILE":"","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"3500:700"},"gpu":"NVIDIA GeForce RTX 5060 Laptop GPU","driver":"NVIDIA 615.71.09","os":"Linux 7.2.8-zen1-2-zen","resolution":"3840x2160","window":{"spec":"frames 3500:700","first_present":3500,"ms":57186.269},"presents":700,"frame_ms":{"p50":79.77,"p90":89.907,"p99":111.025,"max":120.187},"gpu_busy_ms_per_present":64.252,"worker_busy_pct":{"queue worker 0x0":3678.844},"top_phases_ms_per_frame":{"Driver.EndSubmission":2939.752,"Driver.Packet":63.384,"Graphics.Draw":60.365,"Graphics.Draw.draw_and_resource_release":56.558,"Driver.Packet.draw":50.596,"Driver.Draw":50.385,"VideoOut.Flip":25.643,"Driver.Present":25.625},"trace_dropped":false,"trace":"aps5-trace-eaa5c9238687-1045163.json.gz"}
{"commit":"a04965c19dca","dirty":false,"env":{"APS5_DUMP_FRAMES":"110","APS5_DUMP_FRAMES_EVERY":"30","APS5_NO_PAD_INPUT":"1","APS5_PAD_INPUT_FILE":"","APS5_TRACE_EVENTS":"4194304","APS5_TRACE_FRAMES":"3500:700"},"gpu":"NVIDIA GeForce RTX 5060 Laptop GPU","driver":"NVIDIA 615.71.09","os":"Linux 7.2.8-zen1-2-zen","resolution":"3840x2160","window":{"spec":"frames 3500:700","first_present":3500,"ms":57961.181},"presents":700,"frame_ms":{"p50":81.305,"p90":90.808,"p99":119.246,"max":149.866},"gpu_busy_ms_per_present":64.705,"worker_busy_pct":{"queue worker 0x0":3667.613},"top_phases_ms_per_frame":{"Driver.EndSubmission":2970.615,"Driver.Packet":63.939,"Graphics.Draw":61.131,"Graphics.Draw.draw_and_resource_release":57.226,"Driver.Packet.draw":50.747,"Driver.Draw":50.527,"VideoOut.Flip":26.102,"Driver.Present":26.085},"trace_dropped":false,"trace":"aps5-trace-a04965c19dca-1053052.json.gz"}

@nicolasabosch

Copy link
Copy Markdown
Contributor Author

@oneandonlydean do you need something more from me?

@LeandroLP23

Copy link
Copy Markdown
Contributor

Race-scene data on AMD, as a follow-up to my menu numbers: this helps there too, by about 5%.

SuperTuxKart (PPSA69421 00.001.000), tutorial race, kart idle on the start line, APS5_TRACE_SECONDS=110:20, one capture per tree, same machine, one after the other. Radeon 860M (driver 32.0.13058.8001), Windows 11 26300, Release. This PR doesn't merge cleanly with current main. I resolved the two conflicts by keeping both sides: an extra include in EntryPoints.cpp, and the new submitHold members beside progressWatcher in Recorder.hpp.

Both trees include #8538 (the point-light fix) and #6718 (the texture-array upload saving):

Tree Presents in 20 s Frame p50 / p90 / p99 (ms) GPU busy per present
main 75787d2 + #8538 + #6718 153 126.8 / 147.2 / 183.9 27.9 ms
the same + this PR (60d5149) 162 120.9 / 144.3 / 162.0 27.6 ms

The waiting this PR targets is most of the frame:

  • with APS5_TRACE_USLEEP, the title calls sceKernelUsleep(1000) about 77 times per frame in the race (from exe+0x11397 and exe+0x110cb);
  • the queue worker waits 89% of the time;
  • the GPU is busy only 28 ms of the ~125 ms frame.

The gain here is smaller than in the menu (6.7 → 9.7 FPS there), so in the race most of each wait seems to be the submission round trip itself rather than the rest of the 1 ms sleep.

AI-assisted: yes (Claude Code)

# Conflicts:
#	core/libs/prx/libSceAgcDriver/Execution/src/Driver/EntryPoints.cpp
#	core/libs/prx/libSceAgcDriver/Graphics/include/Recorder.hpp
@github-actions github-actions Bot removed the needs rebase Conflicts with main, rebase needed label Oct 20, 2026
@oneandonlydean
oneandonlydean merged commit b7596be into boykopovar:main Oct 20, 2026
10 checks passed
@nicolasabosch
nicolasabosch deleted the perf/gpu-wake-sleeps branch October 20, 2026 19:04
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

7 participants