Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion DECISIONS.md
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@ Cost: a shader that needs a start reads it from a uniform, and a draw over a lat

## 2026-10-05: Performance diagnostics are logged, measured at three points, and count no draws

With `PIXELY_DIAGNOSTICS`, `PixelyApp.RunFrame` and `RenderCoordinator<T>` record the update, the render and the swapchain wait of every frame in `FrameTimings`, through `IFrameTimingRecorder`. `PerformanceReport`, an updatable, logs the average, 95th percentile and maximum of each every 5 seconds, together with gen0 collections and GPU memory, and the GPU device at startup and each window's swapchain. Without diagnostics the recorder is `NullFrameTimingRecorder` and no report is registered. This replaces `PerformanceTracker`, which Pixely never registered and which read the frame clock, so in headless mode it reported the fixed step.
With `PIXELY_DIAGNOSTICS`, `PixelyApp.RunFrame` and `RenderCoordinator<T>` record the update, the render and the swapchain wait of every frame in `FrameTimings`, through `IFrameTimingRecorder`. `PerformanceReport`, an updatable, logs the average, 95th percentile and maximum of each every 5 seconds, together with gen0 collections and GPU memory, and the GPU device at startup and each window's swapchain. Without diagnostics the recorder is `NullFrameTimingRecorder` and no report is created. `Build()` registers them last, and the report resolves the logger factory and the GPU device only while diagnostics are on, so diagnostics change neither when the app's services are created nor when they are disposed. This replaces `PerformanceTracker`, which Pixely never registered and which read the frame clock, so in headless mode it reported the fixed step.

- The numbers must be readable on a kiosk compositor, where the screen is the game, so they go to the log instead of an overlay.
- .NET metrics with `dotnet-counters` would give percentiles and gen0 collections for free, but a NativeAOT app needs `EventSourceSupport` at build time. Diagnostics must turn on in the shipped build with an environment variable.
Expand Down
2 changes: 1 addition & 1 deletion docs/class-registration.md
Original file line number Diff line number Diff line change
Expand Up @@ -486,7 +486,7 @@ A throwing `OnDisposing` callback, service `Dispose()`, or child provider does n
## Lifecycle

1. **Registration** — call `AddSingleton`, `AddTransient`, `AddAlias`, `OnBuilt`, `OnActivated`, `OnDisposing` on `ServiceCollection`.
2. **`BuildServiceProvider`** — singleton services are instantiated in dependency order; `OnActivated` callbacks fire per singleton instance.
2. **`BuildServiceProvider`** — singleton services are instantiated type by type, in the order each service type was first registered, and in registration order within a type. A singleton that another one depends on is created first, when it is first needed. `OnActivated` callbacks fire per singleton instance.
3. **`OnBuilt` callbacks** — fire in registration order after all singleton services exist.
4. **Freeze** — the provider becomes immutable; build-time resolvers are cleared.
5. **Runtime resolution** — `GetRequiredService`, `GetService`, `GetServices` serve singletons from frozen arrays and construct transients on demand.
Expand Down
4 changes: 2 additions & 2 deletions docs/diagnostics.md
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@ Pixely can report where a frame's time goes, which GPU device it runs on, and ho

## Turning it on

Set `PIXELY_DIAGNOSTICS` to `1` or `true`, or register `new PixelyConfig(EnableDiagnostics: true)`. The variable overrides the configured value, like the other variables in [headless.md](headless.md#environment-variables). Diagnostics are off by default. When they are off, nothing is created and each frame pays only a few null checks.
Set `PIXELY_DIAGNOSTICS` to `1` or `true`, or register `new PixelyConfig(EnableDiagnostics: true)`. The variable overrides the configured value, like the other variables in [headless.md](headless.md#environment-variables). Diagnostics are off by default. When they are off, each frame calls a recorder that does nothing, and no report is created.

The report is written to the logger category `Pixely.Diagnostics` at the `Information` level when the app registers a logger factory (see [logging.md](logging.md)), and to standard output otherwise.

Expand Down Expand Up @@ -37,7 +37,7 @@ Every 5 seconds of frames, or every 4096 frames if that comes first, and once mo
| `render` | Every render coordinator, without the swapchain wait: recording commands, uploads and submits. |
| `swapchain wait` | Waiting for each window's swapchain texture, added up over the windows. |
| `gen0 collections` | Garbage collections of generation 0, per frame. |
| `GPU memory` | The textures and buffers Pixely created on the root GPU device, at the time of the report. The report on dispose leaves it out, because stages and windows have released theirs by then. |
| `GPU memory` | The textures and buffers Pixely created on the root GPU device, at the time of the report. In the report on dispose, stages have already released theirs. |

## Reading the numbers

Expand Down
27 changes: 18 additions & 9 deletions src/Pixely/App/PerformanceReport.cs
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@

namespace Pixely.App;

// Writes FrameTimings to the log: the GPU device at startup, each swapchain change, and the frames of every period. Registered
// Writes FrameTimings to the log: the GPU device at startup, each swapchain change, and the frames of every period. Created
// only while PixelyConfig.EnableDiagnostics is on. See docs/diagnostics.md for what the numbers mean.
internal sealed class PerformanceReport : IUpdatable, IDisposable
{
Expand All @@ -18,7 +18,8 @@ internal sealed class PerformanceReport : IUpdatable, IDisposable
private readonly ILogger? _logger;
private readonly GpuDevice? _gpuDevice;
private readonly double[] _sortedTimes = new double[FrameTimings.Capacity];
private int _periodStartGen0Collections = GC.CollectionCount(0);
private bool _hasGen0Baseline;
private int _periodStartGen0Collections;

internal PerformanceReport(FrameTimings timings, ILogger? logger, GpuDevice? gpuDevice)
{
Expand All @@ -35,22 +36,30 @@ internal PerformanceReport(FrameTimings timings, ILogger? logger, GpuDevice? gpu

public void Update()
{
// Taken on the first frame rather than at construction, so the collections of building the app and loading its content
// are not counted against the first period.
if (!_hasGen0Baseline)
{
_periodStartGen0Collections = GC.CollectionCount(0);
_hasGen0Baseline = true;
}

WriteSwapchainChanges();
if (_timings.Duration >= PeriodSeconds || _timings.IsFull)
{
WritePeriod(true);
WritePeriod();
}
}

// Reports the frames since the last report, so a run shorter than a period still reports. The provider disposes this before
// the logger factory and the GPU device it was created from, but after the stages and the services created after it, which
// have released their GPU memory by then, so the GPU memory is left out.
// Reports the frames since the last report, so a run shorter than a period still reports. Build() registers this last, so
// the root provider disposes it before its own services, among them the logger factory and the GPU device. Stages are
// disposed before it, so their GPU memory is no longer counted.
public void Dispose()
{
WriteSwapchainChanges();
if (_timings.Count > 0)
{
WritePeriod(false);
WritePeriod();
}
}

Expand All @@ -69,7 +78,7 @@ private void WriteSwapchainChanges()
_timings.ClearSwapchainChanges();
}

private void WritePeriod(bool withGpuMemory)
private void WritePeriod()
{
int gen0Collections = GC.CollectionCount(0) - _periodStartGen0Collections;
StringBuilder builder = new();
Expand All @@ -79,7 +88,7 @@ private void WritePeriod(bool withGpuMemory)
AppendTimes(builder, ", render ", _timings.RenderTimes);
AppendTimes(builder, ", swapchain wait ", _timings.SwapchainWaitTimes);
builder.Append(CultureInfo.InvariantCulture, $"; gen0 collections {(double)gen0Collections / _timings.Count:F2} per frame");
if (withGpuMemory && _gpuDevice != null)
if (_gpuDevice != null)
{
GpuMemoryStats memory = _gpuDevice.MemoryStats;
builder.Append($"; GPU memory {FormatBytes(memory.TotalBytes)}, textures {FormatBytes(memory.TextureBytes)}");
Expand Down
16 changes: 9 additions & 7 deletions src/Pixely/App/PixelyAppBuilder.cs
Original file line number Diff line number Diff line change
Expand Up @@ -27,13 +27,6 @@ public PixelyAppBuilder()
AddRegistry<IRenderCoordinator>();
AddRegistry<IRenderer<BasicRenderContext>>(static renderer => renderer.RenderOrder);
AddRegistry<IUpdatable>(static updatable => updatable.UpdateOrder);

// Diagnostics, see docs/diagnostics.md. While they are off, the frame records its timings to a recorder that does
// nothing and nothing reports them.
AddSingleton<FrameTimings>(static (PixelyConfig? config) => config is { EnableDiagnostics: true } ? new FrameTimings() : null);
AddSingleton<IFrameTimingRecorder>(static (FrameTimings? timings) => timings ?? (IFrameTimingRecorder)NullFrameTimingRecorder.Instance);
AddSingleton<PerformanceReport>(static (FrameTimings? timings, ILoggerFactory? loggerFactory, GpuDevice? gpuDevice) =>
timings is null ? null : new PerformanceReport(timings, loggerFactory?.CreateLogger(PerformanceReport.LoggerCategoryName), gpuDevice));
}

public PixelyAppBuilder ConfigureContent(Action<ContentSourceBuilder> configure)
Expand Down Expand Up @@ -104,6 +97,15 @@ public IPixelyApp Build()
AddSingleton<IImageLoader, SdlImageLoader>();
}

// Diagnostics, see docs/diagnostics.md. Registered last, and the report resolves the logger factory and the GPU device only
// while diagnostics are on, so they change neither when the app's services are created nor when they are disposed. While
// they are off, the frame records its timings to a recorder that does nothing and no report is created.
AddSingleton<FrameTimings>(static provider => provider.GetRequiredService<PixelyConfig>().EnableDiagnostics ? new FrameTimings() : null);
AddSingleton<IFrameTimingRecorder>(static provider => provider.GetService<FrameTimings>() ?? (IFrameTimingRecorder)NullFrameTimingRecorder.Instance);
AddSingleton<PerformanceReport>(static provider => provider.GetService<FrameTimings>() is { } timings
? new PerformanceReport(timings, provider.GetService<ILoggerFactory>()?.CreateLogger(PerformanceReport.LoggerCategoryName), provider.GetService<GpuDevice>())
: null);

ServiceProvider serviceProvider = BuildServiceProvider();
return new PixelyApp(
serviceProvider,
Expand Down
3 changes: 2 additions & 1 deletion src/Pixely/RenderOrchestration/RenderingExtensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,7 @@ private static void ConfigureWindowRendering<TRenderContext>(ServiceCollection s
new RenderCoordinatorGpu(provider.GetRequiredService<GpuDevice>(), provider.GetRequiredService<GpuMemorySystem>()),
provider.GetRequiredService<RenderContextProvider<TRenderContext>>(),
provider.GetRequiredService<ServiceRegistry<IRenderer<TRenderContext>>>(),
provider.GetRequiredService<IFrameTimingRecorder>()));
// PixelyAppBuilder.Build() registers the recorder; a provider built without it records nothing.
provider.GetService<IFrameTimingRecorder>() ?? NullFrameTimingRecorder.Instance));
}
}
35 changes: 33 additions & 2 deletions tests/Pixely.Tests/InputAutomationConsoleTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -128,12 +128,33 @@ public void Update_PartialCommand_BlocksUntilItsSemicolonWithinOneUpdate()
});
}

[Test]
public void Update_RecordsTheReadsAsInputWait()
{
long now = 0;
FrameTimings timings = new(() => now, FrameTimingsTests.Frequency);
Fixture fixture = CreateConsole(new AdvancingReader("key press A;", () => now += 100), timings);

timings.BeginFrame();
fixture.Console.Update();
timings.EndUpdate();
timings.EndRender();
timings.EndFrame();

Assert.Multiple(() =>
{
Assert.That(now, Is.Positive);
Assert.That(timings.UpdateTimes[0], Is.Zero);
Assert.That(timings.FrameTimes[0], Is.Zero);
});
}

private static Fixture CreateConsole(string input)
{
return CreateConsole(new StringReader(input));
}

private static Fixture CreateConsole(TextReader input)
private static Fixture CreateConsole(TextReader input, IFrameTimingRecorder? frameTimingRecorder = null)
{
WindowRegistry windowRegistry = new();
windowRegistry.Register(InputAutomationTests.CreateWindow(default, 42));
Expand All @@ -145,7 +166,17 @@ private static Fixture CreateConsole(TextReader input)

AppControl appControl = new();
InputAutomationCommandInterpreter interpreter = new(automation, windowRegistry, new NoImageWriter(), appControl);
return new Fixture(new InputAutomationConsole(interpreter, input, appControl, NullFrameTimingRecorder.Instance), presses, appControl);
return new Fixture(new InputAutomationConsole(interpreter, input, appControl, frameTimingRecorder ?? NullFrameTimingRecorder.Instance), presses, appControl);
}

// Advances a clock on every character read, standing in for a read that blocks.
private sealed class AdvancingReader(string input, Action advance) : StringReader(input)
{
public override int Read()
{
advance();
return base.Read();
}
}

private sealed record Fixture(InputAutomationConsole Console, ConcurrentQueue<Scancode> Presses, AppControl AppControl);
Expand Down
37 changes: 0 additions & 37 deletions tests/Pixely.Tests/PerformanceReportTests.cs
Original file line number Diff line number Diff line change
@@ -1,6 +1,4 @@
using Pixely.App;
using Pixely.DependencyInjection;
using SDL;
using static Pixely.Tests.FrameTimingsTests;

namespace Pixely.Tests;
Expand Down Expand Up @@ -130,39 +128,4 @@ public void Update_WritesEachSwapchainChangeOnce()
"Swapchain of view 0: 800x600, B8G8R8A8Unorm, offscreen"
}));
}

[Test]
[NonParallelizable]
public void Build_WithoutDiagnostics_RecordsNothingAndReportsNothing()
{
using PixelyApp app = BuildApp(new PixelyConfig(Headless: true));

Assert.Multiple(() =>
{
Assert.That(app.ServiceProvider.GetRequiredService<IFrameTimingRecorder>(), Is.SameAs(NullFrameTimingRecorder.Instance));
Assert.That(app.ServiceProvider.GetRequiredService<ServiceRegistry<IUpdatable>>().OfType<PerformanceReport>(), Is.Empty);
});
}

[Test]
[NonParallelizable]
public void Build_WithDiagnostics_RecordsFrameTimingsAndUpdatesTheReport()
{
using PixelyApp app = BuildApp(new PixelyConfig(Headless: true, EnableDiagnostics: true));

Assert.Multiple(() =>
{
Assert.That(app.ServiceProvider.GetRequiredService<IFrameTimingRecorder>(), Is.SameAs(app.ServiceProvider.GetRequiredService<FrameTimings>()));
Assert.That(app.ServiceProvider.GetRequiredService<ServiceRegistry<IUpdatable>>().OfType<PerformanceReport>().Count(), Is.EqualTo(1));
});
}

// Building initializes SDL video; the dummy driver needs no display, and an environment override still wins.
private static PixelyApp BuildApp(PixelyConfig config)
{
SDL3.SDL_SetHintWithPriority(SDL3.SDL_HINT_VIDEO_DRIVER, "dummy", SDL_HintPriority.SDL_HINT_DEFAULT);
PixelyAppBuilder builder = new();
builder.AddSingleton(config);
return (PixelyApp)builder.Build();
}
}
Loading