The cadence work ended with a question the log could not answer: the compositor
manages 6.8 composites/s at ~141ms while the 10:03 take did 29-34ms on the "same
scene shape" (full-render split=0 elements=6 dynamic=5). Nothing in the stats line
said WHICH of the six elements cost what, and nothing recorded the scene itself, so
the two takes could only be compared by eye. This closes that gap and nothing else:
no fix is attempted until a real take names the culprit.
- Services/Compositor/CompositeTimings.cs (new): per-window collector.
Add(stage, ticks) accumulates; Describe(renders, minMs = 0.1) prints the averaged
breakdown slowest-first, dropping sub-0.1ms noise.
- SceneCompositor.Render / CompositeLayers / BakeStaticBase / BlitBakedElement /
BlitCachedLayer + SceneGraph.GetBakedBase: trailing optional CompositeTimings?
Every stage is timed (backdrop, base, flash, social, ticker, zoom, scale, overlay,
bake backdrop, bake overlays) and EVERY element gets its own entry keyed by
z-index + name ("#2 Webcam"), with the nested "raster" sub-stage recording the
paste-cache rasterize miss - the split between "re-samples every tick" and "slow
paste" without a second session. Bake-pass elements are prefixed "bake #..." so a
one-off rebake cannot masquerade as a per-composite cost. Callers that pass
nothing (thumbnails, existing tests) are unaffected and pay nothing.
- FramePump: owns the collector, threads it through RenderScene/RenderFull/
GetBakedBase/CompositeLayers, and logs "FramePump parts (N renders/5s): ..." once
per 5s window beside the stats line (averaged per render, so it compares directly
with "avg render"), then resets it. Also dumps the scene - "FramePump scene dump:"
header plus one line per element (z-index, name, kind, source type, visibility,
rect, opacity, clip) - at pump start and on every scene change.
- One Good Dog integration test (ytLive.Tests/CompositeTimingTests.cs): a real
composite of a full-canvas element plus a 64x64 one through the real collector
must rank the full-canvas element first, carry the raster sub-stage and the fixed
stages, and the dump must name both elements with z-index/type/rect and echo the
split point.
Derivative work (AGENTS.md): OBS's answer to "which source is slow" is the Source
Profiler - average execution time of each source's tick and render functions
(https://docs.obsproject.com/reference-libobs-util-source-profiler, util/profiler.h).
Same shape here: one timer per element per composite, reported as an average, plus
the stage split this case needs.
Docs in the same commit: ai.md (new subsection "Per-element composite timing + scene
dump", the closed gap corrected in "Frame cadence"), Services/index.md (new file row
+ FramePump/SceneCompositor rows), TASKS.md (unit marked shipped, next = creator
take), HANDOFF.md (rewritten: unpushed commit, next step, verify.sh whitelist hole).
Also recorded this session (from the creator): the launch command is
`dotnet run -c Release` - Release is the DEFAULT, Debug only when explicitly named,
and perf takes must read Release. ai.md -> Run updated.
Full suite 428 tests, 0 warnings; the only failures are the known audio env flakes
(both pass in isolation). Scope check passed.
71 lines
3.6 KiB
C#
71 lines
3.6 KiB
C#
using Xunit;
|
||
using ytLive.Models;
|
||
using ytLive.Services;
|
||
using ytLive.Services.Compositor;
|
||
using ytLive.Services.Encoder;
|
||
|
||
namespace ytLive.Tests;
|
||
|
||
/// <summary>
|
||
/// Per-element composite timing + the pump's scene dump (webcam-cadence unit,
|
||
/// 2026-10-16). The judder diagnosis ended with a question the log could not answer:
|
||
/// the compositor was doing 6.8 composites/s at ~141ms each, and nothing in the stats
|
||
/// line said WHICH of the scene's six elements ate the budget — only that the render
|
||
/// cost 141ms. This pins the two readings that close that gap: a real composite
|
||
/// attributes wall time per element (slowest first) with the paste-cache rasterize
|
||
/// split, and the scene dump records the shape a take was made from.
|
||
/// </summary>
|
||
public class CompositeTimingTests
|
||
{
|
||
/// <summary>The ONE integration test for this change: a REAL SceneCompositor.Render
|
||
/// over a full-canvas element plus a small one, through the real timing collector —
|
||
/// the parts line must name both elements, sort the full-canvas one first, and carry
|
||
/// the raster sub-stage; the dump must name every element with its z-index, source
|
||
/// type and rect, and echo the split point. No 5s stats window is waited on: the
|
||
/// window logic only formats what the collector already accumulated.</summary>
|
||
[Fact]
|
||
public void Composite_Timings_Rank_The_Slowest_Element_And_The_Dump_Names_The_Scene_Shape()
|
||
{
|
||
const int w = 640, h = 480;
|
||
var scene = new Scene { Name = "Live" };
|
||
var big = new Source { Type = SourceType.Image, Name = "FullCanvas", X = 0, Y = 0, Width = w, Height = h };
|
||
var small = new Source { Type = SourceType.Image, Name = "TinyBadge", X = 16, Y = 16, Width = 64, Height = 64 };
|
||
scene.Elements.Add(big);
|
||
scene.Elements.Add(small);
|
||
|
||
var bigFrame = SceneCompositorTests.Solid(w, h, 200, 40, 40);
|
||
var smallFrame = SceneCompositorTests.Solid(64, 64, 40, 200, 40);
|
||
VideoFrame? FrameFor(SceneElement e) => ReferenceEquals(e, big) ? bigFrame : smallFrame;
|
||
|
||
var options = new CompositorOptions
|
||
{
|
||
SourceRectX = 0, SourceRectY = 0, SourceRectWidth = w, SourceRectHeight = h,
|
||
OutputWidth = w, OutputHeight = h,
|
||
};
|
||
|
||
var timings = new CompositeTimings();
|
||
new SceneCompositor().Render(scene, FrameFor, null, options, timings: timings);
|
||
|
||
// minMs 0: a 640×480 test scene is sub-millisecond per stage, so the production
|
||
// 0.1ms floor would hide exactly the entries being asserted.
|
||
var parts = timings.Describe(1, minMs: 0);
|
||
Assert.Contains("#0 FullCanvas", parts);
|
||
Assert.Contains("#1 TinyBadge", parts);
|
||
Assert.Contains("#0 FullCanvas raster", parts); // the paste-cache rasterize miss
|
||
Assert.Contains("scale", parts);
|
||
Assert.Contains("backdrop", parts);
|
||
Assert.True(
|
||
parts.IndexOf("#0 FullCanvas", StringComparison.Ordinal) < parts.IndexOf("#1 TinyBadge", StringComparison.Ordinal),
|
||
$"the full-canvas element must rank above the 64×64 one: {parts}");
|
||
|
||
var dump = FramePump.FormatSceneDump(scene, split: 1);
|
||
Assert.Contains("FramePump scene dump: 'Live' elements=2 split=1", dump[0]);
|
||
Assert.Contains(dump, l => l.Contains("[0] FullCanvas") && l.Contains("type=Image")
|
||
&& l.Contains("vis=1") && l.Contains("rect=0,0 640x480"));
|
||
Assert.Contains(dump, l => l.Contains("[1] TinyBadge") && l.Contains("rect=16,16 64x64"));
|
||
|
||
// No SceneGraph wired (-1) — the dump says nothing about a split point.
|
||
Assert.DoesNotContain("split=", FramePump.FormatSceneDump(scene, split: -1)[0]);
|
||
}
|
||
}
|