fix(opcua): #855 review 1 — re-decide frozen replay entries; a failed delivery is not a deferral

- QueueFrozenReplay re-asks each item's verdict right before each entry's gate
  hold (Server-object and folder cut paths): a grant revoked between the
  pre-Lock verdicts and the replay no longer lets the replay through. A denied
  entry is also removed from the cut's re-sent set.
- ReportEventWithoutBlocking logs and returns on a delivery that faulted
  inline instead of booking it as a deferral episode (which ran the drain and
  ClearStaleRefreshCuts under the event-report gate while Lock was held).
- OnConditionReportEvent isolates failures per Server-object item.
- Tests: revocation between cut and replay (folder + Server object), throwing
  hop not booked as a deferral; production-overload sampling inside Lock.

Claude-Session: https://claude.ai/code/session_01GT67AD99zQQqpLCVm3p7xk
This commit is contained in:
Joseph Doherty
2026-11-11 12:31:02 -05:00
parent d9b23e0b95
commit d2b1545659
3 changed files with 182 additions and 15 deletions
+5 -1
View File
@@ -924,7 +924,11 @@ Behaviours worth knowing before enabling it:
`QueueSize`) and the verdict runs on the reporter's thread, which already holds `Lock` — so a burst under one
`Lock` hold completes with nothing deferred, and the #838 deadlock shape is gone for condition events. Folder items
therefore see condition events in report order. The cost moves with it: the per-event verdict and filter for
folder items now run under `Lock` (as for Server-object items), where the SDK used to cache the verdict off it.
folder items now run under `Lock` (as for Server-object items), where the SDK used to cache the verdict off it —
including the SDK item queue's own per-event costs (its duplicate scan, and at a full queue a list shift), so many
folder items on one notifier whose clients stop publishing make each report proportionally slower under `Lock`.
With auditing on (off in this repo), a condition's SDK method **audit** event still takes the folder's channel, so
at a folder item it may now arrive after the condition event that method produced (they were one FIFO before).
- **The deferral queue and the cut stay as the safety net**, for a hop that is not ours (none exists today:
conditions are never event notifiers and variables cannot host event items) — and folder items share the cut:
a `ConditionRefresh`/`ConditionRefresh2` of a folder item takes the same two paths as the Server object (plain walk
@@ -1529,6 +1529,16 @@ public sealed class OtOpcUaNodeManager : CustomNodeManager2, INodeManager3
if (delivery.IsCompletedSuccessfully) return;
// #855 review: a delivery that FAILED inline is over, not suspended. Booking it as a deferral used to open and close
// a deferral episode synchronously (moving the episode a concurrent plain refresh checks, and clearing cuts under
// the event-report gate while Lock was held). Only an incomplete delivery is deferred.
if (delivery.IsCompleted)
{
_logger.LogError(delivery.AsTask().Exception?.GetBaseException(),
"OtOpcUaNodeManager: failed to report Part 9 condition event for {NodeId}", condition.NodeId);
return;
}
lock (_eventReportGate)
{
var queue = new DeferredConditionReports();
@@ -1901,6 +1911,9 @@ public sealed class OtOpcUaNodeManager : CustomNodeManager2, INodeManager3
/// </summary>
private long _deferralEpisode;
/// <summary>Deferral episodes ended since start (test observation, #855 review).</summary>
internal long DeferralEpisodes => Interlocked.Read(ref _deferralEpisode);
/// <summary>What a Server-object item's latest ConditionRefresh conveyed (#854).</summary>
/// <param name="Watermark">Every condition event with a sequence at or below this was reported before the replay was read.</param>
/// <param name="Episode">The deferral episode the cut was taken in; once it ends the cut is stale and inert.</param>
@@ -5782,17 +5795,26 @@ public sealed class OtOpcUaNodeManager : CustomNodeManager2, INodeManager3
foreach (var item in _allEventsItems.Keys)
{
if (e is AuditEventState && !IsAuditDeliverableTo(item)) continue;
if (scopes is not null && !IsConditionVisibleTo(item, scopes)) continue;
if (ServiceResult.IsBad(ValidateEventRolePermissions(item, e))) continue;
if (reportingSession is { IsNull: false } reportingId
&& item.Session?.Id is { } own
&& !own.Equals(reportingId))
try
{
continue;
}
if (e is AuditEventState && !IsAuditDeliverableTo(item)) continue;
if (scopes is not null && !IsConditionVisibleTo(item, scopes)) continue;
if (ServiceResult.IsBad(ValidateEventRolePermissions(item, e))) continue;
if (reportingSession is { IsNull: false } reportingId
&& item.Session?.Id is { } own
&& !own.Equals(reportingId))
{
continue;
}
QueueConditionEventToItem(item, e, deferred, DeferredServerObjectDeliveryProbe);
QueueConditionEventToItem(item, e, deferred, DeferredServerObjectDeliveryProbe);
}
catch (Exception ex)
{
// #855 review: one item's failure (an item disposed under us, the SDK's operation guard at shutdown) must
// not cost the other Server-object items, nor abort the walk before the folder hops.
_logger.LogWarning(ex, "OtOpcUaNodeManager: failed to deliver a condition event to Server-object item {ItemId}", item.Id);
}
}
}
@@ -6671,7 +6693,24 @@ public sealed class OtOpcUaNodeManager : CustomNodeManager2, INodeManager3
}
ServerObjectRefreshProbe?.Invoke(true, Monitor.IsEntered(Lock));
QueueFrozenReplay(items, states, perItem.Select(entries => entries.Select(x => (x.Event, x.Condition.NodeId)).ToList()).ToArray(), generation);
// #855 review: the verdicts above were taken before Lock; a deploy may have revoked a grant since. Each replay entry
// is re-decided right before it is queued (scopes resolved once per condition).
var scopeCache = new Dictionary<NodeId, List<NodeId>>();
QueueFrozenReplay(
items, states, perItem.Select(entries => entries.Select(x => (x.Event, x.Condition.NodeId)).ToList()).ToArray(),
generation,
(item, e) =>
{
if (enforced)
{
if (ConditionOf(e) is not { } condition) return false;
if (!scopeCache.TryGetValue(condition.NodeId, out var scopes))
scopeCache[condition.NodeId] = scopes = ConditionVisibilityScopes(condition);
if (!IsConditionVisibleTo(item, scopes)) return false;
}
return !ServiceResult.IsBad(ValidateEventRolePermissions(item, e));
});
}
finally
{
@@ -6685,8 +6724,15 @@ public sealed class OtOpcUaNodeManager : CustomNodeManager2, INodeManager3
/// replay of its condition, so that replay entry is dropped rather than queued after it (the newer event is already
/// inside RefreshStart..RefreshEnd). A later refresh of the item supersedes this one.
/// </summary>
/// <param name="allowed">
/// The item's verdict for one entry, asked right before the entry's gate hold (never under it: it takes <c>Lock</c>),
/// against the CURRENT generation — the verdicts the cut was built on were taken earlier (#855 review). An entry
/// denied here is dropped AND removed from the cut's re-sent set, so the condition counts as "omitted for the
/// grants" and its later events are left to the ACL rather than withheld as superseded.
/// </param>
private static void QueueFrozenReplay(
List<IEventMonitoredItem> items, List<EventItemState> states, List<(IFilterTarget Event, NodeId ConditionId)>[] perItem, int generation)
List<IEventMonitoredItem> items, List<EventItemState> states, List<(IFilterTarget Event, NodeId ConditionId)>[] perItem,
int generation, Func<IEventMonitoredItem, IFilterTarget, bool> allowed)
{
for (var i = 0; i < items.Count; i++)
{
@@ -6694,9 +6740,17 @@ public sealed class OtOpcUaNodeManager : CustomNodeManager2, INodeManager3
var state = states[i];
foreach (var (e, conditionId) in perItem[i])
{
if (state.PendingReplay != generation) break;
var permitted = allowed(item, e);
lock (state.Gate)
{
if (state.PendingReplay != generation) break;
if (!permitted)
{
state.Cut?.Refreshed.Remove(conditionId);
continue;
}
if (state.NewerSinceCut.Contains(conditionId)) continue;
item.QueueEvent(e);
}
@@ -6926,7 +6980,8 @@ public sealed class OtOpcUaNodeManager : CustomNodeManager2, INodeManager3
}
DirectRefreshProbe?.Invoke(true, Monitor.IsEntered(Lock));
QueueFrozenReplay(items, states, perItem, generation);
// #855 review: re-decided per entry right before queueing — a deploy may have revoked since the verdicts.
QueueFrozenReplay(items, states, perItem, generation, (item, e) => IsDirectRefreshEventAllowed(item, e, enforced));
}
finally
{
@@ -358,6 +358,110 @@ public sealed class FolderConditionRefreshWireTests
keyEvents.Has(keyA, "after-revoke").ShouldBeFalse();
}
/// <summary>
/// #855 review: the cut path decides its replay before taking <c>Lock</c>; a grant revoked between that decision
/// and the queueing of the frozen replay must still withhold the replay (it is re-decided right before each entry).
/// The revocation lands from the refresh probe, which runs after the cut is installed and before the replay is queued.
/// </summary>
/// <param name="serverObject">Refresh a Server-object item instead of a folder item.</param>
[Theory]
[InlineData(false)]
[InlineData(true)]
public async Task A_grant_revoked_between_the_cut_and_its_replay_withholds_the_replay(bool serverObject)
{
var ct = TestContext.Current.CancellationToken;
await using var rig = await ServerEventRig.StartAsync("Refresh855RevokeCut", encrypted: false, ct);
rig.KeyRoles = [];
rig.MaterialiseNative();
var anonGrant = ServerEventRig.EquipmentGrant(EqA, NodePermissions.ReadOnly);
var state = rig.Enforce(true, [ServerEventRig.Key()], KeyEquipmentGrant(EqA), anonGrant);
// An anonymous subscriber keeps EqA a notifier fan-out the stall applies to (and stays granted throughout).
using var anonymous = await rig.ConnectAsync(anonymous: true, ct);
var anonEvents = new RecordedEvents();
var anonSub = await RecordedEvents.SubscribeAsync(anonymous, anonEvents, ct);
RecordedEvents.AddEventItem(anonSub, ServerEventRig.UnsNodeId(anonymous, EqA));
await anonSub.ApplyChangesAsync(ct);
using var keyed = await rig.ConnectAsync(anonymous: false, ct);
var keyEvents = new RecordedEvents();
var keySub = await RecordedEvents.SubscribeAsync(keyed, keyEvents, ct);
var item = RecordedEvents.AddEventItem(keySub, serverObject ? ObjectIds.Server : ServerEventRig.UnsNodeId(keyed, EqA));
await keySub.ApplyChangesAsync(ct);
item.Status.Error.ShouldBeNull();
rig.Project(native: true, Active("seed"));
await RecordedEvents.WaitUntilAsync(() => keyEvents.Has(item, "seed"));
var revoked = 0;
void Revoke(bool cut, bool _)
{
if (!cut || Interlocked.Exchange(ref revoked, 1) != 0) return;
state.Apply(
ServerEventRig.Cluster, "rev-2", [ServerEventRig.Key()], [anonGrant], ServerEventRig.ScopePaths(),
ServerEventRig.EquipmentOwnerPaths(), ServerEventRig.ScriptedAlarmOwners(), ServerEventRig.FolderScopes(),
ServerEventRig.TagReferences());
}
if (serverObject) rig.Nm.ServerObjectRefreshProbe = Revoke;
else rig.Nm.DirectRefreshProbe = Revoke;
using (var stall = NotifierStall.Hold(rig.Nm, EqA))
{
for (var i = 0; i < FloodSize; i++) rig.Project(native: true, Active($"f{i}"));
rig.Nm.DeferredEventReports.ShouldBeGreaterThan(0);
await keyed.CallAsync(ObjectTypeIds.ConditionType, MethodIds.ConditionType_ConditionRefresh, ct, keySub.Id);
await RecordedEvents.WaitUntilAsync(() => keyEvents.HasType(item, ObjectTypeIds.RefreshEndEventType));
stall.Release();
}
rig.Nm.ServerObjectRefreshProbe = null;
rig.Nm.DirectRefreshProbe = null;
Volatile.Read(ref revoked).ShouldBe(1, "the refresh took the cut path");
await RecordedEvents.WaitUntilAsync(() => rig.Nm.DeferredEventReports == 0);
await Task.Delay(TimeSpan.FromMilliseconds(500), ct);
var (replayed, after) = Window(keyEvents.Of(item));
replayed.ShouldBeEmpty("the grant was revoked before the replay was queued");
after.ShouldBeEmpty("and nothing reaches the item after RefreshEnd either");
}
/// <summary>
/// #855 review: a delivery that fails inline (here: a hop that throws) is over, not suspended — it must not be booked
/// as a deferral episode (which moved the episode a concurrent plain refresh checks, and cleared cuts under the
/// event-report gate while <c>Lock</c> was held). The Server-object item, served before the failing hop, still gets
/// the event, and the next event is delivered normally.
/// </summary>
[Fact]
public async Task A_delivery_that_throws_is_not_booked_as_a_deferral()
{
var ct = TestContext.Current.CancellationToken;
await using var rig = await ServerEventRig.StartAsync("Refresh855Fault", encrypted: false, ct);
rig.KeyRoles = [];
rig.MaterialiseNative();
rig.Enforce(false, [ServerEventRig.Key()], KeyEquipmentGrant(EqA));
using var session = await rig.ConnectAsync(anonymous: false, ct);
var events = new RecordedEvents();
var subscription = await RecordedEvents.SubscribeAsync(session, events, ct);
var onA = RecordedEvents.AddEventItem(subscription, ServerEventRig.UnsNodeId(session, EqA));
var onServer = RecordedEvents.AddEventItem(subscription, ObjectIds.Server);
await subscription.ApplyChangesAsync(ct);
var episodes = rig.Nm.DeferralEpisodes;
rig.Nm.NotifierDeliveryStall = node =>
node.NodeId.IdentifierAsString == EqA ? throw new InvalidOperationException("hop fault (test)") : null;
rig.Project(native: true, Active("faulted"));
rig.Nm.NotifierDeliveryStall = null;
rig.Nm.DeferredEventReports.ShouldBe(0);
rig.Nm.DeferralEpisodes.ShouldBe(episodes, "a failed delivery is not a deferral episode");
rig.Project(native: true, Active("next"));
await RecordedEvents.WaitUntilAsync(() =>
events.Has(onServer, "faulted") && events.Has(onServer, "next") && events.Has(onA, "next"));
events.Has(onA, "faulted").ShouldBeFalse("the faulted hop delivered nothing");
}
/// <summary>
/// Production shape, no stall: bursts reported under one <c>Lock</c> hold (an apply pass) and single reports, against
/// folder items that refresh repeatedly while their client is slow to publish. Folder items are served per item, so
@@ -398,10 +502,14 @@ public sealed class FolderConditionRefreshWireTests
{
lock (rig.Nm.Lock)
{
for (var i = 0; i < 1000; i++) rig.Project(native: true, Active($"s{Interlocked.Increment(ref counter)}"));
for (var i = 0; i < 1000; i++)
{
rig.Project(native: true, Active($"s{Interlocked.Increment(ref counter)}"));
// Sampled inside Lock, after each report: a deferral cannot open and drain unseen (#855 review).
peakDeferred = Math.Max(peakDeferred, rig.Nm.DeferredEventReports);
}
}
peakDeferred = Math.Max(peakDeferred, rig.Nm.DeferredEventReports);
rig.Project(native: true, Active($"s{Interlocked.Increment(ref counter)}"));
Thread.Sleep(2);
}