perf(adminui): coalesce /script-log and /alerts renders with a ring buffer (R04 P7)

Each received event used to Insert(0) into a List and render the full page.
LiveTailBuffer queues events from the bridge thread into a bounded newest-first
ring; CoalescingRenderScheduler (TimeProvider-driven, drained on dispose)
flushes and renders at most once per 200 ms window. ScriptLog's filtered rows
are recomputed on flush/filter change instead of three times per render.

Refs #745
Claude-Session: https://claude.ai/code/session_01Ub9hGmYLQvn9XETzw7CMsT
This commit is contained in:
Joseph Doherty
2026-10-22 17:28:23 -04:00
parent 348ffaec1c
commit 8e69118200
5 changed files with 426 additions and 47 deletions
@@ -12,6 +12,7 @@
@inject AuthenticationStateProvider AuthState
@inject IAuthorizationService AuthorizationService
@inject IAdminOperationsClient AdminOps
@using ZB.MOM.WW.OtOpcUa.AdminUI.LiveTail
@implements IAsyncDisposable
<PageErrorBoundary>
@@ -29,7 +30,7 @@
Shows the most-recent @Capacity entries since the page opened; reload for a fresh window.
</section>
@if (_rows.Count == 0)
@if (_tail.Items.Count == 0)
{
<section class="panel notice rise mt-3" style="animation-delay:.08s">
No alarms in the current window. The table will populate as soon as a
@@ -39,7 +40,7 @@
else
{
<section class="panel rise mt-3" style="animation-delay:.08s">
<div class="panel-head">Recent transitions (@_rows.Count)</div>
<div class="panel-head">Recent transitions (@_tail.Items.Count)</div>
<div class="table-wrap">
<table class="data-table">
<thead>
@@ -58,7 +59,7 @@ else
</tr>
</thead>
<tbody>
@foreach (var e in _rows)
@foreach (var e in _tail.Items)
{
<tr>
<td><span class="mono small">@e.TimestampUtc.ToString("HH:mm:ss.fff")</span></td>
@@ -137,7 +138,9 @@ else
@code {
private const int Capacity = 200;
private readonly List<AlarmTransitionEvent> _rows = new();
// Newest-first ring, filled from the bridge thread and drained once per coalescing window (R04 P7).
private readonly LiveTailBuffer<AlarmTransitionEvent> _tail = new(Capacity);
private CoalescingRenderScheduler? _render;
private bool _connected;
// Authorization — DriverOperator gates the per-row Ack/Shelve/Unshelve controls.
@@ -172,6 +175,8 @@ else
// Subscribe to the health signal BEFORE reading IsConnected so a state change between the
// read and the subscribe can't be missed (TOCTOU) — mirrors DriverStatusPanel's
// SnapshotChanged-then-TryGet ordering.
_render = new CoalescingRenderScheduler(CoalescingRenderScheduler.DefaultWindow,
() => InvokeAsync(FlushTail));
Alarms.ConnectionStateChanged += OnConnectionStateChanged;
Alarms.Received += OnAlarm;
_connected = Alarms.IsConnected;
@@ -275,15 +280,18 @@ else
null, TimeSpan.FromSeconds(8), Timeout.InfiniteTimeSpan);
}
private void OnAlarm(AlarmTransitionEvent evt) =>
// Marshal both the mutation and the re-render onto the circuit sync context so this can't
// race ClearAsync (which runs there) over the shared _rows list.
InvokeAsync(() =>
{
_rows.Insert(0, evt);
if (_rows.Count > Capacity) _rows.RemoveAt(_rows.Count - 1);
StateHasChanged();
});
// Bridge-actor thread: queue only. The first transition of a window arms one render ~200 ms
// later, so an alarm storm costs one render per window per tab instead of one per transition.
private void OnAlarm(AlarmTransitionEvent evt)
{
if (_tail.Add(evt)) _render?.Schedule();
}
// Render context: drain the queue into the ring and render once.
private void FlushTail()
{
if (_tail.Flush()) StateHasChanged();
}
// Raised by the broadcaster (on the bridge actor's thread) whenever the upstream DPS
// subscription's health flips. Marshal onto the circuit sync context like OnAlarm so the live
@@ -293,7 +301,7 @@ else
private async Task ClearAsync()
{
_rows.Clear();
_tail.Clear();
await InvokeAsync(StateHasChanged);
}
@@ -314,5 +322,6 @@ else
Alarms.ConnectionStateChanged -= OnConnectionStateChanged;
Alarms.Received -= OnAlarm;
if (_opResultClearTimer is not null) await _opResultClearTimer.DisposeAsync();
if (_render is not null) await _render.DisposeAsync();
}
}
@@ -6,13 +6,14 @@
@using ZB.MOM.WW.OtOpcUa.AdminUI.Hubs
@using ZB.MOM.WW.OtOpcUa.Commons.Messages.Logging
@inject IInProcessBroadcaster<ScriptLogEntry> ScriptLogs
@implements IDisposable
@using ZB.MOM.WW.OtOpcUa.AdminUI.LiveTail
@implements IAsyncDisposable
<PageErrorBoundary>
<div class="d-flex justify-content-between align-items-center mb-3">
<h4 class="mb-0">Script log</h4>
<div class="d-flex align-items-center gap-2">
<select class="form-select form-select-sm" style="width:auto" @bind="_levelFilter">
<select class="form-select form-select-sm" style="width:auto" @bind="_levelFilter" @bind:after="RecomputeVisible">
<option value="">All levels</option>
<option value="Trace">Trace+</option>
<option value="Debug">Debug+</option>
@@ -21,7 +22,7 @@
<option value="Error">Error+</option>
</select>
<input type="text" class="form-control form-control-sm" style="width:200px"
placeholder="Filter script ID…" @bind="_scriptFilter" @bind:event="oninput" />
placeholder="Filter script ID…" @bind="_scriptFilter" @bind:event="oninput" @bind:after="RecomputeVisible" />
<span class="conn-pill" data-state="@(_connected ? "connected" : "disconnected")">
<span class="dot"></span><span>@(_connected ? "live" : "disconnected")</span>
</span>
@@ -29,23 +30,23 @@
</div>
</div>
@if (VisibleRows.Count == 0)
@if (_visible.Count == 0)
{
<section class="panel notice rise mt-3" style="animation-delay:.08s">
@if (_rows.Count == 0)
@if (_tail.Items.Count == 0)
{
<span>No script-log entries yet.</span>
}
else
{
<span>No entries match the current filter (@_rows.Count entries available).</span>
<span>No entries match the current filter (@_tail.Items.Count entries available).</span>
}
</section>
}
else
{
<section class="panel rise mt-3" style="animation-delay:.08s">
<div class="panel-head">Showing @VisibleRows.Count of @_rows.Count</div>
<div class="panel-head">Showing @_visible.Count of @_tail.Items.Count</div>
<div class="table-wrap">
<table class="data-table">
<thead>
@@ -58,7 +59,7 @@ else
</tr>
</thead>
<tbody>
@foreach (var e in VisibleRows)
@foreach (var e in _visible)
{
<tr>
<td><span class="mono small">@e.TimestampUtc.ToString("HH:mm:ss.fff")</span></td>
@@ -82,7 +83,11 @@ else
@code {
private const int Capacity = 500;
private readonly List<ScriptLogEntry> _rows = new();
// Newest-first ring, filled from the bridge thread and drained once per coalescing window (R04 P7).
private readonly LiveTailBuffer<ScriptLogEntry> _tail = new(Capacity);
private CoalescingRenderScheduler? _render;
// The filtered rows, recomputed on flush / filter change — not on every render.
private IReadOnlyList<ScriptLogEntry> _visible = Array.Empty<ScriptLogEntry>();
private bool _connected;
private string _levelFilter = "";
private string _scriptFilter = "";
@@ -92,22 +97,19 @@ else
["Trace"] = 0, ["Debug"] = 1, ["Information"] = 2, ["Warning"] = 3, ["Error"] = 4, ["Critical"] = 5,
};
private List<ScriptLogEntry> VisibleRows
private void RecomputeVisible()
{
get
IEnumerable<ScriptLogEntry> q = _tail.Items;
if (!string.IsNullOrWhiteSpace(_levelFilter)
&& LevelRank.TryGetValue(_levelFilter, out var minRank))
{
IEnumerable<ScriptLogEntry> q = _rows;
if (!string.IsNullOrWhiteSpace(_levelFilter)
&& LevelRank.TryGetValue(_levelFilter, out var minRank))
{
q = q.Where(e => LevelRank.TryGetValue(e.Level, out var r) && r >= minRank);
}
if (!string.IsNullOrWhiteSpace(_scriptFilter))
{
q = q.Where(e => e.ScriptId.Contains(_scriptFilter, StringComparison.OrdinalIgnoreCase));
}
return q.ToList();
q = q.Where(e => LevelRank.TryGetValue(e.Level, out var r) && r >= minRank);
}
if (!string.IsNullOrWhiteSpace(_scriptFilter))
{
q = q.Where(e => e.ScriptId.Contains(_scriptFilter, StringComparison.OrdinalIgnoreCase));
}
_visible = q.ToList();
}
protected override void OnInitialized()
@@ -116,6 +118,8 @@ else
// 'script-logs' DPS topic). Blazor Server can't self-connect a SignalR HubConnection behind
// a reverse proxy — see IInProcessBroadcaster — so we subscribe in-process instead.
// Subscribe the state-change event BEFORE reading IsConnected so no transition is missed.
_render = new CoalescingRenderScheduler(CoalescingRenderScheduler.DefaultWindow,
() => InvokeAsync(FlushTail));
ScriptLogs.ConnectionStateChanged += OnConnectionStateChanged;
ScriptLogs.Received += OnEntry;
_connected = ScriptLogs.IsConnected;
@@ -124,19 +128,25 @@ else
private void OnConnectionStateChanged(bool connected) =>
InvokeAsync(() => { _connected = connected; StateHasChanged(); });
private void OnEntry(ScriptLogEntry entry) =>
// Marshal both the mutation and the re-render onto the circuit sync context so this can't
// race ClearAsync (which runs there) over the shared _rows list.
InvokeAsync(() =>
{
_rows.Insert(0, entry);
if (_rows.Count > Capacity) _rows.RemoveAt(_rows.Count - 1);
StateHasChanged();
});
// Bridge-actor thread: queue only. The first entry of a window arms one render ~200 ms later, so
// a chatty script costs one render per window per tab instead of one per log line.
private void OnEntry(ScriptLogEntry entry)
{
if (_tail.Add(entry)) _render?.Schedule();
}
// Render context: drain the queue into the ring and render once.
private void FlushTail()
{
if (!_tail.Flush()) return;
RecomputeVisible();
StateHasChanged();
}
private async Task ClearAsync()
{
_rows.Clear();
_tail.Clear();
RecomputeVisible();
await InvokeAsync(StateHasChanged);
}
@@ -148,9 +158,11 @@ else
_ => "chip-idle",
};
public void Dispose()
public async ValueTask DisposeAsync()
{
ScriptLogs.ConnectionStateChanged -= OnConnectionStateChanged;
ScriptLogs.Received -= OnEntry;
// Drains an in-flight window and suppresses later ones, so no flush renders a gone component.
if (_render is not null) await _render.DisposeAsync();
}
}
@@ -0,0 +1,79 @@
namespace ZB.MOM.WW.OtOpcUa.AdminUI.LiveTail;
/// <summary>
/// Coalesces bursts of "please re-render" requests into at most one flush per window. The first
/// <see cref="Schedule"/> after a flush arms a one-shot timer; further calls inside the window are
/// no-ops; when the timer fires the flush callback runs once (the page marshals it onto its render
/// context with <c>InvokeAsync</c>). Disposal drains an in-flight callback and suppresses later ones.
/// </summary>
public sealed class CoalescingRenderScheduler : IAsyncDisposable
{
/// <summary>The default coalescing window for live-tail pages.</summary>
public static readonly TimeSpan DefaultWindow = TimeSpan.FromMilliseconds(200);
private readonly TimeSpan _window;
private readonly Func<Task> _flush;
private readonly ITimer _timer;
private int _armed;
private volatile bool _disposed;
/// <summary>Creates the scheduler.</summary>
/// <param name="window">The coalescing window.</param>
/// <param name="flush">The callback run once per window; exceptions are swallowed (the page is the
/// only consumer, and a throw here would surface as an unobserved timer-thread exception).</param>
/// <param name="timeProvider">The time source; <see cref="TimeProvider.System"/> when null.</param>
public CoalescingRenderScheduler(TimeSpan window, Func<Task> flush, TimeProvider? timeProvider = null)
{
_window = window;
_flush = flush;
_timer = (timeProvider ?? TimeProvider.System)
.CreateTimer(OnFire, null, Timeout.InfiniteTimeSpan, Timeout.InfiniteTimeSpan);
}
/// <summary>Requests a flush within one window. Safe from any thread.</summary>
public void Schedule()
{
if (_disposed) return;
if (Interlocked.CompareExchange(ref _armed, 1, 0) != 0) return;
try
{
_timer.Change(_window, Timeout.InfiniteTimeSpan);
}
catch (ObjectDisposedException)
{
// Raced DisposeAsync — nothing left to render to.
}
}
private void OnFire(object? state)
{
// Disarm BEFORE flushing: an item arriving during the flush schedules the next window rather
// than being stranded until some later item happens to arrive.
Volatile.Write(ref _armed, 0);
if (_disposed) return;
// Not async void: a fault is observed on the returned task, never thrown onto the timer thread.
// The circuit going away mid-flush (ObjectDisposedException and friends) is the expected fault,
// and a live-tail render failure is never worth an unhandled exception.
Task task;
try
{
task = _flush();
}
catch
{
return;
}
_ = task.ContinueWith(static t => _ = t.Exception, CancellationToken.None,
TaskContinuationOptions.OnlyOnFaulted | TaskContinuationOptions.ExecuteSynchronously,
TaskScheduler.Default);
}
/// <inheritdoc />
public async ValueTask DisposeAsync()
{
_disposed = true;
await _timer.DisposeAsync().ConfigureAwait(false);
}
}
@@ -0,0 +1,94 @@
namespace ZB.MOM.WW.OtOpcUa.AdminUI.LiveTail;
/// <summary>
/// A bounded, newest-first buffer for a live event tail (the <c>/script-log</c> and <c>/alerts</c>
/// pages). Producers call <see cref="Add"/> from the bridge actor's thread; it only queues the item.
/// The page drains the queue into a fixed-capacity ring on its render context (<see cref="Flush"/>),
/// once per coalescing window, so a chatty feed costs one render per window instead of one per event,
/// and no <c>List.Insert(0, …)</c> memmove per event.
/// </summary>
/// <typeparam name="T">The event type.</typeparam>
public sealed class LiveTailBuffer<T>
{
private readonly object _gate = new();
private readonly T[] _ring;
private readonly List<T> _pending = new();
private int _head; // index the next item is written to
private int _count;
private IReadOnlyList<T> _snapshot = Array.Empty<T>();
/// <summary>Creates a buffer that keeps the most recent <paramref name="capacity"/> items.</summary>
/// <param name="capacity">Maximum retained items; must be positive.</param>
public LiveTailBuffer(int capacity)
{
ArgumentOutOfRangeException.ThrowIfNegativeOrZero(capacity);
_ring = new T[capacity];
}
/// <summary>The maximum number of retained items.</summary>
public int Capacity => _ring.Length;
/// <summary>Retained items, newest first, as of the last <see cref="Flush"/> or <see cref="Clear"/>.</summary>
public IReadOnlyList<T> Items => Volatile.Read(ref _snapshot);
/// <summary>Queues an item. Safe from any thread; does not change <see cref="Items"/> until the next flush.</summary>
/// <param name="item">The item to queue.</param>
/// <returns><see langword="true"/> when the queue was empty before this call, i.e. the caller should
/// schedule a flush.</returns>
public bool Add(T item)
{
lock (_gate)
{
// A burst larger than the ring would be evicted at flush anyway; dropping the oldest pending
// now keeps the queue bounded when no flush runs (e.g. a stalled circuit).
if (_pending.Count >= _ring.Length) _pending.RemoveAt(0);
_pending.Add(item);
return _pending.Count == 1;
}
}
/// <summary>Moves the queued items into the ring (evicting the oldest past capacity) and refreshes <see cref="Items"/>.</summary>
/// <returns><see langword="true"/> when anything was queued, i.e. a render is worthwhile.</returns>
public bool Flush()
{
lock (_gate)
{
if (_pending.Count == 0) return false;
foreach (var item in _pending)
{
_ring[_head] = item;
_head = (_head + 1) % _ring.Length;
if (_count < _ring.Length) _count++;
}
_pending.Clear();
Volatile.Write(ref _snapshot, BuildNewestFirst());
return true;
}
}
/// <summary>Drops every retained and queued item.</summary>
public void Clear()
{
lock (_gate)
{
_pending.Clear();
Array.Clear(_ring);
_head = 0;
_count = 0;
Volatile.Write(ref _snapshot, Array.Empty<T>());
}
}
private T[] BuildNewestFirst()
{
var result = new T[_count];
for (var i = 0; i < _count; i++)
{
var idx = (_head - 1 - i + _ring.Length) % _ring.Length;
result[i] = _ring[idx];
}
return result;
}
}
@@ -0,0 +1,185 @@
using Shouldly;
using Xunit;
using ZB.MOM.WW.OtOpcUa.AdminUI.LiveTail;
namespace ZB.MOM.WW.OtOpcUa.AdminUI.Tests.LiveTail;
/// <summary>
/// R04 P7: the live-tail pages coalesce event bursts into one render per window and keep their rows
/// in a bounded ring. All timing here is driven by a manual <see cref="TimeProvider"/>, so nothing
/// depends on wall-clock scheduling.
/// </summary>
[Trait("Category", "Unit")]
public sealed class LiveTailTests
{
[Fact]
public void Buffer_items_are_newest_first_and_only_change_on_flush()
{
var buffer = new LiveTailBuffer<int>(capacity: 3);
buffer.Add(1).ShouldBeTrue(); // first pending ⇒ caller schedules
buffer.Add(2).ShouldBeFalse(); // already pending ⇒ no second schedule
buffer.Items.ShouldBeEmpty(); // not visible until flush
buffer.Flush().ShouldBeTrue();
buffer.Items.ShouldBe([2, 1]);
buffer.Flush().ShouldBeFalse(); // nothing queued ⇒ no render worth doing
}
[Fact]
public void Buffer_evicts_the_oldest_past_capacity()
{
var buffer = new LiveTailBuffer<int>(capacity: 3);
for (var i = 1; i <= 5; i++) buffer.Add(i);
buffer.Flush();
buffer.Items.ShouldBe([5, 4, 3]);
buffer.Add(6);
buffer.Flush();
buffer.Items.ShouldBe([6, 5, 4]);
}
[Fact]
public void Buffer_Clear_drops_retained_and_pending_items()
{
var buffer = new LiveTailBuffer<int>(capacity: 3);
buffer.Add(1);
buffer.Flush();
buffer.Add(2);
buffer.Clear();
buffer.Items.ShouldBeEmpty();
buffer.Flush().ShouldBeFalse();
// Positive control: the buffer still works after a clear, and the next add re-arms scheduling.
buffer.Add(3).ShouldBeTrue();
buffer.Flush();
buffer.Items.ShouldBe([3]);
}
[Fact]
public async Task Scheduler_runs_one_flush_per_window_for_a_burst()
{
var time = new ManualTimeProvider();
var flushes = 0;
await using var scheduler = new CoalescingRenderScheduler(
TimeSpan.FromMilliseconds(200), () => { flushes++; return Task.CompletedTask; }, time);
for (var i = 0; i < 100; i++) scheduler.Schedule();
flushes.ShouldBe(0);
time.Advance(TimeSpan.FromMilliseconds(199));
flushes.ShouldBe(0);
time.Advance(TimeSpan.FromMilliseconds(1));
flushes.ShouldBe(1);
// The window re-arms after a fire: a later burst gets exactly one more flush.
scheduler.Schedule();
scheduler.Schedule();
time.Advance(TimeSpan.FromMilliseconds(200));
flushes.ShouldBe(2);
}
[Fact]
public async Task Scheduler_does_not_flush_after_dispose()
{
var time = new ManualTimeProvider();
var flushes = 0;
var scheduler = new CoalescingRenderScheduler(
TimeSpan.FromMilliseconds(200), () => { flushes++; return Task.CompletedTask; }, time);
// Positive control: the scheduler does flush before dispose.
scheduler.Schedule();
time.Advance(TimeSpan.FromMilliseconds(200));
flushes.ShouldBe(1);
scheduler.Schedule();
await scheduler.DisposeAsync();
time.Advance(TimeSpan.FromMilliseconds(500));
flushes.ShouldBe(1);
Should.NotThrow(scheduler.Schedule);
}
[Fact]
public async Task Scheduler_swallows_a_faulting_flush_and_keeps_working()
{
var time = new ManualTimeProvider();
var calls = 0;
await using var scheduler = new CoalescingRenderScheduler(TimeSpan.FromMilliseconds(200), () =>
{
calls++;
if (calls == 1) throw new ObjectDisposedException("renderer");
return Task.FromException(new InvalidOperationException("late"));
}, time);
scheduler.Schedule();
Should.NotThrow(() => time.Advance(TimeSpan.FromMilliseconds(200)));
scheduler.Schedule();
Should.NotThrow(() => time.Advance(TimeSpan.FromMilliseconds(200)));
calls.ShouldBe(2);
}
[Fact]
public void Pages_use_the_coalescing_tail_instead_of_a_render_per_event()
{
foreach (var page in new[] { "ScriptLog.razor", "Alerts.razor" })
{
var src = AdminUiSource.Read("Components", "Pages", page);
src.ShouldContain("CoalescingRenderScheduler", customMessage: page);
src.ShouldContain("LiveTailBuffer<", customMessage: page);
src.ShouldNotContain("_rows.Insert(0,", customMessage: page);
}
}
/// <summary>A deterministic <see cref="TimeProvider"/>: timers fire only when <see cref="Advance"/> passes their due time.</summary>
private sealed class ManualTimeProvider : TimeProvider
{
private readonly List<ManualTimer> _timers = new();
private DateTimeOffset _now = new(2026, 10, 22, 0, 0, 0, TimeSpan.Zero);
public override DateTimeOffset GetUtcNow() => _now;
public override ITimer CreateTimer(TimerCallback callback, object? state, TimeSpan dueTime, TimeSpan period)
{
var timer = new ManualTimer(this, callback, state);
timer.Change(dueTime, period);
_timers.Add(timer);
return timer;
}
public void Advance(TimeSpan by)
{
_now += by;
foreach (var t in _timers.ToArray()) t.FireIfDue(_now);
}
private sealed class ManualTimer(ManualTimeProvider owner, TimerCallback callback, object? state) : ITimer
{
private DateTimeOffset? _due;
private bool _disposed;
public bool Change(TimeSpan dueTime, TimeSpan period)
{
if (_disposed) throw new ObjectDisposedException(nameof(ManualTimer));
_due = dueTime == Timeout.InfiniteTimeSpan ? null : owner._now + dueTime;
return true;
}
public void FireIfDue(DateTimeOffset now)
{
if (_disposed || _due is null || _due > now) return;
_due = null;
callback(state);
}
public void Dispose() => _disposed = true;
public ValueTask DisposeAsync()
{
_disposed = true;
return ValueTask.CompletedTask;
}
}
}
}