fix(opcua): Server-object ConditionRefresh off Lock unless deferring; cut path O(conditions) with replay queued off Lock (#854 review)

Review of 1622d07f:
1. Perf: every i=2253 refresh ran the whole notifier walk + permission checks +
   QueueEvent under Lock. Now, with nothing deferred (the common case), the refresh is
   the SDK-shaped walk off Lock (Lock only to copy the root notifiers), kept only if no
   deferral episode existed at any moment of it (count 0 before and after, episode
   unchanged); otherwise the cut path also runs and its later replay supersedes. The
   cut path takes ACL/role verdicts off Lock, then one short Lock hold: watermark +
   frozen snapshots of Retain conditions from _alarmConditions (no tree walk) + per-item
   cut and "replay pending" marker; the replay is queued OFF Lock, one event per hold of
   the item gate. While pending, a condition event newer than the cut marks its
   condition so the older frozen entry is dropped rather than following it. A
   concurrent fast-path refresh cancels a pending cut replay of the same item.
   Measured, 3000 retained conditions, longest Lock wait seen by another thread during
   one refresh: 1622d07f 95-106 ms idle / 102-127 ms deferring; now 0-3 ms idle /
   23-32 ms deferring.
2. ACL: a retained condition omitted from the replay for want of a grant is never
   withheld (RefreshCut.RetainedAtCut); only Retain=true events of a condition omitted
   because it was NOT retained are.
3. One gate/cut state per item for its lifetime (ConditionalWeakTable keyed by the
   item): an unsubscribe + resubscribe between refresh and drain keeps the cut.
4. Cuts carry their deferral episode; ClearStaleRefreshCuts runs when the count
   returns to zero, and a stale-episode cut is inert.
5. Dispose guard for the custom refresh (ObjectDisposedException once disposing;
   Dispose waits for refreshes in flight).
6. Docs: a refresh waits at most for one in-progress QueueEvent on the item.

Tests: resubscribe variants, ACL-grant-lands test, pending-replay probe test,
dispose test, 3000-condition Lock-hold measurement with a probe pinning that neither
path queues its replay under Lock; stress invariant tightened (never backwards outside a
refresh; each refresh ends on the newest delivered state) and tolerant of the SDK's own
BadRefreshInProgress overlap refusal. Each new test fails against its targeted mutation.
This commit is contained in:
Joseph Doherty
2026-11-11 07:28:08 -05:00
parent 1622d07f2e
commit fe48458a41
4 changed files with 688 additions and 122 deletions
@@ -9,6 +9,7 @@ using Xunit;
using ZB.MOM.WW.OtOpcUa.Commons.OpcUa;
using ZB.MOM.WW.OtOpcUa.Configuration.Entities;
using ZB.MOM.WW.OtOpcUa.Configuration.Enums;
using ZB.MOM.WW.OtOpcUa.Core.Abstractions;
using ZB.MOM.WW.OtOpcUa.Core.Authorization;
using MonitoredItem = Opc.Ua.Client.MonitoredItem;
@@ -40,15 +41,21 @@ public sealed class ConditionRefreshDeferralWireTests
/// (so the refresh omits it and its final Retain=false event must still arrive).
/// </param>
/// <param name="refresh2">ConditionRefresh2 on the single item instead of ConditionRefresh on the subscription.</param>
/// <param name="resubscribe">
/// The Server-object item is unsubscribed and resubscribed (the SDK drives this on a monitoring-mode change)
/// between the refresh and the drain: its cut must survive (#854 review — it lived in the subscription map entry).
/// </param>
[Theory]
[InlineData(false, true, false)]
[InlineData(true, true, false)]
[InlineData(false, false, false)]
[InlineData(true, false, false)]
[InlineData(false, true, true)]
[InlineData(true, false, true)]
[InlineData(false, true, false, false)]
[InlineData(true, true, false, false)]
[InlineData(false, false, false, false)]
[InlineData(true, false, false, false)]
[InlineData(false, true, true, false)]
[InlineData(true, false, true, false)]
[InlineData(false, true, false, true)]
[InlineData(true, false, false, true)]
public async Task Deferred_events_older_than_a_refresh_never_reach_the_refreshed_server_object_item_after_RefreshEnd(
bool enforced, bool finalRetained, bool refresh2)
bool enforced, bool finalRetained, bool refresh2, bool resubscribe)
{
var ct = TestContext.Current.CancellationToken;
await using var rig = await ServerEventRig.StartAsync("Refresh854", encrypted: false, ct);
@@ -100,10 +107,21 @@ public sealed class ConditionRefreshDeferralWireTests
refresh.Elapsed.ShouldBeLessThan(TimeSpan.FromSeconds(10), "ConditionRefresh must not wait for the stalled drain");
await RecordedEvents.WaitUntilAsync(() => serverEvents.HasType(onServer, ObjectTypeIds.RefreshEndEventType));
rig.Nm.DeferredEventReports.ShouldBeGreaterThan(0, "the deferred events were still waiting at RefreshEnd");
rig.Nm.ActiveRefreshCuts.ShouldBe(1);
if (resubscribe)
{
var serverItem = FindAllEventsItem(rig.Nm, onServer.Status.Id);
rig.Nm.SubscribeToAllEvents(null!, serverSubscription.Id, serverItem, unsubscribe: true);
rig.Nm.SubscribeToAllEvents(null!, serverSubscription.Id, serverItem, unsubscribe: false);
}
stall.Release();
}
await RecordedEvents.WaitUntilAsync(() => rig.Nm.DeferredEventReports == 0);
// #854 review: a cut does not outlive its deferral episode.
await RecordedEvents.WaitUntilAsync(() => rig.Nm.ActiveRefreshCuts == 0);
rig.Nm.ActiveRefreshCuts.ShouldBe(0, "the cut is cleared when the deferral count returns to zero");
// Positive control: a later transition is delivered (and everything deferred before it has been decided).
rig.Project(native: true, Active("after"));
await RecordedEvents.WaitUntilAsync(() => serverEvents.Has(onServer, "after"));
@@ -149,6 +167,144 @@ public sealed class ConditionRefreshDeferralWireTests
folderEvents.Has(onA, "final").ShouldBeTrue();
}
/// <summary>
/// #854 review (ACL on): a condition the refresh omitted for the item because of its grants — not because it was
/// cleared — must not have its deferred events withheld: a grant added before the drain lets them through, and the
/// item must end on the condition's newest state (it would otherwise miss an active alarm entirely).
/// </summary>
[Fact]
public async Task Deferred_events_of_a_condition_the_refresh_omitted_for_want_of_a_grant_are_not_withheld()
{
var ct = TestContext.Current.CancellationToken;
await using var rig = await ServerEventRig.StartAsync("Refresh854Acl", encrypted: false, ct);
rig.KeyRoles = [];
rig.MaterialiseNative();
var anonymousOnA = ServerEventRig.EquipmentGrant(EqA, NodePermissions.ReadOnly);
rig.Enforce(true, [ServerEventRig.Key()], anonymousOnA);
// The stalled folder subscriber is anonymous (granted EqA); the refreshing key session holds no grant yet.
using var folderSession = await rig.ConnectAsync(anonymous: true, ct);
var folderEvents = new RecordedEvents();
var folderSubscription = await RecordedEvents.SubscribeAsync(folderSession, folderEvents, ct);
var onA = RecordedEvents.AddEventItem(folderSubscription, ServerEventRig.UnsNodeId(folderSession, EqA));
await folderSubscription.ApplyChangesAsync(ct);
using var serverSession = await rig.ConnectAsync(anonymous: false, ct);
var serverEvents = new RecordedEvents();
var serverSubscription = await RecordedEvents.SubscribeAsync(serverSession, serverEvents, ct);
var onServer = RecordedEvents.AddEventItem(serverSubscription, ObjectIds.Server);
await serverSubscription.ApplyChangesAsync(ct);
rig.Project(native: true, Active("seed"));
await RecordedEvents.WaitUntilAsync(() => folderEvents.Has(onA, "seed"));
serverEvents.Has(onServer, "seed").ShouldBeFalse("the key holds no grant yet");
await folderSubscription.SetPublishingModeAsync(false, ct);
using (var stall = ItemLockStall.Hold(FindServerItem(rig.Nm, onA.Status.Id)))
{
for (var i = 0; i < FloodSize; i++) rig.Project(native: true, Active($"f{i}"));
rig.Project(native: true, Active("final"));
rig.Nm.DeferredEventReports.ShouldBeGreaterThan(0);
await serverSession.CallAsync(
ObjectTypeIds.ConditionType, MethodIds.ConditionType_ConditionRefresh, ct, serverSubscription.Id);
await RecordedEvents.WaitUntilAsync(() => serverEvents.HasType(onServer, ObjectTypeIds.RefreshEndEventType));
// The grant arrives while the condition's events still wait.
rig.Enforce(true, [ServerEventRig.Key()], anonymousOnA, KeyEquipmentGrant(EqA));
stall.Release();
}
await RecordedEvents.WaitUntilAsync(() => rig.Nm.DeferredEventReports == 0);
await RecordedEvents.WaitUntilAsync(() => serverEvents.Has(onServer, "final"));
var stream = serverEvents.Of(onServer).ToList();
var end = stream.FindIndex(f => f[RecordedEvents.EventTypeField].GetNodeId() == ObjectTypeIds.RefreshEndEventType);
stream.Take(end).Count(f => f[RecordedEvents.AckedField].TryGetValue(out bool _))
.ShouldBe(0, "the refresh omitted the condition: no grant");
var after = stream.Skip(end + 1)
.Where(f => f[RecordedEvents.AckedField].TryGetValue(out bool _))
.Select(RecordedEvents.Message)
.ToList();
after.ShouldNotBeEmpty();
after[^1].ShouldBe("final", "the item ends on the newest state of a condition it was never refreshed");
after.Count(m => m!.StartsWith('f') && m != "final").ShouldBeGreaterThan(0, "its deferred events were delivered, not withheld");
}
/// <summary>
/// #854 review: the cut path queues its frozen replay OFF <c>Lock</c>. An event newer than the cut that reaches the
/// item in that window (here a synchronously delivered condition, reported from the probe between the cut and the
/// queueing) must not be followed by its condition's older frozen replay entry.
/// </summary>
[Fact]
public async Task An_event_newer_than_the_cut_is_never_followed_by_its_conditions_older_frozen_replay()
{
var ct = TestContext.Current.CancellationToken;
await using var rig = await ServerEventRig.StartAsync("Refresh854Pending", encrypted: false, ct);
rig.KeyRoles = [];
rig.MaterialiseNative();
rig.Enforce(false, [ServerEventRig.Key()], KeyEquipmentGrant(EqA));
// A second condition under the device folder only: no folder item, so its events are always synchronous.
const string Free = ServerEventRig.RawDeviceFolder + "/free";
rig.Sink.MaterialiseAlarmCondition(Free, ServerEventRig.RawDeviceFolder, "free", "OffNormalAlarm", 700, AddressSpaceRealm.Raw, isNative: true);
rig.Sink.WriteAlarmCondition(Free, Active("x1"), DateTime.UtcNow, AddressSpaceRealm.Raw);
using var folderSession = await rig.ConnectAsync(anonymous: false, ct);
var folderEvents = new RecordedEvents();
var folderSubscription = await RecordedEvents.SubscribeAsync(folderSession, folderEvents, ct);
var onA = RecordedEvents.AddEventItem(folderSubscription, ServerEventRig.UnsNodeId(folderSession, EqA));
await folderSubscription.ApplyChangesAsync(ct);
using var serverSession = await rig.ConnectAsync(anonymous: false, ct);
var serverEvents = new RecordedEvents();
var serverSubscription = await RecordedEvents.SubscribeAsync(serverSession, serverEvents, ct);
var onServer = RecordedEvents.AddEventItem(serverSubscription, ObjectIds.Server);
await serverSubscription.ApplyChangesAsync(ct);
rig.Project(native: true, Active("seed"));
await RecordedEvents.WaitUntilAsync(() => folderEvents.Has(onA, "seed") && serverEvents.Has(onServer, "seed"));
await folderSubscription.SetPublishingModeAsync(false, ct);
var injected = 0;
rig.Nm.ServerObjectRefreshProbe = (cut, _) =>
{
if (cut && Interlocked.Exchange(ref injected, 1) == 0)
rig.Sink.WriteAlarmCondition(Free, Active("x2"), DateTime.UtcNow, AddressSpaceRealm.Raw);
};
using (var stall = ItemLockStall.Hold(FindServerItem(rig.Nm, onA.Status.Id)))
{
for (var i = 0; i < FloodSize; i++) rig.Project(native: true, Active($"f{i}"));
rig.Nm.DeferredEventReports.ShouldBeGreaterThan(0, "the cut path runs only while something is deferred");
await serverSession.CallAsync(
ObjectTypeIds.ConditionType, MethodIds.ConditionType_ConditionRefresh, ct, serverSubscription.Id);
await RecordedEvents.WaitUntilAsync(() => serverEvents.HasType(onServer, ObjectTypeIds.RefreshEndEventType));
stall.Release();
}
rig.Nm.ServerObjectRefreshProbe = null;
Volatile.Read(ref injected).ShouldBe(1);
var stream = serverEvents.Of(onServer).ToList();
var end = stream.FindIndex(f => f[RecordedEvents.EventTypeField].GetNodeId() == ObjectTypeIds.RefreshEndEventType);
var free = stream.Take(end)
.Select(RecordedEvents.Message)
.Where(m => m is "x1" or "x2")
.ToList();
free.ShouldContain("x2");
free[^1].ShouldBe("x2", "the older frozen replay of the condition must not follow its newer event");
}
/// <summary>#854 review: the custom Server-object refresh is refused once the node manager is disposed, like the base's.</summary>
[Fact]
public async Task A_refresh_after_disposal_is_refused()
{
var ct = TestContext.Current.CancellationToken;
var rig = await ServerEventRig.StartAsync("Refresh854Dispose", encrypted: false, ct);
var nm = rig.Nm;
await rig.DisposeAsync();
nm.Dispose();
Should.Throw<ObjectDisposedException>(() => nm.ConditionRefresh(null!, Array.Empty<IEventMonitoredItem>()));
}
/// <summary>
/// The race the item gate closes, made deterministic: a deferred event is between its supersession check and its
/// queueing to the Server-object item when the refresh arrives. The refresh must wait for that one delivery (so
@@ -294,6 +450,7 @@ public sealed class ConditionRefreshDeferralWireTests
}
}, stop.Token, TaskCreationOptions.LongRunning, TaskScheduler.Default);
var refusedAsInProgress = 0;
for (var r = 0; r < 40; r++)
{
var call = r % 3 == 2
@@ -301,7 +458,17 @@ public sealed class ConditionRefreshDeferralWireTests
serverSubscription.Id, onServer.Status.Id)
: serverSession.CallAsync(ObjectTypeIds.ConditionType, MethodIds.ConditionType_ConditionRefresh, ct,
serverSubscription.Id);
await call.WaitAsync(TimeSpan.FromSeconds(20), ct);
try
{
await call.WaitAsync(TimeSpan.FromSeconds(20), ct);
}
catch (ServiceResultException ex) when (ex.StatusCode == StatusCodes.BadRefreshInProgress)
{
// The SDK answers the Call before the refresh body runs, so under load the previous refresh of this
// subscription may still be in progress; the SDK refuses the overlap (its rule, not ours).
refusedAsInProgress++;
}
await Task.Delay(TimeSpan.FromMilliseconds(80), ct);
}
@@ -311,16 +478,17 @@ public sealed class ConditionRefreshDeferralWireTests
Volatile.Read(ref deferredSeen).ShouldBeGreaterThan(1, "the stress must actually have run with deferred events");
await RecordedEvents.WaitUntilAsync(() => rig.Nm.DeferredEventReports == 0);
var last = $"s{Volatile.Read(ref counter)}";
var newest = $"s{Volatile.Read(ref counter)}";
await folderSubscription.SetPublishingModeAsync(true, ct);
await RecordedEvents.WaitUntilAsync(() => serverEvents.Has(onServer, last));
await RecordedEvents.WaitUntilAsync(() => serverEvents.Has(onServer, newest));
await Task.Delay(TimeSpan.FromMilliseconds(500), ct);
// Walk the Server-object stream: after each RefreshEnd, a condition event must not be older than what that
// refresh replayed (the refresh replays the then-current state, so the floor is its replayed counter).
var floor = -1;
// Walk the Server-object stream (one condition). Outside a refresh its states never go backwards; and each refresh
// ends on the newest state the item has seen — its replay is never older than an event already delivered, and
// nothing older than it follows RefreshEnd.
var max = -1;
var last = -1;
var replaying = false;
var replayedInThisRefresh = -1;
var violations = new List<string>();
foreach (var f in serverEvents.Of(onServer))
{
@@ -328,33 +496,139 @@ public sealed class ConditionRefreshDeferralWireTests
if (type == ObjectTypeIds.RefreshStartEventType)
{
replaying = true;
replayedInThisRefresh = -1;
continue;
}
if (type == ObjectTypeIds.RefreshEndEventType)
{
replaying = false;
floor = Math.Max(floor, replayedInThisRefresh);
if (last < max) violations.Add($"a refresh ended on s{last} after s{max} had been delivered");
continue;
}
if (!f[RecordedEvents.AckedField].TryGetValue(out bool _)) continue;
var n = int.Parse(RecordedEvents.Message(f)![1..], System.Globalization.CultureInfo.InvariantCulture);
if (replaying)
{
replayedInThisRefresh = n;
continue;
}
if (n < floor) violations.Add($"s{n} after a refresh that replayed s{floor}");
if (!replaying && n < max) violations.Add($"s{n} delivered after s{max}");
max = Math.Max(max, n);
last = n;
}
violations.ShouldBeEmpty();
refusedAsInProgress.ShouldBeLessThan(40, "most refreshes must actually have run");
rig.Nm.RefreshSupersededDeliveries.ShouldBeGreaterThan(0, "some refresh must actually have overtaken deferred events");
RecordedEvents.Message(serverEvents.Of(onServer).Last(f => f[RecordedEvents.AckedField].TryGetValue(out bool _)))
.ShouldBe(last, "the stream still converges on the newest state");
await RecordedEvents.WaitUntilAsync(() => folderEvents.Has(onA, last));
.ShouldBe(newest, "the stream still converges on the newest state");
await RecordedEvents.WaitUntilAsync(() => folderEvents.Has(onA, newest));
}
/// <summary>
/// Review of 1622d07f: a Server-object refresh must not hold the node manager's <c>Lock</c> across a walk of a large
/// address space — ScadaBridge refreshes on every reconnect, and any session may loop ConditionRefresh. Measures
/// the longest any other thread waits for <c>Lock</c> while a refresh of 3000 retained conditions runs, with
/// nothing deferred (the common case) and with a deferral in progress, and pins that the common case does not
/// build or queue its replay under <c>Lock</c>.
/// </summary>
/// <param name="deferring">Whether a deferral episode is in progress when the refresh runs.</param>
[Theory]
[InlineData(false)]
[InlineData(true)]
public async Task A_refresh_of_a_large_address_space_keeps_the_node_manager_lock_hold_short(bool deferring)
{
const int Conditions = 3000;
var ct = TestContext.Current.CancellationToken;
await using var rig = await ServerEventRig.StartAsync("Refresh854Lock", encrypted: false, ct);
rig.KeyRoles = [];
rig.MaterialiseNative();
rig.Enforce(false, [ServerEventRig.Key()], KeyEquipmentGrant(EqA));
for (var i = 0; i < Conditions; i++)
{
var id = $"{ServerEventRig.RawDeviceFolder}/c{i}";
rig.Sink.MaterialiseAlarmCondition(id, ServerEventRig.RawDeviceFolder, $"c{i}", "OffNormalAlarm", 700, AddressSpaceRealm.Raw, isNative: true);
rig.Sink.WriteAlarmCondition(id, Active($"c{i}"), DateTime.UtcNow, AddressSpaceRealm.Raw);
}
using var folderSession = await rig.ConnectAsync(anonymous: false, ct);
var folderEvents = new RecordedEvents();
var folderSubscription = await RecordedEvents.SubscribeAsync(folderSession, folderEvents, ct);
var onA = RecordedEvents.AddEventItem(folderSubscription, ServerEventRig.UnsNodeId(folderSession, EqA));
await folderSubscription.ApplyChangesAsync(ct);
using var serverSession = await rig.ConnectAsync(anonymous: false, ct);
var serverEvents = new RecordedEvents();
var serverSubscription = await RecordedEvents.SubscribeAsync(serverSession, serverEvents, ct);
var onServer = RecordedEvents.AddEventItem(serverSubscription, ObjectIds.Server);
onServer.QueueSize = 10_000;
await serverSubscription.ApplyChangesAsync(ct);
rig.Project(native: true, Active("seed"));
await RecordedEvents.WaitUntilAsync(() => folderEvents.Has(onA, "seed") && serverEvents.Has(onServer, "seed"));
await folderSubscription.SetPublishingModeAsync(false, ct);
var stall = deferring ? ItemLockStall.Hold(FindServerItem(rig.Nm, onA.Status.Id)) : null;
try
{
if (deferring)
{
for (var i = 0; i < FloodSize; i++) rig.Project(native: true, Active($"f{i}"));
rig.Nm.DeferredEventReports.ShouldBeGreaterThan(0);
}
var probes = new System.Collections.Concurrent.ConcurrentQueue<(bool Cut, bool LockHeld)>();
rig.Nm.ServerObjectRefreshProbe = (cut, held) => probes.Enqueue((cut, held));
var waits = new List<double>();
for (var round = 0; round < 5; round++)
{
var ends = serverEvents.Of(onServer).Count(f => f[RecordedEvents.EventTypeField].GetNodeId() == ObjectTypeIds.RefreshEndEventType);
using var stop = new CancellationTokenSource();
var maxWait = 0.0;
var prober = Task.Factory.StartNew(() =>
{
var sw = new Stopwatch();
while (!stop.IsCancellationRequested)
{
sw.Restart();
lock (rig.Nm.Lock) { }
maxWait = Math.Max(maxWait, sw.Elapsed.TotalMilliseconds);
Thread.Yield();
}
}, CancellationToken.None, TaskCreationOptions.LongRunning, TaskScheduler.Default);
await serverSession.CallAsync(
ObjectTypeIds.ConditionType, MethodIds.ConditionType_ConditionRefresh, ct, serverSubscription.Id);
await RecordedEvents.WaitUntilAsync(() => serverEvents.Of(onServer)
.Count(f => f[RecordedEvents.EventTypeField].GetNodeId() == ObjectTypeIds.RefreshEndEventType) > ends);
await stop.CancelAsync();
await prober;
waits.Add(maxWait);
}
TestContext.Current.TestOutputHelper?.WriteLine(
$"#854 lock-hold deferring={deferring} conditions={Conditions}: max Lock wait per refresh (ms) = "
+ string.Join(", ", waits.Select(w => w.ToString("F1", System.Globalization.CultureInfo.InvariantCulture))));
// Neither path queues its replay under Lock; only a deferral makes a refresh take the cut path.
probes.ShouldNotBeEmpty();
probes.ShouldAllBe(p => !p.LockHeld);
if (deferring) probes.ShouldContain(p => p.Cut);
else probes.ShouldAllBe(p => !p.Cut);
}
finally
{
stall?.Dispose();
}
}
/// <summary>The server-side Server-object (all-events) item behind a client item.</summary>
private static IEventMonitoredItem FindAllEventsItem(OtOpcUaNodeManager nm, uint id)
{
var map = (IDictionary)typeof(OtOpcUaNodeManager)
.GetField("_allEventsItems", BindingFlags.Instance | BindingFlags.NonPublic)!
.GetValue(nm)!;
foreach (var key in map.Keys)
{
if (key is IEventMonitoredItem item && item.Id == id) return item;
}
throw new InvalidOperationException($"no server-side all-events item {id}");
}
/// <summary>The server-side event item behind a client item, from the node manager's direct-item map.</summary>