mirror of
https://github.com/jkdansereau/goldeneye-pc-port.git
synced 2026-10-24 00:02:45 +02:00
* D250: fix sysSleep unit-conversion bug in frame-pacing; add GE_D250 lvlRender probe port/fast3d/gfx_sdl2.cpp sync_framerate_with_timer() computed the remaining frame budget in 100ns units (qpc_to_100ns) and passed it straight into sysSleep(), which takes microseconds -- a real 10x oversleep whenever that branch fires. Genuine bug, but only active when target_fps is nonzero (tied to Input/Video FpsCap); confirmed via live testing that it is NOT the active cause of the user's reported ~45-50fps with FpsCap=0/VSync=0, where this pacing path never runs. Added GE_D250 (src/boss.c, #ifdef PORT) to isolate lvlRender()'s DL-building cost (culling/animation/scene traversal) from gfx_run's already-measured software-RSP interpretation cost. Live test on Dam shows lvlRender averaging ~0.5-1.5ms -- also not the bottleneck. Documented in docs/dev/GE-ENV-PROBES.md (GE_D250 row). findings.md D250 update to follow after rebase. Claude-Session: https://claude.ai/code/session_016DQUKGLZxFtPy52MkKXXog * docs(D250): live A/B session -- MSAA/aniso/FOV/resolution/vsync all ruled out Live session with the user driving the game directly, confirmed the sim-healthy/render-sagging pattern from earlier idle testing reproduces under real play on Dam. One-at-a-time A/B via the F10 overlay ruled out MSAA, anisotropy, FOV, resolution (1280x960 fullscreen vs 640x480 windowed), and VSync (render never exceeds ~60 even uncapped) as the cause -- the cost is resolution/GPU-setting-independent. gfx_run (~6-10ms) + lvlRender (~0.5-1.5ms, via the new GE_D250 probe) together don't account for the real ~20-22ms/frame. Leading remaining suspect: the emulated N64 thread-handoff/scheduler round-trip (gesched.c/sched.c) -- real OS context-switch/wake latency standing in for what was free hardware handoff on N64. Needs a real profiler (Visual Studio / WPR) attached during a live bad-fps moment to confirm; ad-hoc per-call timers have now ruled out the two most obvious CPU call sites without finding the cost. Claude-Session: https://claude.ai/code/session_016DQUKGLZxFtPy52MkKXXog * D250: fix uncached getenv() in fast3d hot paths -- root cause of the fps drop A live WPR/xperf CPU trace (tools_pc/perf.ps1, new sister script to debug.ps1) with Microsoft public symbols resolved found the dominant render thread spending only 5.2% of its CPU time in the game's own code -- 43% was in msvcrt.dll, and getenv()/_getenv_helper_nolock alone accounted for ~50% of the thread's total CPU time. Root cause: port/fast3d/gfx_pc.cpp's import_texture() (runs on every texture bind) and several per-triangle/per-G_SETCOMBINE debug-probe checks (GE_DTEX, GE_TEXDUMP, GE_TEXRAW, GE_D229 x2, GE_D172 x2, plus GE_TEXDUMP/GE_PCDUMP in gfx_opengl.cpp) called getenv() uncached on every call, unlike the safe static-cached pattern already used elsewhere in this codebase. On a texture-heavy scene that's tens of thousands of locked, locale-aware Windows CRT environment lookups per second -- invisible to both of the timers added earlier this session (gfx_run's own cost measurement and the new GE_D250 lvlRender probe), since neither isolates CRT/library time from the game's own code. Fix: cache every getenv() site in gfx_pc.cpp/gfx_opengl.cpp with the established static-int pattern. Narrow, mechanical, no logic change. Verified: the exact idle-Dam test that was pinned at 45-50fps before the fix now holds a rock-steady 60-61fps, zero dips. Also explains why the earlier MSAA/aniso/FOV/resolution/vsync A/B pass all showed "no change" -- the getenv() cost was a large per-call constant that swamped any real, smaller resolution-dependent GPU cost at every setting tried. Residual, separate issue found once this was fixed: still runs badly at 1440p+ (640x480 now holds a clean 60fps) -- likely the real GPU fill-rate cost the getenv() bug was masking, now exposed on its own. Not yet investigated. docs/dev/findings.md D250 updated with the full root-cause writeup. docs/porting-notes.md gets a new lesson under section E (cache getenv() in any hot-path probe). tools_pc/perf.ps1 automates the trace-and-analyze workflow for next time. Claude-Session: https://claude.ai/code/session_016DQUKGLZxFtPy52MkKXXog * docs(D250): correct the 1440p+ follow-up -- it was a stale-build false alarm User re-tested 1440p/4K on the actual getenv-fix build and confirmed it holds up fine too. The "still runs badly at 1440p+" report was from before the fix was live, same stale-build class as the DLL-load false alarm earlier in the session. D250 is fully resolved across all resolutions tested, not just 640x480. Claude-Session: https://claude.ai/code/session_016DQUKGLZxFtPy52MkKXXog * docs: add missing GE_D219RAW row to GE-ENV-PROBES.md (CI validate fix) Pre-existing gap unrelated to this branch's own changes -- gen_env_probes.py --check caught it now since it runs on every PR. GE_D219RAW has had live getenv() sites in src/game/image.c since the D219 investigation but was never added to the probe doc.
131 lines
6.6 KiB
PowerShell
131 lines
6.6 KiB
PowerShell
<#
|
|
perf.ps1 - sister script to debug.ps1: launch the PC port under an ETW
|
|
trace (xperf, part of the Windows Performance Toolkit) so a bad-fps
|
|
playtest always leaves a CPU profile, not just a "felt slow" report.
|
|
|
|
Requires an ELEVATED PowerShell/cmd (xperf needs SeSystemProfilePrivilege).
|
|
Re-launch this script itself as admin if it complains.
|
|
|
|
Usage (from repo root, elevated):
|
|
.\tools_pc\perf.ps1 # front-end / menu playtest
|
|
.\tools_pc\perf.ps1 -level_33 # boot straight into a level (Dam)
|
|
.\tools_pc\perf.ps1 -level_33 -Seconds 30 # auto-stop after 30s instead of waiting for exit
|
|
.\tools_pc\perf.ps1 -NoBuild -NoSymbols # skip rebuild + skip MS symbol download (faster)
|
|
|
|
Produces, under perf_captures\<timestamp>\:
|
|
trace.etl - raw ETW trace (open in WPA for the full GUI view)
|
|
cswitch_thread.csv - per-thread CPU time (xperf -a cswitch -thread -process)
|
|
profile_detail.csv - per-module CPU sample weight, per process
|
|
summary.txt - tracerpt event-count summary
|
|
and prints a quick top-offenders readout (busiest thread, busiest modules)
|
|
straight to the console so most sessions won't need WPA at all.
|
|
|
|
Symbol resolution (-Symbols, off by default): downloads Microsoft's public
|
|
PDBs for system DLLs (msvcrt.dll, ntdll.dll, ...) so hot functions inside
|
|
them resolve by name instead of just module -- this is what caught the
|
|
D250 getenv() bug. Slow on first run (network), fast after (local cache
|
|
under perf_captures\symcache\). Our own ge007.x86_64.exe uses DWARF debug
|
|
info (GCC -g), which xperf/WPA cannot read regardless of -Symbols -- that
|
|
part of any stack always shows as the raw module name, not a function.
|
|
#>
|
|
[CmdletBinding()]
|
|
param(
|
|
[int]$Seconds = 0, # 0 = wait for the game to exit on its own
|
|
[switch]$NoBuild,
|
|
[switch]$Symbols,
|
|
[string]$Xperf = "C:\Program Files (x86)\Windows Kits\10\Windows Performance Toolkit\xperf.exe",
|
|
[Parameter(ValueFromRemainingArguments = $true)]
|
|
[string[]]$GameArgs
|
|
)
|
|
|
|
$ErrorActionPreference = "Stop"
|
|
|
|
$isAdmin = ([Security.Principal.WindowsPrincipal][Security.Principal.WindowsIdentity]::GetCurrent()).IsInRole([Security.Principal.WindowsBuiltInRole]::Administrator)
|
|
if (-not $isAdmin) { throw "perf.ps1 needs an elevated shell (xperf requires SeSystemProfilePrivilege) - re-run from an admin PowerShell/cmd." }
|
|
if (-not (Test-Path $Xperf)) { throw "xperf not found at $Xperf (pass -Xperf <path>; it ships with the Windows Performance Toolkit / Windows SDK)" }
|
|
|
|
# The exe links MSYS2 mingw64 DLLs (SDL2, libgcc, libstdc++, libwinpthread,
|
|
# zlib). An elevated PowerShell doesn't have these on PATH and the game dies
|
|
# at startup with 0xc0000135 (DLL not found) -- same fix as debug.ps1.
|
|
$MingwBin = "C:\msys64\mingw64\bin"
|
|
if ((Test-Path $MingwBin) -and (($env:PATH -split ';') -notcontains $MingwBin)) {
|
|
$env:PATH = "$MingwBin;$env:PATH"
|
|
}
|
|
|
|
$exe = "build-pc\ge007.x86_64.exe"
|
|
if (-not $NoBuild) {
|
|
Write-Host "building (bash build-pc.sh ntsc-final) - pass -NoBuild to skip" -ForegroundColor DarkGray
|
|
& "C:\msys64\usr\bin\bash.exe" -lc "cd '$($PWD -replace '\\','/')' && export PATH=/c/msys64/mingw64/bin:`$PATH && ./build-pc.sh ntsc-final"
|
|
if ($LASTEXITCODE -ne 0) { throw "build failed" }
|
|
}
|
|
if (-not (Test-Path $exe)) { throw "no exe - build the port: bash build-pc.sh ntsc-final" }
|
|
|
|
$stamp = Get-Date -Format "yyyyMMdd_HHmmss"
|
|
$outDir = "perf_captures\$stamp"
|
|
New-Item -ItemType Directory -Force -Path $outDir | Out-Null
|
|
$etl = Join-Path $outDir "trace.etl"
|
|
|
|
Write-Host "starting xperf trace (CPU sampling + context switches)" -ForegroundColor Cyan
|
|
& $Xperf -on PROC_THREAD+LOADER+CSWITCH+DISPATCHER+PROFILE -stackwalk PROFILE
|
|
if ($LASTEXITCODE -ne 0) { throw "xperf -start failed" }
|
|
|
|
try {
|
|
Write-Host "launching $exe $GameArgs" -ForegroundColor Green
|
|
$proc = Start-Process -FilePath $exe -ArgumentList $GameArgs -PassThru
|
|
|
|
if ($Seconds -gt 0) {
|
|
Write-Host "capturing for $Seconds s (play now) ..." -ForegroundColor Yellow
|
|
Start-Sleep -Seconds $Seconds
|
|
if (-not $proc.HasExited) { Stop-Process -Id $proc.Id -Force }
|
|
} else {
|
|
Write-Host "capturing until the game exits (close the window when done) ..." -ForegroundColor Yellow
|
|
$proc.WaitForExit()
|
|
}
|
|
} finally {
|
|
Write-Host "stopping xperf trace -> $etl" -ForegroundColor Cyan
|
|
& $Xperf -stop -d $etl
|
|
}
|
|
|
|
if (-not (Test-Path $etl)) { throw "trace file was not written - xperf -stop likely errored above" }
|
|
|
|
$symArgs = @()
|
|
if ($Symbols) {
|
|
$symCache = "perf_captures\symcache"
|
|
New-Item -ItemType Directory -Force -Path $symCache | Out-Null
|
|
$env:_NT_SYMBOL_PATH = "srv*$symCache*https://msdl.microsoft.com/download/symbols"
|
|
$env:_NT_SYMCACHE_PATH = $symCache
|
|
$symArgs = @("-symbols")
|
|
Write-Host "resolving symbols against Microsoft's public server (first run is slow)" -ForegroundColor DarkGray
|
|
}
|
|
|
|
Write-Host "`nanalyzing trace ..." -ForegroundColor Cyan
|
|
& "C:\Windows\System32\tracerpt.exe" $etl -summary (Join-Path $outDir "summary.txt") -y | Out-Null
|
|
& $Xperf -i $etl @symArgs -o (Join-Path $outDir "cswitch_thread.csv") -a cswitch -thread -process
|
|
& $Xperf -i $etl @symArgs -o (Join-Path $outDir "profile_detail.csv") -a profile -detail
|
|
|
|
# ---- Quick top-offenders readout -------------------------------------------
|
|
$procRow = Select-String -Path (Join-Path $outDir "cswitch_thread.csv") -Pattern "ge007\.x86_64\.exe" | Select-Object -First 1
|
|
Write-Host "`n===================== RESULT =====================" -ForegroundColor Yellow
|
|
if ($procRow) { Write-Host "process total CPU time: $($procRow.Line.Trim())" }
|
|
|
|
Write-Host "`n-- busiest ge007 threads (CPU us) --" -ForegroundColor Red
|
|
Get-Content (Join-Path $outDir "cswitch_thread.csv") |
|
|
Select-String -Pattern "ge007\.x86_64\.exe.*,\s*\d+\s*$" |
|
|
ForEach-Object { $_.Line.Trim() } |
|
|
Sort-Object { [int]($_ -replace ',.*$', '') } -Descending |
|
|
Select-Object -First 8
|
|
|
|
Write-Host "`n-- busiest modules inside ge007 (sample weight) --" -ForegroundColor Red
|
|
Get-Content (Join-Path $outDir "profile_detail.csv") |
|
|
Select-String -Pattern "^ge007\.x86_64\.exe" |
|
|
ForEach-Object {
|
|
$f = $_.Line -split ","
|
|
[PSCustomObject]@{ Weight = [long]($f[1].Trim()); Pct = $f[2].Trim(); Module = $f[3].Trim() }
|
|
} | Sort-Object Weight -Descending | Select-Object -First 12 |
|
|
Format-Table -AutoSize
|
|
|
|
Write-Host "`nraw data: $outDir\ (open trace.etl in WPA for the full GUI view)" -ForegroundColor DarkGray
|
|
if (-not $Symbols) {
|
|
Write-Host "re-run with -Symbols to resolve system-DLL function names (e.g. this is how D250's getenv() bug was found)" -ForegroundColor DarkGray
|
|
}
|