fix: audio silence (idempotent sync-delay configure), webcam gray block, truncated videos

- AudioSyncDelay.Configure reallocated/zeroed its buffer every ~10ms tick
  (AudioMixer re-reads the UI setting each mix), so any non-zero sync offset
  erased the just-written audio -> total silence. Now early-returns when the
  delay samples are unchanged. Regression test proven both ways.
- SceneCompositor.BlitContentRaw defaulted cbW/cbH=0 when CropBounds is null
  (regression from ed9d7c1) -> webcam blit to an empty rect = gray block.
  Default to src.Width/Height. Regression test proven both ways.
- Truncated recordings: rawvideo mux stamps frames at declared 60fps by
  arrival; a scene whose first layer is dynamic (hidden elements still count)
  kills the bake cache -> full render ~35ms -> ~27fps submitted -> halved
  file length. Static scenes bake once (246ms cold, then <1ms) -> 60fps,
  full-length (probe + 13:53 take, 301/300 per 5s, 12.46s file from 12.3s
  wall). FramePump.ProbeRender names the hot render path on slow frames.
This commit is contained in:
2026-09-12 13:56:55 -07:00
parent a62a283fd4
commit 724af1499b
9 changed files with 310 additions and 134 deletions
+48 -9
View File
@@ -87,6 +87,11 @@ public sealed class FramePump : IDisposable
private bool _started;
private long _outputIndex;
/// <summary>Captured by <see cref="ProbeRender"/> when a render exceeds ~20ms —
/// the 2026-09-12 half-speed-render probe. Appended (once) to the next stats or
/// stall line, then cleared.</summary>
private string _renderDetail = "";
/// <summary>Forwards the encoder's parsed health — ship step 6 binds this to the bottom bar.</summary>
public event EventHandler<StreamHealth>? HealthUpdated;
@@ -306,8 +311,10 @@ public sealed class FramePump : IDisposable
IFfmpegEncoder? encoder;
lock (_gate) encoder = _encoder;
var dropped = encoder == null ? 0 : encoder.DroppedFrames;
var detail = _renderDetail;
_renderDetail = "";
_log?.Invoke(statFrames == 0
? "FramePump stats: NO frames produced in 5s (loop stalled?)"
? "FramePump stats: NO frames produced in 5s (loop stalled?)" + (detail.Length > 0 ? " | " + detail : "")
: $"FramePump stats: {statFrames}/{target:F0} frames per 5s, " +
$"avg render {renderTicks / (double)System.Diagnostics.Stopwatch.Frequency * 1000 / statFrames:F1}ms " +
$"(resolve {resolveTicks / (double)System.Diagnostics.Stopwatch.Frequency * 1000 / statFrames:F1}), " +
@@ -315,7 +322,7 @@ public sealed class FramePump : IDisposable
+ $"avg wait {waitTicks / (double)System.Diagnostics.Stopwatch.Frequency * 1000 / statFrames:F1}ms, "
+ $"worst render {worstRender / (double)System.Diagnostics.Stopwatch.Frequency * 1000:F1}ms, "
+ $"worst submit {worstSubmit / (double)System.Diagnostics.Stopwatch.Frequency * 1000:F1}ms, "
+ $"dropped {dropped}, stalls {stalls}");
+ $"dropped {dropped}, stalls {stalls}" + (detail.Length > 0 ? " | " + detail : ""));
worstRender = 0;
worstSubmit = 0;
renderTicks = submitTicks = resolveTicks = waitTicks = 0;
@@ -454,10 +461,13 @@ public sealed class FramePump : IDisposable
if (iterWall > 2 * intervalTicks)
{
stalls++;
var detail = _renderDetail;
_renderDetail = "";
_log?.Invoke($"FramePump stall: iteration {iterWall / (double)System.Diagnostics.Stopwatch.Frequency * 1000:F0}ms " +
$"(> 2× the {interval.TotalMilliseconds:F0}ms interval): worst render " +
$"{worstRender / (double)System.Diagnostics.Stopwatch.Frequency * 1000:F0}ms, worst submit " +
$"{worstSubmit / (double)System.Diagnostics.Stopwatch.Frequency * 1000:F0}ms, dropped {encoder.DroppedFrames}");
$"{worstSubmit / (double)System.Diagnostics.Stopwatch.Frequency * 1000:F0}ms, dropped {encoder.DroppedFrames}" +
(detail.Length > 0 ? " | " + detail : ""));
}
ReportStats();
}
@@ -505,30 +515,59 @@ public sealed class FramePump : IDisposable
byte[]? scratch = null,
Func<SceneElement, VideoFrame?>? resolver = null)
{
// per-tick composites use the (timed) resolver; the rare bake uses the raw one
// so bake cost lands in "render" but not "resolve".
resolver ??= _frameResolver;
if (_sceneGraph == null)
return _compositor.Render(scene, resolver, null, options, socialBarFrame, socialBarTop, scratch: scratch);
{
var sw = System.Diagnostics.Stopwatch.StartNew();
var frame = _compositor.Render(scene, resolver, null, options, socialBarFrame, socialBarTop, scratch: scratch);
ProbeRender("full-no-graph", scene, -1, sw.ElapsedMilliseconds, 0);
return frame;
}
var split = _sceneGraph.GetSplitPoint(scene);
if (split == scene.Elements.Count)
{
// Fully static scene: bake once, reuse.
var sw = System.Diagnostics.Stopwatch.StartNew();
var baked = _sceneGraph.GetBakedBase(scene, _frameResolver, _compositorOptions);
if (baked != null)
return StretchMath.BilinearScale(baked, options.OutputWidth, options.OutputHeight);
{
var stretched = StretchMath.BilinearScale(baked, options.OutputWidth, options.OutputHeight);
ProbeRender("fully-static", scene, split, sw.ElapsedMilliseconds, (int)sw.ElapsedMilliseconds);
return stretched;
}
}
var swBase = System.Diagnostics.Stopwatch.StartNew();
var baseFrame = _sceneGraph.GetBakedBase(scene, _frameResolver, _compositorOptions);
if (baseFrame != null)
{
return SceneCompositor.CompositeLayers(
var frame = SceneCompositor.CompositeLayers(
baseFrame, scene, split, resolver, options, socialBarFrame, socialBarTop, scratch: scratch);
ProbeRender("base+layers", scene, split, swBase.ElapsedMilliseconds, 0);
return frame;
}
// No static base (first layer is dynamic or empty scene) — full render.
return _compositor.Render(scene, resolver, null, options, socialBarFrame, socialBarTop, scratch: scratch);
var swFull = System.Diagnostics.Stopwatch.StartNew();
var frame2 = _compositor.Render(scene, resolver, null, options, socialBarFrame, socialBarTop, scratch: scratch);
ProbeRender("full-render", scene, split, swFull.ElapsedMilliseconds, 0);
return frame2;
}
/// <summary>2026-09-12 half-speed-render probe: the pump only produces ~27fps
/// (render ~35ms vs the 16.7ms deadline), and rawvideo muxes at the DECLARED fps,
/// so every take muxes at ~half its wall length (the truncation complaint). This
/// names WHICH compositor path ate the slow frame so the fix targets the real
/// stage. Records only when a frame takes ≥20ms (or carries the previous detail).</summary>
private void ProbeRender(string path, Scene scene, int split, long totalMs, int bakeMs)
{
if (totalMs < 20 && _renderDetail.Length == 0) return;
var dynamics = 0;
foreach (var e in scene.Elements)
if (e.Kind == ElementKind.Dynamic) dynamics++;
_renderDetail = $"render={path} split={split} elements={scene.Elements.Count} dynamic={dynamics}" +
(bakeMs > 0 ? $" bakeMs={bakeMs}" : "") + $" totalMs={totalMs}";
}
// Dot-matrix digits (5×7, one row per raster line, '1' = lit) burned into the