chore: strip throwaway dense-town FPS profiling apparatus (plan Task 5)

The FPS deep-dive landed (dense Arwic 75 -> ~165 fps via the cell-object
batching + cell-particle consolidation, both already committed). Remove the
throwaway diagnostic apparatus now that it has served its purpose:

- delete FrameProfiler.cs (whole-frame TimeElapsed + [PASS-GPU] glFinish +
  [CPU-PHASE]/[GPU-PHASE] timers + the =1/=2 ACDREAM_FPS_PROF modes)
- GameWindow: _fpsProf/_frameProfiler/_msaaSamples fields, the BeginFrame/
  EndFrame/MarkUpdateStart hooks, the terrain glFinish, and the landscape
  sub-phase LsMark instrumentation
- RetailPViewRenderer: the DrawInside per-phase Phase()/MarkGpu markers
- ParticleRenderer / PortalDepthMaskRenderer / EnvCellRenderer: the per-pass
  glFinish brackets
- delete DegradeCoverageProbeTests.cs (the dead distance-degrade probe)

KEPT (the real fixes): RetailPViewRenderer cell-object batching + consolidated
cell-particle pass; EnvCellRenderer.CellHasTransparent. Build + full test suite
green (468 App incl. pview replay tests; 1566 Core; 317 Net; 425 UI).

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This commit is contained in:
Erik 2026-06-24 00:10:00 +02:00
parent 9f51a4db18
commit a9d06a613a
7 changed files with 0 additions and 569 deletions

View file

@ -1,219 +0,0 @@
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using Silk.NET.OpenGL;
namespace AcDream.App.Rendering;
/// <summary>
/// THROWAWAY perf apparatus (2026-06-23) for the dense-town FPS investigation.
/// Gated on <c>ACDREAM_FPS_PROF=1</c>. Answers the first fork — is the frame
/// CPU-render-bound, GPU-bound, or wait/vsync-bound — by measuring three numbers
/// per frame and printing their distribution every ~1 s:
///
/// <list type="bullet">
/// <item><b>wall</b>: the real frame period the user sees (Silk's inter-frame
/// delta). 1000/wall = the title-bar FPS.</item>
/// <item><b>cpuRender</b>: wall-clock CPU time spent inside <c>OnRender</c>
/// (the render-thread submission cost — walk, group-build, draw issue).</item>
/// <item><b>gpu</b>: GPU time for the whole frame's GL work, via a
/// <c>TimeElapsed</c> query bracketing the frame (ring of 3 for async readback,
/// mirroring WbDrawDispatcher's #125-safe pattern).</item>
/// </list>
///
/// Interpretation: gpu≈wall ⇒ GPU-bound (then break down by pass); cpuRender≈wall
/// &amp; gpu≪ ⇒ CPU-render-bound (draw-call submission / batching / the walk);
/// wall≫both ⇒ wait/vsync-bound (the 60→30 quantization cliff — confirm via the
/// printed vsync state). Also prints live vsync + MSAA sample count.
///
/// Do NOT run alongside <c>ACDREAM_WB_DIAG=1</c>: WB-DIAG opens its own per-pass
/// <c>TimeElapsed</c> queries and GL forbids nesting them inside this frame query.
/// </summary>
internal sealed class FrameProfiler
{
private const int RingDepth = 3;
private const int SampleCap = 512;
private readonly GL _gl;
private readonly uint[] _gpuQuery = new uint[RingDepth];
private readonly bool[] _begun = new bool[RingDepth];
private bool _queriesInit;
private int _frame;
private readonly Stopwatch _cpuSw = new();
// Free-running clock to measure the OnUpdate→OnRender gap robustly (no
// EndUpdate hook needed → survives any early-return in OnUpdate).
private readonly Stopwatch _clock = Stopwatch.StartNew();
private double _updateStartMs;
private double _lastUpdateMs;
private readonly double[] _wallMs = new double[SampleCap];
private readonly double[] _cpuMs = new double[SampleCap];
private readonly double[] _gpuMs = new double[SampleCap];
private readonly double[] _updMs = new double[SampleCap];
private readonly double[] _presMs = new double[SampleCap];
private int _count;
private double _lastGpuMs; // carried forward when a slot isn't ready yet
private double _accumSeconds;
private int _flushFrames = 1;
private const double FlushSeconds = 1.0;
private bool _vsync;
private int _msaa;
public FrameProfiler(GL gl) => _gl = gl ?? throw new ArgumentNullException(nameof(gl));
// THROWAWAY per-renderer GPU attribution (glFinish-bracketed, set true by
// ACDREAM_FPS_PROF=1). Renderers drain+time their own draw and report here;
// glFinish serializes CPU/GPU so the FRAME time inflates, but each renderer's
// GPU cost is exact while the view is held still. Read+cleared each Flush.
internal static readonly bool PassGpuEnabled =
string.Equals(Environment.GetEnvironmentVariable("ACDREAM_FPS_PROF"), "1", StringComparison.Ordinal);
private static readonly Dictionary<string, (double sum, int n)> _rendererGpu = new();
private static readonly object _rgLock = new();
internal static void AddRendererGpu(string name, double ms)
{
lock (_rgLock)
{
var cur = _rendererGpu.TryGetValue(name, out var v) ? v : (sum: 0.0, n: 0);
_rendererGpu[name] = (cur.sum + ms, cur.n + 1);
}
}
// THROWAWAY per-frame CPU sub-phase timing for DrawInside. Gated on
// ACDREAM_FPS_PROF in {1,2}; run under =2 (no glFinish) so the DRAW phases
// measure pure CPU submission cost, not GPU. Read+cleared each Flush.
internal static readonly bool CpuPhaseEnabled =
Environment.GetEnvironmentVariable("ACDREAM_FPS_PROF") is "1" or "2";
private static readonly Dictionary<string, (double sum, int n)> _cpuPhase = new();
private static readonly object _cpLock = new();
internal static void AddCpuPhase(string name, double ms)
{
lock (_cpLock)
{
var cur = _cpuPhase.TryGetValue(name, out var v) ? v : (sum: 0.0, n: 0);
_cpuPhase[name] = (cur.sum + ms, cur.n + 1);
}
}
/// <summary>Call at the very top of OnUpdate. Stamps the start of the update phase.</summary>
public void MarkUpdateStart() => _updateStartMs = _clock.Elapsed.TotalMilliseconds;
/// <summary>Call at the very top of OnRender, before any GL work.</summary>
public void BeginFrame()
{
if (!_queriesInit)
{
for (int i = 0; i < RingDepth; i++) _gpuQuery[i] = _gl.GenQuery();
_queriesInit = true;
}
// OnUpdate ran immediately before this; its duration ≈ render-start update-start.
double nowMs = _clock.Elapsed.TotalMilliseconds;
_lastUpdateMs = _updateStartMs > 0 ? nowMs - _updateStartMs : 0;
_cpuSw.Restart();
int slot = _frame % RingDepth;
_gl.BeginQuery(QueryTarget.TimeElapsed, _gpuQuery[slot]);
_begun[slot] = true;
}
/// <summary>Call at the very end of OnRender, after all GL work (incl. ImGui).</summary>
public void EndFrame(double wallMs, bool vsync, int msaa, double deltaSeconds)
{
_gl.EndQuery(QueryTarget.TimeElapsed);
_cpuSw.Stop();
double cpuMs = _cpuSw.Elapsed.TotalMilliseconds;
_vsync = vsync;
_msaa = msaa;
// Read the oldest ring slot (written RingDepth-1 frames ago, now ready).
int readSlot = (_frame + 1) % RingDepth;
if (_begun[readSlot])
{
_gl.GetQueryObject(_gpuQuery[readSlot], QueryObjectParameterName.ResultAvailable, out int avail);
if (avail != 0)
{
_gl.GetQueryObject(_gpuQuery[readSlot], QueryObjectParameterName.Result, out ulong ns);
_lastGpuMs = ns / 1_000_000.0;
}
}
// Present/swap/GPU-tail wait = whatever the frame period isn't update or render CPU.
double presentMs = Math.Max(0.0, wallMs - _lastUpdateMs - cpuMs);
if (_count < SampleCap)
{
_wallMs[_count] = wallMs;
_cpuMs[_count] = cpuMs;
_gpuMs[_count] = _lastGpuMs;
_updMs[_count] = _lastUpdateMs;
_presMs[_count] = presentMs;
_count++;
}
_frame++;
_accumSeconds += deltaSeconds;
if (_accumSeconds >= FlushSeconds)
{
Flush();
_accumSeconds = 0;
_count = 0;
}
}
private void Flush()
{
if (_count == 0) return;
_flushFrames = _count;
var (wP50, wP95, wMin, wMax) = Stats(_wallMs, _count);
var (cP50, cP95, _, cMax) = Stats(_cpuMs, _count);
var (gP50, gP95, _, gMax) = Stats(_gpuMs, _count);
var (uP50, uP95, _, uMax) = Stats(_updMs, _count);
var (pP50, pP95, _, pMax) = Stats(_presMs, _count);
double fpsP50 = wP50 > 0 ? 1000.0 / wP50 : 0;
double fpsLow = wMax > 0 ? 1000.0 / wMax : 0; // worst frame → lowest fps
Console.WriteLine(
$"[FPS-PROF] n={_count} vsync={(_vsync ? "ON" : "off")} msaa={_msaa}x | "
+ $"wall={wP50:F1}/{wP95:F1}/{wMin:F1}/{wMax:F1} ms (fps {fpsP50:F0} p50, {fpsLow:F0} low)\n"
+ $" update={uP50:F1}/{uP95:F1} ms (max {uMax:F1}) | "
+ $"cpuRender={cP50:F1}/{cP95:F1} ms (max {cMax:F1}) | "
+ $"present(wait)={pP50:F1}/{pP95:F1} ms (max {pMax:F1}) | "
+ $"gpu={gP50:F1}/{gP95:F1} ms (max {gMax:F1})");
lock (_rgLock)
{
if (_rendererGpu.Count > 0)
{
var parts = _rendererGpu
.OrderByDescending(kv => kv.Value.sum)
.Select(kv => $"{kv.Key}={kv.Value.sum / Math.Max(1, _flushFrames):F2}ms/frame (calls/frame={kv.Value.n / (double)Math.Max(1, _flushFrames):F1})");
Console.WriteLine("[PASS-GPU] (glFinish, frame time inflated) " + string.Join(" ", parts));
_rendererGpu.Clear();
}
}
lock (_cpLock)
{
if (_cpuPhase.Count > 0)
{
var parts = _cpuPhase
.OrderByDescending(kv => kv.Value.sum)
.Select(kv => $"{kv.Key}={kv.Value.sum / Math.Max(1, _flushFrames):F2}ms/frame (calls/frame={kv.Value.n / (double)Math.Max(1, _flushFrames):F1})");
Console.WriteLine("[CPU-PHASE] (DrawInside CPU ms/frame; =2 no-glFinish) " + string.Join(" ", parts));
_cpuPhase.Clear();
}
}
}
private static (double p50, double p95, double min, double max) Stats(double[] src, int n)
{
var buf = new double[n];
Array.Copy(src, buf, n);
Array.Sort(buf);
double p50 = buf[(int)(n * 0.50)];
double p95 = buf[Math.Min(n - 1, (int)(n * 0.95))];
return (p50, p95, buf[0], buf[n - 1]);
}
}

View file

@ -62,20 +62,6 @@ public sealed class GameWindow : IDisposable
private double _lastFps = 60.0;
private double _lastFrameMs = 16.7;
// THROWAWAY FPS-investigation apparatus (2026-06-23):
// frame-level CPU/GPU/wall profiler to find the dense-town bottleneck. See
// FrameProfiler. Lazy-constructed on first OnRender once _gl is live.
// ACDREAM_FPS_PROF=1 — whole-frame query + per-pass glFinish brackets
// ([PASS-GPU]); the glFinish SERIALIZES the pipe so cpuRender/gpu/wall
// collapse together — relative per-pass attribution only.
// ACDREAM_FPS_PROF=2 — whole-frame TimeElapsed query ONLY, NO per-pass
// glFinish (PassGpuEnabled stays "1"-gated). This is the honest CPU-vs-GPU
// split: gpu≈wall+present>0 ⇒ GPU-bound; cpuRender≈wall+present≈0 ⇒ CPU-bound.
private readonly bool _fpsProf =
Environment.GetEnvironmentVariable("ACDREAM_FPS_PROF") is "1" or "2";
private FrameProfiler? _frameProfiler;
private int _msaaSamples;
// Phase I.2: per-frame counters surfaced through the ImGui DebugPanel
// VM closures. Computed once per render pass alongside the frustum
// walk + nearest-object scan; the VM closures just read the cached
@ -990,8 +976,6 @@ public sealed class GameWindow : IDisposable
var startupDisplay = startupStore.LoadDisplay();
var startupBase = AcDream.UI.Abstractions.Settings.QualitySettings.From(startupDisplay.Quality);
var startupQuality = AcDream.UI.Abstractions.Settings.QualitySettings.WithEnvOverrides(startupBase);
_msaaSamples = startupQuality.MsaaSamples; // ACDREAM_FPS_PROF apparatus
var options = WindowOptions.Default with
{
Size = new Vector2D<int>(1280, 720),
@ -7628,11 +7612,6 @@ public sealed class GameWindow : IDisposable
private void OnUpdate(double dt)
{
// THROWAWAY FPS apparatus (ACDREAM_FPS_PROF=1): stamp the start of the
// update phase so the profiler can split frame time into update vs render
// vs present. Robust to early-returns below (no matching EndUpdate needed).
if (_fpsProf) _frameProfiler?.MarkUpdateStart();
// [FRAME-DIAG]: applies run later this frame inside _streamingController.Tick;
// flush the PREVIOUS OnUpdate's accumulated apply cost here (a clean per-frame
// boundary, independent of where in OnUpdate the applies landed) and reset.
@ -8367,14 +8346,6 @@ public sealed class GameWindow : IDisposable
private void OnRender(double deltaSeconds)
{
// THROWAWAY FPS apparatus (ACDREAM_FPS_PROF=1): bracket the whole frame's
// CPU (this method) + GPU (TimeElapsed query) work. Begin before any GL.
if (_fpsProf && _gl is not null)
{
_frameProfiler ??= new FrameProfiler(_gl);
_frameProfiler.BeginFrame();
}
// Phase G.1: set the clear color from the current sky's fog
// tint so the horizon band continues naturally past the
// rendered geometry. Fog blends to this color at max distance
@ -9427,11 +9398,6 @@ public sealed class GameWindow : IDisposable
_imguiBootstrap.Render();
}
// THROWAWAY FPS apparatus (ACDREAM_FPS_PROF=1): close the frame's CPU+GPU
// brackets after ALL GL work (incl. ImGui). wall = the real frame period.
if (_fpsProf && _frameProfiler is not null)
_frameProfiler.EndFrame(deltaSeconds * 1000.0, _window!.VSync, _msaaSamples, deltaSeconds);
// Update the window title with performance stats every ~0.5s.
_perfAccum += deltaSeconds;
_perfFrameCount++;
@ -10798,15 +10764,9 @@ public sealed class GameWindow : IDisposable
AcDream.Core.Vfx.ParticleRenderPass.SkyPreScene);
EnableClipDistances();
// THROWAWAY FPS apparatus: glFinish-bracket the PER-SLICE terrain draw so
// [PASS-GPU] reports terrain ms/frame + calls/frame (= slice count). This
// is the suspected multiplier: terrain is redrawn fully once per slice.
System.Diagnostics.Stopwatch? _terrGpuSw = null;
if (FrameProfiler.PassGpuEnabled) { _gl!.Finish(); _terrGpuSw = System.Diagnostics.Stopwatch.StartNew(); }
_terrainCpuStopwatch.Restart();
_terrain?.Draw(camera, frustum, neverCullLandblockId: playerLb);
_terrainCpuStopwatch.Stop();
if (_terrGpuSw is not null) { _gl!.Finish(); FrameProfiler.AddRendererGpu("terrain", _terrGpuSw.Elapsed.TotalMilliseconds); }
_terrainCpuSamples[_terrainCpuSampleCursor] =
(long)(_terrainCpuStopwatch.Elapsed.TotalMicroseconds * 100.0);
_terrainCpuSampleCursor = (_terrainCpuSampleCursor + 1) % _terrainCpuSamples.Length;

View file

@ -123,11 +123,6 @@ public sealed unsafe class ParticleRenderer : IDisposable
ParticleRenderPass renderPass = ParticleRenderPass.Scene,
Func<AcDream.Core.Vfx.ParticleEmitter, bool>? emitterFilter = null)
{
// THROWAWAY FPS apparatus: glFinish-bracket particle GPU (ACDREAM_FPS_PROF).
System.Diagnostics.Stopwatch? _pSw = null;
if (AcDream.App.Rendering.FrameProfiler.PassGpuEnabled) { _gl.Finish(); _pSw = System.Diagnostics.Stopwatch.StartNew(); }
try
{
if (particles is null || camera is null)
return;
@ -173,15 +168,6 @@ public sealed unsafe class ParticleRenderer : IDisposable
_gl.BindVertexArray(0);
_gl.DepthMask(true);
_gl.Disable(EnableCap.Blend);
}
finally
{
if (_pSw is not null)
{
_gl.Finish();
AcDream.App.Rendering.FrameProfiler.AddRendererGpu("particles", _pSw.Elapsed.TotalMilliseconds);
}
}
}
private List<ParticleDraw> BuildDrawList(

View file

@ -208,12 +208,6 @@ void main() { } // depth-only: color writes are masked off by the caller state
ReadOnlySpan<Vector4> planes,
bool forceFarZ)
{
// THROWAWAY FPS apparatus: glFinish-bracket each punch/seal fan (accumulated
// into "punchseal") under ACDREAM_FPS_PROF.
System.Diagnostics.Stopwatch? _fSw = null;
if (AcDream.App.Rendering.FrameProfiler.PassGpuEnabled) { _gl.Finish(); _fSw = System.Diagnostics.Stopwatch.StartNew(); }
try
{
if (worldVerts.Length < 3)
return;
int n = Math.Min(worldVerts.Length, MaxFanVerts);
@ -311,15 +305,6 @@ void main() { } // depth-only: color writes are masked off by the caller state
_gl.CullFace(TriangleFace.Back);
_gl.FrontFace(FrontFaceDirection.CW);
_gl.UseProgram(0);
}
finally
{
if (_fSw is not null)
{
_gl.Finish();
AcDream.App.Rendering.FrameProfiler.AddRendererGpu("punchseal", _fSw.Elapsed.TotalMilliseconds);
}
}
}
public void Dispose()

View file

@ -65,20 +65,6 @@ public sealed class RetailPViewRenderer
{
ArgumentNullException.ThrowIfNull(ctx);
// THROWAWAY CPU sub-phase timing (ACDREAM_FPS_PROF=2 clean-split): attribute
// which CPU phase of DrawInside eats the dense-town frame. Strip with the FPS
// apparatus (plan Task 5). Zero-alloc: GetTimestamp/GetElapsedTime + a direct-
// call local fn (struct closure over _ts, never a delegate).
long _ts = System.Diagnostics.Stopwatch.GetTimestamp();
FrameProfiler.MarkGpu("_start"); // GPU timestamp baseline (=2; CPU-only phases diff ~0)
void Phase(string n)
{
if (FrameProfiler.CpuPhaseEnabled)
FrameProfiler.AddCpuPhase(n, System.Diagnostics.Stopwatch.GetElapsedTime(_ts).TotalMilliseconds);
FrameProfiler.MarkGpu(n);
_ts = System.Diagnostics.Stopwatch.GetTimestamp();
}
var pvFrame = PortalVisibilityBuilder.Build(
ctx.RootCell,
ctx.ViewerEyePos,
@ -115,11 +101,9 @@ public sealed class RetailPViewRenderer
&& ctx.NearbyBuildingCells is not null
&& pvFrame.OutsideView.Polygons.Count > 0)
BuildInteriorRootLookIns(ctx, pvFrame);
Phase("flood");
var clipAssembly = ClipFrameAssembler.Assemble(_clipFrame, pvFrame);
UploadClipFrame(ctx.SetTerrainClipUbo);
Phase("assemble");
// R1: draw EVERY visible cell (retail cell_draw_list), not only the cells the
// assembler handed a clip-slot. This feeds the Prepare filter + entity partition,
@ -152,7 +136,6 @@ public sealed class RetailPViewRenderer
centerLbX: ctx.RenderCenterLbX,
centerLbY: ctx.RenderCenterLbY,
renderRadius: ctx.RenderRadius);
Phase("prepare");
var partition = InteriorEntityPartition.Partition(prepareCells, ctx.LandblockEntries);
var result = new RetailPViewFrameResult
@ -206,18 +189,12 @@ public sealed class RetailPViewRenderer
}
}
Phase("partition");
DrawLandscapeThroughOutsideView(ctx, clipAssembly, partition, viewcone);
Phase("landscape");
UseIndoorMembershipOnlyRouting();
DrawExitPortalMasks(ctx, pvFrame, clipAssembly, drawableCells);
Phase("portalmask");
DrawEnvCellShells(pvFrame);
Phase("shells");
DrawCellObjectLists(ctx, pvFrame, clipAssembly, drawableCells, partition, viewcone);
Phase("cellobjects");
DrawDynamicsLast(ctx, partition, viewcone, ctx.RootCell.IsOutdoorNode);
Phase("dynamics");
return result;
}

View file

@ -836,18 +836,6 @@ public sealed unsafe class EnvCellRenderer : IDisposable
/// </summary>
public void Render(WbRenderPass renderPass, HashSet<uint>? filter)
{
// THROWAWAY FPS apparatus (ACDREAM_FPS_PROF=1): glFinish-bracket this cell
// draw so the profiler can attribute its exact GPU cost. Serializes the
// pipeline (inflates frame time) but isolates cell-draw GPU at a held view.
System.Diagnostics.Stopwatch? _passSw = null;
if (AcDream.App.Rendering.FrameProfiler.PassGpuEnabled)
{
_gl.Finish();
_passSw = System.Diagnostics.Stopwatch.StartNew();
}
try
{
// WB EnvCellRenderManager.cs:400:
if (!_initialized || _shader is null || _shader.Program == 0) return;
@ -1042,15 +1030,6 @@ public sealed unsafe class EnvCellRenderer : IDisposable
System.Console.WriteLine(sb.ToString());
}
}
}
finally
{
if (_passSw is not null)
{
_gl.Finish();
AcDream.App.Rendering.FrameProfiler.AddRendererGpu("cells", _passSw.Elapsed.TotalMilliseconds);
}
}
}
/// <summary>