Capture PresentMon metrics and record Windows release validation
This commit is contained in:
1 parent
eba26c3a76
commit
7eaeb8c3db
4 files changed
+151
-3
No files matched your search
@@ -151,6 +151,47 @@ All sixteen CTest gates pass on the rebuilt shim. Reproduce with:
|
|||||||
.\scripts\windows\test-async-k.ps1 -ProfileGpuBoundary
|
.\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 <capture-directory> --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):
|
Further game coverage (HIP kernel profiling disabled, GPU output checks enabled):
|
||||||
M at 1920x1080 completes 4833 frames, all finite. K at 3840x2160 completes
|
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
|
4685 frames, all finite. Neither has a backend failure, CPU image copy or an
|
||||||
|
|||||||
@@ -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
|
controls query reuse/readback; only 32 timing bytes are read, with no extra
|
||||||
completion wait. The timestamp-enabled burst/recreate gate passes all twelve
|
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`),
|
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
|
and all sixteen CTest gates pass on the rebuilt shim. A 9384-frame game run
|
||||||
the next performance diagnostic; their span includes scheduling as well as HIP.
|
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
|
Three ordinary K/4K async frames and three queued together without intermediate
|
||||||
CPU completion all match their corresponding prior synchronous RGB exactly;
|
CPU completion all match their corresponding prior synchronous RGB exactly;
|
||||||
|
|||||||
@@ -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"
|
||||||
@@ -5,7 +5,9 @@ are not hardware counters. No bandwidth / WMMA utilization is inferred here.
|
|||||||
"""
|
"""
|
||||||
import argparse
|
import argparse
|
||||||
import collections
|
import collections
|
||||||
|
import csv
|
||||||
import json
|
import json
|
||||||
|
import math
|
||||||
import pathlib
|
import pathlib
|
||||||
import re
|
import re
|
||||||
import statistics
|
import statistics
|
||||||
@@ -36,6 +38,44 @@ def metadata(directory):
|
|||||||
return result
|
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):
|
def report(directory, metadata_directory=None):
|
||||||
kernel_metadata = metadata(metadata_directory)
|
kernel_metadata = metadata(metadata_directory)
|
||||||
stages = collections.defaultdict(list)
|
stages = collections.defaultdict(list)
|
||||||
@@ -83,12 +123,14 @@ def report(directory, metadata_directory=None):
|
|||||||
commandHookSamples=[],
|
commandHookSamples=[],
|
||||||
cudaApi=[],
|
cudaApi=[],
|
||||||
gpuBoundaryStages={},
|
gpuBoundaryStages={},
|
||||||
|
presentMon=presentmon(directory),
|
||||||
replayPairs=[],
|
replayPairs=[],
|
||||||
kernels=[], notes=[
|
kernels=[], notes=[
|
||||||
'CPU stage times include waits and host work; they are not isolated GPU timings.',
|
'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.',
|
'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.',
|
'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.',
|
'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.',
|
'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 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.',
|
'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')
|
parser.add_argument('--metadata-directory', type=pathlib.Path, help='llvm-readobj --notes output for native code objects')
|
||||||
args = parser.parse_args()
|
args = parser.parse_args()
|
||||||
result = report(args.directory, args.metadata_directory)
|
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')
|
parser.error('no complete stage or HIP-event records found')
|
||||||
if args.output:
|
if args.output:
|
||||||
args.output.write_text(json.dumps(result, indent=2) + '\n', encoding='utf-8')
|
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")
|
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():
|
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")
|
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]:
|
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")
|
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']:
|
for row in result['commandHookSamples']:
|
||||||
|
|||||||
Reference in new issue
Block a user