From 70050c9d7e713f8f48ccfd98cdd1608f698d02c1 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Tue, 10 Nov 2026 05:05:18 -0500 Subject: [PATCH] test(opcuaclient): slow server-side subscription delete keeps the stale-BadNoSubscription grace running from delete completion (lmxopcua#764) Unsubscribe paths now delete through the existing DeleteSubscriptionAsync seam so a test can hold the delete open >grace. Mutation: dropping the post-delete restamp fails both slow-delete tests. Claude-Session: https://claude.ai/code/session_01GT67AEHd2Acv1YPwGfXEoV --- .../OpcUaClientDriver.cs | 6 +- .../OpcUaClientStaleNoSubscriptionTests.cs | 103 ++++++++++++++++++ 2 files changed, 106 insertions(+), 3 deletions(-) diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient/OpcUaClientDriver.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient/OpcUaClientDriver.cs index d1bd8853..0222a7cf 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient/OpcUaClientDriver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient/OpcUaClientDriver.cs @@ -1242,7 +1242,7 @@ public sealed class OpcUaClientDriver : IDriver, ITagDiscovery, IReadable, IWrit /// internal TimeSpan TeardownBudget { get; set; } = TimeSpan.FromSeconds(4); - /// Test seam: the wire delete of one subscription. Production calls the SDK's silent delete. + /// Test seam: the wire delete of one subscription (unsubscribe + shutdown). Production calls the SDK's silent delete. internal Func DeleteSubscriptionAsync { get; set; } = static (subscription, ct) => subscription.DeleteAsync(silent: true, ct); @@ -2050,7 +2050,7 @@ public sealed class OpcUaClientDriver : IDriver, ITagDiscovery, IReadable, IWrit // RemoteSubscription is the exact instance that was added, so `-=` removes it // cleanly. DetachNotificationHandlers(rs.ItemHandlers); - try { await rs.Subscription.DeleteAsync(silent: true, cancellationToken).ConfigureAwait(false); } + try { await DeleteSubscriptionAsync(rs.Subscription, cancellationToken).ConfigureAwait(false); } catch { /* best-effort — the subscription may already be gone on reconnect */ } } finally @@ -2555,7 +2555,7 @@ public sealed class OpcUaClientDriver : IDriver, ITagDiscovery, IReadable, IWrit // closure. try { rs.EventItem.Notification -= rs.Handler; } catch { /* best-effort */ } - try { await rs.Subscription.DeleteAsync(silent: true, cancellationToken).ConfigureAwait(false); } + try { await DeleteSubscriptionAsync(rs.Subscription, cancellationToken).ConfigureAwait(false); } catch { /* best-effort — session may already be gone across a reconnect */ } } finally diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.Tests/OpcUaClientStaleNoSubscriptionTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.Tests/OpcUaClientStaleNoSubscriptionTests.cs index 9990c8b1..8c7ea995 100644 --- a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.Tests/OpcUaClientStaleNoSubscriptionTests.cs +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.Tests/OpcUaClientStaleNoSubscriptionTests.cs @@ -184,3 +184,106 @@ public sealed class OpcUaClientStaleNoSubscriptionTests ShouldBeDeclaredLost(drv, seen, "the delete belonged to the released session"); } } + +/// +/// Gitea #764 residual: the server's DeleteSubscriptions can be slow (> ). +/// The server answers the stale publish only once the delete is done, so the grace runs from the delete's +/// COMPLETION, not its start. +/// +[Trait("Category", "Unit")] +public sealed class OpcUaClientSlowDeleteTests +{ + private const string SpeedRef = "Plant/dev/Speed"; + private const string AlarmRef = "Plant/dev/TempHi"; + + private sealed class ManualClock(DateTimeOffset start) : TimeProvider + { + public DateTimeOffset Now { get; set; } = start; + public override DateTimeOffset GetUtcNow() => Now; + public void Advance(TimeSpan by) => Now += by; + } + + private static (OpcUaClientDriver Driver, ManualClock Clock, List Lost, + TaskCompletionSource Gate, TaskCompletionSource Started) New() + { + RawTagEntry[] tags = [new(SpeedRef, JsonSerializer.Serialize(new { nodeId = "ns=0;s=Speed" }), WriteIdempotent: true)]; + var drv = new OpcUaClientDriver(new OpcUaClientDriverOptions { RawTags = tags }, "opcua-764"); + var session = new Mock(MockBehavior.Loose); + session.SetupGet(s => s.MessageContext).Returns(new ServiceMessageContext(SdkTelemetry.Context)); + session.SetupGet(s => s.NamespaceUris).Returns(new NamespaceTable()); + var clock = new ManualClock(new DateTimeOffset(2026, 11, 10, 12, 0, 0, TimeSpan.Zero)); + drv.Clock = clock; + drv.SetSessionForTest(session.Object); + drv.SetNamespaceMapForTest(NamespaceMap.FromTable(new NamespaceTable(), tags)); + drv.SetHealthForTest(new DriverHealth(DriverState.Healthy, clock.Now.UtcDateTime, null)); + var lost = new List(); + drv.ConnectionLost += (_, e) => lost.Add(e); + var gate = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var started = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + drv.DeleteSubscriptionAsync = async (_, _) => { started.TrySetResult(); await gate.Task; }; + return (drv, clock, lost, gate, started); + } + + [Fact] + public async Task A_slow_data_delete_still_attributes_the_stale_error_to_the_delete() + { + var (drv, clock, lost, gate, started) = New(); + await using var _ = drv; + var first = drv.AddSubscriptionForTest([SpeedRef]); + + var unsub = drv.UnsubscribeAsync(first, TestContext.Current.CancellationToken); + await started.Task.WaitAsync(TimeSpan.FromSeconds(10), TestContext.Current.CancellationToken); + clock.Advance(TimeSpan.FromSeconds(30)); // the delete takes far longer than the grace + gate.SetResult(); + await unsub; + + drv.AddSubscriptionForTest([SpeedRef]); + clock.Advance(TimeSpan.FromMilliseconds(850)); + drv.RaisePublishErrorForTest(StatusCodes.BadNoSubscription); + + lost.ShouldBeEmpty("the grace runs from the delete's completion, not its start"); + drv.GetHealth().State.ShouldBe(DriverState.Healthy); + } + + [Fact] + public async Task A_slow_alarm_delete_still_attributes_the_stale_error_to_the_delete() + { + var (drv, clock, lost, gate, started) = New(); + await using var _ = drv; + var first = drv.AddAlarmSubscriptionForTest([AlarmRef]); + + var unsub = drv.UnsubscribeAlarmsAsync(first, TestContext.Current.CancellationToken); + await started.Task.WaitAsync(TimeSpan.FromSeconds(10), TestContext.Current.CancellationToken); + clock.Advance(TimeSpan.FromSeconds(30)); + gate.SetResult(); + await unsub; + + drv.AddAlarmSubscriptionForTest([AlarmRef]); + clock.Advance(TimeSpan.FromMilliseconds(850)); + drv.RaisePublishErrorForTest(StatusCodes.BadNoSubscription); + + lost.ShouldBeEmpty("the grace runs from the delete's completion, not its start"); + drv.GetHealth().State.ShouldBe(DriverState.Healthy); + } + + /// Positive control: a slow delete does not extend the window beyond grace after completion. + [Fact] + public async Task After_a_slow_delete_completes_the_grace_still_expires() + { + var (drv, clock, lost, gate, started) = New(); + await using var _ = drv; + var first = drv.AddSubscriptionForTest([SpeedRef]); + + var unsub = drv.UnsubscribeAsync(first, TestContext.Current.CancellationToken); + await started.Task.WaitAsync(TimeSpan.FromSeconds(10), TestContext.Current.CancellationToken); + clock.Advance(TimeSpan.FromSeconds(30)); + gate.SetResult(); + await unsub; + + drv.AddSubscriptionForTest([SpeedRef]); + clock.Advance(OpcUaClientDriver.StaleNoSubscriptionGrace); + drv.RaisePublishErrorForTest(StatusCodes.BadNoSubscription); + + lost.ShouldHaveSingleItem().Reason.ShouldContain("subscription lost"); + } +}