acdream/docs/superpowers/plans/2026-07-05-mp0-frame-profiler.md
Erik 2757dda63a docs(pipeline): MP0 implementation plan - frame profiler + baseline capture
Five bite-sized tasks: FrameStatsBuffer (TDD), FrameProfEnabled flag +
GpuFrameTimer TimeElapsed ring, FrameProfiler facade (TDD on the report
formatter), GameWindow wiring (one boundary call + three stage scopes)
with DebugPanel mirror, and the user-driven baseline capture that gates
MP1. Records two spec deviations: GPU per-stage timestamps deferred
(frame is CPU-bound at ~0.5ms GPU), and the toggle lives in
RenderingDiagnostics per the diagnostic-owner rule, not RuntimeOptions.
Encodes the discovered GL constraint: whole-frame TimeElapsed is
mutually exclusive with ACDREAM_WB_DIAG per-pass queries.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-05 19:03:59 +02:00

754 lines
31 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

# MP0 — Honest Frame Profiler + Baseline Capture Implementation Plan
> **For agentic workers:** REQUIRED SUB-SKILL: Use superpowers:subagent-driven-development (recommended) or superpowers:executing-plans to implement this plan task-by-task. Steps use checkbox (`- [ ]`) syntax for tracking.
**Goal:** Build the permanent frame profiler (CPU frame time, GPU frame time, per-stage CPU attribution, per-frame allocation) and capture the MP baseline report that gates the rest of the Modern Pipeline track.
**Architecture:** A pure, unit-testable stats core (`FrameStatsBuffer`) + a GL query wrapper (`GpuFrameTimer`) + a facade (`FrameProfiler`) wired into `GameWindow` at exactly one frame-boundary call plus three stage scopes. Toggle lives in `RenderingDiagnostics` (the established diagnostic-owner pattern), mirrored in the DebugPanel. Spec: `docs/superpowers/specs/2026-07-05-modern-pipeline-design.md` §5.
**Tech Stack:** .NET 10, Silk.NET OpenGL (`QueryTarget.TimeElapsed` ring, mirroring `WbDrawDispatcher`'s existing idiom), xunit in `tests/AcDream.App.Tests`.
**Spec deviations (recorded):**
1. Spec §5 lists per-stage GPU attribution via `glQueryCounter` (GL_TIMESTAMP) markers. Deferred: the measured GPU total is ~0.5 ms (the frame is CPU-bound), so MP0 ships per-stage **CPU** attribution + whole-frame GPU only. GPU timestamps get added in the MP phase whose gate first needs GPU-side attribution (likely MP3).
2. The spec says "Toggles via `RuntimeOptions` + DebugPanel". `RuntimeOptions`' own doc comment says runtime diagnostic toggles belong in diagnostic owner classes, NOT RuntimeOptions ([RuntimeOptions.cs:13-19](../../src/AcDream.App/RuntimeOptions.cs)). We follow the codebase rule: the flag goes in `RenderingDiagnostics` (env-seeded, runtime-toggleable). No RuntimeOptions change.
**Hard GL constraint (discovered during planning):** GL forbids two simultaneously active `TimeElapsed` queries. `WbDrawDispatcher` already brackets its opaque/transparent passes with `TimeElapsed` queries when `ACDREAM_WB_DIAG=1` ([WbDrawDispatcher.cs:1642](../../src/AcDream.App/Rendering/Wb/WbDrawDispatcher.cs)). Therefore the profiler's whole-frame GPU query is **disabled (with a one-time console notice) when `ACDREAM_WB_DIAG=1`**. This is also the 2026-06-23 measurement lesson (separate flags for whole-frame vs per-pass) enforced in code.
**Threading assumption:** Silk.NET drives `OnUpdate` and `OnRender` on the same loop thread in this app. `FrameProfiler` captures the first caller's managed thread id and emits a one-time warning if any later call arrives on a different thread (guards the `GC.GetAllocatedBytesForCurrentThread` validity).
---
## File map
| File | Action | Responsibility |
|---|---|---|
| `src/AcDream.App/Diagnostics/FrameStatsBuffer.cs` | Create | Pure ring-buffer stats: samples, percentiles, stage accumulators, report line. Zero GL, zero statics. |
| `src/AcDream.App/Diagnostics/GpuFrameTimer.cs` | Create | GL `TimeElapsed` query ring (depth 4, `Begun` flags per the #125 lesson). |
| `src/AcDream.App/Diagnostics/FrameProfiler.cs` | Create | Facade: frame boundary, stage scopes, GC counters, 5-second `[frame-prof]` report. |
| `src/AcDream.Core/Rendering/RenderingDiagnostics.cs` | Modify | Add `FrameProfEnabled` flag (env `ACDREAM_FRAME_PROF`). |
| `src/AcDream.App/Rendering/GameWindow.cs` | Modify | One field + one call at `OnRender` top (~:8757), stage scope around `_wbMeshAdapter?.Tick()` (~:8813), around `_imguiBootstrap.Render()` (~:9821), and at `OnUpdate` top (~:7952). Wiring only — no logic in GameWindow. |
| `src/AcDream.UI.Abstractions/Panels/Debug/DebugVM.cs` | Modify | `FrameProf` mirror property (copy the `ProbeResolve` pattern at :248). |
| `src/AcDream.UI.ImGui/` (renderer for DebugPanel) | Modify | Checkbox for the mirror (locate via `grep -rn "ProbeResolve" src/AcDream.UI.ImGui/`). |
| `tests/AcDream.App.Tests/FrameStatsBufferTests.cs` | Create | Percentiles, ring wrap, stage reset, report format. |
| `docs/research/2026-07-XX-mp0-baseline.md` | Create (Task 5) | The baseline report — MP0's deliverable. |
Line numbers drift; match by the quoted anchor code, not the number.
---
### Task 1: FrameStatsBuffer (pure stats core, TDD)
**Files:**
- Create: `src/AcDream.App/Diagnostics/FrameStatsBuffer.cs`
- Test: `tests/AcDream.App.Tests/FrameStatsBufferTests.cs`
- [ ] **Step 1: Write the failing tests**
```csharp
using AcDream.App.Diagnostics;
using Xunit;
namespace AcDream.App.Tests;
public class FrameStatsBufferTests
{
[Fact]
public void Percentiles_OnKnownDistribution_AreExact()
{
var buf = new FrameStatsBuffer(capacity: 100);
// 1..100 µs — p50 = 50, p95 = 95, p99 = 99, max = 100.
for (long i = 1; i <= 100; i++) buf.Push(i);
Assert.Equal(50, buf.Percentile(0.50));
Assert.Equal(95, buf.Percentile(0.95));
Assert.Equal(99, buf.Percentile(0.99));
Assert.Equal(100, buf.Max());
}
[Fact]
public void Push_PastCapacity_KeepsOnlyNewestWindow()
{
var buf = new FrameStatsBuffer(capacity: 4);
foreach (long v in new long[] { 1000, 1000, 1000, 1000, 1, 2, 3, 4 })
buf.Push(v);
// The four 1000s were overwritten; window is {1,2,3,4}.
Assert.Equal(4, buf.Count);
Assert.Equal(4, buf.Max());
Assert.Equal(2, buf.Percentile(0.50));
}
[Fact]
public void Percentile_Empty_ReturnsZero()
{
var buf = new FrameStatsBuffer(capacity: 8);
Assert.Equal(0, buf.Percentile(0.95));
Assert.Equal(0, buf.Max());
Assert.Equal(0, buf.Count);
}
[Fact]
public void Reset_ClearsWindow()
{
var buf = new FrameStatsBuffer(capacity: 8);
buf.Push(5); buf.Push(7);
buf.Reset();
Assert.Equal(0, buf.Count);
Assert.Equal(0, buf.Percentile(0.5));
}
}
```
- [ ] **Step 2: Run tests to verify they fail**
Run: `dotnet test tests/AcDream.App.Tests --filter FrameStatsBufferTests -v minimal`
Expected: FAIL — `FrameStatsBuffer` does not exist (compile error).
- [ ] **Step 3: Implement FrameStatsBuffer**
```csharp
using System;
namespace AcDream.App.Diagnostics;
/// <summary>
/// MP0 (2026-07-05) — fixed-capacity ring buffer of long samples
/// (microseconds or bytes) with percentile/max over the current window.
/// Pure and allocation-free after construction: <see cref="Percentile"/>
/// sorts into a preallocated scratch array, so the 5-second report path
/// allocates nothing. Not thread-safe — owned by the window loop thread.
/// Spec: docs/superpowers/specs/2026-07-05-modern-pipeline-design.md §5.
/// </summary>
public sealed class FrameStatsBuffer
{
private readonly long[] _samples;
private readonly long[] _scratch;
private int _cursor;
private int _count;
public FrameStatsBuffer(int capacity)
{
if (capacity <= 0) throw new ArgumentOutOfRangeException(nameof(capacity));
_samples = new long[capacity];
_scratch = new long[capacity];
}
public int Count => _count;
public void Push(long value)
{
_samples[_cursor] = value;
_cursor = (_cursor + 1) % _samples.Length;
if (_count < _samples.Length) _count++;
}
public void Reset()
{
_cursor = 0;
_count = 0;
}
/// <summary>
/// Nearest-rank percentile over the current window: element at
/// ceil(q·n) in the ascending sort (1-based), 0 when empty.
/// </summary>
public long Percentile(double q)
{
if (_count == 0) return 0;
Array.Copy(_samples, _scratch, _count);
Array.Sort(_scratch, 0, _count);
int rank = (int)Math.Ceiling(q * _count); // 1-based nearest rank
if (rank < 1) rank = 1;
if (rank > _count) rank = _count;
return _scratch[rank - 1];
}
public long Max()
{
long max = 0;
for (int i = 0; i < _count; i++)
if (_samples[i] > max) max = _samples[i];
return max;
}
}
```
- [ ] **Step 4: Run tests to verify they pass**
Run: `dotnet test tests/AcDream.App.Tests --filter FrameStatsBufferTests -v minimal`
Expected: 4 passed.
- [ ] **Step 5: Commit**
```bash
git add src/AcDream.App/Diagnostics/FrameStatsBuffer.cs tests/AcDream.App.Tests/FrameStatsBufferTests.cs
git commit -m "feat(pipeline): MP0 - FrameStatsBuffer ring/percentile core"
```
---
### Task 2: RenderingDiagnostics flag + GpuFrameTimer
**Files:**
- Modify: `src/AcDream.Core/Rendering/RenderingDiagnostics.cs` (append inside the class, before the closing brace)
- Create: `src/AcDream.App/Diagnostics/GpuFrameTimer.cs`
- [ ] **Step 1: Add the flag to RenderingDiagnostics**
Append inside `public static class RenderingDiagnostics` (after `ShouldRenderIndoor`, before the final `}`):
```csharp
/// <summary>
/// MP0 (2026-07-05) — master toggle for the permanent frame profiler
/// (<c>AcDream.App.Diagnostics.FrameProfiler</c>): CPU frame time
/// (swap-to-swap), whole-frame GPU time, per-stage CPU attribution,
/// per-frame allocation counters, reported as one <c>[frame-prof]</c>
/// line every ~5 s. Permanent apparatus (every MP-track gate reads it) —
/// do NOT strip with session probes. The whole-frame GPU query is
/// self-disabled while <c>ACDREAM_WB_DIAG=1</c> (GL forbids nested
/// TimeElapsed queries; WbDrawDispatcher owns per-pass queries under
/// that flag — the 2026-06-23 "separate flags" measurement lesson).
/// Initial state from <c>ACDREAM_FRAME_PROF=1</c>; runtime-toggleable
/// via the DebugPanel mirror (<c>DebugVM.FrameProf</c>).
/// Spec: docs/superpowers/specs/2026-07-05-modern-pipeline-design.md §5.
/// </summary>
public static bool FrameProfEnabled { get; set; } =
Environment.GetEnvironmentVariable("ACDREAM_FRAME_PROF") == "1";
```
- [ ] **Step 2: Create GpuFrameTimer**
```csharp
using System;
using Silk.NET.OpenGL;
namespace AcDream.App.Diagnostics;
/// <summary>
/// MP0 (2026-07-05) — whole-frame GPU time via a ring of
/// <see cref="QueryTarget.TimeElapsed"/> queries (depth 4, so results are
/// read ~3 frames late and never stall). Mirrors WbDrawDispatcher's query
/// idiom including the #125 lesson: a glGenQueries name is not a query
/// OBJECT until first glBeginQuery, so never-begun slots are skipped via
/// the Begun flags.
///
/// <para>MUST NOT be active while ACDREAM_WB_DIAG=1: GL forbids two
/// simultaneously active TimeElapsed queries and WbDrawDispatcher brackets
/// its passes with them under that flag. The caller (FrameProfiler)
/// enforces the exclusion; this class just does the ring.</para>
/// </summary>
internal sealed class GpuFrameTimer : IDisposable
{
private const int RingDepth = 4;
private readonly GL _gl;
private readonly uint[] _queries = new uint[RingDepth];
private readonly bool[] _begun = new bool[RingDepth];
private int _frameIndex;
private bool _queryActive;
public GpuFrameTimer(GL gl)
{
_gl = gl ?? throw new ArgumentNullException(nameof(gl));
for (int i = 0; i < RingDepth; i++)
_queries[i] = _gl.GenQuery();
}
/// <summary>
/// Call once per frame at the frame boundary. Ends the previous
/// frame's query, polls the oldest slot non-blocking, begins this
/// frame's query. Returns the completed GPU time in microseconds for
/// a ~RingDepth-frames-old frame, or null when no result is ready.
/// </summary>
public long? FrameBoundary()
{
if (_queryActive)
{
_gl.EndQuery(QueryTarget.TimeElapsed);
_queryActive = false;
}
long? completedUs = null;
int readSlot = _frameIndex % RingDepth; // about to be reused — oldest
if (_begun[readSlot])
{
_gl.GetQueryObject(_queries[readSlot], QueryObjectParameterName.ResultAvailable, out int avail);
if (avail != 0)
{
_gl.GetQueryObject(_queries[readSlot], QueryObjectParameterName.Result, out ulong ns);
completedUs = (long)(ns / 1000UL);
}
// Not available ⇒ sample silently dropped (same policy as
// WbDrawDispatcher) — percentiles tolerate missing samples.
}
_gl.BeginQuery(QueryTarget.TimeElapsed, _queries[readSlot]);
_begun[readSlot] = true;
_queryActive = true;
_frameIndex++;
return completedUs;
}
/// <summary>End any active query without beginning a new one (used when the profiler is toggled off mid-session).</summary>
public void Stop()
{
if (_queryActive)
{
_gl.EndQuery(QueryTarget.TimeElapsed);
_queryActive = false;
}
}
public void Dispose()
{
Stop();
for (int i = 0; i < RingDepth; i++)
_gl.DeleteQuery(_queries[i]);
}
}
```
Note: `_gl.GenQuery()` / `_gl.DeleteQuery(uint)` are the Silk.NET single-name helpers; if this overload doesn't resolve on the project's Silk.NET version, use the array forms exactly as `WbDrawDispatcher` does (`grep -n "GenQueries" src/AcDream.App/Rendering/Wb/WbDrawDispatcher.cs`) and copy that call shape.
- [ ] **Step 3: Build**
Run: `dotnet build`
Expected: green (no tests possible for the GL class headless; correctness rides on the copied WbDrawDispatcher idiom + Task 5's live run).
- [ ] **Step 4: Commit**
```bash
git add src/AcDream.Core/Rendering/RenderingDiagnostics.cs src/AcDream.App/Diagnostics/GpuFrameTimer.cs
git commit -m "feat(pipeline): MP0 - FrameProfEnabled flag + GPU TimeElapsed ring"
```
---
### Task 3: FrameProfiler facade
**Files:**
- Create: `src/AcDream.App/Diagnostics/FrameProfiler.cs`
- Test: `tests/AcDream.App.Tests/FrameProfilerReportTests.cs`
- [ ] **Step 1: Write the failing test (report formatting is the testable part)**
```csharp
using AcDream.App.Diagnostics;
using Xunit;
namespace AcDream.App.Tests;
public class FrameProfilerReportTests
{
[Fact]
public void FormatReport_IsInvariantAndComplete()
{
var cpu = new FrameStatsBuffer(16);
var gpu = new FrameStatsBuffer(16);
var alloc = new FrameStatsBuffer(16);
var stages = new[] { new FrameStatsBuffer(16), new FrameStatsBuffer(16), new FrameStatsBuffer(16) };
for (long i = 1; i <= 10; i++)
{
cpu.Push(i * 1000); // 1..10 ms in µs
gpu.Push(i * 100);
alloc.Push(i * 1024); // bytes
stages[0].Push(i * 200);
stages[1].Push(i * 50);
stages[2].Push(i * 10);
}
string line = FrameProfiler.FormatReport(
frameCount: 10, cpu: cpu, gpu: gpu, gpuActive: true,
alloc: alloc, gc0: 3, gc1: 1, gc2: 0, stages: stages);
Assert.StartsWith("[frame-prof]", line);
Assert.Contains("n=10", line);
Assert.Contains("cpu_ms p50=5.0 p95=10.0 p99=10.0 max=10.0", line);
Assert.Contains("gpu_ms p50=0.5", line);
Assert.Contains("alloc_kb p50=5.0 max=10.0", line);
Assert.Contains("gc=3/1/0", line);
Assert.Contains("upd p50=1.0", line); // stage 0: 200µs·5 = 1.0 ms
Assert.DoesNotContain(",0", line.Replace("gc=3/1/0", "")); // no comma decimals (invariant culture)
}
[Fact]
public void FormatReport_GpuInactive_SaysWhy()
{
var empty = new FrameStatsBuffer(4);
string line = FrameProfiler.FormatReport(
frameCount: 0, cpu: empty, gpu: empty, gpuActive: false,
alloc: empty, gc0: 0, gc1: 0, gc2: 0,
stages: new[] { empty, empty, empty });
Assert.Contains("gpu=off(wbdiag)", line);
}
}
```
- [ ] **Step 2: Run tests to verify they fail**
Run: `dotnet test tests/AcDream.App.Tests --filter FrameProfilerReportTests -v minimal`
Expected: FAIL — `FrameProfiler` does not exist.
- [ ] **Step 3: Implement FrameProfiler**
```csharp
using System;
using System.Diagnostics;
using System.Globalization;
using System.Text;
using AcDream.Core.Rendering;
using Silk.NET.OpenGL;
namespace AcDream.App.Diagnostics;
/// <summary>Stage indices for per-frame CPU attribution.</summary>
public enum FrameStage
{
/// <summary>Whole OnUpdate body (simulation + streaming apply).</summary>
Update = 0,
/// <summary>WbMeshAdapter.Tick — staged mesh/texture GPU upload drain.</summary>
Upload = 1,
/// <summary>ImGui Render (dev overlay).</summary>
ImGui = 2,
}
/// <summary>
/// MP0 (2026-07-05) — the permanent honest frame profiler. One
/// <c>FrameBoundary</c> call at the top of <c>GameWindow.OnRender</c>
/// measures CPU frame time as the delta between consecutive boundaries
/// (captures the FULL frame including present), brackets the frame in a
/// GPU <c>TimeElapsed</c> query (via <see cref="GpuFrameTimer"/>), and
/// samples per-frame allocated bytes + GC collection counts. Stage scopes
/// (<see cref="BeginStage"/>) attribute CPU time to Update / Upload /
/// ImGui. Emits one <c>[frame-prof]</c> line every ~5 s while
/// <see cref="RenderingDiagnostics.FrameProfEnabled"/> is true; costs one
/// bool check per frame when off.
///
/// <para>Permanent apparatus — every MP-track gate reads it; do not strip.
/// Whole-frame GPU timing self-disables under <c>ACDREAM_WB_DIAG=1</c>
/// (nested TimeElapsed is illegal GL; see GpuFrameTimer).</para>
/// Spec: docs/superpowers/specs/2026-07-05-modern-pipeline-design.md §5.
/// </summary>
public sealed class FrameProfiler : IDisposable
{
private const int WindowCapacity = 2048; // ~12 s at 165 fps
private const long ReportIntervalTicks = 5 * TimeSpan.TicksPerSecond;
private static readonly int StageCount = Enum.GetValues<FrameStage>().Length;
private readonly FrameStatsBuffer _cpuUs = new(WindowCapacity);
private readonly FrameStatsBuffer _gpuUs = new(WindowCapacity);
private readonly FrameStatsBuffer _allocBytes = new(WindowCapacity);
private readonly FrameStatsBuffer[] _stageUs;
private readonly long[] _stageAccumTicks;
private readonly bool _wbDiagActive =
Environment.GetEnvironmentVariable("ACDREAM_WB_DIAG") == "1";
private GpuFrameTimer? _gpuTimer;
private long _lastBoundaryTimestamp;
private long _lastAllocBytes;
private long _lastReportTicks;
private int _gc0Base, _gc1Base, _gc2Base;
private int _framesInWindow;
private int _ownerThreadId;
private bool _threadWarned;
private bool _wbDiagNoticePrinted;
private bool _wasEnabled;
public FrameProfiler()
{
_stageUs = new FrameStatsBuffer[StageCount];
for (int i = 0; i < StageCount; i++) _stageUs[i] = new FrameStatsBuffer(WindowCapacity);
_stageAccumTicks = new long[StageCount];
}
/// <summary>
/// Call as the FIRST statement of <c>GameWindow.OnRender</c>.
/// </summary>
public void FrameBoundary(GL gl)
{
bool enabled = RenderingDiagnostics.FrameProfEnabled;
if (!enabled)
{
if (_wasEnabled) { _gpuTimer?.Stop(); _wasEnabled = false; _lastBoundaryTimestamp = 0; }
return;
}
if (_ownerThreadId == 0) _ownerThreadId = Environment.CurrentManagedThreadId;
else if (!_threadWarned && _ownerThreadId != Environment.CurrentManagedThreadId)
{
_threadWarned = true;
Console.WriteLine("[frame-prof] WARNING: frame boundary crossed threads; alloc counter is per-thread and now unreliable");
}
long now = Stopwatch.GetTimestamp();
long allocNow = GC.GetAllocatedBytesForCurrentThread();
if (!_wasEnabled)
{
// First enabled frame (startup or runtime toggle-on): establish
// baselines, emit nothing.
_wasEnabled = true;
_lastReportTicks = DateTime.UtcNow.Ticks;
_gc0Base = GC.CollectionCount(0); _gc1Base = GC.CollectionCount(1); _gc2Base = GC.CollectionCount(2);
if (_gpuTimer is null && !_wbDiagActive) _gpuTimer = new GpuFrameTimer(gl);
if (_wbDiagActive && !_wbDiagNoticePrinted)
{
_wbDiagNoticePrinted = true;
Console.WriteLine("[frame-prof] GPU frame timing OFF: ACDREAM_WB_DIAG=1 owns TimeElapsed queries (nested queries are illegal GL)");
}
}
else
{
long cpuUs = (now - _lastBoundaryTimestamp) * 1_000_000L / Stopwatch.Frequency;
_cpuUs.Push(cpuUs);
_allocBytes.Push(allocNow - _lastAllocBytes);
for (int i = 0; i < StageCount; i++)
{
_stageUs[i].Push(_stageAccumTicks[i] * 1_000_000L / Stopwatch.Frequency);
_stageAccumTicks[i] = 0;
}
_framesInWindow++;
}
_lastBoundaryTimestamp = now;
_lastAllocBytes = allocNow;
if (_gpuTimer?.FrameBoundary() is long gpuUs)
_gpuUs.Push(gpuUs);
long nowTicks = DateTime.UtcNow.Ticks;
if (nowTicks - _lastReportTicks >= ReportIntervalTicks && _framesInWindow > 0)
{
int gc0 = GC.CollectionCount(0) - _gc0Base;
int gc1 = GC.CollectionCount(1) - _gc1Base;
int gc2 = GC.CollectionCount(2) - _gc2Base;
Console.WriteLine(FormatReport(_framesInWindow, _cpuUs, _gpuUs,
gpuActive: _gpuTimer is not null, _allocBytes, gc0, gc1, gc2, _stageUs));
_lastReportTicks = nowTicks;
_gc0Base += gc0; _gc1Base += gc1; _gc2Base += gc2;
_framesInWindow = 0;
_cpuUs.Reset(); _gpuUs.Reset(); _allocBytes.Reset();
for (int i = 0; i < StageCount; i++) _stageUs[i].Reset();
}
}
/// <summary>
/// Attribute the enclosed CPU time to <paramref name="stage"/>.
/// Usage: <c>using var _ = profiler.BeginStage(FrameStage.Update);</c>.
/// Zero-cost (default scope) when the profiler is off.
/// </summary>
public StageScope BeginStage(FrameStage stage)
=> RenderingDiagnostics.FrameProfEnabled
? new StageScope(this, stage, Stopwatch.GetTimestamp())
: default;
internal void EndStage(FrameStage stage, long startTimestamp)
=> _stageAccumTicks[(int)stage] += Stopwatch.GetTimestamp() - startTimestamp;
/// <summary>Pure report formatter — unit-tested; invariant culture.</summary>
public static string FormatReport(
int frameCount,
FrameStatsBuffer cpu, FrameStatsBuffer gpu, bool gpuActive,
FrameStatsBuffer alloc, int gc0, int gc1, int gc2,
FrameStatsBuffer[] stages)
{
var ci = CultureInfo.InvariantCulture;
var sb = new StringBuilder(256);
sb.Append("[frame-prof] n=").Append(frameCount);
sb.AppendFormat(ci, " | cpu_ms p50={0:0.0} p95={1:0.0} p99={2:0.0} max={3:0.0}",
cpu.Percentile(0.50) / 1000.0, cpu.Percentile(0.95) / 1000.0,
cpu.Percentile(0.99) / 1000.0, cpu.Max() / 1000.0);
if (gpuActive)
sb.AppendFormat(ci, " | gpu_ms p50={0:0.0} p95={1:0.0}",
gpu.Percentile(0.50) / 1000.0, gpu.Percentile(0.95) / 1000.0);
else
sb.Append(" | gpu=off(wbdiag)");
sb.AppendFormat(ci, " | alloc_kb p50={0:0.0} max={1:0.0} gc={2}/{3}/{4}",
alloc.Percentile(0.50) / 1024.0, alloc.Max() / 1024.0, gc0, gc1, gc2);
string[] names = { "upd", "upl", "imgui" };
for (int i = 0; i < stages.Length && i < names.Length; i++)
sb.AppendFormat(ci, " | {0} p50={1:0.0} p95={2:0.0}",
names[i], stages[i].Percentile(0.50) / 1000.0, stages[i].Percentile(0.95) / 1000.0);
return sb.ToString();
}
public void Dispose() => _gpuTimer?.Dispose();
}
/// <summary>Disposable stage scope; default instance is a no-op.</summary>
public readonly struct StageScope : IDisposable
{
private readonly FrameProfiler? _owner;
private readonly FrameStage _stage;
private readonly long _start;
internal StageScope(FrameProfiler owner, FrameStage stage, long start)
{
_owner = owner; _stage = stage; _start = start;
}
public void Dispose() => _owner?.EndStage(_stage, _start);
}
```
- [ ] **Step 4: Run tests to verify they pass**
Run: `dotnet test tests/AcDream.App.Tests --filter FrameProfilerReportTests -v minimal`
Expected: 2 passed. (If the `,0` invariant assertion trips on stage names, adjust only the assertion's exclusion — the formatter must keep `CultureInfo.InvariantCulture` everywhere.)
- [ ] **Step 5: Commit**
```bash
git add src/AcDream.App/Diagnostics/FrameProfiler.cs tests/AcDream.App.Tests/FrameProfilerReportTests.cs
git commit -m "feat(pipeline): MP0 - FrameProfiler facade (CPU/GPU/alloc/stages, 5s report)"
```
---
### Task 4: GameWindow wiring + DebugPanel mirror
**Files:**
- Modify: `src/AcDream.App/Rendering/GameWindow.cs`
- Modify: `src/AcDream.UI.Abstractions/Panels/Debug/DebugVM.cs`
- Modify: the DebugPanel ImGui renderer (locate in step 4)
- [ ] **Step 1: Add the field and frame-boundary call**
Near GameWindow's other diagnostic fields (search for `_frameDiag` field declaration to co-locate):
```csharp
// MP0 (2026-07-05): permanent frame profiler — one FrameBoundary call
// per OnRender + three stage scopes. All logic lives in
// AcDream.App.Diagnostics.FrameProfiler (structure rule 1).
private readonly AcDream.App.Diagnostics.FrameProfiler _frameProfiler = new();
```
At the very top of `OnRender` (anchor: `private void OnRender(double deltaSeconds)` ~line 8756 — the call goes BEFORE the `var kf = WorldTime.CurrentSky;` line):
```csharp
_frameProfiler.FrameBoundary(_gl!);
```
In `Dispose`/`OnClosing` teardown (anchor: where `_wbMeshAdapter` is disposed — profiler goes before `_dats`):
```csharp
_frameProfiler.Dispose();
```
- [ ] **Step 2: Add the three stage scopes**
`OnUpdate` (anchor: `private void OnUpdate(double dt)` ~line 7952) — first statement of the body:
```csharp
using var _updStage = _frameProfiler.BeginStage(AcDream.App.Diagnostics.FrameStage.Update);
```
Upload drain (anchor: `_wbMeshAdapter?.Tick();` ~line 8813 — wrap it, keeping the existing `[FRAME-DIAG]` lines untouched):
```csharp
using (var _uplStage = _frameProfiler.BeginStage(AcDream.App.Diagnostics.FrameStage.Upload))
{
_wbMeshAdapter?.Tick();
}
```
ImGui render (anchor: `_imguiBootstrap.Render();` ~line 9821):
```csharp
using (var _imguiStage = _frameProfiler.BeginStage(AcDream.App.Diagnostics.FrameStage.ImGui))
{
_imguiBootstrap.Render();
}
```
- [ ] **Step 3: Add the DebugVM mirror**
In `src/AcDream.UI.Abstractions/Panels/Debug/DebugVM.cs`, after the `ProbeResolve` property (~line 252), following the same pattern:
```csharp
/// <summary>
/// Runtime mirror of <c>RenderingDiagnostics.FrameProfEnabled</c>
/// (env var <c>ACDREAM_FRAME_PROF</c>). Toggling here starts/stops the
/// [frame-prof] 5-second report live — no relaunch required.
/// </summary>
public bool FrameProf
{
get => AcDream.Core.Rendering.RenderingDiagnostics.FrameProfEnabled;
set => AcDream.Core.Rendering.RenderingDiagnostics.FrameProfEnabled = value;
}
```
- [ ] **Step 4: Add the DebugPanel checkbox**
Locate the renderer: `grep -rn "ProbeResolve" src/AcDream.UI.ImGui/` — expected: one hit in the DebugPanel renderer drawing a checkbox bound to `vm.ProbeResolve`. Add an identical checkbox line for `vm.FrameProf` labeled `"Frame profiler ([frame-prof])"` adjacent to it, copying the exact checkbox idiom used there.
- [ ] **Step 5: Build + full test suite**
Run: `dotnet build`
Expected: green.
Run: `dotnet test`
Expected: all green (no existing test touches these paths).
- [ ] **Step 6: Commit**
```bash
git add src/AcDream.App/Rendering/GameWindow.cs src/AcDream.UI.Abstractions/Panels/Debug/DebugVM.cs src/AcDream.UI.ImGui/
git commit -m "feat(pipeline): MP0 - wire FrameProfiler into GameWindow + DebugPanel toggle"
```
---
### Task 5: Baseline capture (user-driven; MP0's deliverable + gate)
**Files:**
- Create: `docs/research/2026-07-XX-mp0-baseline.md` (use the actual capture date)
- [ ] **Step 1: Confirm Release build is green**
Run: `dotnet build -c Release`
Expected: green. Never launch on a red build.
- [ ] **Step 2: Launch with the profiler on (user drives)**
```powershell
$env:ACDREAM_DAT_DIR="$env:USERPROFILE\Documents\Asheron's Call"; $env:ACDREAM_LIVE="1"
$env:ACDREAM_TEST_HOST="127.0.0.1"; $env:ACDREAM_TEST_PORT="9000"
$env:ACDREAM_TEST_USER="testaccount"; $env:ACDREAM_TEST_PASS="testpassword"
$env:ACDREAM_FRAME_PROF="1" # NOT ACDREAM_WB_DIAG — mutually exclusive GPU timing
dotnet run --project src\AcDream.App\AcDream.App.csproj --no-build -c Release 2>&1 | Tee-Object -FilePath "mp0-baseline.log"
```
Launch in the background (`run_in_background: true`); the user manages the client lifecycle per CLAUDE.md. Ask the user to run this route, pausing ~30 s (≥5 report lines) in each state:
1. Dense town, standing still, facing the dense view (Holtburg center; Fort Tethana/Arwic if reachable).
2. Dense town, panning the camera continuously.
3. Walking a full town traversal (streaming active).
4. 23 portal hops (the hitch scenario).
5. A dungeon interior walk.
- [ ] **Step 3: Extract the numbers**
Run: `Select-String -Path mp0-baseline.log -Pattern "\[frame-prof\]"`
Expected: one line per 5 s. Map line timestamps/order to the route states (the user says when each state started; correlate by order).
- [ ] **Step 4: Write the baseline report**
Create `docs/research/2026-07-XX-mp0-baseline.md` containing, per route state: cpu_ms p50/p95/p99/max, gpu_ms p50/p95, alloc_kb p50/max, gc counts, stage split (upd/upl/imgui p50/p95) — plus:
- **The attribution verdict:** where do the ~6 dense-town CPU ms actually go (update vs upload vs imgui vs unattributed-render)? Does it confirm the spec §1 split (render-submission dominant)?
- **The gate decision (spec §5):** if attribution confirms the assumed split → proceed to MP1 planning unchanged. If it contradicts (e.g. Update dominates) → amend the spec's phase order BEFORE MP1, in the same session, and say so in this doc.
- The hitch profile: worst max/p99 during portal hops and traversal — this is MP1's "before" number.
- [ ] **Step 5: Commit + update the spec status**
Mark the spec's MP0 row as baseline-captured (one-line edit in `docs/superpowers/specs/2026-07-05-modern-pipeline-design.md` §5 gate line: append "— PASSED <date>, see baseline doc").
```bash
git add docs/research/2026-07-XX-mp0-baseline.md docs/superpowers/specs/2026-07-05-modern-pipeline-design.md
git commit -m "docs(pipeline): MP0 baseline captured - attribution verdict + gate decision"
```
---
## Post-plan notes for the executor
- **Do not strip `[frame-prof]`** in future probe-cleanup commits — it is permanent apparatus (the flag doc comment says so; so does spec §5).
- The existing `[FRAME-DIAG]` / `[WB-DIAG]` apparatus is untouched by this plan — the distance-degrade handoff still owns its strip decision.
- The roadmap "Modern Pipeline side track" section + milestones-doc freeze-exception paragraph (spec §12) should be added in the same commit as Task 5's baseline doc if not already present.