diff --git a/AcDream.slnx b/AcDream.slnx index abf3defb..238ab20c 100644 --- a/AcDream.slnx +++ b/AcDream.slnx @@ -17,6 +17,7 @@ + diff --git a/docs/research/2026-07-24-performance-capture-playbook.md b/docs/research/2026-07-24-performance-capture-playbook.md new file mode 100644 index 00000000..9a9fc888 --- /dev/null +++ b/docs/research/2026-07-24-performance-capture-playbook.md @@ -0,0 +1,113 @@ +# Performance capture playbook + +This is the reproducible Slice A capture procedure for the Modern Runtime +Architecture plan. The machine and graphical contract is +[`2026-07-24-performance-reference-configuration.json`](2026-07-24-performance-reference-configuration.json). + +## Connected captures + +Build once from a clean tracked worktree: + +```powershell +dotnet build AcDream.slnx -c Release +``` + +Run the capped nine-stop route: + +```powershell +.\tools\run-connected-r6-soak.ps1 ` + -Repository (Get-Location).Path ` + -SkipBuild ` + -CaptureContention +``` + +Run the uncapped nine-stop route: + +```powershell +.\tools\run-connected-r6-soak.ps1 ` + -Repository (Get-Location).Path ` + -SkipBuild ` + -Uncapped +``` + +Run the pinned uncapped Arwic scene: + +```powershell +.\tools\run-connected-r6-soak.ps1 ` + -Repository (Get-Location).Path ` + -SkipBuild ` + -Uncapped ` + -DenseTown +``` + +Credentials come from `ACDREAM_TEST_USER` and `ACDREAM_TEST_PASS`, or the +script's local test defaults. The generated environment disclosure redacts +secret-like variable names. Never commit credentials, raw stdout/stderr, +counter CSVs, `.nettrace`, or machine-local absolute paths. + +Every run captures: + +- Per-frame CPU, GL GPU, frame-thread allocation, and stage history. +- Route-wide and five-second checkpoint percentiles. +- Per-portal windows from 10 seconds before through 5 seconds after + materialization, including the 20 worst frames. +- Process-wide `System.Runtime` counters at one-second cadence. +- Canonical resource/checkpoint JSON and named screenshots. +- Optional CLR contention events with call stacks. + +`-SkipRuntimeCounters` exists for measurement-overhead experiments only. A +baseline captured with it is incomplete. + +## Allocation and contention attribution + +The per-frame history answers which frame and which update/upload phase was +expensive. Canonical checkpoint deltas and `runtime-counters.csv` answer +whether allocations were merely moved to workers. + +For per-thread allocation stacks, make a separate reproduction capture so the +observer cost is not mixed into the baseline: + +```powershell +dotnet-trace collect ` + --process-id ` + --providers Microsoft-Windows-DotNETRuntime:0x0000000000000001:5 ` + --duration 00:00:00:30 ` + --output allocation-stacks.nettrace +``` + +The provider enables CLR GC events at verbose level; inspect allocation-tick +stacks grouped by managed thread in PerfView or Visual Studio. Interpret +sampled bytes as attribution weights, not exact object sizes. + +The soak's `-CaptureContention` mode captures the CLR contention keyword +(`0x4000`) at verbose level. Inspect `ContentionStart` call stacks and group by +lock acquisition site. The first comparisons are the DAT typed-object lock, +`ObjectMeshManager` pending-request ownership, and any newly dominant caller; +do not optimize a lock solely from event count. + +## Screenshot contract + +Compare a candidate against the matching reference image: + +```powershell +dotnet .\src\AcDream.Cli\bin\Release\net10.0\AcDream.Cli.dll ` + compare-screenshots ` + ` + ` + ` + 2 ` + 0.001 ` + +``` + +The routes pin world time and camera input. A nonzero-alpha mask excludes +known dynamic pixels such as DAT particles. Never widen the global tolerance +to conceal a deterministic geometry, texture, visibility, or UI difference. + +## Baseline authority + +Name every committed compact result `capped-local`, `uncapped-local`, +`capped-rdp`, or `uncapped-rdp`. RDP captures are diagnostic only for +throughput. An authoritative local baseline must be run on the physical AMD +display path defined in the reference configuration. A baseline report records +the exact commit and must have a clean tracked source status. diff --git a/docs/research/2026-07-24-performance-reference-configuration.json b/docs/research/2026-07-24-performance-reference-configuration.json new file mode 100644 index 00000000..8eb7226a --- /dev/null +++ b/docs/research/2026-07-24-performance-reference-configuration.json @@ -0,0 +1,74 @@ +{ + "schemaVersion": 1, + "recordedUtc": "2026-07-24T00:00:00Z", + "referenceHardware": { + "cpu": { + "name": "AMD Ryzen 7 9800X3D 8-Core Processor", + "physicalCores": 8, + "logicalProcessors": 16 + }, + "memoryBytes": 34359738368, + "gpu": { + "name": "AMD Radeon RX 9070 XT", + "driverVersion": "32.0.31021.5001" + }, + "os": { + "name": "Microsoft Windows 11 Pro", + "version": "10.0.26200", + "build": "26200", + "architecture": "x64" + }, + "dotnetSdk": "10.0.300" + }, + "displayPaths": { + "authoritativeLocal": { + "adapter": "AMD Radeon RX 9070 XT", + "desktopResolution": "2560x1440", + "refreshHz": 240, + "authority": "performance-gate" + }, + "diagnosticRdp": { + "adapter": "Microsoft Remote Display Adapter", + "desktopResolution": "2056x1290", + "refreshHz": 32, + "authority": "diagnostic-only" + } + }, + "clientConfiguration": { + "build": "Release", + "windowMode": "windowed", + "renderResolution": "1280x720", + "quality": "High", + "fieldOfViewDegrees": 60, + "vsync": false, + "retailUi": true, + "developerUi": false, + "audio": true, + "datSource": "local retail EoR DAT files", + "server": "local ACE" + }, + "routes": { + "canonicalNineStop": "tools/connected-r6-soak.route.txt", + "denseTown": { + "name": "Arwic", + "route": "tools/connected-dense-town.route.txt", + "arrival": "ACE canonical /telepoi Arwic position and heading", + "camera": "six seconds of MovementTurnRight after materialization", + "timeOfDay": 0.5 + } + }, + "screenshotComparison": { + "channelTolerance": 2, + "maxDifferentPixelFraction": 0.001, + "timeOfDay": 0.5, + "dynamicPixelRule": "Particles and other nondeterministic dynamic pixels must be excluded by an explicit same-resolution alpha mask. An unmasked failure is never waived by increasing the global tolerance." + }, + "baselineRules": [ + "Capped-local, uncapped-local, capped-RDP, and uncapped-RDP captures are separate populations and are never compared as if interchangeable.", + "Only an authoritative-local capture may establish or pass FPS, CPU, GPU, or frame-time budgets.", + "RDP captures may validate automation, lifetime, allocation attribution, and large regressions, but are labeled diagnostic-only.", + "Re-baseline after a CPU, GPU, driver, OS build, physical display path, render resolution, quality, FOV, VSync, DAT set, route, or measurement-schema change.", + "A re-baseline records the source commit and keeps the prior committed baseline for historical comparison unless its data is invalid.", + "Performance captures use a clean tracked worktree and disclose all ACDREAM_* launch variables with secrets redacted." + ] +} diff --git a/docs/research/2026-07-24-performance-reference-configuration.md b/docs/research/2026-07-24-performance-reference-configuration.md new file mode 100644 index 00000000..6726c470 --- /dev/null +++ b/docs/research/2026-07-24-performance-reference-configuration.md @@ -0,0 +1,22 @@ +# Performance reference configuration + +The machine-readable contract is +[`2026-07-24-performance-reference-configuration.json`](2026-07-24-performance-reference-configuration.json). +It fixes the reference CPU/GPU/driver/OS, graphical settings, routes, display +paths, screenshot rule, and re-baseline policy used by the Modern Runtime +Architecture plan. + +Only the physical AMD display path is authoritative for frame-time, CPU, and +GPU acceptance gates. Remote Desktop runs are intentionally retained as a +separate diagnostic population: they validate the connected route, resource +lifetime, allocation attribution, and major regressions, but the 32 Hz remote +presentation path cannot establish maximum throughput. + +The connected routes pin the client-only world-time override at noon. The +dense-town route uses ACE's canonical Arwic point-of-interest arrival and a +fixed six-second retail-input turn before its screenshot and checkpoint. + +Screenshot comparison uses a per-channel tolerance of 2 and permits at most +0.1% differing unmasked pixels. Dynamic particles or similarly nondeterministic +pixels require an explicit same-resolution alpha mask; a failure is not +accepted by silently increasing the global tolerance. diff --git a/src/AcDream.App/Composition/FrameRootComposition.cs b/src/AcDream.App/Composition/FrameRootComposition.cs index 4c7eca99..369ce330 100644 --- a/src/AcDream.App/Composition/FrameRootComposition.cs +++ b/src/AcDream.App/Composition/FrameRootComposition.cs @@ -256,9 +256,7 @@ internal sealed class FrameRootCompositionPhase interaction.RetainedUi?.Host.TextRenderer, live.ClipFrame, foundation.Terrain, - foundation.SceneLighting, - d.FrameProfiler, - d.Gl), + foundation.SceneLighting), new RuntimeRenderFrameClearPhase( d.Gl, d.WorldTime, @@ -454,6 +452,7 @@ internal sealed class FrameRootCompositionPhase renderWeatherFrame); var renderFrame = new RenderFrameOrchestrator( host.GpuFrameFlights, + new FrameProfilerGpuMeasurement(d.FrameProfiler, d.Gl), framePreparation, worldSceneRenderer, privatePresentation, diff --git a/src/AcDream.App/Diagnostics/FrameProfiler.cs b/src/AcDream.App/Diagnostics/FrameProfiler.cs index f19c2d13..69d02add 100644 --- a/src/AcDream.App/Diagnostics/FrameProfiler.cs +++ b/src/AcDream.App/Diagnostics/FrameProfiler.cs @@ -32,35 +32,25 @@ public enum FrameStage /// together. GpuUs is -1 for a frame with no available GPU /// sample (warm-up, or ACDREAM_WB_DIAG=1 self-disable). /// -internal readonly struct FrameHistoryRecord( - int frameIndex, - double timestampMs, - long cpuUs, - long gpuUs, - long allocBytes, - long updateUs, - long uploadUs, - long imGuiUs, - long pacingUs) -{ - public readonly int FrameIndex = frameIndex; - public readonly double TimestampMs = timestampMs; - public readonly long CpuUs = cpuUs; - public readonly long GpuUs = gpuUs; - public readonly long AllocBytes = allocBytes; - public readonly long UpdateUs = updateUs; - public readonly long UploadUs = uploadUs; - public readonly long ImGuiUs = imGuiUs; - public readonly long PacingUs = pacingUs; -} +internal readonly record struct FrameHistoryRecord( + int FrameIndex, + double TimestampMs, + long CpuUs, + long GpuUs, + long AllocBytes, + long UpdateUs, + long UploadUs, + long ImGuiUs, + long PacingUs); /// /// MP0 (2026-07-05) — the permanent honest frame profiler. One -/// FrameBoundary call at the top of GameWindow.OnRender +/// FrameBoundary call at the top of the accepted render transaction /// measures CPU frame time as the delta between consecutive boundaries -/// (captures the FULL frame including present), brackets the frame in a -/// GPU TimeElapsed query (via ), and -/// samples per-frame allocated bytes + GC collection counts. Stage scopes +/// (captures the FULL frame including present) and samples per-frame allocated +/// bytes + GC collection counts. and +/// separately bracket only submitted render work. +/// Stage scopes /// () attribute CPU time to Update / Upload / /// ImGui. Emits one [frame-prof] line every ~5 s while /// is true; costs one @@ -79,8 +69,9 @@ internal readonly struct FrameHistoryRecord( /// preallocated, grow-as-needed (1 int + 1 double + /// 7 longs ≈ 72 bytes/record; a multi-hour capture at 165 fps is roughly /// 165 * 3600 * 72 bytes ≈ 43 MB/hour — fine for a bounded diagnostic run, -/// not for unattended day-long capture). ZERO frame-thread I/O: the list only grows during -/// ; the CSV is written once, from +/// not for unattended day-long capture). Its initial capacity is about 9 MiB +/// and covers the canonical route above 300 FPS without a frame-thread resize. +/// ZERO frame-thread I/O: the CSV is written once, from /// , at shutdown. Recording only takes effect while /// is ALSO true — it /// reuses that instrumentation rather than duplicating it. Does not @@ -90,7 +81,7 @@ internal readonly struct FrameHistoryRecord( public sealed class FrameProfiler : IDisposable { private const int WindowCapacity = 2048; // ~12 s at 165 fps - private const int HistoryInitialCapacity = 4096; + private const int HistoryInitialCapacity = 131072; private const long ReportIntervalTicks = 5 * TimeSpan.TicksPerSecond; private static readonly int StageCount = Enum.GetValues().Length; @@ -104,7 +95,8 @@ public sealed class FrameProfiler : IDisposable Environment.GetEnvironmentVariable("ACDREAM_WB_DIAG") == "1"; private readonly List? _history; private readonly long _profilerStartTimestamp; - private int _historyFrameIndex; + private readonly DateTime _profilerStartUtc; + private int _currentFrameIndex = -1; private GpuFrameTimer? _gpuTimer; private long _lastBoundaryTimestamp; @@ -127,12 +119,14 @@ public sealed class FrameProfiler : IDisposable _stageAccumTicks = new long[StageCount]; _lastStageUs = new long[StageCount]; _profilerStartTimestamp = Stopwatch.GetTimestamp(); + _profilerStartUtc = DateTime.UtcNow; if (RenderingDiagnostics.FrameHistoryPath is not null) _history = new List(HistoryInitialCapacity); } /// - /// Call as the FIRST statement of GameWindow.OnRender. + /// Call once at the accepted render-transaction boundary, before + /// . /// public void FrameBoundary(GL gl) { @@ -150,6 +144,7 @@ public sealed class FrameProfiler : IDisposable _gpuTimer = null; _wasEnabled = false; _lastBoundaryTimestamp = 0; + _currentFrameIndex = -1; } return; } @@ -164,8 +159,6 @@ public sealed class FrameProfiler : IDisposable long now = Stopwatch.GetTimestamp(); long allocNow = GC.GetAllocatedBytesForCurrentThread(); - bool historyFrame = false; - long historyCpuUs = 0, historyAllocBytes = 0; if (!_wasEnabled) { // First enabled frame (startup or runtime toggle-on): establish @@ -179,6 +172,7 @@ public sealed class FrameProfiler : IDisposable Array.Clear(_stageAccumTicks); _gc0Base = GC.CollectionCount(0); _gc1Base = GC.CollectionCount(1); _gc2Base = GC.CollectionCount(2); if (_gpuTimer is null && !_wbDiagActive) _gpuTimer = new GpuFrameTimer(gl); + _currentFrameIndex = 0; if (_wbDiagActive && !_wbDiagNoticePrinted) { _wbDiagNoticePrinted = true; @@ -199,32 +193,25 @@ public sealed class FrameProfiler : IDisposable _stageAccumTicks[i] = 0; } _framesInWindow++; - historyFrame = _history is not null; - historyCpuUs = cpuUs; - historyAllocBytes = allocDelta; + if (_history is not null) + { + _history.Add(new FrameHistoryRecord( + _currentFrameIndex, + (now - _profilerStartTimestamp) * 1000.0 / Stopwatch.Frequency, + cpuUs, + -1L, + allocDelta, + _lastStageUs[(int)FrameStage.Update], + _lastStageUs[(int)FrameStage.Upload], + _lastStageUs[(int)FrameStage.ImGui], + _lastStageUs[(int)FrameStage.Pacing])); + } + _currentFrameIndex++; } _lastBoundaryTimestamp = now; _lastAllocBytes = allocNow; - long? gpuUsSample = _gpuTimer?.FrameBoundary(); - if (gpuUsSample is long gpuUs) - _gpuUs.Push(gpuUs); - - if (historyFrame) - { - _history!.Add(new FrameHistoryRecord( - _historyFrameIndex++, - (now - _profilerStartTimestamp) * 1000.0 / Stopwatch.Frequency, - historyCpuUs, - gpuUsSample ?? -1L, - historyAllocBytes, - _lastStageUs[(int)FrameStage.Update], - _lastStageUs[(int)FrameStage.Upload], - _lastStageUs[(int)FrameStage.ImGui], - _lastStageUs[(int)FrameStage.Pacing])); - } - long nowTicks = DateTime.UtcNow.Ticks; if (nowTicks - _lastReportTicks >= ReportIntervalTicks && _framesInWindow > 0) { @@ -242,6 +229,38 @@ public sealed class FrameProfiler : IDisposable } } + /// + /// Begin GPU timing immediately before render-resource, world, and private + /// presentation submission. Completed delayed samples are associated with + /// their owning history row rather than the frame that happened to poll + /// them. + /// + public void BeginGpuFrame() + { + if (!_wasEnabled || _gpuTimer is null || _currentFrameIndex < 0) + return; + + Span completed = stackalloc GpuFrameSample[4]; + int completedCount = _gpuTimer.BeginFrame(_currentFrameIndex, completed); + for (int index = 0; index < completedCount; index++) + { + GpuFrameSample sample = completed[index]; + _gpuUs.Push(sample.ElapsedUs); + if (_history is not null + && (uint)sample.FrameIndex < (uint)_history.Count) + { + FrameHistoryRecord row = _history[sample.FrameIndex]; + _history[sample.FrameIndex] = row with { GpuUs = sample.ElapsedUs }; + } + } + } + + /// End GPU timing immediately after render submission. + public void EndGpuFrame() + { + _gpuTimer?.EndFrame(); + } + /// /// Attribute the enclosed CPU time to . /// Usage: using var _ = profiler.BeginStage(FrameStage.Update);. @@ -283,14 +302,22 @@ public sealed class FrameProfiler : IDisposable } /// Pure CSV formatter — unit-tested; invariant culture. One header row plus one row per record. - internal static void WriteHistoryCsv(IEnumerable records, TextWriter writer) + internal static void WriteHistoryCsv( + IEnumerable records, + TextWriter writer, + DateTime profilerStartUtc) { var ci = CultureInfo.InvariantCulture; - writer.WriteLine("frame,timestamp_ms,cpu_us,gpu_us,alloc_bytes,update_us,upload_us,imgui_us,pacing_us"); + DateTime startUtc = profilerStartUtc.ToUniversalTime(); + writer.WriteLine( + "frame,timestamp_ms,timestamp_utc,cpu_us,gpu_us,alloc_bytes," + + "update_us,upload_us,imgui_us,pacing_us"); foreach (FrameHistoryRecord r in records) { writer.Write(r.FrameIndex.ToString(ci)); writer.Write(','); writer.Write(r.TimestampMs.ToString("0.000", ci)); writer.Write(','); + writer.Write(startUtc.AddMilliseconds(r.TimestampMs).ToString("O", ci)); + writer.Write(','); writer.Write(r.CpuUs.ToString(ci)); writer.Write(','); writer.Write(r.GpuUs.ToString(ci)); writer.Write(','); writer.Write(r.AllocBytes.ToString(ci)); writer.Write(','); @@ -316,7 +343,7 @@ public sealed class FrameProfiler : IDisposable try { using var writer = new StreamWriter(path, append: false); - WriteHistoryCsv(_history, writer); + WriteHistoryCsv(_history, writer, _profilerStartUtc); Console.WriteLine($"[frame-prof] wrote {_history.Count} history record(s) to '{path}'"); } catch (Exception ex) diff --git a/src/AcDream.App/Diagnostics/GpuFrameTimer.cs b/src/AcDream.App/Diagnostics/GpuFrameTimer.cs index d75621e9..b000c789 100644 --- a/src/AcDream.App/Diagnostics/GpuFrameTimer.cs +++ b/src/AcDream.App/Diagnostics/GpuFrameTimer.cs @@ -3,18 +3,27 @@ using Silk.NET.OpenGL; namespace AcDream.App.Diagnostics; +internal readonly record struct GpuFrameSample(int FrameIndex, long ElapsedUs); + /// -/// MP0 (2026-07-05) — whole-frame GPU time via a ring of +/// MP0 (2026-07-05) — render-transaction GPU time via a ring of /// queries (depth 4, so results are -/// read ~3 frames late and never stall). Mirrors WbDrawDispatcher's query +/// read several 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. +/// the pending flags. /// /// 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. +/// +/// The query begins immediately before render-resource/world/private +/// presentation submission and ends immediately after it. It is deliberately +/// NOT left active until the next render callback: doing so includes display +/// pacing and an arbitrary CPU idle interval in the GPU clock. Completed +/// samples retain the frame index that owned the query so the delayed result +/// can be paired with the correct CPU/history row. /// internal sealed class GpuFrameTimer : IDisposable { @@ -22,9 +31,10 @@ internal sealed class GpuFrameTimer : IDisposable private readonly GL _gl; private readonly uint[] _queries = new uint[RingDepth]; - private readonly bool[] _begun = new bool[RingDepth]; - private int _frameIndex; - private bool _queryActive; + private readonly bool[] _pending = new bool[RingDepth]; + private readonly int[] _frameIndices = new int[RingDepth]; + private int _nextSlot; + private int _activeSlot = -1; public GpuFrameTimer(GL gl) { @@ -34,48 +44,74 @@ internal sealed class GpuFrameTimer : IDisposable } /// - /// 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. + /// Poll every ended query non-blocking, then begin this frame's render + /// transaction in the first free ring slot. If all slots are still in + /// flight the current frame is intentionally left unmeasured rather than + /// stalling or overwriting a pending result. /// - public long? FrameBoundary() + public int BeginFrame(int frameIndex, Span completed) { - if (_queryActive) + if (_activeSlot >= 0) + throw new InvalidOperationException("GPU frame timing was begun twice without an end."); + if (completed.Length < RingDepth) + throw new ArgumentException( + $"Completed-sample storage must hold at least {RingDepth} entries.", + nameof(completed)); + + int completedCount = 0; + for (int slot = 0; slot < RingDepth; slot++) { - _gl.EndQuery(QueryTarget.TimeElapsed); - _queryActive = false; + if (!_pending[slot]) + continue; + + _gl.GetQueryObject( + _queries[slot], + QueryObjectParameterName.ResultAvailable, + out int available); + if (available == 0) + continue; + + _gl.GetQueryObject( + _queries[slot], + QueryObjectParameterName.Result, + out ulong elapsedNanoseconds); + completed[completedCount++] = new GpuFrameSample( + _frameIndices[slot], + (long)(elapsedNanoseconds / 1000UL)); + _pending[slot] = false; } - long? completedUs = null; - int readSlot = _frameIndex % RingDepth; // about to be reused — oldest - if (_begun[readSlot]) + for (int offset = 0; offset < RingDepth; offset++) { - _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. + int slot = (_nextSlot + offset) % RingDepth; + if (_pending[slot]) + continue; + + _gl.BeginQuery(QueryTarget.TimeElapsed, _queries[slot]); + _frameIndices[slot] = frameIndex; + _activeSlot = slot; + _nextSlot = (slot + 1) % RingDepth; + break; } - _gl.BeginQuery(QueryTarget.TimeElapsed, _queries[readSlot]); - _begun[readSlot] = true; - _queryActive = true; - _frameIndex++; - return completedUs; + return completedCount; } - /// End any active query without beginning a new one (used when the profiler is toggled off mid-session). + /// End the query around the current render transaction. + public void EndFrame() + { + if (_activeSlot < 0) + return; + + _gl.EndQuery(QueryTarget.TimeElapsed); + _pending[_activeSlot] = true; + _activeSlot = -1; + } + + /// End an active query without beginning another. public void Stop() { - if (_queryActive) - { - _gl.EndQuery(QueryTarget.TimeElapsed); - _queryActive = false; - } + EndFrame(); } public void Dispose() diff --git a/src/AcDream.App/Rendering/FrameProfilerGpuMeasurement.cs b/src/AcDream.App/Rendering/FrameProfilerGpuMeasurement.cs new file mode 100644 index 00000000..fe7d927a --- /dev/null +++ b/src/AcDream.App/Rendering/FrameProfilerGpuMeasurement.cs @@ -0,0 +1,32 @@ +using AcDream.App.Diagnostics; +using Silk.NET.OpenGL; + +namespace AcDream.App.Rendering; + +/// +/// Production render-transaction measurement adapter. CPU frame boundaries +/// remain owned by while this adapter places the +/// GPU query around only the GL-producing render phases. +/// +internal sealed class FrameProfilerGpuMeasurement : IRenderFrameGpuMeasurement +{ + private readonly FrameProfiler _profiler; + private readonly GL _gl; + + public FrameProfilerGpuMeasurement(FrameProfiler profiler, GL gl) + { + _profiler = profiler ?? throw new ArgumentNullException(nameof(profiler)); + _gl = gl ?? throw new ArgumentNullException(nameof(gl)); + } + + public void BeginFrame() + { + _profiler.FrameBoundary(_gl); + _profiler.BeginGpuFrame(); + } + + public void EndFrame() + { + _profiler.EndGpuFrame(); + } +} diff --git a/src/AcDream.App/Rendering/RenderFrameOrchestrator.cs b/src/AcDream.App/Rendering/RenderFrameOrchestrator.cs index 0ca3d915..a687cfe8 100644 --- a/src/AcDream.App/Rendering/RenderFrameOrchestrator.cs +++ b/src/AcDream.App/Rendering/RenderFrameOrchestrator.cs @@ -43,6 +43,18 @@ internal interface IRenderFrameResourcePhase void Prepare(RenderFrameInput input); } +/// +/// Diagnostic GPU timer bracketing only render-resource, world, and private +/// presentation submission. It deliberately excludes diagnostics, pacing, +/// and the idle interval before the next render callback. +/// +internal interface IRenderFrameGpuMeasurement +{ + void BeginFrame(); + + void EndFrame(); +} + internal interface IWorldSceneFramePhase { WorldRenderFrameOutcome Render(RenderFrameInput input); @@ -117,6 +129,7 @@ internal sealed class NullRenderFrameFailureRecovery : IRenderFrameFailureRecove internal sealed class RenderFrameOrchestrator : IGameRenderFrameRoot { private readonly IRenderFrameLifetime _lifetime; + private readonly IRenderFrameGpuMeasurement _gpuMeasurement; private readonly IRenderFrameResourcePhase _resources; private readonly IWorldSceneFramePhase _world; private readonly IPrivatePresentationFramePhase _presentation; @@ -126,6 +139,7 @@ internal sealed class RenderFrameOrchestrator : IGameRenderFrameRoot public RenderFrameOrchestrator( IRenderFrameLifetime lifetime, + IRenderFrameGpuMeasurement gpuMeasurement, IRenderFrameResourcePhase resources, IWorldSceneFramePhase world, IPrivatePresentationFramePhase presentation, @@ -134,6 +148,8 @@ internal sealed class RenderFrameOrchestrator : IGameRenderFrameRoot IRenderFrameFailureRecovery recovery) { _lifetime = lifetime ?? throw new ArgumentNullException(nameof(lifetime)); + _gpuMeasurement = gpuMeasurement + ?? throw new ArgumentNullException(nameof(gpuMeasurement)); _resources = resources ?? throw new ArgumentNullException(nameof(resources)); _world = world ?? throw new ArgumentNullException(nameof(world)); _presentation = presentation ?? throw new ArgumentNullException(nameof(presentation)); @@ -149,10 +165,37 @@ internal sealed class RenderFrameOrchestrator : IGameRenderFrameRoot Exception? renderFailure = null; try { - _resources.Prepare(input); - WorldRenderFrameOutcome world = _world.Render(input); - PrivatePresentationFrameOutcome presentation = - _presentation.Render(input, world); + WorldRenderFrameOutcome world; + PrivatePresentationFrameOutcome presentation; + Exception? measuredRenderFailure = null; + _gpuMeasurement.BeginFrame(); + try + { + _resources.Prepare(input); + world = _world.Render(input); + presentation = _presentation.Render(input, world); + } + catch (Exception error) + { + measuredRenderFailure = error; + throw; + } + finally + { + try + { + _gpuMeasurement.EndFrame(); + } + catch (Exception measurementFailure) + when (measuredRenderFailure is not null) + { + throw new AggregateException( + "Rendering failed and its GPU measurement could not be closed.", + measuredRenderFailure, + measurementFailure); + } + } + var outcome = new RenderFrameOutcome(world, presentation); _diagnostics.Publish(input, outcome); _postDiagnostics.Process(input, outcome); diff --git a/src/AcDream.App/Rendering/RenderFrameResourceController.cs b/src/AcDream.App/Rendering/RenderFrameResourceController.cs index def8f00d..03d4792d 100644 --- a/src/AcDream.App/Rendering/RenderFrameResourceController.cs +++ b/src/AcDream.App/Rendering/RenderFrameResourceController.cs @@ -93,9 +93,6 @@ internal sealed class RuntimeRenderFrameBeginResources : IRenderFrameBeginResour private readonly ClipFrame? _clip; private readonly TerrainModernRenderer? _terrain; private readonly SceneLightingUboBinding? _lighting; - private readonly FrameProfiler _profiler; - private readonly GL _gl; - public RuntimeRenderFrameBeginResources( TextureCache? textures, WbDrawDispatcher? dispatcher, @@ -105,9 +102,7 @@ internal sealed class RuntimeRenderFrameBeginResources : IRenderFrameBeginResour TextRenderer? uiText, ClipFrame? clip, TerrainModernRenderer? terrain, - SceneLightingUboBinding? lighting, - FrameProfiler profiler, - GL gl) + SceneLightingUboBinding? lighting) { _textures = textures; _dispatcher = dispatcher; @@ -118,8 +113,6 @@ internal sealed class RuntimeRenderFrameBeginResources : IRenderFrameBeginResour _clip = clip; _terrain = terrain; _lighting = lighting; - _profiler = profiler ?? throw new ArgumentNullException(nameof(profiler)); - _gl = gl ?? throw new ArgumentNullException(nameof(gl)); } public void Begin(int gpuSlot) @@ -134,7 +127,6 @@ internal sealed class RuntimeRenderFrameBeginResources : IRenderFrameBeginResour _clip?.BeginFrame(gpuSlot); _terrain?.BeginFrame(gpuSlot); _lighting?.BeginFrame(gpuSlot); - _profiler.FrameBoundary(_gl); } } diff --git a/src/AcDream.Cli/PerformanceTools.cs b/src/AcDream.Cli/PerformanceTools.cs new file mode 100644 index 00000000..4c3bd4c7 --- /dev/null +++ b/src/AcDream.Cli/PerformanceTools.cs @@ -0,0 +1,533 @@ +using System.Globalization; +using System.Text.Json; +using System.Text.RegularExpressions; +using SixLabors.ImageSharp; +using SixLabors.ImageSharp.PixelFormats; + +namespace AcDream.Cli; + +public static partial class PerformanceTools +{ + private static readonly JsonSerializerOptions JsonOptions = new() + { + PropertyNamingPolicy = JsonNamingPolicy.CamelCase, + WriteIndented = true, + }; + + public static int SummarizeFrameHistory(string[] args) + { + if (args.Length < 4) + { + Console.Error.WriteLine( + "usage: AcDream.Cli summarize-frame-history " + + " "); + return 2; + } + + try + { + IReadOnlyList frames = ReadFrames(args[0]); + IReadOnlyList checkpoints = ReadCheckpoints(args[1]); + IReadOnlyList portals = ReadPortalMarkers(args[2]); + var summary = new FrameHistoryReport( + SourceFrameHistory: Path.GetFileName(args[0]), + FrameCount: frames.Count, + FirstFrameUtc: frames.Count == 0 ? null : frames[0].TimestampUtc, + LastFrameUtc: frames.Count == 0 ? null : frames[^1].TimestampUtc, + Route: SummarizeWindow(frames), + CheckpointWindows: checkpoints.Select(checkpoint => + new NamedWindowSummary( + checkpoint.Name, + checkpoint.TimestampUtc.AddSeconds(-5), + checkpoint.TimestampUtc, + SummarizeWindow(frames.Where(frame => + frame.TimestampUtc >= checkpoint.TimestampUtc.AddSeconds(-5) + && frame.TimestampUtc <= checkpoint.TimestampUtc)), + checkpoint.ProcessAllocationRateBytesPerSecond)) + .ToArray(), + PortalWindows: portals.Select(portal => + new PortalWindowSummary( + portal.Destination, + portal.TimestampUtc, + SummarizeWindow(frames.Where(frame => + frame.TimestampUtc >= portal.TimestampUtc.AddSeconds(-10) + && frame.TimestampUtc <= portal.TimestampUtc.AddSeconds(5))), + frames.Where(frame => + frame.TimestampUtc >= portal.TimestampUtc.AddSeconds(-10) + && frame.TimestampUtc <= portal.TimestampUtc.AddSeconds(5)) + .OrderByDescending(frame => frame.CpuUs) + .Take(20) + .Select(frame => new WorstFrame( + frame.Frame, + Math.Round( + (frame.TimestampUtc - portal.TimestampUtc).TotalMilliseconds, + 3), + frame.CpuUs, + frame.GpuUs, + frame.AllocBytes, + frame.UpdateUs, + frame.UploadUs, + frame.PacingUs)) + .ToArray())) + .ToArray()); + + string output = Path.GetFullPath(args[3]); + Directory.CreateDirectory( + Path.GetDirectoryName(output) + ?? throw new InvalidOperationException("Output path has no directory.")); + File.WriteAllText(output, JsonSerializer.Serialize(summary, JsonOptions)); + Console.WriteLine($"wrote frame-history summary: {output}"); + return 0; + } + catch (Exception error) + { + Console.Error.WriteLine($"frame-history summary failed: {error.Message}"); + return 1; + } + } + + public static int CompareScreenshots(string[] args) + { + if (args.Length < 3) + { + Console.Error.WriteLine( + "usage: AcDream.Cli compare-screenshots " + + " " + + "[channelTolerance=2] [maxDifferentFraction=0.001] [mask.png]"); + return 2; + } + + try + { + int tolerance = args.Length >= 4 + ? int.Parse(args[3], CultureInfo.InvariantCulture) + : 2; + double maxDifferentFraction = args.Length >= 5 + ? double.Parse(args[4], CultureInfo.InvariantCulture) + : 0.001; + string? maskPath = args.Length >= 6 ? args[5] : null; + ScreenshotComparison comparison = CompareImages( + args[0], + args[1], + tolerance, + maxDifferentFraction, + maskPath); + + string output = Path.GetFullPath(args[2]); + Directory.CreateDirectory( + Path.GetDirectoryName(output) + ?? throw new InvalidOperationException("Output path has no directory.")); + File.WriteAllText(output, JsonSerializer.Serialize(comparison, JsonOptions)); + Console.WriteLine( + $"screenshot comparison {(comparison.Passed ? "passed" : "failed")}: " + + $"{comparison.DifferentPixelFraction:P6} different"); + return comparison.Passed ? 0 : 1; + } + catch (Exception error) + { + Console.Error.WriteLine($"screenshot comparison failed: {error.Message}"); + return 1; + } + } + + public static ScreenshotComparison CompareImages( + string expectedPath, + string actualPath, + int channelTolerance, + double maxDifferentFraction, + string? maskPath = null) + { + if ((uint)channelTolerance > byte.MaxValue) + throw new ArgumentOutOfRangeException(nameof(channelTolerance)); + if (maxDifferentFraction is < 0 or > 1 || double.IsNaN(maxDifferentFraction)) + throw new ArgumentOutOfRangeException(nameof(maxDifferentFraction)); + + using Image expected = Image.Load(expectedPath); + using Image actual = Image.Load(actualPath); + using Image? mask = maskPath is null + ? null + : Image.Load(maskPath); + + if (expected.Width != actual.Width || expected.Height != actual.Height) + { + return new ScreenshotComparison( + Passed: false, + Width: actual.Width, + Height: actual.Height, + ExpectedWidth: expected.Width, + ExpectedHeight: expected.Height, + ChannelTolerance: channelTolerance, + MaxDifferentPixelFraction: maxDifferentFraction, + ComparedPixels: 0, + MaskedPixels: 0, + DifferentPixels: 0, + DifferentPixelFraction: 1, + MaximumChannelDelta: byte.MaxValue, + MeanAbsoluteChannelDelta: 0, + RootMeanSquareChannelDelta: 0, + ExpectedPath: Path.GetFileName(expectedPath), + ActualPath: Path.GetFileName(actualPath), + MaskPath: maskPath is null ? null : Path.GetFileName(maskPath)); + } + + if (mask is not null + && (mask.Width != expected.Width || mask.Height != expected.Height)) + { + throw new InvalidDataException( + "Screenshot mask dimensions must match the compared images."); + } + + long comparedPixels = 0; + long maskedPixels = 0; + long differentPixels = 0; + long absoluteDeltaSum = 0; + long squaredDeltaSum = 0; + int maximumDelta = 0; + + for (int y = 0; y < expected.Height; y++) + { + for (int x = 0; x < expected.Width; x++) + { + if (mask is not null && mask[x, y].A != 0) + { + maskedPixels++; + continue; + } + + comparedPixels++; + Rgba32 left = expected[x, y]; + Rgba32 right = actual[x, y]; + int redDelta = Math.Abs(left.R - right.R); + int greenDelta = Math.Abs(left.G - right.G); + int blueDelta = Math.Abs(left.B - right.B); + int alphaDelta = Math.Abs(left.A - right.A); + + absoluteDeltaSum += redDelta + greenDelta + blueDelta + alphaDelta; + squaredDeltaSum += + redDelta * redDelta + + greenDelta * greenDelta + + blueDelta * blueDelta + + alphaDelta * alphaDelta; + maximumDelta = Math.Max( + maximumDelta, + Math.Max( + Math.Max(redDelta, greenDelta), + Math.Max(blueDelta, alphaDelta))); + bool different = + redDelta > channelTolerance + || greenDelta > channelTolerance + || blueDelta > channelTolerance + || alphaDelta > channelTolerance; + + if (different) + differentPixels++; + } + } + + double differingFraction = comparedPixels == 0 + ? throw new InvalidDataException( + "Screenshot mask excludes every pixel; no comparison is possible.") + : differentPixels / (double)comparedPixels; + long comparedChannels = comparedPixels * 4; + return new ScreenshotComparison( + Passed: differingFraction <= maxDifferentFraction, + Width: actual.Width, + Height: actual.Height, + ExpectedWidth: expected.Width, + ExpectedHeight: expected.Height, + ChannelTolerance: channelTolerance, + MaxDifferentPixelFraction: maxDifferentFraction, + ComparedPixels: comparedPixels, + MaskedPixels: maskedPixels, + DifferentPixels: differentPixels, + DifferentPixelFraction: differingFraction, + MaximumChannelDelta: maximumDelta, + MeanAbsoluteChannelDelta: comparedChannels == 0 + ? 0 + : absoluteDeltaSum / (double)comparedChannels, + RootMeanSquareChannelDelta: comparedChannels == 0 + ? 0 + : Math.Sqrt(squaredDeltaSum / (double)comparedChannels), + ExpectedPath: Path.GetFileName(expectedPath), + ActualPath: Path.GetFileName(actualPath), + MaskPath: maskPath is null ? null : Path.GetFileName(maskPath)); + } + + private static IReadOnlyList ReadFrames(string path) + { + string[] lines = File.ReadAllLines(path); + if (lines.Length == 0) + throw new InvalidDataException("Frame-history CSV is empty."); + + string[] header = lines[0].Split(','); + var columns = header + .Select((name, index) => (name, index)) + .ToDictionary(pair => pair.name, pair => pair.index, StringComparer.Ordinal); + string[] required = + [ + "frame", "timestamp_utc", "cpu_us", "gpu_us", "alloc_bytes", + "update_us", "upload_us", "imgui_us", "pacing_us", + ]; + foreach (string name in required) + { + if (!columns.ContainsKey(name)) + throw new InvalidDataException($"Frame-history CSV is missing '{name}'."); + } + + var rows = new List(lines.Length - 1); + for (int lineNumber = 1; lineNumber < lines.Length; lineNumber++) + { + if (string.IsNullOrWhiteSpace(lines[lineNumber])) + continue; + string[] values = lines[lineNumber].Split(','); + try + { + rows.Add(new FrameRow( + ParseInt(values, columns, "frame"), + DateTime.Parse( + values[columns["timestamp_utc"]], + CultureInfo.InvariantCulture, + DateTimeStyles.AdjustToUniversal | DateTimeStyles.AssumeUniversal), + ParseLong(values, columns, "cpu_us"), + ParseLong(values, columns, "gpu_us"), + ParseLong(values, columns, "alloc_bytes"), + ParseLong(values, columns, "update_us"), + ParseLong(values, columns, "upload_us"), + ParseLong(values, columns, "imgui_us"), + ParseLong(values, columns, "pacing_us"))); + } + catch (Exception error) when ( + error is FormatException + or IndexOutOfRangeException + or KeyNotFoundException) + { + throw new InvalidDataException( + $"Invalid frame-history row {lineNumber + 1}: {error.Message}", + error); + } + } + + return rows; + } + + private static IReadOnlyList ReadCheckpoints(string path) + { + var rows = new List(); + CheckpointRaw? previous = null; + foreach (string line in File.ReadLines(path)) + { + if (string.IsNullOrWhiteSpace(line)) + continue; + using JsonDocument document = JsonDocument.Parse(line); + JsonElement root = document.RootElement; + JsonElement resources = root.GetProperty("resources"); + var current = new CheckpointRaw( + root.GetProperty("name").GetString() + ?? throw new InvalidDataException("Checkpoint name is null."), + root.GetProperty("timestampUtc").GetDateTime().ToUniversalTime(), + resources.GetProperty("processTotalAllocatedBytes").GetInt64()); + double? allocationRate = null; + if (previous is not null) + { + double seconds = (current.TimestampUtc - previous.TimestampUtc).TotalSeconds; + if (seconds > 0) + { + allocationRate = Math.Max( + 0, + current.ProcessAllocatedBytes - previous.ProcessAllocatedBytes) + / seconds; + } + } + + rows.Add(new CheckpointRow( + current.Name, + current.TimestampUtc, + allocationRate)); + previous = current; + } + + return rows; + } + + private static IReadOnlyList ReadPortalMarkers(string path) + { + var markers = new List(); + foreach (string line in File.ReadLines(path)) + { + Match match = PortalMarkerPattern().Match(line); + if (!match.Success) + continue; + markers.Add(new PortalMarker( + DateTime.Parse( + match.Groups["timestamp"].Value, + CultureInfo.InvariantCulture, + DateTimeStyles.AdjustToUniversal | DateTimeStyles.AssumeUniversal), + match.Groups["destination"].Value)); + } + + return markers; + } + + private static WindowSummary SummarizeWindow(IEnumerable source) + { + FrameRow[] rows = source.OrderBy(row => row.TimestampUtc).ToArray(); + return new WindowSummary( + FrameCount: rows.Length, + DurationSeconds: rows.Length < 2 + ? 0 + : (rows[^1].TimestampUtc - rows[0].TimestampUtc).TotalSeconds, + CpuUs: SummarizeMetric(rows.Select(row => row.CpuUs)), + GpuUs: SummarizeMetric(rows.Where(row => row.GpuUs >= 0).Select(row => row.GpuUs)), + AllocationBytes: SummarizeMetric(rows.Select(row => row.AllocBytes)), + UpdateUs: SummarizeMetric(rows.Select(row => row.UpdateUs)), + UploadUs: SummarizeMetric(rows.Select(row => row.UploadUs)), + ImGuiUs: SummarizeMetric(rows.Select(row => row.ImGuiUs)), + PacingUs: SummarizeMetric(rows.Select(row => row.PacingUs)), + TotalPositiveAllocationBytes: rows.Sum(row => Math.Max(0, row.AllocBytes)), + CpuStandardDeviationUs: StandardDeviation(rows.Select(row => row.CpuUs))); + } + + private static MetricSummary SummarizeMetric(IEnumerable source) + { + long[] values = source.Order().ToArray(); + if (values.Length == 0) + return new MetricSummary(0, 0, 0, 0, 0, 0, 0); + return new MetricSummary( + values.Length, + Percentile(values, 0.50), + Percentile(values, 0.95), + Percentile(values, 0.99), + Percentile(values, 0.999), + values[^1], + values.Average()); + } + + private static long Percentile(long[] sorted, double percentile) + { + int index = (int)Math.Ceiling(sorted.Length * percentile) - 1; + return sorted[Math.Clamp(index, 0, sorted.Length - 1)]; + } + + private static double StandardDeviation(IEnumerable source) + { + long[] values = source.ToArray(); + if (values.Length == 0) + return 0; + double average = values.Average(); + double variance = values.Sum(value => Math.Pow(value - average, 2)) / values.Length; + return Math.Sqrt(variance); + } + + private static int ParseInt( + string[] values, + IReadOnlyDictionary columns, + string name) => + int.Parse(values[columns[name]], CultureInfo.InvariantCulture); + + private static long ParseLong( + string[] values, + IReadOnlyDictionary columns, + string name) => + long.Parse(values[columns[name]], CultureInfo.InvariantCulture); + + [GeneratedRegex( + "^(?\\S+) materialized destination='(?[^']+)'", + RegexOptions.CultureInvariant)] + private static partial Regex PortalMarkerPattern(); + + private sealed record FrameRow( + int Frame, + DateTime TimestampUtc, + long CpuUs, + long GpuUs, + long AllocBytes, + long UpdateUs, + long UploadUs, + long ImGuiUs, + long PacingUs); + + private sealed record CheckpointRaw( + string Name, + DateTime TimestampUtc, + long ProcessAllocatedBytes); + + private sealed record CheckpointRow( + string Name, + DateTime TimestampUtc, + double? ProcessAllocationRateBytesPerSecond); + + private sealed record PortalMarker(DateTime TimestampUtc, string Destination); +} + +public sealed record MetricSummary( + int Count, + long P50, + long P95, + long P99, + long P999, + long Maximum, + double Mean); + +public sealed record WindowSummary( + int FrameCount, + double DurationSeconds, + MetricSummary CpuUs, + MetricSummary GpuUs, + MetricSummary AllocationBytes, + MetricSummary UpdateUs, + MetricSummary UploadUs, + MetricSummary ImGuiUs, + MetricSummary PacingUs, + long TotalPositiveAllocationBytes, + double CpuStandardDeviationUs); + +public sealed record NamedWindowSummary( + string Name, + DateTime StartUtc, + DateTime EndUtc, + WindowSummary Metrics, + double? ProcessAllocationRateBytesPerSecond); + +public sealed record WorstFrame( + int Frame, + double RelativeToMaterializationMs, + long CpuUs, + long GpuUs, + long AllocationBytes, + long UpdateUs, + long UploadUs, + long PacingUs); + +public sealed record PortalWindowSummary( + string Destination, + DateTime MaterializedUtc, + WindowSummary Metrics, + IReadOnlyList WorstFrames); + +public sealed record FrameHistoryReport( + string SourceFrameHistory, + int FrameCount, + DateTime? FirstFrameUtc, + DateTime? LastFrameUtc, + WindowSummary Route, + IReadOnlyList CheckpointWindows, + IReadOnlyList PortalWindows); + +public sealed record ScreenshotComparison( + bool Passed, + int Width, + int Height, + int ExpectedWidth, + int ExpectedHeight, + int ChannelTolerance, + double MaxDifferentPixelFraction, + long ComparedPixels, + long MaskedPixels, + long DifferentPixels, + double DifferentPixelFraction, + int MaximumChannelDelta, + double MeanAbsoluteChannelDelta, + double RootMeanSquareChannelDelta, + string ExpectedPath, + string ActualPath, + string? MaskPath); diff --git a/src/AcDream.Cli/Program.cs b/src/AcDream.Cli/Program.cs index 4bb7cba8..f91fc215 100644 --- a/src/AcDream.Cli/Program.cs +++ b/src/AcDream.Cli/Program.cs @@ -8,6 +8,16 @@ using DatReaderWriter.Types; using Env = System.Environment; // ─── subcommand dispatch ──────────────────────────────────────────────────── +if (args.Length >= 1 && args[0] == "summarize-frame-history") +{ + return PerformanceTools.SummarizeFrameHistory(args[1..]); +} + +if (args.Length >= 1 && args[0] == "compare-screenshots") +{ + return PerformanceTools.CompareScreenshots(args[1..]); +} + if (args.Length >= 1 && args[0] == "dump-vitals-bars") { string? dvbDatDir = args.ElementAtOrDefault(1) ?? Env.GetEnvironmentVariable("ACDREAM_DAT_DIR"); diff --git a/tests/AcDream.App.Tests/Diagnostics/ConnectedR6SoakContractTests.cs b/tests/AcDream.App.Tests/Diagnostics/ConnectedR6SoakContractTests.cs index 5078426e..7c86f2d8 100644 --- a/tests/AcDream.App.Tests/Diagnostics/ConnectedR6SoakContractTests.cs +++ b/tests/AcDream.App.Tests/Diagnostics/ConnectedR6SoakContractTests.cs @@ -18,10 +18,11 @@ public sealed class ConnectedR6SoakContractTests [Fact] public void RouteContainsExactlyNineOrderedCheckpointBarriers() { - string[] checkpoints = File.ReadAllLines(Path.Combine( - FindRepoRoot(), - "tools", - "connected-r6-soak.route.txt")) + string routePath = Path.Combine( + FindRepoRoot(), + "tools", + "connected-r6-soak.route.txt"); + string[] checkpoints = File.ReadAllLines(routePath) .Select(static line => line.Trim()) .Where(static line => line.StartsWith( "checkpoint ", @@ -31,10 +32,7 @@ public sealed class ConnectedR6SoakContractTests Assert.Equal(ExpectedCheckpointNames, checkpoints); - string[] teleports = File.ReadAllLines(Path.Combine( - FindRepoRoot(), - "tools", - "connected-r6-soak.route.txt")) + string[] teleports = File.ReadAllLines(routePath) .Select(static line => line.Trim()) .Where(static line => line.StartsWith( "command /teleloc ", @@ -45,6 +43,97 @@ public sealed class ConnectedR6SoakContractTests " 1 0 0 0", line, StringComparison.Ordinal)); + + string[] screenshots = File.ReadAllLines(routePath) + .Select(static line => line.Trim()) + .Where(static line => line.StartsWith( + "screenshot ", + StringComparison.Ordinal)) + .Select(static line => line.Split(' ', StringSplitOptions.RemoveEmptyEntries)[1]) + .ToArray(); + Assert.Equal(ExpectedCheckpointNames, screenshots); + } + + [Fact] + public void DenseTownRoutePinsArwicViewAndScreenshot() + { + string[] route = File.ReadAllLines(Path.Combine( + FindRepoRoot(), + "tools", + "connected-dense-town.route.txt")) + .Select(static line => line.Trim()) + .Where(static line => line.Length > 0 && !line.StartsWith('#')) + .ToArray(); + + AssertAppearsInOrder( + string.Join('\n', route), + "command /telepoi Arwic", + "wait materialized 1 60000", + "input down MovementTurnRight", + "sleep 6000", + "input up MovementTurnRight", + "screenshot arwic-dense 10000", + "checkpoint arwic-dense"); + } + + [Fact] + public void PerformanceRoutesPinNoonBeforeTheirFirstTeleport() + { + foreach (string routeName in new[] + { + "connected-r6-soak.route.txt", + "connected-dense-town.route.txt", + }) + { + string source = File.ReadAllText(Path.Combine( + FindRepoRoot(), + "tools", + routeName)); + int firstTeleport = source.IndexOf("command /tele", StringComparison.Ordinal); + Assert.True(firstTeleport > 0, $"{routeName} has no teleport command."); + string preTeleport = source[..firstTeleport]; + Assert.Equal( + 3, + CountOccurrences( + preTeleport, + "input press AcdreamCycleTimeOfDay")); + } + } + + [Fact] + public void ReferenceConfigurationDefinesLocalAuthorityAndScreenshotRule() + { + string source = File.ReadAllText(Path.Combine( + FindRepoRoot(), + "docs", + "research", + "2026-07-24-performance-reference-configuration.json")); + using System.Text.Json.JsonDocument document = + System.Text.Json.JsonDocument.Parse(source); + System.Text.Json.JsonElement root = document.RootElement; + + Assert.Equal( + "performance-gate", + root.GetProperty("displayPaths") + .GetProperty("authoritativeLocal") + .GetProperty("authority") + .GetString()); + Assert.Equal( + "diagnostic-only", + root.GetProperty("displayPaths") + .GetProperty("diagnosticRdp") + .GetProperty("authority") + .GetString()); + Assert.Equal( + 2, + root.GetProperty("screenshotComparison") + .GetProperty("channelTolerance") + .GetInt32()); + Assert.Equal( + 0.001, + root.GetProperty("screenshotComparison") + .GetProperty("maxDifferentPixelFraction") + .GetDouble()); } [Fact] @@ -178,11 +267,102 @@ public sealed class ConnectedR6SoakContractTests "EnvDisclosure = Join-Path $artifactDir 'env-disclosure.json'", source, StringComparison.Ordinal); + Assert.Contains( + "$sensitive = $_.Name -match '(?i)(PASS|PASSWORD|TOKEN|SECRET|KEY)'", + source, + StringComparison.Ordinal); + Assert.Contains( + "Value = if ($sensitive) { '' } else { $_.Value }", + source, + StringComparison.Ordinal); // ACDREAM_DUMP_MOVE_TRUTH stays SET (the exercise gate greps its // output) — it is now disclosed, not removed. Assert.Contains("$env:ACDREAM_DUMP_MOVE_TRUTH = '1'", source, StringComparison.Ordinal); } + [Fact] + public void SoakExportsAndSummarizesFrameHistory() + { + string source = File.ReadAllText(Path.Combine( + FindRepoRoot(), + "tools", + "run-connected-r6-soak.ps1")); + + Assert.Contains( + "$env:ACDREAM_FRAME_HISTORY = $frameHistory", + source, + StringComparison.Ordinal); + AssertAppearsInOrder( + source, + "& dotnet $cliDll summarize-frame-history", + "$frameHistory", + "$checkpointTimeline", + "$markerLog", + "$frameSummary"); + Assert.Contains("FrameHistory = $frameHistory", source, StringComparison.Ordinal); + Assert.Contains("FrameSummary = $frameSummary", source, StringComparison.Ordinal); + } + + [Fact] + public void ContentionCaptureIsExplicitAndIncludesStackEvents() + { + string source = File.ReadAllText(Path.Combine( + FindRepoRoot(), + "tools", + "run-connected-r6-soak.ps1")); + + Assert.Contains("[switch]$CaptureContention", source, StringComparison.Ordinal); + Assert.Contains( + "'Microsoft-Windows-DotNETRuntime:0x4000:5'", + source, + StringComparison.Ordinal); + Assert.Contains( + "ContentionTrace = if ($CaptureContention) { $contentionTrace } else { $null }", + source, + StringComparison.Ordinal); + } + + [Fact] + public void RuntimeCountersCaptureProcessWideAllocationByDefault() + { + string source = File.ReadAllText(Path.Combine( + FindRepoRoot(), + "tools", + "run-connected-r6-soak.ps1")); + + Assert.Contains("[switch]$SkipRuntimeCounters", source, StringComparison.Ordinal); + AssertAppearsInOrder( + source, + "if (-not $SkipRuntimeCounters) {", + "'--counters', 'System.Runtime'", + "'--refresh-interval', '1'", + "'--format', 'csv'", + "'--output', $runtimeCounters"); + Assert.Contains( + "RuntimeCounters = if (-not $SkipRuntimeCounters) { $runtimeCounters } else { $null }", + source, + StringComparison.Ordinal); + } + + [Fact] + public void DenseTownModeUsesTheDedicatedOneCheckpointRoute() + { + string source = File.ReadAllText(Path.Combine( + FindRepoRoot(), + "tools", + "run-connected-r6-soak.ps1")); + + Assert.Contains("[switch]$DenseTown", source, StringComparison.Ordinal); + AssertAppearsInOrder( + source, + "if ($DenseTown) {", + "Name = 'Arwic dense'", + "$expectedCheckpointNames = @('arwic-dense')", + "$routeFileName = 'connected-dense-town.route.txt'", + "$runName = 'connected-dense-town'"); + Assert.Contains("if (-not $DenseTown) {", source, StringComparison.Ordinal); + } + private static int CountOccurrences(string source, string value) { int count = 0; diff --git a/tests/AcDream.App.Tests/FrameProfilerReportTests.cs b/tests/AcDream.App.Tests/FrameProfilerReportTests.cs index 06e8c4b6..dd901f45 100644 --- a/tests/AcDream.App.Tests/FrameProfilerReportTests.cs +++ b/tests/AcDream.App.Tests/FrameProfilerReportTests.cs @@ -20,18 +20,25 @@ public class FrameProfilerReportTests }; var buffer = new StringWriter(CultureInfo.InvariantCulture); - FrameProfiler.WriteHistoryCsv(records, buffer); + FrameProfiler.WriteHistoryCsv( + records, + buffer, + new DateTime(2026, 7, 24, 10, 0, 0, DateTimeKind.Utc)); string[] lines = buffer.ToString().Split( Environment.NewLine, StringSplitOptions.RemoveEmptyEntries); Assert.Equal(3, lines.Length); Assert.Equal( - "frame,timestamp_ms,cpu_us,gpu_us,alloc_bytes,update_us,upload_us,imgui_us,pacing_us", + "frame,timestamp_ms,timestamp_utc,cpu_us,gpu_us,alloc_bytes,update_us,upload_us,imgui_us,pacing_us", lines[0]); - Assert.Equal("0,12.500,1000,500,2048,100,200,30,40", lines[1]); + Assert.Equal( + "0,12.500,2026-07-24T10:00:00.0125000Z,1000,500,2048,100,200,30,40", + lines[1]); // gpu_us=-1 marks "no GPU sample available"; alloc_bytes can go // negative (documented alloc-channel behavior, matches FrameStatsBuffer.Max). - Assert.Equal("1,18.750,1200,-1,-256,110,210,31,41", lines[2]); + Assert.Equal( + "1,18.750,2026-07-24T10:00:00.0187500Z,1200,-1,-256,110,210,31,41", + lines[2]); } diff --git a/tests/AcDream.App.Tests/Rendering/GameWindowRenderLeafCompositionTests.cs b/tests/AcDream.App.Tests/Rendering/GameWindowRenderLeafCompositionTests.cs index 6bf45442..6101bf90 100644 --- a/tests/AcDream.App.Tests/Rendering/GameWindowRenderLeafCompositionTests.cs +++ b/tests/AcDream.App.Tests/Rendering/GameWindowRenderLeafCompositionTests.cs @@ -182,8 +182,10 @@ public sealed class GameWindowRenderLeafCompositionTests "screenshotCaptured);"); AssertAppearsInOrder( orchestrator, - "WorldRenderFrameOutcome world = _world.Render(input);", + "_gpuMeasurement.BeginFrame();", + "world = _world.Render(input);", "_presentation.Render(input, world);", + "_gpuMeasurement.EndFrame();", "new RenderFrameOutcome(world, presentation);", "_diagnostics.Publish(input, outcome);"); } diff --git a/tests/AcDream.App.Tests/Rendering/RenderFrameOrchestratorTests.cs b/tests/AcDream.App.Tests/Rendering/RenderFrameOrchestratorTests.cs index 43539e70..0a23f6ac 100644 --- a/tests/AcDream.App.Tests/Rendering/RenderFrameOrchestratorTests.cs +++ b/tests/AcDream.App.Tests/Rendering/RenderFrameOrchestratorTests.cs @@ -39,7 +39,8 @@ public sealed class RenderFrameOrchestratorTests Assert.Equal( [ - "gpu-begin", "resources", "world", "presentation", + "gpu-begin", "measure-begin", "resources", "world", "presentation", + "measure-end", "diagnostics", "post-diagnostics", "gpu-end", ], calls); @@ -118,7 +119,8 @@ public sealed class RenderFrameOrchestratorTests Assert.Same(expected, actual); Assert.Equal( [ - "gpu-begin", "resources", "world", "presentation", + "gpu-begin", "measure-begin", "resources", "world", "presentation", + "measure-end", "diagnostics", "post-diagnostics", "gpu-end", ], calls); @@ -177,7 +179,10 @@ public sealed class RenderFrameOrchestratorTests Assert.Same(renderFailure, actual.InnerExceptions[0]); Assert.Same(recoveryFailure, actual.InnerExceptions[1]); Assert.Equal( - ["gpu-begin", "resources", "world", "recovery-abort", "gpu-end"], + [ + "gpu-begin", "measure-begin", "resources", "world", + "measure-end", "recovery-abort", "gpu-end", + ], calls); } @@ -205,7 +210,8 @@ public sealed class RenderFrameOrchestratorTests Assert.Same(closeFailure, actual.InnerExceptions[2]); Assert.Equal( [ - "gpu-begin", "resources", "world", "presentation", + "gpu-begin", "measure-begin", "resources", "world", "presentation", + "measure-end", "recovery-abort", "gpu-end", ], calls); @@ -217,19 +223,21 @@ public sealed class RenderFrameOrchestratorTests var phases = new RecordingPhases([]); Assert.Throws(() => new RenderFrameOrchestrator( - null!, phases, phases, phases, phases, phases, phases)); + null!, phases, phases, phases, phases, phases, phases, phases)); Assert.Throws(() => new RenderFrameOrchestrator( - phases, null!, phases, phases, phases, phases, phases)); + phases, null!, phases, phases, phases, phases, phases, phases)); Assert.Throws(() => new RenderFrameOrchestrator( - phases, phases, null!, phases, phases, phases, phases)); + phases, phases, null!, phases, phases, phases, phases, phases)); Assert.Throws(() => new RenderFrameOrchestrator( - phases, phases, phases, null!, phases, phases, phases)); + phases, phases, phases, null!, phases, phases, phases, phases)); Assert.Throws(() => new RenderFrameOrchestrator( - phases, phases, phases, phases, null!, phases, phases)); + phases, phases, phases, phases, null!, phases, phases, phases)); Assert.Throws(() => new RenderFrameOrchestrator( - phases, phases, phases, phases, phases, null!, phases)); + phases, phases, phases, phases, phases, null!, phases, phases)); Assert.Throws(() => new RenderFrameOrchestrator( - phases, phases, phases, phases, phases, phases, null!)); + phases, phases, phases, phases, phases, phases, null!, phases)); + Assert.Throws(() => new RenderFrameOrchestrator( + phases, phases, phases, phases, phases, phases, phases, null!)); } [Fact] @@ -238,6 +246,7 @@ public sealed class RenderFrameOrchestratorTests Type[] expectedFieldTypes = [ typeof(IRenderFrameLifetime), + typeof(IRenderFrameGpuMeasurement), typeof(IRenderFrameResourcePhase), typeof(IWorldSceneFramePhase), typeof(IPrivatePresentationFramePhase), @@ -308,22 +317,33 @@ public sealed class RenderFrameOrchestratorTests private static string[] ExpectedFailureCalls(string failurePoint) => failurePoint switch { - "resources" => ["gpu-begin", "resources", "recovery-abort", "gpu-end"], - "world" => ["gpu-begin", "resources", "world", "recovery-abort", "gpu-end"], + "resources" => + [ + "gpu-begin", "measure-begin", "resources", "measure-end", + "recovery-abort", "gpu-end", + ], + "world" => + [ + "gpu-begin", "measure-begin", "resources", "world", "measure-end", + "recovery-abort", "gpu-end", + ], "presentation" => [ - "gpu-begin", "resources", "world", "presentation", + "gpu-begin", "measure-begin", "resources", "world", "presentation", + "measure-end", "recovery-abort", "gpu-end", ], "diagnostics" => [ - "gpu-begin", "resources", "world", "presentation", "diagnostics", + "gpu-begin", "measure-begin", "resources", "world", "presentation", + "measure-end", "diagnostics", "recovery-abort", "gpu-end", ], "post-diagnostics" => [ - "gpu-begin", "resources", "world", "presentation", "diagnostics", - "post-diagnostics", "recovery-abort", "gpu-end", + "gpu-begin", "measure-begin", "resources", "world", "presentation", + "measure-end", "diagnostics", "post-diagnostics", + "recovery-abort", "gpu-end", ], _ => throw new ArgumentOutOfRangeException(nameof(failurePoint)), }; @@ -348,10 +368,11 @@ public sealed class RenderFrameOrchestratorTests } private static RenderFrameOrchestrator Create(RecordingPhases phases) => - new(phases, phases, phases, phases, phases, phases, phases); + new(phases, phases, phases, phases, phases, phases, phases, phases); private sealed class RecordingPhases : IRenderFrameLifetime, + IRenderFrameGpuMeasurement, IRenderFrameResourcePhase, IWorldSceneFramePhase, IPrivatePresentationFramePhase, @@ -376,15 +397,19 @@ public sealed class RenderFrameOrchestratorTests public WorldRenderFrameOutcome ObservedWorld { get; private set; } public RenderFrameOutcome ObservedOutcome { get; private set; } - public void BeginFrame() => Record("gpu-begin"); + void IRenderFrameLifetime.BeginFrame() => Record("gpu-begin"); - public void EndFrame() + void IRenderFrameLifetime.EndFrame() { _calls.Add("gpu-end"); if (CloseFailure is not null) throw CloseFailure; } + void IRenderFrameGpuMeasurement.BeginFrame() => Record("measure-begin"); + + void IRenderFrameGpuMeasurement.EndFrame() => _calls.Add("measure-end"); + public void AbortFrame() { _calls.Add("recovery-abort"); diff --git a/tests/AcDream.App.Tests/Rendering/RenderFrameRecoveryIntegrationTests.cs b/tests/AcDream.App.Tests/Rendering/RenderFrameRecoveryIntegrationTests.cs index b0c2b6fc..8efe150b 100644 --- a/tests/AcDream.App.Tests/Rendering/RenderFrameRecoveryIntegrationTests.cs +++ b/tests/AcDream.App.Tests/Rendering/RenderFrameRecoveryIntegrationTests.cs @@ -33,6 +33,7 @@ public sealed class RenderFrameRecoveryIntegrationTests new Screenshots()); var orchestrator = new RenderFrameOrchestrator( gpu, + new GpuMeasurement(), preparation, new World(failure), presentation, @@ -87,6 +88,17 @@ public sealed class RenderFrameRecoveryIntegrationTests } } + private sealed class GpuMeasurement : IRenderFrameGpuMeasurement + { + public void BeginFrame() + { + } + + public void EndFrame() + { + } + } + private sealed class DevTools(FailureSwitch failure) : IDevToolsFrameLifecycle { public bool IsOpen { get; private set; } diff --git a/tests/AcDream.App.Tests/Rendering/RenderFrameResourceControllerTests.cs b/tests/AcDream.App.Tests/Rendering/RenderFrameResourceControllerTests.cs index 208ff93b..4ac71907 100644 --- a/tests/AcDream.App.Tests/Rendering/RenderFrameResourceControllerTests.cs +++ b/tests/AcDream.App.Tests/Rendering/RenderFrameResourceControllerTests.cs @@ -60,8 +60,8 @@ public sealed class RenderFrameResourceControllerTests "_uiText?.BeginFrame(gpuSlot);", "_clip?.BeginFrame(gpuSlot);", "_terrain?.BeginFrame(gpuSlot);", - "_lighting?.BeginFrame(gpuSlot);", - "_profiler.FrameBoundary(_gl);"); + "_lighting?.BeginFrame(gpuSlot);"); + Assert.DoesNotContain("_profiler.FrameBoundary(", source); } [Fact] diff --git a/tests/AcDream.Cli.Tests/AcDream.Cli.Tests.csproj b/tests/AcDream.Cli.Tests/AcDream.Cli.Tests.csproj new file mode 100644 index 00000000..2f2bccdd --- /dev/null +++ b/tests/AcDream.Cli.Tests/AcDream.Cli.Tests.csproj @@ -0,0 +1,24 @@ + + + + net10.0 + enable + enable + false + + + + + + + + + + + + + + + + + diff --git a/tests/AcDream.Cli.Tests/PerformanceToolsTests.cs b/tests/AcDream.Cli.Tests/PerformanceToolsTests.cs new file mode 100644 index 00000000..b3fc1cec --- /dev/null +++ b/tests/AcDream.Cli.Tests/PerformanceToolsTests.cs @@ -0,0 +1,178 @@ +using System.Text.Json; +using AcDream.Cli; +using SixLabors.ImageSharp; +using SixLabors.ImageSharp.PixelFormats; + +namespace AcDream.Cli.Tests; + +public sealed class PerformanceToolsTests +{ + [Fact] + public void CompareImages_AppliesChannelToleranceAndMask() + { + using var directory = new TemporaryDirectory(); + string expectedPath = Path.Combine(directory.Path, "expected.png"); + string actualPath = Path.Combine(directory.Path, "actual.png"); + string maskPath = Path.Combine(directory.Path, "mask.png"); + + using (var expected = new Image(2, 1)) + using (var actual = new Image(2, 1)) + using (var mask = new Image(2, 1)) + { + expected[0, 0] = new Rgba32(10, 20, 30, 255); + expected[1, 0] = new Rgba32(40, 50, 60, 255); + actual[0, 0] = new Rgba32(12, 20, 30, 255); + actual[1, 0] = new Rgba32(200, 50, 60, 255); + mask[1, 0] = new Rgba32(0, 0, 0, 255); + expected.SaveAsPng(expectedPath); + actual.SaveAsPng(actualPath); + mask.SaveAsPng(maskPath); + } + + ScreenshotComparison unmasked = PerformanceTools.CompareImages( + expectedPath, + actualPath, + channelTolerance: 2, + maxDifferentFraction: 0); + ScreenshotComparison masked = PerformanceTools.CompareImages( + expectedPath, + actualPath, + channelTolerance: 2, + maxDifferentFraction: 0, + maskPath); + + Assert.False(unmasked.Passed); + Assert.Equal(1, unmasked.DifferentPixels); + Assert.True(masked.Passed); + Assert.Equal(1, masked.ComparedPixels); + Assert.Equal(1, masked.MaskedPixels); + Assert.Equal(0, masked.DifferentPixels); + } + + [Fact] + public void CompareImages_RejectsAFullyMaskedComparison() + { + using var directory = new TemporaryDirectory(); + string expectedPath = Path.Combine(directory.Path, "expected.png"); + string actualPath = Path.Combine(directory.Path, "actual.png"); + string maskPath = Path.Combine(directory.Path, "mask.png"); + using (var image = new Image(1, 1)) + using (var mask = new Image(1, 1)) + { + mask[0, 0] = new Rgba32(0, 0, 0, 255); + image.SaveAsPng(expectedPath); + image.SaveAsPng(actualPath); + mask.SaveAsPng(maskPath); + } + + InvalidDataException error = Assert.Throws(() => + PerformanceTools.CompareImages( + expectedPath, + actualPath, + channelTolerance: 2, + maxDifferentFraction: 0.001, + maskPath)); + + Assert.Contains("excludes every pixel", error.Message); + } + + [Fact] + public void CompareScreenshots_WritesSerializableDimensionMismatch() + { + using var directory = new TemporaryDirectory(); + string expectedPath = Path.Combine(directory.Path, "expected.png"); + string actualPath = Path.Combine(directory.Path, "actual.png"); + string outputPath = Path.Combine(directory.Path, "comparison.json"); + using (var expected = new Image(1, 1)) + using (var actual = new Image(2, 1)) + { + expected.SaveAsPng(expectedPath); + actual.SaveAsPng(actualPath); + } + + int exitCode = PerformanceTools.CompareScreenshots( + [expectedPath, actualPath, outputPath]); + + Assert.Equal(1, exitCode); + using JsonDocument report = JsonDocument.Parse(File.ReadAllText(outputPath)); + Assert.False(report.RootElement.GetProperty("passed").GetBoolean()); + Assert.Equal("expected.png", report.RootElement.GetProperty("expectedPath").GetString()); + Assert.Equal("actual.png", report.RootElement.GetProperty("actualPath").GetString()); + } + + [Fact] + public void SummarizeFrameHistory_WritesRouteCheckpointAndPortalPopulations() + { + using var directory = new TemporaryDirectory(); + string framesPath = Path.Combine(directory.Path, "frames.csv"); + string checkpointsPath = Path.Combine(directory.Path, "checkpoints.jsonl"); + string markersPath = Path.Combine(directory.Path, "markers.log"); + string outputPath = Path.Combine(directory.Path, "summary.json"); + + File.WriteAllLines(framesPath, + [ + "frame,timestamp_ms,timestamp_utc,cpu_us,gpu_us,alloc_bytes,update_us,upload_us,imgui_us,pacing_us", + "0,0.000,2026-07-24T10:00:00.0000000Z,1000,500,100,100,10,0,0", + "1,1000.000,2026-07-24T10:00:01.0000000Z,2000,600,200,200,20,0,0", + "2,2000.000,2026-07-24T10:00:02.0000000Z,9000,700,300,300,30,0,0", + ]); + File.WriteAllText( + checkpointsPath, + """ + {"name":"baseline","timestampUtc":"2026-07-24T10:00:01Z","resources":{"processTotalAllocatedBytes":1000}} + {"name":"return","timestampUtc":"2026-07-24T10:00:02Z","resources":{"processTotalAllocatedBytes":5000}} + + """); + File.WriteAllText( + markersPath, + "2026-07-24T10:00:01.0000000Z materialized destination='Arwic' occurrence=1 elapsed=1.0s"); + + int exitCode = PerformanceTools.SummarizeFrameHistory( + [framesPath, checkpointsPath, markersPath, outputPath]); + + Assert.Equal(0, exitCode); + using JsonDocument report = JsonDocument.Parse(File.ReadAllText(outputPath)); + JsonElement root = report.RootElement; + Assert.Equal(3, root.GetProperty("frameCount").GetInt32()); + Assert.Equal( + 9000, + root.GetProperty("route").GetProperty("cpuUs").GetProperty("p99").GetInt64()); + Assert.Equal( + 2, + root.GetProperty("checkpointWindows").GetArrayLength()); + Assert.Equal( + 4000, + root.GetProperty("checkpointWindows")[1] + .GetProperty("processAllocationRateBytesPerSecond") + .GetDouble()); + Assert.Equal( + "Arwic", + root.GetProperty("portalWindows")[0].GetProperty("destination").GetString()); + Assert.Equal( + 9000, + root.GetProperty("portalWindows")[0] + .GetProperty("worstFrames")[0] + .GetProperty("cpuUs") + .GetInt64()); + } + + private sealed class TemporaryDirectory : IDisposable + { + public TemporaryDirectory() + { + Path = System.IO.Path.Combine( + System.IO.Path.GetTempPath(), + "acdream-cli-tests", + Guid.NewGuid().ToString("N")); + Directory.CreateDirectory(Path); + } + + public string Path { get; } + + public void Dispose() + { + if (Directory.Exists(Path)) + Directory.Delete(Path, recursive: true); + } + } +} diff --git a/tools/connected-dense-town.route.txt b/tools/connected-dense-town.route.txt new file mode 100644 index 00000000..bf143348 --- /dev/null +++ b/tools/connected-dense-town.route.txt @@ -0,0 +1,19 @@ +# Deterministic dense-town performance scene. Arwic is the established +# dense-town oracle used by the June and July renderer investigations. +# /telepoi supplies ACE's canonical arrival position and heading. The fixed +# six-second retail-input turn pins the view facing for every capture. + +sleep 15000 +# Pin the client-only world-time override at noon for reproducible screenshots. +input press AcdreamCycleTimeOfDay +input press AcdreamCycleTimeOfDay +input press AcdreamCycleTimeOfDay +command /telepoi Arwic +wait materialized 1 60000 +sleep 8000 +input down MovementTurnRight +sleep 6000 +input up MovementTurnRight +sleep 26000 +screenshot arwic-dense 10000 +checkpoint arwic-dense diff --git a/tools/connected-r6-soak.route.txt b/tools/connected-r6-soak.route.txt index 9d2d1552..8786fbc0 100644 --- a/tools/connected-r6-soak.route.txt +++ b/tools/connected-r6-soak.route.txt @@ -3,6 +3,11 @@ # remains deterministic when no RDP/interactive desktop is attached. sleep 15000 +# Pin the client-only world-time override at noon for reproducible screenshots. +# The diagnostic action cycles: live -> 0.00 -> 0.25 -> 0.50. +input press AcdreamCycleTimeOfDay +input press AcdreamCycleTimeOfDay +input press AcdreamCycleTimeOfDay # Caul baseline + local movement/jump/combat exercise. Every teleloc carries # the identity quaternion so each timed turn begins from the same heading. @@ -41,6 +46,7 @@ input up MovementForward sleep 700 input press CombatToggleCombat sleep 7400 +screenshot caul-baseline 10000 checkpoint caul-baseline # Sawato baseline. @@ -51,6 +57,7 @@ input down MovementTurnRight sleep 6000 input up MovementTurnRight sleep 22000 +screenshot sawato-baseline 10000 checkpoint sawato-baseline # Rynthid world-edge streaming. @@ -61,6 +68,7 @@ input down MovementTurnRight sleep 6000 input up MovementTurnRight sleep 22000 +screenshot rynthid 10000 checkpoint rynthid # Aerlinthe dense island. @@ -71,6 +79,7 @@ input down MovementTurnRight sleep 6000 input up MovementTurnRight sleep 22000 +screenshot aerlinthe 10000 checkpoint aerlinthe # Same-location lifecycle revisit. @@ -81,6 +90,7 @@ input down MovementTurnRight sleep 6000 input up MovementTurnRight sleep 22000 +screenshot sawato-return 10000 checkpoint sawato-return # Holtburg mixed-town workload + local exercise. @@ -119,6 +129,7 @@ input up MovementForward sleep 700 input press CombatToggleCombat sleep 7400 +screenshot holtburg 10000 checkpoint holtburg # Caul return/leak oracle + final local exercise. @@ -157,6 +168,7 @@ input up MovementForward sleep 700 input press CombatToggleCombat sleep 15000 +screenshot caul-return 10000 checkpoint caul-return # A second warm-cache Sawato/Caul revisit is the plateau oracle. The first @@ -170,6 +182,7 @@ input down MovementTurnRight sleep 6000 input up MovementTurnRight sleep 22000 +screenshot sawato-plateau 10000 checkpoint sawato-plateau command /teleloc 0xC95B0001 14.8 0.3 12.005 1 0 0 0 @@ -179,4 +192,5 @@ input down MovementTurnRight sleep 6000 input up MovementTurnRight sleep 22000 +screenshot caul-plateau 10000 checkpoint caul-plateau diff --git a/tools/run-connected-r6-soak.ps1 b/tools/run-connected-r6-soak.ps1 index a05c12e0..3e71438a 100644 --- a/tools/run-connected-r6-soak.ps1 +++ b/tools/run-connected-r6-soak.ps1 @@ -5,6 +5,9 @@ param( [string]$Password = $env:ACDREAM_TEST_PASS, [switch]$SkipBuild, [switch]$Uncapped, + [switch]$DenseTown, + [switch]$CaptureContention, + [switch]$SkipRuntimeCounters, [int]$LoginTimeoutSeconds = 90 ) @@ -14,33 +17,45 @@ $ErrorActionPreference = 'Stop' if ([string]::IsNullOrWhiteSpace($Account)) { $Account = 'testaccount' } if ([string]::IsNullOrWhiteSpace($Password)) { $Password = 'testpassword' } -$destinations = @( - [pscustomobject]@{ Name = 'Caul'; Occurrence = 1; Exercise = $true }, - [pscustomobject]@{ Name = 'Sawato'; Occurrence = 2; Exercise = $false }, - [pscustomobject]@{ Name = 'Rynthid'; Occurrence = 3; Exercise = $false }, - [pscustomobject]@{ Name = 'Aerlinthe'; Occurrence = 4; Exercise = $false }, - [pscustomobject]@{ Name = 'Sawato revisit'; Occurrence = 5; Exercise = $false }, - [pscustomobject]@{ Name = 'Holtburg'; Occurrence = 6; Exercise = $true }, - [pscustomobject]@{ Name = 'Caul return'; Occurrence = 7; Exercise = $true }, - [pscustomobject]@{ Name = 'Sawato plateau'; Occurrence = 8; Exercise = $false }, - [pscustomobject]@{ Name = 'Caul plateau'; Occurrence = 9; Exercise = $false } -) -$expectedCheckpointNames = @( - 'caul-baseline', - 'sawato-baseline', - 'rynthid', - 'aerlinthe', - 'sawato-return', - 'holtburg', - 'caul-return', - 'sawato-plateau', - 'caul-plateau' -) +if ($DenseTown) { + [object[]]$destinations = @( + [pscustomobject]@{ Name = 'Arwic dense'; Occurrence = 1; Exercise = $false } + ) + [string[]]$expectedCheckpointNames = @('arwic-dense') + $routeFileName = 'connected-dense-town.route.txt' + $runName = 'connected-dense-town' +} +else { + [object[]]$destinations = @( + [pscustomobject]@{ Name = 'Caul'; Occurrence = 1; Exercise = $true }, + [pscustomobject]@{ Name = 'Sawato'; Occurrence = 2; Exercise = $false }, + [pscustomobject]@{ Name = 'Rynthid'; Occurrence = 3; Exercise = $false }, + [pscustomobject]@{ Name = 'Aerlinthe'; Occurrence = 4; Exercise = $false }, + [pscustomobject]@{ Name = 'Sawato revisit'; Occurrence = 5; Exercise = $false }, + [pscustomobject]@{ Name = 'Holtburg'; Occurrence = 6; Exercise = $true }, + [pscustomobject]@{ Name = 'Caul return'; Occurrence = 7; Exercise = $true }, + [pscustomobject]@{ Name = 'Sawato plateau'; Occurrence = 8; Exercise = $false }, + [pscustomobject]@{ Name = 'Caul plateau'; Occurrence = 9; Exercise = $false } + ) + [string[]]$expectedCheckpointNames = @( + 'caul-baseline', + 'sawato-baseline', + 'rynthid', + 'aerlinthe', + 'sawato-return', + 'holtburg', + 'caul-return', + 'sawato-plateau', + 'caul-plateau' + ) + $routeFileName = 'connected-r6-soak.route.txt' + $runName = 'connected-r6-soak' +} $stamp = Get-Date -Format 'yyyyMMdd-HHmmss' $logDir = Join-Path $Repository 'logs' $null = New-Item -ItemType Directory -Force -Path $logDir -$prefix = Join-Path $logDir "connected-r6-soak-$stamp" +$prefix = Join-Path $logDir "$runName-$stamp" $stdoutLog = "$prefix.out.log" $stderrLog = "$prefix.err.log" $markerLog = "$prefix.markers.log" @@ -48,13 +63,24 @@ $sampleCsv = "$prefix.samples.csv" $reportJson = "$prefix.report.json" $artifactDir = "$prefix.artifacts" $checkpointTimeline = Join-Path $artifactDir 'world-lifecycle.checkpoints.jsonl' -$routePath = Join-Path $Repository 'tools\connected-r6-soak.route.txt' +$frameHistory = Join-Path $artifactDir 'frame-history.csv' +$frameSummary = Join-Path $artifactDir 'frame-history-summary.json' +$contentionTrace = Join-Path $artifactDir 'contention.nettrace' +$contentionStdout = Join-Path $artifactDir 'contention.out.log' +$contentionStderr = Join-Path $artifactDir 'contention.err.log' +$runtimeCounters = Join-Path $artifactDir 'runtime-counters.csv' +$counterStdout = Join-Path $artifactDir 'runtime-counters.out.log' +$counterStderr = Join-Path $artifactDir 'runtime-counters.err.log' +$routePath = Join-Path $Repository "tools\$routeFileName" $exe = Join-Path $Repository 'src\AcDream.App\bin\Release\net10.0\AcDream.App.exe' +$cliDll = Join-Path $Repository 'src\AcDream.Cli\bin\Release\net10.0\AcDream.Cli.dll' $samples = [System.Collections.Generic.List[object]]::new() $failures = [System.Collections.Generic.List[string]]::new() $warnings = [System.Collections.Generic.List[string]]::new() $process = $null +$traceProcess = $null +$counterProcess = $null $stopwatch = [Diagnostics.Stopwatch]::StartNew() $gracefulExit = $false $exitCode = $null @@ -374,6 +400,10 @@ function Add-CanonicalCheckpointFailures([Diagnostics.Process]$Client) { } } + if ($DenseTown) { + return + } + $caulReturn = $canonicalCheckpoints | Where-Object { $_.name -eq 'caul-return' } | Select-Object -First 1 @@ -588,6 +618,7 @@ if (-not $SkipBuild) { if ($LASTEXITCODE -ne 0) { throw "Release build failed with exit code $LASTEXITCODE" } } if (-not (Test-Path -LiteralPath $exe)) { throw "client executable not found: $exe" } +if (-not (Test-Path -LiteralPath $cliDll)) { throw "CLI assembly not found: $cliDll" } $commit = (& git -C $Repository rev-parse HEAD).Trim() $sourceStatus = @(& git -C $Repository status --short) @@ -603,6 +634,7 @@ $env:ACDREAM_TEST_USER = $Account $env:ACDREAM_TEST_PASS = $Password $env:ACDREAM_RETAIL_UI = '1' $env:ACDREAM_FRAME_PROF = '1' +$env:ACDREAM_FRAME_HISTORY = $frameHistory # Capped by default (matches the retail presentation cadence the connected # visual matrix is gated against); pass -Uncapped to opt into uncapped # render, matching run-connected-world-lifecycle-gate.ps1's pattern. @@ -623,11 +655,21 @@ $env:ACDREAM_WB_DIAG = $null $null = New-Item -ItemType Directory -Force -Path $artifactDir $acdreamEnvVars = Get-ChildItem Env: | Where-Object { $_.Name -like 'ACDREAM_*' } | Sort-Object Name | - ForEach-Object { [pscustomobject]@{ Name = $_.Name; Value = $_.Value } } + ForEach-Object { + $sensitive = $_.Name -match '(?i)(PASS|PASSWORD|TOKEN|SECRET|KEY)' + [pscustomobject]@{ + Name = $_.Name + Value = if ($sensitive) { '' } else { $_.Value } + } + } $envDisclosure = [pscustomobject][ordered]@{ Script = 'run-connected-r6-soak.ps1' GeneratedUtc = [DateTime]::UtcNow.ToString('O') Uncapped = [bool]$Uncapped + DenseTown = [bool]$DenseTown + CaptureContention = [bool]$CaptureContention + RuntimeCounters = -not [bool]$SkipRuntimeCounters + Route = $routeFileName EnvironmentVariables = @($acdreamEnvVars) } $envDisclosure | ConvertTo-Json -Depth 4 | @@ -638,6 +680,42 @@ try { -RedirectStandardOutput $stdoutLog -RedirectStandardError $stderrLog -PassThru Write-Marker "launch pid=$($process.Id) commit=$commit session='$env:SESSIONNAME'" + if (-not $SkipRuntimeCounters) { + $counterArguments = @( + 'collect', + '--process-id', $process.Id, + '--counters', 'System.Runtime', + '--refresh-interval', '1', + '--format', 'csv', + '--output', $runtimeCounters, + '--duration', '00:00:15:00' + ) + $counterProcess = Start-Process -FilePath 'dotnet-counters' ` + -ArgumentList $counterArguments ` + -RedirectStandardOutput $counterStdout ` + -RedirectStandardError $counterStderr ` + -PassThru ` + -WindowStyle Hidden + Write-Marker "runtime-counters pid=$($counterProcess.Id)" + } + + if ($CaptureContention) { + $traceArguments = @( + 'collect', + '--process-id', $process.Id, + '--providers', 'Microsoft-Windows-DotNETRuntime:0x4000:5', + '--output', $contentionTrace, + '--duration', '00:00:15:00' + ) + $traceProcess = Start-Process -FilePath 'dotnet-trace' ` + -ArgumentList $traceArguments ` + -RedirectStandardOutput $contentionStdout ` + -RedirectStandardError $contentionStderr ` + -PassThru ` + -WindowStyle Hidden + Write-Marker "contention-capture pid=$($traceProcess.Id)" + } + $null = Wait-ForLogPattern $process $stdoutLog 'live: in world' 1 $LoginTimeoutSeconds $null = Wait-ForLogPattern $process $stdoutLog 'live: first player position' 1 $LoginTimeoutSeconds Write-Marker ("in-world elapsed={0:N1}s" -f $stopwatch.Elapsed.TotalSeconds) @@ -681,15 +759,19 @@ try { $failures.Add("expected $($destinations.Count) teleport materializations") } + $lastCheckpointName = $expectedCheckpointNames[-1] + $lastCheckpointSequence = $expectedCheckpointNames.Count $null = Wait-ForLogPattern ` $process ` $stdoutLog ` - '[world-gate] checkpoint name=caul-plateau sequence=9' ` + "[world-gate] checkpoint name=$lastCheckpointName sequence=$lastCheckpointSequence" ` 1 ` 30 $canonicalCheckpoints = @(Read-CanonicalCheckpoints) Add-CanonicalCheckpointFailures $process - Add-RelativeGateFailures + if (-not $DenseTown) { + Add-RelativeGateFailures + } Write-Marker 'route-complete requesting graceful close' $gracefulExit = Close-ClientGracefully $process @@ -717,6 +799,46 @@ finally { if ($process.HasExited -and $null -eq $exitCode) { $exitCode = [int]$process.ExitCode } $process.Dispose() } + if ($null -ne $traceProcess) { + if (-not $traceProcess.WaitForExit(30000)) { + $warnings.Add('dotnet-trace did not exit within 30 seconds of client shutdown') + Stop-Process -Id $traceProcess.Id -Force + $traceProcess.WaitForExit(10000) + } + if (-not (Test-Path -LiteralPath $contentionTrace)) { + $failures.Add('contention capture did not produce a nettrace artifact') + } + $traceProcess.Dispose() + } + if ($null -ne $counterProcess) { + if (-not $counterProcess.WaitForExit(30000)) { + $warnings.Add('dotnet-counters did not exit within 30 seconds of client shutdown') + Stop-Process -Id $counterProcess.Id -Force + $counterProcess.WaitForExit(10000) + } + if (-not (Test-Path -LiteralPath $runtimeCounters)) { + $failures.Add('runtime counter capture did not produce a CSV artifact') + } + $counterProcess.Dispose() + } + + if (-not (Test-Path -LiteralPath $frameHistory)) { + $failures.Add('frame-history export was not written during graceful shutdown') + } + elseif ((Test-Path -LiteralPath $checkpointTimeline) -and + (Test-Path -LiteralPath $markerLog)) { + & dotnet $cliDll summarize-frame-history ` + $frameHistory ` + $checkpointTimeline ` + $markerLog ` + $frameSummary + if ($LASTEXITCODE -ne 0) { + $failures.Add("frame-history summary failed with exit code $LASTEXITCODE") + } + elseif (-not (Test-Path -LiteralPath $frameSummary)) { + $failures.Add('frame-history summary did not produce its JSON artifact') + } + } $samples | Export-Csv -LiteralPath $sampleCsv -NoTypeInformation $report = [pscustomobject][ordered]@{ @@ -742,6 +864,10 @@ finally { ReportJson = $reportJson CheckpointTimeline = $checkpointTimeline EnvDisclosure = Join-Path $artifactDir 'env-disclosure.json' + FrameHistory = $frameHistory + FrameSummary = $frameSummary + ContentionTrace = if ($CaptureContention) { $contentionTrace } else { $null } + RuntimeCounters = if (-not $SkipRuntimeCounters) { $runtimeCounters } else { $null } } } $report | ConvertTo-Json -Depth 8 | Set-Content -LiteralPath $reportJson -Encoding utf8