From 7eaeb8c3db37fe7b1a04e1a15b8a859049743c8a Mon Sep 17 00:00:00 2001 From: Codex Date: Fri, 2 Oct 2026 10:44:09 +0300 Subject: [PATCH] Capture PresentMon metrics and record Windows release validation --- docs/windows-performance.md | 41 ++++++++++++++++++++++ docs/windows-rdna4-port.md | 18 ++++++++-- scripts/windows/capture-presentmon.ps1 | 47 +++++++++++++++++++++++++ tools/windows/profile_report.py | 48 +++++++++++++++++++++++++- 4 files changed, 151 insertions(+), 3 deletions(-) create mode 100644 scripts/windows/capture-presentmon.ps1 diff --git a/docs/windows-performance.md b/docs/windows-performance.md index 4b49487..cec2521 100644 --- a/docs/windows-performance.md +++ b/docs/windows-performance.md @@ -151,6 +151,47 @@ All sixteen CTest gates pass on the rebuilt shim. Reproduce with: .\scripts\windows\test-async-k.ps1 -ProfileGpuBoundary ``` +The 2026-10-02 game timestamp run completes 9384 K/4K frames without backend +errors (`test-results/silent-hill2-k-gpu-boundary-4k`). Median GPU intervals: +input copies 0.061 ms, external span 5.586 ms, output copy 0.208 ms, entire +boundary 5.856 ms, between boundaries 9.512 ms. Median input interval is +15.383 ms. Output scans and serializing kernel events are off. This locates +the remaining time outside the small D3D12 copies; it does not prove whether +that time is game GPU work, CPU waits or context scheduling. + +### Present and GPU-busy capture + +`capture-presentmon.ps1` attaches the official PresentMon 2.6.0 x64 CLI to +one running game process. It verifies SHA256 +`b2a706bc6ad475749e3b7e3409263aa1e6906d45bdcf993f6dbc0f660188f1af`, +uses a unique ETW session and stops at its time bound/process exit, without +replacing any existing trace or installing a service. It saves CSV, console +output, driver version, target PID and the HWS registry setting. The default +downloads the pinned CLI into `.tools` if needed. Run elevated when ETW access +requires it; no driver or security setting is changed. + +```powershell +.\scripts\windows\capture-presentmon.ps1 -Seconds 30 +python .\tools\windows\profile_report.py --output profile.json +``` + +Keep the game foreground and use the same scene/quality setting for comparison. +The report separates swapchains and preserves missing metrics. Present FPS +comes from present intervals, rather than NGX recording timestamps. GPU +busy/wait are ETW estimates, not a hardware sensor percentage; CPU busy is +frame work/wait attribution before Present, not physical CPU utilization. +HWS and cross-API context attribution can affect accuracy. Metric definitions: +[PresentMon console documentation](https://github.com/GameTechDev/PresentMon/blob/v2.6.0/README-ConsoleApplication.md). + +The initial 60-second trace captures 2172 presents during a changing +Independent Flip / Composed Flip session, with mean present interval +27.593 ms (36.241 FPS), mean GPU busy 18.759 ms and GPU wait 2.303 ms. +This is not a controlled capture of the user's 62 FPS scene and is excluded +from speedup conclusions. Its containing game run completes 9627 K/4K frames +without backend errors; ordinary recording intervals later return to about +16 ms. A stable foreground-scene capture is needed before optimizing from +the ETW metrics. Raw files: `test-results/silent-hill2-k-presentmon-4k`. + Further game coverage (HIP kernel profiling disabled, GPU output checks enabled): M at 1920x1080 completes 4833 frames, all finite. K at 3840x2160 completes 4685 frames, all finite. Neither has a backend failure, CPU image copy or an diff --git a/docs/windows-rdna4-port.md b/docs/windows-rdna4-port.md index 138c7f3..e87c92a 100644 --- a/docs/windows-rdna4-port.md +++ b/docs/windows-rdna4-port.md @@ -71,8 +71,22 @@ copies, the external-fence span and output copies. Copy-slot completion controls query reuse/readback; only 32 timing bytes are read, with no extra completion wait. The timestamp-enabled burst/recreate gate passes all twelve K/4K frames with exact candidate RGB (`test-results/k-async-gpu-boundary-4k`), -and all sixteen CTest gates pass on the rebuilt shim. Game timestamps remain -the next performance diagnostic; their span includes scheduling as well as HIP. +and all sixteen CTest gates pass on the rebuilt shim. A 9384-frame game run +measures median input/output copies at 0.061/0.208 ms and external span at +5.586 ms, with zero backend failures. The span includes scheduling as well +as HIP. PresentMon 2.6.0 capture/report tooling is added; its first trace +contains changing presentation modes and is not a controlled capture of +the user's 62 FPS scene. See `windows-performance.md` for exact metrics and +the stable foreground-scene gate that remains open. + +The public prerelease `windows-rdna4-dev-20261002-a346d76` is published to +`xdfnx-dev/d4r`, containing source commit `a346d76` and ZLUDA `a1c506f`. +Archive: `d4r-windows-rdna4-20261002.zip`, 88893567 bytes, SHA256 +`5b9a47e9d0c9a042567c2096eb8eaafb0a28473614b656865d794a39f5165d8e`. +All 65 entries and the 274-entry source snapshot match the manifest; GitHub's +uploaded asset digest matches the local ZIP. NVIDIA DLLs/private kernels and +captures are excluded. This is a development artifact, not completion of +the K performance gate. Three ordinary K/4K async frames and three queued together without intermediate CPU completion all match their corresponding prior synchronous RGB exactly; diff --git a/scripts/windows/capture-presentmon.ps1 b/scripts/windows/capture-presentmon.ps1 new file mode 100644 index 0000000..d686f22 --- /dev/null +++ b/scripts/windows/capture-presentmon.ps1 @@ -0,0 +1,47 @@ +[CmdletBinding()] +param( + [int]$TargetProcessId, + [string]$ProcessName = 'SHProto-Win64-Shipping', + [ValidateRange(5,300)][int]$Seconds = 30, + [ValidateRange(0,300)][int]$DelaySeconds = 0, + [string]$PresentMonPath, + [string]$OutputDirectory +) +$ErrorActionPreference='Stop' +$repo=[IO.Path]::GetFullPath((Join-Path $PSScriptRoot '../..')) +if (!$PresentMonPath) { + $PresentMonPath=Join-Path $repo '.tools/presentmon-2.6.0/PresentMon.exe' + if (!(Test-Path -LiteralPath $PresentMonPath)) { + New-Item -ItemType Directory -Force (Split-Path $PresentMonPath) | Out-Null + Invoke-WebRequest -UseBasicParsing -Uri 'https://github.com/GameTechDev/PresentMon/releases/download/v2.6.0/PresentMon-2.6.0-x64.exe' -OutFile $PresentMonPath + } +} +if (!$OutputDirectory) { $OutputDirectory=Join-Path $repo ('test-results/presentmon-' + (Get-Date -Format 'yyyyMMdd-HHmmss-fff')) } +$PresentMonPath=(Get-Item -LiteralPath $PresentMonPath -ErrorAction Stop).FullName +if ((Get-FileHash -LiteralPath $PresentMonPath -Algorithm SHA256).Hash.ToLowerInvariant() -ne + 'b2a706bc6ad475749e3b7e3409263aa1e6906d45bdcf993f6dbc0f660188f1af') { + throw 'Expected the official PresentMon 2.6.0 x64 CLI. See docs/windows-performance.md.' +} +if ($TargetProcessId) { $target=Get-Process -Id $TargetProcessId -ErrorAction Stop } +else { + $targets=@(Get-Process -Name $ProcessName -ErrorAction Stop) + if ($targets.Count -ne 1) { throw 'Select one running game process using -TargetProcessId.' } + $target=$targets[0] +} +$OutputDirectory=[IO.Path]::GetFullPath($OutputDirectory) +New-Item -ItemType Directory -Force $OutputDirectory | Out-Null +$csv=Join-Path $OutputDirectory 'presentmon.csv' +if (Test-Path -LiteralPath $csv) { throw 'Preserve the existing capture; choose another OutputDirectory.' } +@{version='2.6.0'; executable=$PresentMonPath; sha256=(Get-FileHash -LiteralPath $PresentMonPath -Algorithm SHA256).Hash; + targetProcessId=$target.Id; processName=$target.ProcessName; seconds=$Seconds; delaySeconds=$DelaySeconds; + hwsRegistry=$(Get-ItemPropertyValue -LiteralPath 'HKLM:/SYSTEM/CurrentControlSet/Control/GraphicsDrivers' -Name HwSchMode -ErrorAction SilentlyContinue); + driver=@(Get-CimInstance Win32_VideoController | Select-Object Name,DriverVersion)} | + ConvertTo-Json -Depth 4 | Set-Content -LiteralPath (Join-Path $OutputDirectory 'presentmon-environment.json') -Encoding UTF8 +# Unique ETW session: never stop or replace an existing user's trace. The CLI +# terminates itself at the bound/process exit, without a service installation. +$session='D4R_' + [Guid]::NewGuid().ToString('N') +& $PresentMonPath --process_id $target.Id --timed $Seconds --delay $DelaySeconds --terminate_after_timed --terminate_on_proc_exit --session_name $session --no_console_stats --no_track_input --qpc_time_ms --output_file $csv 2>&1 | + Tee-Object -FilePath (Join-Path $OutputDirectory 'presentmon-console.log') +if ($LASTEXITCODE) { throw "PresentMon failed with exit code $LASTEXITCODE; see presentmon-console.log." } +if (!(Test-Path -LiteralPath $csv) -or (Get-Item -LiteralPath $csv).Length -eq 0) { throw 'PresentMon captured no frames.' } +Write-Host "PresentMon capture: $csv" diff --git a/tools/windows/profile_report.py b/tools/windows/profile_report.py index 212d5f1..602de91 100644 --- a/tools/windows/profile_report.py +++ b/tools/windows/profile_report.py @@ -5,7 +5,9 @@ are not hardware counters. No bandwidth / WMMA utilization is inferred here. """ import argparse import collections +import csv import json +import math import pathlib import re import statistics @@ -36,6 +38,44 @@ def metadata(directory): return result +def presentmon(directory): + # Keep swapchains separate: combining startup/menu/overlay chains invents + # frame intervals. Missing/NA metrics remain absent rather than becoming 0. + captures = [] + for path in sorted(directory.glob('presentmon*.csv')): + groups = collections.defaultdict(list) + with path.open(encoding='utf-8-sig', newline='') as stream: + for row in csv.DictReader(stream): + if row.get('ProcessID') and row.get('SwapChainAddress'): + groups[(row['ProcessID'], row['SwapChainAddress'])].append(row) + for (process, swapchain), rows in groups.items(): + metrics = {} + for name in ('MsBetweenPresents', 'MsBetweenAppStart', 'MsCPUBusy', 'MsCPUWait', + 'MsGPULatency', 'MsGPUTime', 'MsGPUBusy', 'MsGPUWait', + 'MsInPresentAPI', 'DisplayedTime', 'DisplayLatency'): + values = [] + for row in rows: + raw = row.get(name, row.get(name.removeprefix('Ms'), '')) + try: + value = float(raw) + except (ValueError, TypeError): + continue + if math.isfinite(value) and value >= 0: + values.append(value) + if values: + metrics[name] = stats(values) + item = dict(file=path.name, processId=int(process), swapchain=swapchain, + frames=len(rows), metrics=metrics, + presentModes=dict(collections.Counter(row.get('PresentMode', '') for row in rows)), + syncIntervals=dict(collections.Counter(row.get('SyncInterval', '') for row in rows))) + interval = metrics.get('MsBetweenPresents', metrics.get('MsBetweenAppStart')) + if interval and interval['mean'] > 0: + item['presentFps'] = 1000. / interval['mean'] + captures.append(item) + captures.sort(key=lambda row: row['frames'], reverse=True) + return captures + + def report(directory, metadata_directory=None): kernel_metadata = metadata(metadata_directory) stages = collections.defaultdict(list) @@ -83,12 +123,14 @@ def report(directory, metadata_directory=None): commandHookSamples=[], cudaApi=[], gpuBoundaryStages={}, + presentMon=presentmon(directory), replayPairs=[], kernels=[], notes=[ 'CPU stage times include waits and host work; they are not isolated GPU timings.', 'CUDA API profiles measure host call duration without GPU events or added synchronization; they still include existing waits.', 'D3D12 boundary timestamps span copies and HIP/scheduling across the external fence; they do not isolate kernel execution or measure Present.', 'Boundary timestamps are read after existing completion fences; only 32 timing bytes are read, with no extra completion wait. GPU clock idle behavior can affect intervals.', + 'PresentMon ETW GPU busy/wait are per-process frame estimates, not hardware sensor utilization. HWS and cross-API context attribution can affect them.', 'Command record intervals are between NGX recording calls on one thread, not Present/FPS.', 'Hook estimates use random one-in-64 samples; driver timing covers generated forwarding methods only.', 'Hook access includes lock waits; summing threads does not measure serial frame latency or CPU execution time.', @@ -158,7 +200,7 @@ def main(): parser.add_argument('--metadata-directory', type=pathlib.Path, help='llvm-readobj --notes output for native code objects') args = parser.parse_args() result = report(args.directory, args.metadata_directory) - if not any(result[key] for key in ('cpuStages', 'kernels', 'commandStages', 'commandHookSamples', 'replayPairs', 'cudaApi', 'gpuBoundaryStages')): + if not any(result[key] for key in ('cpuStages', 'kernels', 'commandStages', 'commandHookSamples', 'replayPairs', 'cudaApi', 'gpuBoundaryStages', 'presentMon')): parser.error('no complete stage or HIP-event records found') if args.output: args.output.write_text(json.dumps(result, indent=2) + '\n', encoding='utf-8') @@ -168,6 +210,10 @@ def main(): print(f"COMMAND {name}: n={row['samples']} mean={row['mean']:.3f} ms median={row['median']:.3f} ms p95={row['p95']:.3f} ms") for name, row in result['gpuBoundaryStages'].items(): print(f"GPU BOUNDARY {name}: n={row['samples']} mean={row['mean']:.3f} ms median={row['median']:.3f} ms p95={row['p95']:.3f} ms") + for capture in result['presentMon']: + print(f"PRESENT {capture['file']} process={capture['processId']} swapchain={capture['swapchain']} frames={capture['frames']} fps={capture.get('presentFps', float('nan')):.3f}") + for name, row in capture['metrics'].items(): + print(f" {name}: n={row['samples']} mean={row['mean']:.3f} ms median={row['median']:.3f} ms p95={row['p95']:.3f} ms") for row in result['cudaApi'][:20]: print(f"CUDA API {row['api']} {row['thread']}: n={row['calls']} mean={row['meanMs']:.6f} ms total={row['totalMs']:.3f} ms max={row['maxMs']:.3f} ms") for row in result['commandHookSamples']: