perf(render): Campaign V slice V8 commit 1 - the Vulkan arm gets an instrument

V8 is the performance gate, and it opened on a plain fact: the Vulkan arm
emitted no [frame-prof] line at all. V6h wired it to
NullRenderFrameGpuMeasurement, whose BeginFrame does nothing - and that method
is the ONLY caller of FrameProfiler.FrameBoundary. So a Vulkan run produced no
CPU frame distribution, no allocation-per-frame column, no frame-history CSV
and no GPU sample. The campaign's own performance vehicle,
tools/run-connected-r6-soak.ps1, waits on [frame-prof] boundaries to time its
samples, so it could not be pointed at the backend V8 exists to judge. You
cannot measure what you have not instrumented, so the instrument lands first.

The bracket is deliberately identical on both arms. On GL,
FrameProfilerGpuMeasurement begins a TimeElapsed query at BeginFrame and ends
it at EndFrame, spanning resource preparation, the world scene and private
presentation, and NOT the swapchain present. VulkanFrameGpuMeasurement opens
and closes a Vulkan timestamp scope at exactly those two points. Two
differently-bracketed numbers in one comparison table would have been worse
than reporting none.

Vulkan timestamps resolve two or three frames late, so the sample carries the
profiler frame index that ISSUED it rather than being credited to the frame
that happened to read it - the pairing GpuFrameTimer already performs
internally on GL. VulkanGpuDevice opens the whole-frame scope tagged with that
index, reads the previous use of the slot back in BeginFrameResources BEFORE
the tag is overwritten, and hands completed (tag, microseconds) pairs to the
adapter through a bounded queue that never blocks.

VulkanGpuTimerPool gains TryTakeResolved, which consumes the value it reports.
TryResolve deliberately reports the last known measurement forever, which is
right for a diagnostic readout and wrong for a percentile: counting one
measurement into the distribution twice is how an instrument flatters itself.

FrameProfiler gains a GL-free FrameBoundary() overload and RecordGpuSample.
Every other line of its bookkeeping - the CPU delta, the per-thread allocation
delta, the stage buffers, the history row, the five-second report - is the same
code the GL arm runs. The GL path is byte-for-byte unchanged in behaviour:
FrameBoundary(GL) still owns and creates the query ring.

Gates: Release build green. App tests 4,152 passed / 3 skipped, exactly the
pre-slice baseline. Strict GL offline pixel gate against 13c8733d:
1.95e-05 (11 px of 563,200), inside the documented 9-31 px band, so GL did not
move. An offline Vulkan run now reports gpu_ms in [frame-prof] and fills gpu_us
in the frame-history CSV, where before this commit it reported neither.

No divergence-register row is owed: this is diagnostic apparatus and no
rendered pixel depends on it.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Erik 2026-07-28 20:35:59 +02:00
parent 13c8733d90
commit 00e1b32177
5 changed files with 213 additions and 5 deletions

View file

@ -588,7 +588,15 @@ internal sealed class FrameRootCompositionPhase
host.GpuFrameLifetime,
gl is not null
? new FrameProfilerGpuMeasurement(d.FrameProfiler, gl)
: AcDream.App.Rendering.Gpu.Vk.NullRenderFrameGpuMeasurement.Instance,
// Campaign V slice V8: the Vulkan arm measures the same bracket
// through its own timestamp scope. It stayed on the null adapter
// from V6h until V8, which meant no [frame-prof] line existed on
// Vulkan at all — see VulkanFrameGpuMeasurement.
: d.Graphics.Vulkan is { } vulkanGraphics
? new AcDream.App.Rendering.Gpu.Vk.VulkanFrameGpuMeasurement(
d.FrameProfiler,
vulkanGraphics.Device)
: AcDream.App.Rendering.Gpu.Vk.NullRenderFrameGpuMeasurement.Instance,
framePreparation,
worldSceneRenderer,
privatePresentation,

View file

@ -99,6 +99,7 @@ public sealed class FrameProfiler : IDisposable
private int _currentFrameIndex = -1;
private GpuFrameTimer? _gpuTimer;
private bool _externalGpuActive;
private long _lastBoundaryTimestamp;
private long _lastAllocBytes;
private long _lastReportTicks;
@ -112,6 +113,14 @@ public sealed class FrameProfiler : IDisposable
/// <summary>Most recent immutable report line, for explicit automation checkpoints.</summary>
public string? LastReport { get; private set; }
/// <summary>
/// Index of the frame currently being measured, or -1 before the first
/// enabled boundary. Campaign V slice V8: a backend whose GPU timer is not
/// GL's query ring pairs its delayed samples with this index, exactly as
/// <see cref="GpuFrameTimer"/> does internally on the GL arm.
/// </summary>
public int CurrentFrameIndex => _currentFrameIndex;
public FrameProfiler()
{
_stageUs = new FrameStatsBuffer[StageCount];
@ -128,7 +137,20 @@ public sealed class FrameProfiler : IDisposable
/// Call once at the accepted render-transaction boundary, before
/// <see cref="BeginGpuFrame"/>.
/// </summary>
public void FrameBoundary(GL gl)
public void FrameBoundary(GL gl) => FrameBoundary(gl, ownsGpuTimer: true);
/// <summary>
/// Campaign V slice V8: the same CPU/allocation boundary with no GL context.
/// The Vulkan arm has no <c>TimeElapsed</c> query ring to own, so it drives
/// this overload and feeds GPU time in through
/// <see cref="RecordGpuSample"/>. Everything else — the CPU delta, the
/// per-thread allocation delta, the stage buffers, the history row and the
/// five-second report — is the identical code path GL uses, because a
/// perf gate that compared two different instruments would compare nothing.
/// </summary>
public void FrameBoundary() => FrameBoundary(null, ownsGpuTimer: false);
private void FrameBoundary(GL? gl, bool ownsGpuTimer)
{
bool enabled = RenderingDiagnostics.FrameProfEnabled;
if (!enabled)
@ -171,7 +193,8 @@ public sealed class FrameProfiler : IDisposable
_lastReportTicks = DateTime.UtcNow.Ticks;
Array.Clear(_stageAccumTicks);
_gc0Base = GC.CollectionCount(0); _gc1Base = GC.CollectionCount(1); _gc2Base = GC.CollectionCount(2);
if (_gpuTimer is null && !_wbDiagActive) _gpuTimer = new GpuFrameTimer(gl);
if (ownsGpuTimer && gl is not null && _gpuTimer is null && !_wbDiagActive)
_gpuTimer = new GpuFrameTimer(gl);
_currentFrameIndex = 0;
if (_wbDiagActive && !_wbDiagNoticePrinted)
{
@ -219,7 +242,8 @@ public sealed class FrameProfiler : IDisposable
int gc1 = GC.CollectionCount(1) - _gc1Base;
int gc2 = GC.CollectionCount(2) - _gc2Base;
LastReport = FormatReport(_framesInWindow, _cpuUs, _gpuUs,
gpuActive: _gpuTimer is not null, _allocBytes, gc0, gc1, gc2, _stageUs);
gpuActive: _gpuTimer is not null || _externalGpuActive,
_allocBytes, gc0, gc1, gc2, _stageUs);
Console.WriteLine(LastReport);
_lastReportTicks = nowTicks;
_gc0Base += gc0; _gc1Base += gc1; _gc2Base += gc2;
@ -261,6 +285,28 @@ public sealed class FrameProfiler : IDisposable
_gpuTimer?.EndFrame();
}
/// <summary>
/// Campaign V slice V8: publish one delayed GPU sample measured by a backend
/// that owns its own timer (Vulkan timestamp queries). Identical bookkeeping
/// to <see cref="BeginGpuFrame"/>'s promotion loop — the sample joins the
/// five-second window and back-fills the history row of the frame that
/// issued it, so <c>gpu_us</c> in the CSV is never attributed to a frame
/// that merely happened to poll it.
/// </summary>
public void RecordGpuSample(int frameIndex, long elapsedUs)
{
if (!_wasEnabled)
return;
_externalGpuActive = true;
_gpuUs.Push(elapsedUs);
if (_history is not null && (uint)frameIndex < (uint)_history.Count)
{
FrameHistoryRecord row = _history[frameIndex];
_history[frameIndex] = row with { GpuUs = elapsedUs };
}
}
/// <summary>
/// Attribute the enclosed CPU time to <paramref name="stage"/>.
/// Usage: <c>using var _ = profiler.BeginStage(FrameStage.Update);</c>.

View file

@ -0,0 +1,56 @@
using AcDream.App.Diagnostics;
namespace AcDream.App.Rendering.Gpu.Vk;
/// <summary>
/// Campaign V slice V8: the Vulkan arm's render-transaction measurement.
///
/// <para>V6h left the Vulkan arm on <c>NullRenderFrameGpuMeasurement</c>,
/// which meant <see cref="FrameProfiler.FrameBoundary()"/> was never called at
/// all — so a Vulkan run produced no <c>[frame-prof]</c> line, no frame-history
/// CSV and no allocation-per-frame column. That is not a missing nicety: the R6
/// soak waits on <c>[frame-prof]</c> boundaries to time its samples, so the
/// campaign's performance vehicle could not be pointed at the backend it was
/// meant to judge. V8 cannot measure what it cannot instrument, so the
/// instrument lands first.</para>
///
/// <para>The bracket is deliberately the SAME one GL uses. On GL,
/// <see cref="FrameProfilerGpuMeasurement"/> begins a <c>TimeElapsed</c> query
/// at <see cref="BeginFrame"/> and ends it at <see cref="EndFrame"/>, spanning
/// resource preparation, the world scene and private presentation but not the
/// swapchain present. This adapter opens and closes a Vulkan timestamp scope at
/// exactly those two points, so <c>gpu_ms</c> means the same thing in both
/// columns of the V8 table. Comparing two differently-bracketed numbers would
/// have been worse than reporting none.</para>
///
/// <para>Timestamps resolve two or three frames late, which is why the sample
/// carries the profiler frame index that ISSUED it
/// (<see cref="VulkanGpuDevice.TryTakeFrameGpuSample"/>) rather than being
/// credited to the frame that happened to read it — the same pairing
/// <c>GpuFrameTimer</c> performs internally on the GL arm.</para>
/// </summary>
internal sealed class VulkanFrameGpuMeasurement : IRenderFrameGpuMeasurement
{
private readonly FrameProfiler _profiler;
private readonly VulkanGpuDevice _device;
internal VulkanFrameGpuMeasurement(FrameProfiler profiler, VulkanGpuDevice device)
{
_profiler = profiler ?? throw new ArgumentNullException(nameof(profiler));
_device = device ?? throw new ArgumentNullException(nameof(device));
}
public void BeginFrame()
{
_profiler.FrameBoundary();
// Drain first: these are measurements of frames that have already
// retired, and the queue is bounded by the flight count.
while (_device.TryTakeFrameGpuSample(out int frameIndex, out long elapsedUs))
_profiler.RecordGpuSample(frameIndex, elapsedUs);
_device.BeginFrameTimerScope(_profiler.CurrentFrameIndex);
}
public void EndFrame() => _device.EndFrameTimerScope();
}

View file

@ -32,6 +32,23 @@ internal sealed unsafe partial class VulkanGpuDevice
private VulkanGpuPassEncoder? _openPass;
private bool _openPassIsBackbuffer;
/// <summary>
/// Campaign V slice V8: name of the whole-frame GPU timer scope. One scope
/// spanning the frame's entire command buffer is the Vulkan equivalent of
/// GL's <c>TimeElapsed</c> query around the render transaction, and is what
/// makes the two backends' <c>gpu_ms</c> columns the same measurement.
/// </summary>
private const string FrameTimerScopeName = "frame";
/// <summary>
/// Profiler frame index the scope in each flight slot was opened under. The
/// timestamps resolve two or three frames later, so the sample has to carry
/// the index of the frame that ISSUED it rather than the one that read it.
/// </summary>
private int[] _frameTimerTags = [];
private readonly Queue<(int Tag, long ElapsedUs)> _frameGpuSamples = new();
private IDisposable? _openFrameTimerScope;
private void InitialiseResources(string? shaderSpirvDirectory, string? pipelineCacheDirectory)
{
_shaderSpirvDirectory = shaderSpirvDirectory ?? string.Empty;
@ -47,6 +64,8 @@ internal sealed unsafe partial class VulkanGpuDevice
_device,
_flights.SlotCount,
Capabilities.SupportsTimestampQueries);
_frameTimerTags = new int[_flights.SlotCount];
Array.Fill(_frameTimerTags, -1);
_textureTable = new VulkanTextureTable(
_vk,
_device,
@ -112,7 +131,64 @@ internal sealed unsafe partial class VulkanGpuDevice
}
}
private void BeginFrameResources(int slotIndex) => _timerPool?.BeginSlot(slotIndex);
private void BeginFrameResources(int slotIndex)
{
if (_timerPool is null)
return;
// BeginSlot reads back whatever this slot recorded the last time it was
// used. That measurement belongs to the frame whose tag the slot still
// holds — read it BEFORE BeginFrameTimerScope overwrites the tag.
int issuingTag = _frameTimerTags[slotIndex];
_timerPool.BeginSlot(slotIndex);
if (issuingTag >= 0
&& _timerPool.TryTakeResolved(FrameTimerScopeName, out double milliseconds))
{
_frameGpuSamples.Enqueue((issuingTag, (long)(milliseconds * 1000d)));
}
}
/// <summary>
/// Campaign V slice V8: opens the whole-frame timer scope on the open
/// frame's command buffer, tagged with the profiler frame index that will
/// own the delayed result. Called by the frame spine's measurement adapter
/// immediately after the frame opens and before any renderer records work,
/// which is exactly where GL's <c>BeginQuery</c> sits.
/// </summary>
internal void BeginFrameTimerScope(int frameIndex)
{
if (_openFrame is null || _timerPool is null || _openFrameTimerScope is not null)
return;
int slot = _openFrame.SlotIndex;
_frameTimerTags[slot] = frameIndex;
_openFrameTimerScope = _timerPool.BeginScope(_commandBuffers[slot], FrameTimerScopeName);
}
/// <summary>Closes the whole-frame timer scope. Idempotent.</summary>
internal void EndFrameTimerScope()
{
_openFrameTimerScope?.Dispose();
_openFrameTimerScope = null;
}
/// <summary>
/// Drains one completed whole-frame GPU measurement, with the profiler frame
/// index that issued it. Never blocks: a frame whose timestamps have not
/// landed yet simply is not in the queue.
/// </summary>
internal bool TryTakeFrameGpuSample(out int frameIndex, out long elapsedUs)
{
if (_frameGpuSamples.Count == 0)
{
frameIndex = -1;
elapsedUs = 0;
return false;
}
(frameIndex, elapsedUs) = _frameGpuSamples.Dequeue();
return true;
}
/// <summary>Slice V6i: the descriptor-set arena for one flight slot.</summary>
private VulkanFrameBindings FrameBindingsAt(int slotIndex) => _frameBindings[slotIndex];
@ -121,6 +197,11 @@ internal sealed unsafe partial class VulkanGpuDevice
{
_ = slotIndex;
_ = commands;
// Normally already closed by the measurement adapter, which brackets the
// same phases GL's TimeElapsed query does. This is the safety net: a
// scope left open would write its closing timestamp into a pool the next
// frame has already reset.
EndFrameTimerScope();
if (_openPass is not null)
{
throw new InvalidOperationException(
@ -131,6 +212,9 @@ internal sealed unsafe partial class VulkanGpuDevice
private void DisposeResources()
{
_openFrameTimerScope = null;
_frameGpuSamples.Clear();
_frameTimerTags = [];
foreach (VulkanFrameBindings bindings in _frameBindings)
bindings.Dispose();
_frameBindings = [];

View file

@ -170,6 +170,20 @@ internal sealed unsafe class VulkanGpuTimerPool : IGpuTimerPool, IDisposable
public bool TryResolve(string scopeName, out double milliseconds) =>
_resolved.TryGetValue(scopeName, out milliseconds);
/// <summary>
/// Campaign V slice V8: reads a resolved value and CONSUMES it, so a caller
/// building a distribution counts each measurement exactly once.
/// <see cref="TryResolve"/> deliberately reports the last known value
/// forever — right for a diagnostic readout, wrong for a percentile.
/// </summary>
internal bool TryTakeResolved(string scopeName, out double milliseconds)
{
if (!_resolved.TryGetValue(scopeName, out milliseconds))
return false;
_resolved.Remove(scopeName);
return true;
}
public void Dispose()
{
if (_disposed)