diff --git a/docs/windows-game.md b/docs/windows-game.md index 64b7c57..0de82e3 100644 --- a/docs/windows-game.md +++ b/docs/windows-game.md @@ -46,6 +46,18 @@ the GPU before returning it to D3D12. Only two diagnostic counters (8 bytes) are read by the CPU; image data remains in VRAM. Validation failures are reported explicitly. Disable this diagnostic when measuring production speed. +`-ProfileStages` records CPU completion time for seven interop/NGX stages. +The runner drains stdout/stderr concurrently as raw bytes; the earlier +line-oriented PowerShell collector imposed large per-frame delays. The optional +ZLUDA kernel profiler is for diagnostics only. Measurements and reproduction +commands are in [windows-performance.md](windows-performance.md). + +Ordinary runs use OptiScaler info logging and suppress successful HIP/CUDA API +messages. Errors, GPU identity, imports, frame records and native/translated +kernel launches remain logged. `-VerboseRuntime` enables all API and frontend +trace messages when investigating a failure. Numerical relaxation flags are +cleared in the child process; FP16 rounding and subnormals stay enabled. + Original files are backed up before replacement. Restore with: ```powershell diff --git a/docs/windows-performance.md b/docs/windows-performance.md new file mode 100644 index 0000000..5582a72 --- /dev/null +++ b/docs/windows-performance.md @@ -0,0 +1,77 @@ +# Windows RDNA4 measurements + +Hardware: RX 9070 XT / gfx1201, Windows 11, display driver 32.0.31041.1004. +Runtime: TheRock 10.2.0a20260929, HIP 7.17.26386; ZLUDA b0161a4 with +`D4R_ZLUDA_WMMA=1`, FP8 widening, native FP8 disabled, f16 reference rounding. + +The optional profiler uses HIP events on the actual launch stream, including +separate measurements of one-time weight preparation. It synchronizes each +sampled launch and changes scheduling: these numbers are not application FPS. +HIP occupancy predictions are not measured hardware occupancy. The native +objects' actual wave32, LDS, VGPR/SGPR and spill counts are available in +`llvm-readobj --notes` and can be attached to the JSON report. Memory bandwidth +and WMMA utilization were not measured; no utilization is inferred from timing. + +The identical four-frame standalone D3D12/OptiScaler workloads output 512x288. +Summing the measured main-kernel event times and dividing by four gives: + +| Preset | Fully translated, ms/frame | Native FP16-equivalent, ms/frame | +| --- | ---: | ---: | +| K | 157.745441 | 0.684675 | +| M | 7.428538 | 1.566500 | + +Both rows include translated input/output tails. Native overrides cover all +11 K layers and five M layers; M's tube layer executes six times per frame. +M native and translated RGB are bit-exact, with max absolute/relative error 0. +K native remains bit-exact against its independently validated native control; +fully translated K has the previously documented arithmetic differences. +All outputs are finite. These are reference-correct codegen settings, not +measurements of a relaxed fast-math translated configuration. + +M's first profiled Evaluate includes about 0.9 seconds of host initialization; +the four-sample CPU mean must not be treated as steady-state latency. Its +median Evaluate host completion is 4.855 ms. GPU events and prep phases are +reported separately in the raw JSON. + +The initial game runner used PowerShell line-oriented output redirection. +It heavily throttled verbose stdout/stderr. The runner now concurrently drains +raw byte streams using the same approach as the standalone diagnostics. + +| Silent Hill 2 stage, CPU mean | Initial capture, ms | Raw-byte capture with HIP profiler, ms | +| --- | ---: | ---: | +| Input fence wait | 5.641 | 0.833 | +| Input conversion and CUDA array upload | 13.196 | 0.668 | +| NGX Evaluate host call | 25.715 | 3.350 | +| NGX all-stream completion | 1.846 | 0.033 | +| Output CUDA array download | 4.288 | 0.167 | +| Output conversion and shared fence signal | 1.500 | 0.033 | + +The first run additionally scanned every output (10.142 ms in that throttled +capture); the kernel-profiling run disables that scan. Both use a temporary +1280x720 window and current-frame VRAM interop. These are separate menu/game +runs, not a controlled whole-game FPS comparison. No synchronization was +removed to obtain the improvement. The raw-byte profiling run completed +2345 K frames, with no d4r failure, CPU image copy or previous-frame output. + +Reproduce native or translated measurements with locally supplied NVIDIA DLLs +at the repository root and the separately built profiling runtime: + +```powershell +.\scripts\windows\profile-windows-rdna4.ps1 -Preset 11 +.\scripts\windows\profile-windows-rdna4.ps1 -Preset 11 -Translated +.\scripts\windows\profile-windows-rdna4.ps1 -Preset 13 +.\scripts\windows\profile-windows-rdna4.ps1 -Preset 13 -Translated +``` + +`profile_report.py --output profile.json` summarizes raw +CPU stages and every kernel's event time, launch geometry, registers, private +memory, LDS and predicted blocks per multiprocessor. Add +`--metadata-directory ` for native wave sizes +and compiler spill counts. Reports and proprietary workload inputs remain local. + +Native FP8 is not the validated baseline and has no performance claim here. +Replacing the exact per-MMA f16 rounding with f32 FP8 accumulation requires a +new layer/reference validation; it is not justified by the observed CPU stalls. + +References: [HIP events](https://rocmdocs.amd.com/projects/HIP/en/develop/doxygen/html/group___event.html), +[HIP occupancy API](https://rocm.docs.amd.com/projects/HIP/en/latest/doxygen/html/group___occupancy.html). diff --git a/docs/windows-rdna4-port.md b/docs/windows-rdna4-port.md index 925fe95..8dd02ee 100644 --- a/docs/windows-rdna4-port.md +++ b/docs/windows-rdna4-port.md @@ -9,6 +9,23 @@ validation coverage are recorded below. Performance remains in progress. ## Milestone and gates +Performance diagnostics (2026-10-01): the separate ZLUDA `b0161a4` runtime +passes 32 PTX launches in each context and all four native K/M frames with +bit-exact RGB against their controls. All thirteen exported patches (0002 +through 0014) apply to the pinned fresh base. The full Windows build and all +16 CTest gates pass. Actual K profiling completes 2345 frames with zero backend +errors. Replacing PowerShell's line-oriented stdout/stderr collection with +concurrent raw byte copies removes substantial diagnostic backpressure: +mean Evaluate host time drops from 25.715 to 3.350 ms despite per-kernel HIP +event synchronization. Native/translated GPU times, scope and limitations are +in [windows-performance.md](windows-performance.md). Quiet successful API +logging is separately selectable via `D4R_QUIET_API=1`; error checks stay active. + +An additional K game run (`silent-hill2-k-output-stages.zip`) completes 1688 +frames / 18568 native launches / 1688 GPU output scans, all finite, with no +backend failure or previous-frame output. The user confirms visible imagery +after the depth-plane fix; low FPS is the current investigation. + Actual K rendering: `silent-hill2-k-depth-plane.zip` completes **1794 DLSS frames / 19734 native K launches / zero d4r failures** at 753x424 -> 1280x720 with the game's depth-inverted HDR path and DXGI-19 depth plane. The captured diff --git a/patches/zluda/0014-windows-kernel-profiling.patch b/patches/zluda/0014-windows-kernel-profiling.patch new file mode 100644 index 0000000..e219cfb --- /dev/null +++ b/patches/zluda/0014-windows-kernel-profiling.patch @@ -0,0 +1,148 @@ +From b0161a4166652eee86a8113a38d042b02403db6e Mon Sep 17 00:00:00 2001 +From: Codex +Date: Thu, 1 Oct 2026 18:07:07 +0300 +Subject: [PATCH] Add opt-in Windows HIP event and occupancy diagnostics + +--- + zluda/src/impl/d4r_profile.rs | 60 +++++++++++++++++++++++++++++++++++ + zluda/src/impl/function.rs | 9 ++++++ + zluda/src/impl/mod.rs | 1 + + zluda/src/impl/module.rs | 2 +- + 4 files changed, 71 insertions(+), 1 deletion(-) + create mode 100644 zluda/src/impl/d4r_profile.rs + +diff --git a/zluda/src/impl/d4r_profile.rs b/zluda/src/impl/d4r_profile.rs +new file mode 100644 +index 0000000..33ba5f6 +--- /dev/null ++++ b/zluda/src/impl/d4r_profile.rs +@@ -0,0 +1,60 @@ ++//! Optional, deliberately serializing HIP-event diagnostics. Not a production ++//! scheduler or a claim about application FPS / measured hardware occupancy. ++use hip_runtime_sys::*; ++use std::{ffi::CStr, ptr, time::Instant}; ++ ++pub(super) struct Launch { ++ start: hipEvent_t, ++ end: hipEvent_t, ++ host: Instant, ++} ++ ++impl Drop for Launch { ++ fn drop(&mut self) { ++ unsafe { ++ if !self.end.is_null() { let _ = hipEventDestroy(self.end); } ++ if !self.start.is_null() { let _ = hipEventDestroy(self.start); } ++ } ++ } ++} ++ ++impl Launch { ++ pub(super) unsafe fn begin(stream: hipStream_t) -> Result, hipErrorCode_t> { ++ if std::env::var_os("D4R_ZLUDA_PROFILE").is_none() { return Ok(None); } ++ let mut result = Self { start: ptr::null_mut(), end: ptr::null_mut(), host: Instant::now() }; ++ hipEventCreateWithFlags(&mut result.start, 0)?; ++ hipEventCreateWithFlags(&mut result.end, 0)?; ++ hipEventRecord(result.start, stream)?; ++ result.host = Instant::now(); ++ Ok(Some(result)) ++ } ++ ++ pub(super) unsafe fn finish(self, function: hipFunction_t, name: &CStr, backend: &str, ++ phase: &str, grid: [u32;3], block: [u32;3], shared: u32, stream: hipStream_t) -> hipError_t { ++ let enqueue_ms = self.host.elapsed().as_secs_f64() * 1000.; ++ hipEventRecord(self.end, stream)?; ++ hipEventSynchronize(self.end)?; ++ let completion_ms = self.host.elapsed().as_secs_f64() * 1000.; ++ let mut gpu_ms = 0.; ++ hipEventElapsedTime(&mut gpu_ms, self.start, self.end)?; ++ // Module function handles use the Driver API attribute query. The ++ // plural Runtime API expects a registered host function address. ++ let mut lds = 0; ++ let mut regs = 0; ++ let mut private = 0; ++ let mut max_threads = 0; ++ hipFuncGetAttribute(&mut lds, hipFunction_attribute::HIP_FUNC_ATTRIBUTE_SHARED_SIZE_BYTES, function)?; ++ hipFuncGetAttribute(&mut regs, hipFunction_attribute::HIP_FUNC_ATTRIBUTE_NUM_REGS, function)?; ++ hipFuncGetAttribute(&mut private, hipFunction_attribute::HIP_FUNC_ATTRIBUTE_LOCAL_SIZE_BYTES, function)?; ++ hipFuncGetAttribute(&mut max_threads, hipFunction_attribute::HIP_FUNC_ATTRIBUTE_MAX_THREADS_PER_BLOCK, function)?; ++ let threads = block.iter().try_fold(1u32, |a, b| a.checked_mul(*b)) ++ .filter(|n| *n <= i32::MAX as u32).ok_or(hipErrorCode_t::InvalidValue)?; ++ let mut blocks_per_multiprocessor = 0; ++ hipModuleOccupancyMaxActiveBlocksPerMultiprocessor(&mut blocks_per_multiprocessor, ++ function, threads as i32, shared as usize)?; ++ eprintln!("D4R_KERNEL_PROFILE kernel={name:?} backend={backend} phase={phase} gpu_ms={gpu_ms:.6} enqueue_ms={enqueue_ms:.6} completion_ms={completion_ms:.6} grid={},{},{} block={},{},{} static_lds_bytes={} dynamic_lds_bytes={shared} regs={} private_bytes={} max_threads={} predicted_blocks_per_multiprocessor={blocks_per_multiprocessor} serializing=1", ++ grid[0], grid[1], grid[2], block[0], block[1], block[2], lds, ++ regs, private, max_threads); ++ Ok(()) ++ } ++} +diff --git a/zluda/src/impl/function.rs b/zluda/src/impl/function.rs +index 7a7470a..c456dfe 100644 +--- a/zluda/src/impl/function.rs ++++ b/zluda/src/impl/function.rs +@@ -191,6 +191,7 @@ pub(crate) fn launch_kernel( + } + }; + if let (Some((prep, blocks)), true) = (f.prep, run_prep) { ++ let profile = unsafe { super::d4r_profile::Launch::begin(stream) }?; + unsafe { + hipModuleLaunchKernel( + prep, +@@ -206,6 +207,9 @@ pub(crate) fn launch_kernel( + extra_for_hip, + ) + }?; ++ if let Some(profile) = profile { ++ unsafe { profile.finish(prep, &f.name, "native", "prep", [blocks,1,1], [128,1,1], 0, stream) }?; ++ } + f.prep_last.store(prep_key, std::sync::atomic::Ordering::Relaxed); + } + let block_dim_z = if f.block_z != 0 { f.block_z } else { block_dim_z }; +@@ -214,6 +218,7 @@ pub(crate) fn launch_kernel( + eprintln!("[d4r-launch] kernel={:?} backend={} grid={grid_dim_x},{grid_dim_y},{grid_dim_z} block={block_dim_x},{block_dim_y},{block_dim_z}", + f.name, if f.native_owner.is_some() { "native" } else { "translated" }); + } ++ let profile = unsafe { super::d4r_profile::Launch::begin(stream) }?; + let result = unsafe { + hipModuleLaunchKernel( + f.base, +@@ -230,6 +235,10 @@ pub(crate) fn launch_kernel( + ) + }; + result?; ++ if let Some(profile) = profile { ++ unsafe { profile.finish(f.base, &f.name, if f.native_owner.is_some() { "native" } else { "translated" }, ++ "main", [grid_dim_x, grid_dim_y, grid_dim_z], [block_dim_x, block_dim_y, block_dim_z], shared_mem_bytes, stream) }?; ++ } + if let Some(replay) = replay { replay.finish(stream)?; } + Ok(()) + } +diff --git a/zluda/src/impl/mod.rs b/zluda/src/impl/mod.rs +index 14e0aee..380eb6e 100644 +--- a/zluda/src/impl/mod.rs ++++ b/zluda/src/impl/mod.rs +@@ -6,6 +6,7 @@ pub(super) mod context; + pub(super) mod device; + pub(super) mod driver; + pub(super) mod d4r_replay; ++pub(super) mod d4r_profile; + pub(super) mod event; + pub(super) mod function; + pub(super) mod graph; +diff --git a/zluda/src/impl/module.rs b/zluda/src/impl/module.rs +index 5a79368..232f7d4 100644 +--- a/zluda/src/impl/module.rs ++++ b/zluda/src/impl/module.rs +@@ -502,7 +502,7 @@ fn zluda_build_version() -> &'static str { + key.starts_with("D4R_ZLUDA_") + && !matches!( + key.as_str(), +- "D4R_ZLUDA_NATIVE_DIR" | "D4R_ZLUDA_DIR" | "D4R_ZLUDA_DUMP_DIR" | "D4R_ZLUDA_DUMP_PTX_DIR" | "D4R_ZLUDA_LIBCUDA" | "D4R_ZLUDA_VERBOSE" ++ "D4R_ZLUDA_NATIVE_DIR" | "D4R_ZLUDA_DIR" | "D4R_ZLUDA_DUMP_DIR" | "D4R_ZLUDA_DUMP_PTX_DIR" | "D4R_ZLUDA_LIBCUDA" | "D4R_ZLUDA_VERBOSE" | "D4R_ZLUDA_PROFILE" + | "D4R_ZLUDA_WMMA_FP8_NATIVE" // keyed by effect (ExtraCacheAttributes) + ) + }) +-- +2.55.0.windows.5 + diff --git a/scripts/windows/capture-game-window.ps1 b/scripts/windows/capture-game-window.ps1 index d09d1e9..aca2e2d 100644 --- a/scripts/windows/capture-game-window.ps1 +++ b/scripts/windows/capture-game-window.ps1 @@ -15,6 +15,7 @@ public static class D4RWindowCapture { [DllImport("user32.dll")] public static extern bool GetWindowRect(IntPtr window, out Rect rect); [DllImport("user32.dll",CharSet=CharSet.Unicode)] public static extern int GetWindowText(IntPtr window, StringBuilder text, int count); [DllImport("user32.dll")] public static extern bool IsWindowVisible(IntPtr window); + [DllImport("user32.dll")] public static extern IntPtr GetForegroundWindow(); [DllImport("user32.dll")] public static extern IntPtr SetThreadDpiAwarenessContext(IntPtr context); } '@ @@ -39,6 +40,9 @@ $callback = [D4RWindowCapture+Callback]{ param($window,$data) $windows | Select-Object handle,title,visible,area | Format-Table $chosen = $windows | Where-Object { $_.visible -and $_.area -gt 4096 } | Sort-Object area -Descending | Select-Object -First 1 if (!$chosen) { throw "No visible game window for PID $GameProcessId" } +if ([D4RWindowCapture]::GetForegroundWindow() -ne $chosen.handle) { + throw 'Game window is not foreground; capture refused to avoid including unrelated overlapping windows.' +} $rect = $chosen.rect $bitmap = [Drawing.Bitmap]::new($rect.Right-$rect.Left,$rect.Bottom-$rect.Top) $graphics = [Drawing.Graphics]::FromImage($bitmap) diff --git a/scripts/windows/package-windows-game.ps1 b/scripts/windows/package-windows-game.ps1 index 5250a5e..937945a 100644 --- a/scripts/windows/package-windows-game.ps1 +++ b/scripts/windows/package-windows-game.ps1 @@ -49,6 +49,7 @@ Stage (Join-Path $repo 'scripts/windows/windows-game.ps1') 'windows-game.ps1' Stage (Join-Path $repo 'scripts/windows/capture-game-window.ps1') 'capture-game-window.ps1' Stage (Join-Path $repo 'scripts/windows/send-game-key.ps1') 'send-game-key.ps1' Stage (Join-Path $repo 'docs/windows-game.md') 'README.md' +Stage (Join-Path $repo 'docs/windows-performance.md') 'windows-performance.md' Stage (Join-Path $repo 'LICENSE') 'licenses/d4r.txt' Stage (Join-Path $OptiScalerRoot 'GPL-3.0.txt') 'licenses/OptiScaler.txt' Stage (Join-Path $repo 'external/ZLUDA/LICENSE-MIT') 'licenses/ZLUDA-MIT.txt' @@ -62,8 +63,9 @@ foreach ($patch in Get-ChildItem -LiteralPath (Join-Path $repo 'patches/zluda') $metadata = [ordered]@{ architecture='gfx1201'; nativeKernels=16; dlssSha256='3975567b8943c53acce397f2b72380092f84f162d00b0d2c7d08a1025c563983'; d4rCommit=(& git -C $repo rev-parse HEAD).Trim(); + d4rWorkingTreeDirty=[bool](& git -C $repo status --porcelain); optiScaler=(Get-Content -LiteralPath (Join-Path $OptiScalerRoot 'build-info.json') -Raw | ConvertFrom-Json); - zludaCommit=(& git -C (Join-Path $repo 'external/ZLUDA') rev-parse HEAD).Trim(); + zludaBuild=(Get-Content -LiteralPath (Join-Path $ZludaRoot 'build-info.json') -Raw | ConvertFrom-Json); hipRuntime='TheRock 10.2.0a20260929 / HIP 7.17.26386'; files=@($stagedFiles | ForEach-Object { Get-Item -LiteralPath (Join-Path $PackageRoot $_) } | ForEach-Object { @{path=$_.FullName.Substring($PackageRoot.Length+1); sha256=(Get-FileHash -LiteralPath $_.FullName -Algorithm SHA256).Hash; version=$_.VersionInfo.FileVersion} diff --git a/scripts/windows/profile-windows-rdna4.ps1 b/scripts/windows/profile-windows-rdna4.ps1 new file mode 100644 index 0000000..c6a24d2 --- /dev/null +++ b/scripts/windows/profile-windows-rdna4.ps1 @@ -0,0 +1,30 @@ +[CmdletBinding()] +param( + [ValidateSet(11,13)][int]$Preset = 11, + [string]$ZludaRoot, [string]$PackageRoot, [string]$OutputDirectory, + [int]$Iterations = 4, + [switch]$Translated +) +$ErrorActionPreference='Stop' +$repo=[IO.Path]::GetFullPath((Join-Path $PSScriptRoot '../..')) +if (!$ZludaRoot) { $ZludaRoot=Join-Path $repo 'dist/zluda-windows-profile' } +if (!$PackageRoot) { $PackageRoot=Join-Path $repo 'dist/windows-rdna4-command-list' } +if (!$OutputDirectory) { $OutputDirectory=Join-Path $repo ('test-results/profile-' + $Preset + '-' + (Get-Date -Format 'yyyyMMdd-HHmmss-fff')) } +$settings=@{D4R_ZLUDA_PROFILE='1'; D4R_PROFILE_STAGES='1'; D4R_VALIDATE_OUTPUT='1'; + D4R_ZLUDA_NATIVE_DIR=$(if ($Translated) { $null } elseif ($Preset -eq 11) { Join-Path $repo 'build/native-k-gfx1201' } else { Join-Path $repo 'build/native-m-gfx1201' })} +$old=@{} +try { + foreach ($key in $settings.Keys) { $old[$key]=[Environment]::GetEnvironmentVariable($key,'Process'); [Environment]::SetEnvironmentVariable($key,$settings[$key],'Process') } + $arguments=@{RuntimeProfile='therock'; ZludaRoot=$ZludaRoot; PackageRoot=$PackageRoot; OutputDirectory=$OutputDirectory; + NgxCore=(Join-Path $repo '_nvngx.dll'); DlssDll=(Join-Path $repo 'nvngx_dlss.dll'); NgxMode='d3d12'; + NgxAbi='project-legacy'; Preset=$Preset; NgxOnly=$true; RequireNativeNetwork=(!$Translated); CommandListBackend=$true; + CaptureExceptions=$true; EarlyIndirectProbe=$true; PixelProfile='depth-stencil'; BarrierMode='inherited-legacy'; + Iterations=$Iterations; TimeoutSeconds=300; OptiScalerDll=(Join-Path $repo 'dist/optiscaler-windows-d4r/OptiScaler.dll')} + & (Join-Path $PSScriptRoot 'test-windows-rdna4.ps1') @arguments + if ($LASTEXITCODE) { throw 'Profiling workload failed; see diagnostic bundle.' } + $python=(Get-Command python.exe -ErrorAction Stop).Source + & $python (Join-Path $repo 'tools/windows/profile_report.py') $OutputDirectory --output (Join-Path $OutputDirectory 'profile.json') + if ($LASTEXITCODE) { throw 'No usable profile records.' } +} finally { + foreach ($key in $old.Keys) { [Environment]::SetEnvironmentVariable($key,$old[$key],'Process') } +} diff --git a/scripts/windows/windows-game.ps1 b/scripts/windows/windows-game.ps1 index 6b44f91..ffff863 100644 --- a/scripts/windows/windows-game.ps1 +++ b/scripts/windows/windows-game.ps1 @@ -8,6 +8,8 @@ param( [string]$DiagnosticResolution, [string]$CacheDirectory = $env:ZLUDA_CACHE_DIR, [switch]$ValidateOutput, + [switch]$ProfileStages, + [switch]$VerboseRuntime, [string[]]$GameArguments = @('-dx12','-windowed','-ResX=1280','-ResY=720'), [string]$OutputDirectory ) @@ -108,7 +110,7 @@ RestoreGraphicSignature=false ExtendedStateRestore=false [Log] LogToFile=true -LogLevel=0 +LogLevel=$(if ($VerboseRuntime) { 0 } else { 2 }) [Menu] DisableSplash=true "@ @@ -129,11 +131,18 @@ $settings = @{ D4R_FORMAT_MODULE=(GamePath 'd4r/pixel_convert_gfx1201.hsaco'); D4R_ZLUDA_NATIVE_DIR=(GamePath 'd4r/native'); D4R_D3D12_COMMAND_BACKEND='1'; D4R_ZLUDA_VERBOSE='1'; D4R_ZLUDA_WMMA='1'; D4R_ZLUDA_WMMA_FP8='1'; D4R_ZLUDA_WMMA_FP8_NATIVE='0'; D4R_ZLUDA_WMMA_F16_REFERENCE='1'; + # Do not inherit relaxation flags from unrelated experiments. Unset and + # false have the same numerical effect; unset reuses the validated cache. + D4R_ZLUDA_IGNORE_DENORMAL=$null; D4R_ZLUDA_FAST_MATH=$null; + D4R_ZLUDA_WMMA_F32ACC=$null; D4R_ZLUDA_WAVE64=$null; + D4R_QUIET_API=$(if ($VerboseRuntime) { $null } else { '1' }); D4R_DIAG_DIR=$OutputDirectory; ZLUDA_LOG_DIR=(Join-Path $OutputDirectory 'zluda-trace'); ZLUDA_CACHE_DIR=$CacheDirectory; PATH=((GamePath 'd4r/hip/bin') + ';' + (GamePath 'd4r/zluda') + ';' + $env:PATH) } $old = @{}; $process = $null; $originalSettings = @() +$outFile = $null; $errFile = $null; $outTask = $null; $errTask = $null if ($ValidateOutput) { $settings['D4R_VALIDATE_OUTPUT']='1' } +if ($ProfileStages) { $settings['D4R_PROFILE_STAGES']='1' } try { if ($DiagnosticResolution) { if ([IO.Path]::GetFileName($GameExe) -ne 'SHProto-Win64-Shipping.exe' -or $DiagnosticResolution -notmatch '^([0-9]{3,4})x([0-9]{3,4})$') { throw 'DiagnosticResolution currently supports Silent Hill 2 only; use e.g. 1280x720.' } @@ -168,14 +177,28 @@ try { ConvertTo-Json -Depth 12 | Set-Content -LiteralPath (Join-Path $OutputDirectory 'environment.json') -Encoding UTF8 function Quote([string]$value) { if ($value.Contains('"')) { throw 'A command argument contains an unsupported quote.' }; return '"' + $value + '"' } $arguments = @('--output-directory', (Quote $OutputDirectory), '--', (Quote $GameExe)) + @($GameArguments | ForEach-Object { Quote $_ }) - $process = Start-Process -FilePath (GamePath 'd4r/d4r_debug_launcher.exe') -ArgumentList $arguments -WorkingDirectory $game -WindowStyle Hidden -PassThru ` - -RedirectStandardOutput (Join-Path $OutputDirectory 'd4r.stdout.log') -RedirectStandardError (Join-Path $OutputDirectory 'd4r.stderr.log') + # Drain raw bytes concurrently. PowerShell's line-oriented redirection can + # throttle a verbose game and distort the very timings we are collecting. + $info = [Diagnostics.ProcessStartInfo]::new() + $info.FileName = GamePath 'd4r/d4r_debug_launcher.exe' + $info.Arguments = $arguments -join ' ' + $info.WorkingDirectory = $game + $info.UseShellExecute = $false; $info.CreateNoWindow = $true + $info.RedirectStandardOutput = $true; $info.RedirectStandardError = $true + $process = [Diagnostics.Process]::new(); $process.StartInfo = $info + if (!$process.Start()) { throw 'Game debugger launch failed.' } + $outFile = [IO.File]::Open((Join-Path $OutputDirectory 'd4r.stdout.log'), [IO.FileMode]::Create, [IO.FileAccess]::Write, [IO.FileShare]::Read) + $errFile = [IO.File]::Open((Join-Path $OutputDirectory 'd4r.stderr.log'), [IO.FileMode]::Create, [IO.FileAccess]::Write, [IO.FileShare]::Read) + $outTask = $process.StandardOutput.BaseStream.CopyToAsync($outFile) + $errTask = $process.StandardError.BaseStream.CopyToAsync($errFile) Write-Host "Game diagnostic started (preset $Preset). Logs: $OutputDirectory" $timer = [Diagnostics.Stopwatch]::StartNew() while (!$process.WaitForExit(1000)) { if ($RunSeconds -gt 0 -and $timer.Elapsed.TotalSeconds -ge $RunSeconds) { $process.Kill(); $process.WaitForExit(); break } } $process.WaitForExit() + [void]$outTask.GetAwaiter().GetResult(); [void]$errTask.GetAwaiter().GetResult() + $outFile.Dispose(); $outFile = $null; $errFile.Dispose(); $errFile = $null foreach ($file in Get-ChildItem -LiteralPath $game -Filter 'OptiScaler*.log' -File) { Copy-Item -LiteralPath $file.FullName -Destination $OutputDirectory -Force } $stderr = Get-Content -LiteralPath (Join-Path $OutputDirectory 'd4r.stderr.log') -Raw $stdout = Get-Content -LiteralPath (Join-Path $OutputDirectory 'd4r.stdout.log') -Raw @@ -201,6 +224,10 @@ try { Write-Host "Game diagnostic bundle: $OutputDirectory.zip" } finally { if ($process -and !$process.HasExited) { $process.Kill(); $process.WaitForExit() } + if ($outTask) { try { [void]$outTask.GetAwaiter().GetResult() } catch {} } + if ($errTask) { try { [void]$errTask.GetAwaiter().GetResult() } catch {} } + if ($outFile) { $outFile.Dispose() }; if ($errFile) { $errFile.Dispose() } + if ($process) { $process.Dispose() } foreach ($key in $old.Keys) { [Environment]::SetEnvironmentVariable($key,$old[$key],'Process') } foreach ($entry in $originalSettings) { Copy-Item -LiteralPath $entry.saved -Destination $entry.path -Force } } diff --git a/tools/windows/cuda_api.h b/tools/windows/cuda_api.h index a2a59a3..0feacd8 100644 --- a/tools/windows/cuda_api.h +++ b/tools/windows/cuda_api.h @@ -7,6 +7,7 @@ using CUcontext = void*; using CUmodule = void*; using CUfunction = void*; struct CudaApi { + bool verbose = true; d4r::diag::SearchDirectory search; d4r::diag::Library library; #define D4R_CU(name, ret, ...) using name##_fn = ret(WINAPI*)(__VA_ARGS__); name##_fn name = library.symbol(#name) @@ -41,7 +42,7 @@ struct CudaApi { const char* name = "unknown", *message = "unknown"; if (result) { cuGetErrorName(result, &name); cuGetErrorString(result, &message); } else name = "CUDA_SUCCESS"; - std::printf("CUDA %s -> %d (%s)\n", call, result, name ? name : "unknown"); + if (verbose || result) std::printf("CUDA %s -> %d (%s)\n", call, result, name ? name : "unknown"); if (result) throw std::runtime_error(std::string(call) + ": " + (message ? message : "unknown")); } }; diff --git a/tools/windows/d4r_nvngx_windows.cpp b/tools/windows/d4r_nvngx_windows.cpp index 765992d..b455002 100644 --- a/tools/windows/d4r_nvngx_windows.cpp +++ b/tools/windows/d4r_nvngx_windows.cpp @@ -154,7 +154,7 @@ API unsigned NVSDK_NGX_D3D12_EvaluateFeature(ID3D12GraphicsCommandList* list, co d4r_ngx_set_uint(snapshot->parameters, (prefix + ".Enhanced").c_str(), state.enhanced); d4r_ngx_set_uint(snapshot->parameters, (prefix + ".Layout").c_str(), unsigned(state.layout)); d4r_ngx_set_uint(snapshot->parameters, (prefix + ".Access").c_str(), unsigned(state.access)); - std::printf("D4R_RESOURCE_ACCESS plane=%s enhanced=%u legacy=0x%x layout=%u access=0x%x\n", + if (!std::getenv("D4R_QUIET_API")) std::printf("D4R_RESOURCE_ACCESS plane=%s enhanced=%u legacy=0x%x layout=%u access=0x%x\n", names[i], state.enhanced, unsigned(state.legacy), unsigned(state.layout), unsigned(state.access)); } d4r::win::commands::record_boundary(list, [feature, snapshot](ID3D12CommandQueue* queue) { @@ -168,7 +168,7 @@ API unsigned NVSDK_NGX_D3D12_EvaluateFeature(ID3D12GraphicsCommandList* list, co d4r_ngx_set_uint(snapshot->parameters, (prefix + ".Enhanced").c_str(), resolved.enhanced); d4r_ngx_set_uint(snapshot->parameters, (prefix + ".Layout").c_str(), unsigned(resolved.layout)); d4r_ngx_set_uint(snapshot->parameters, (prefix + ".Access").c_str(), unsigned(resolved.access)); - std::printf("D4R_INHERITED_ACCESS plane=%s tracked=%u enhanced=%u layout=%u legacy=0x%x\n", + if (!std::getenv("D4R_QUIET_API")) std::printf("D4R_INHERITED_ACCESS plane=%s tracked=%u enhanced=%u layout=%u legacy=0x%x\n", names[i], !resolved.inherited, resolved.enhanced, unsigned(resolved.layout), unsigned(resolved.legacy)); } feature->evaluate_boundary(queue, snapshot->parameters); diff --git a/tools/windows/hip_api.h b/tools/windows/hip_api.h index a465da5..4437e49 100644 --- a/tools/windows/hip_api.h +++ b/tools/windows/hip_api.h @@ -4,6 +4,7 @@ namespace d4r::diag { struct HipApi { + bool verbose = true; // Probes log every call; the game can suppress successful API calls. SearchDirectory search; Library library; #define D4R_HIP_FUNCTION(name) decltype(&::name) name = library.symbol(#name) @@ -36,7 +37,7 @@ struct HipApi { search(std::filesystem::path(wide(root)) / L"bin"), library(std::filesystem::path(wide(root)) / L"bin" / L"amdhip64_7.dll") {} void check(hipError_t result, const char* call) const { - std::printf("HIP %s -> %d (%s)\n", call, static_cast(result), hipGetErrorName(result)); + if (verbose || result != hipSuccess) std::printf("HIP %s -> %d (%s)\n", call, static_cast(result), hipGetErrorName(result)); if (result != hipSuccess) throw std::runtime_error(std::string(call) + ": " + hipGetErrorString(result)); } int select_gfx1201(int requested, hipDeviceProp_t& selected) const { diff --git a/tools/windows/ngx_windows_runtime.h b/tools/windows/ngx_windows_runtime.h index 6cce4f3..366eaab 100644 --- a/tools/windows/ngx_windows_runtime.h +++ b/tools/windows/ngx_windows_runtime.h @@ -17,7 +17,7 @@ inline std::string env_path(const char* name) { return value; } inline void ngx_check(unsigned result, const char* operation) { - std::printf("D4R_NGX %s result=0x%08x\n", operation, result); + if (result != 1 || !std::getenv("D4R_QUIET_API")) std::printf("D4R_NGX %s result=0x%08x\n", operation, result); if (result != 1) throw std::runtime_error(std::string(operation) + " NGX=" + std::to_string(result)); } inline ResourceAccess ngx_resource_access(void* parameters, const char* name, D3D12_RESOURCE_STATES fallback) { @@ -82,6 +82,7 @@ struct Runtime { try { hipDeviceProp_t props{}; hip.select_gfx1201(-1, props); + hip.verbose = cuda.verbose = !std::getenv("D4R_QUIET_API"); const auto luid = adapter_luid(d3d); if (std::memcmp(&luid, props.luid, sizeof(luid))) throw std::runtime_error("D3D12/HIP LUID mismatch"); cuda.check(cuda.cuInit(0), "cuInit(Windows runtime)"); @@ -289,8 +290,18 @@ private: } void execute_cuda(ID3D12CommandQueue* queue) { const auto begin = std::chrono::steady_clock::now(); + auto stage = begin; + const bool profileStages = std::getenv("D4R_PROFILE_STAGES") != nullptr; + auto mark = [&](const char* name) { + if (!profileStages) return; + const auto now = std::chrono::steady_clock::now(); + std::printf("D4R_STAGE name=%s cpu_ms=%.6f\n", name, + std::chrono::duration(now - stage).count()); + stage = std::chrono::steady_clock::now(); + }; rt_->timeline->wait_input(queue); rt_->cuda.check(rt_->cuda.cuCtxSynchronize(), "Interop input producer completion"); + mark("input_fence_wait"); for (unsigned i : {0u, 1u, 2u, 4u}) if (planes_[i].texture) { auto& plane = planes_[i]; void* data = plane.shared->mapped; uint64_t pitch = plane.shared->footprint.Footprint.RowPitch; @@ -301,6 +312,7 @@ private: } plane.image->upload_device(reinterpret_cast(data), pitch); } + mark("input_conversion_array_upload"); if (std::getenv("D4R_INTEROP_VERIFY")) { for (unsigned i : {0u, 1u, 2u, 4u}) if (planes_[i].texture) { uint32_t sample[8]{}; @@ -315,13 +327,16 @@ private: } } ngx_check(rt_->evaluate(handle_, parameters_, nullptr), "CUDA EvaluateFeature"); + mark("ngx_evaluate_host"); // NGX can use internal nonblocking streams. The default stream alone // does not establish completion of those streams. rt_->cuda.check(rt_->cuda.cuCtxSynchronize(), "NGX all-stream completion"); + mark("ngx_all_stream_completion"); auto& output = planes_[3]; output.image->download_device(reinterpret_cast(output.canonical ? output.canonical->data : output.shared->mapped), output.canonical ? output.canonical->pitch : output.shared->footprint.Footprint.RowPitch); rt_->cuda.check(rt_->cuda.cuCtxSynchronize(), "VRAM output completion"); + mark("output_array_download"); if (std::getenv("D4R_VALIDATE_OUTPUT")) { if (!rt_->pixels) rt_->pixels = std::make_unique(rt_->hip, pixel_module_path()); const auto counts = rt_->pixels->validate(output.canonical ? output.canonical->data : output.shared->mapped, @@ -329,9 +344,11 @@ private: std::printf("D4R_OUTPUT_VALIDATION elements=%llu nan=%u inf=%u diagnostics_cpu_bytes=8\n", output.desc.Width * output.desc.Height * 4, counts[0], counts[1]); if (counts[0] || counts[1]) throw std::runtime_error("DLSS output contains NaN/Inf"); } + mark("output_diagnostic"); if (output.canonical) rt_->pixels->convert(true, output.canonical->data, output.canonical->pitch, output.shared->mapped, output.shared->footprint.Footprint.RowPitch, unsigned(output.desc.Width), output.desc.Height, output.spec.storage, 3); rt_->timeline->signal_output(queue); + mark("output_conversion_fence_signal"); std::printf("D4R_FRAME cpu_frame_copies=%u frame_age=0 interop_ngx_ms=%.3f\n", std::getenv("D4R_INTEROP_VERIFY") ? 1u : 0u, std::chrono::duration(std::chrono::steady_clock::now() - begin).count()); } diff --git a/tools/windows/profile_report.py b/tools/windows/profile_report.py new file mode 100644 index 0000000..a8e42dd --- /dev/null +++ b/tools/windows/profile_report.py @@ -0,0 +1,92 @@ +"""Summarize native Windows d4r CPU stages and optional serializing HIP events. + +CPU completion time is not GPU execution time. HIP occupancy API predictions +are not hardware counters. No bandwidth / WMMA utilization is inferred here. +""" +import argparse +import collections +import json +import pathlib +import re +import statistics + + +def stats(values): + values = sorted(values) + def quantile(q): + index = (len(values) - 1) * q + lower = int(index) + return values[lower] + (values[min(lower + 1, len(values) - 1)] - values[lower]) * (index - lower) + return dict(samples=len(values), total=sum(values), mean=statistics.mean(values), + median=statistics.median(values), p95=quantile(.95), maximum=values[-1]) + + +def metadata(directory): + result = {} + if directory is None: + return result + for path in sorted(directory.glob('*.txt')): + text = path.read_text(encoding='utf-8-sig', errors='replace') + for block in re.split(r'(?m)^ - \.args:', text)[1:]: + fields = dict(re.findall(r'(?m)^ \.(\w+):\s*([^\r\n]+)', block)) + if 'name' in fields: + result[fields['name'].strip()] = {key: int(fields[key]) for key in ( + 'wavefront_size', 'vgpr_count', 'sgpr_count', 'vgpr_spill_count', 'sgpr_spill_count', + 'group_segment_fixed_size', 'private_segment_fixed_size') if key in fields} + return result + + +def report(directory, metadata_directory=None): + kernel_metadata = metadata(metadata_directory) + stages = collections.defaultdict(list) + kernels = collections.defaultdict(list) + for path in sorted(directory.glob('*.log')): + text = path.read_text(encoding='utf-8-sig', errors='replace') + for name, value in re.findall(r'D4R_STAGE name=(\S+) cpu_ms=([0-9.]+)', text): + stages[name].append(float(value)) + for line in text.splitlines(): + if not line.startswith('D4R_KERNEL_PROFILE '): + continue + fields = dict(re.findall(r'(\w+)=("[^"]+"|\S+)', line)) + kernels[(fields['kernel'].strip('"'), fields['backend'], fields['phase'])].append(fields) + result = dict(cpuStages={name: stats(values) for name, values in stages.items()}, + kernels=[], notes=[ + 'CPU stage times include waits and host work; they are not isolated GPU timings.', + 'HIP-event profiling synchronizes every sampled launch and changes scheduling.', + 'Occupancy is an API prediction, not a measured hardware counter.', + 'Bandwidth and WMMA utilization require additional supported hardware tooling.']) + for (name, backend, phase), rows in kernels.items(): + item = dict(kernel=name, backend=backend, phase=phase, + gpuMs=stats([float(row['gpu_ms']) for row in rows]), + enqueueMs=stats([float(row['enqueue_ms']) for row in rows]), + completionMs=stats([float(row['completion_ms']) for row in rows]), + configurations=[dict(config) for config in sorted({tuple((key, row[key]) for key in + ('grid', 'block', 'static_lds_bytes', 'dynamic_lds_bytes', 'regs', 'private_bytes', + 'max_threads', 'predicted_blocks_per_multiprocessor')) for row in rows})]) + result['kernels'].append(item) + if backend == 'native': + item['elfMetadata'] = kernel_metadata.get(name + ('_prep' if phase == 'prep' else ''), {}) + result['kernels'].sort(key=lambda row: row['gpuMs']['total'], reverse=True) + return result + + +def main(): + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument('directory', type=pathlib.Path) + parser.add_argument('--output', type=pathlib.Path) + 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 result['cpuStages'] and not result['kernels']: + 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') + for name, row in result['cpuStages'].items(): + print(f"CPU {name}: n={row['samples']} mean={row['mean']:.3f} ms median={row['median']:.3f} ms p95={row['p95']:.3f} ms") + for row in result['kernels']: + times = row['gpuMs'] + print(f"GPU {row['kernel']} {row['backend']} {row['phase']}: n={times['samples']} mean={times['mean']:.6f} ms total={times['total']:.3f} ms") + + +if __name__ == '__main__': + main()