fix(opcuaclient): unresolvable acks warn instead of tripping the ack breaker; shutdown holds subscription management (review r1 N-1, N-2, N-3)

- N-1 (Important): m3's BadNodeIdUnknown throw for an ack with no resolvable condition counted toward the host's AlarmAcknowledge breaker (threshold 5), so re-acks of one unresolvable condition blocked every genuine ack. It now logs a Warning and returns; only a no-reply transport failure throws. Test through the real CapabilityInvoker: six unresolvable acks, then a genuine ack that is still delivered (red with the throw restored). - N-2: ShutdownAsync holds _subscriptionGate for the whole teardown (in-flight subscribes finish first, bounded by the budget), so a subscribe arriving during the delete phase finds the session released instead of creating a subscription on the closing session. Red-tested. - N-3: the shutdown-side cert-validation detach is generation-checked under _probeLock with the map / endpoint clear. Refs #743 Claude-Session: https://claude.ai/code/session_01Ub9hGmYLQvn9XETzw7CMsT
2026-10-22 16:58:37 -04:00
parent 863a00c25d
commit c39bcd6e24
4 changed files with 155 additions and 23 deletions
@@ -104,8 +104,10 @@ The session keep-alive (`KeepAliveInterval`, default 5 s) is the liveness signal
  no health — including a write the host cancelled at its own write deadline against a hung upstream; the session
  keep-alive owns liveness and reports that outage itself. A reply that was in flight across a bad keep-alive advances
  the stamp but does not write `Healthy` while the outage is published — the keep-alive recovery ends the outage.
-  An ack none of whose condition ids resolves sends nothing and fails `BadNodeIdUnknown`; with no session an ack fails
-  `BadNotConnected` (before or inside the gate alike).
+  An ack none of whose condition ids resolves sends nothing and logs a Warning — it does **not** throw (a deterministic
+  per-ack refusal must not count toward the host's AlarmAcknowledge circuit breaker, or five re-acks of one
+  unresolvable condition would block every genuine ack). Only a call with no reply throws; with no session an ack
+  fails `BadNotConnected` (before or inside the gate alike).
 - **Bad keep-alive** ⇒ health `Degraded` (`LastError = "keep-alive: <status>"`, read stamp preserved), host status
  `Stopped`, and — **once per outage**, not per keep-alive — every subscribed ref is published `BadNoCommunication`
  with its last value retained and **source + server timestamp = the detection time** (live-gate F1: stamped with the
@@ -1234,6 +1234,34 @@ public sealed class OpcUaClientDriver : IDriver, ITagDiscovery, IReadable, IWrit
        using var budget = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken);
        budget.CancelAfter(TeardownBudget);

+        // r1 N-2: subscription management is held off for the whole teardown. A subscribe already in flight finishes
+        // first (bounded by the budget) and is enumerated below; one that arrives during the delete phase waits and
+        // then finds the session released, instead of registering a subscription on the closing session after the
+        // registry was enumerated. A wait the budget cut short proceeds without the gate (best effort).
+        var holdsSubscriptionGate = false;
+        try
+        {
+            await _subscriptionGate.WaitAsync(budget.Token).ConfigureAwait(false);
+            holdsSubscriptionGate = true;
+        }
+        catch (OperationCanceledException) { /* budget spent on an in-flight subscribe — tear down regardless */ }
+        catch (ObjectDisposedException) { /* disposed concurrently — tear down regardless */ }
+        try
+        {
+            await ShutdownCoreAsync(generation, budget).ConfigureAwait(false);
+        }
+        finally
+        {
+            if (holdsSubscriptionGate)
+            {
+                try { _subscriptionGate.Release(); } catch (ObjectDisposedException) { }
+            }
+        }
+    }
+
+    private async Task ShutdownCoreAsync(long generation, CancellationTokenSource budget)
+    {
+
        // Tear down remote subscriptions first — otherwise Session.Close will try and may fail
        // with BadSubscriptionIdInvalid noise in the upstream log. _subscriptions is cleared
        // whether or not the wire-side delete succeeds since the local handles are useless
@@ -1287,16 +1315,14 @@ public sealed class OpcUaClientDriver : IDriver, ITagDiscovery, IReadable, IWrit
            {
                _namespaceMap = null;
                _connectedEndpointUrl = null;
-            }
-        }

-        // Detach the cert-validation handler so the (potentially process-shared)
-        // CertificateValidator doesn't hold a delegate to a shutting-down driver.
-        if (_certValidationHandler is not null && _certValidatorRef is not null)
-        {
-            try { _certValidatorRef.CertificateValidation -= _certValidationHandler; } catch { }
-            _certValidationHandler = null;
-            _certValidatorRef = null;
+                // Detach the cert-validation handler so the (potentially process-shared) CertificateValidator doesn't
+                // hold a delegate to a shutting-down driver — generation-checked like the map (r1 N-3): a newer init
+                // that installed its own handler meanwhile keeps it.
+                DetachCertValidation(_certValidatorRef, _certValidationHandler);
+                _certValidationHandler = null;
+                _certValidatorRef = null;
+            }
        }

        if (Volatile.Read(ref _lifecycleGeneration) == generation) TransitionTo(HostState.Unknown);
@@ -2556,12 +2582,16 @@ public sealed class OpcUaClientDriver : IDriver, ITagDiscovery, IReadable, IWrit

            if (callRequests.Count == 0)
            {
-                // Review m3: nothing resolved to a condition node, so nothing was sent — that is not an applied ack.
+                // Review m3 / r1 N-1: nothing resolved to a condition node, so nothing was sent — say so at Warning. NOT
+                // thrown: this is a deterministic per-ack refusal, and a throw would count toward the host's
+                // AlarmAcknowledge circuit breaker (5 failures), so an operator re-acking an unresolvable condition
+                // would block every genuine ack on this driver. Only a no-reply transport failure throws (F2 owns a
+                // per-ack result surface).
                _logger.LogWarning(
                    "OpcUaClientDriver '{DriverInstanceId}': AcknowledgeAsync resolved none of {Count} condition id(s) " +
-                    "against the live session; nothing was sent upstream.", _driverInstanceId, acknowledgements.Count);
-                throw new ServiceResultException(StatusCodes.BadNodeIdUnknown,
-                    "None of the acknowledged condition ids resolved to an upstream condition node.");
+                    "against the live session; nothing was sent upstream and the acknowledgement was NOT applied.",
+                    _driverInstanceId, acknowledgements.Count);
+                return;
            }

            try
@@ -81,21 +81,81 @@ public sealed class OpcUaClientAcknowledgeFailureTests
        await Should.ThrowAsync<ServiceResultException>(() => call);
    }

-    /// <summary>Review m3: an ack none of whose condition ids resolves sent nothing upstream — that fails, it is not "applied".</summary>
-    [Fact]
-    public async Task An_ack_with_no_resolvable_condition_fails_with_BadNodeIdUnknown()
+    private sealed class ListLogger : Microsoft.Extensions.Logging.ILogger<OpcUaClientDriver>
    {
-        using var drv = new OpcUaClientDriver(new OpcUaClientDriverOptions(), "opcua-m3");
+        public List<(Microsoft.Extensions.Logging.LogLevel Level, string Message)> Entries { get; } = [];
+        public IDisposable? BeginScope<TState>(TState state) where TState : notnull => null;
+        public bool IsEnabled(Microsoft.Extensions.Logging.LogLevel logLevel) => true;
+        public void Log<TState>(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId,
+            TState state, Exception? exception, Func<TState, Exception?, string> formatter)
+        {
+            lock (Entries) Entries.Add((logLevel, formatter(state, exception)));
+        }
+    }
+
+    private static AlarmAcknowledgeRequest[] Unresolvable() =>
+        [new("nsu=urn:not-in-table;s=X", "nsu=urn:not-in-table;s=X", "ack")];
+
+    /// <summary>
+    ///     Review m3 / r1 N-1: an ack none of whose condition ids resolves sends nothing upstream and says so at Warning —
+    ///     but does NOT throw (a deterministic per-ack refusal must not count toward the AlarmAcknowledge breaker).
+    /// </summary>
+    [Fact]
+    public async Task An_ack_with_no_resolvable_condition_warns_and_does_not_throw()
+    {
+        var logger = new ListLogger();
+        using var drv = new OpcUaClientDriver(new OpcUaClientDriverOptions(), "opcua-m3", logger);
        var session = NewSession();
        drv.SetSessionForTest(session.Object);

-        var ex = await Should.ThrowAsync<ServiceResultException>(() => drv.AcknowledgeAsync(
-            [new AlarmAcknowledgeRequest("nsu=urn:not-in-table;s=X", "nsu=urn:not-in-table;s=X", "ack")],
-            TestContext.Current.CancellationToken));
+        await drv.AcknowledgeAsync(Unresolvable(), TestContext.Current.CancellationToken);

-        ex.StatusCode.ShouldBe(StatusCodes.BadNodeIdUnknown);
        session.Verify(s => s.CallAsync(It.IsAny<RequestHeader>(), It.IsAny<CallMethodRequestCollection>(), It.IsAny<CancellationToken>()),
            Times.Never);
+        lock (logger.Entries)
+            logger.Entries.ShouldContain(e => e.Level == Microsoft.Extensions.Logging.LogLevel.Warning && e.Message.Contains("resolved none"));
+    }
+
+    /// <summary>
+    ///     r1 N-1 through the host's real resilience pipeline: six unresolvable acks (more than the AlarmAcknowledge
+    ///     breaker's threshold of five) must not open the breaker — a genuine ack that follows is still delivered
+    ///     upstream (the positive control).
+    /// </summary>
+    [Fact]
+    public async Task Unresolvable_acks_do_not_open_the_ack_breaker_for_real_acks()
+    {
+        var ct = TestContext.Current.CancellationToken;
+        using var drv = new OpcUaClientDriver(new OpcUaClientDriverOptions(), "opcua-n1");
+        var session = NewSession();
+        session.Setup(s => s.CallAsync(It.IsAny<RequestHeader>(), It.IsAny<CallMethodRequestCollection>(), It.IsAny<CancellationToken>()))
+            .ReturnsAsync(new CallResponse
+            {
+                ResponseHeader = new ResponseHeader(),
+                Results = [new CallMethodResult { StatusCode = StatusCodes.Good }],
+                DiagnosticInfos = [],
+            });
+        drv.SetSessionForTest(session.Object);
+        var options = new ZB.MOM.WW.OtOpcUa.Core.Resilience.DriverResilienceOptions { Tier = DriverTier.A };
+        var invoker = new ZB.MOM.WW.OtOpcUa.Core.Resilience.CapabilityInvoker(
+            new ZB.MOM.WW.OtOpcUa.Core.Resilience.DriverResiliencePipelineBuilder(), "opcua-n1", () => options, "OpcUaClient");
+
+        // Failures are tolerated here on purpose (the host logs and drops them): what is asserted is that the six do
+        // not trip the breaker — a driver that THREW for them would fail the genuine ack below with an open circuit.
+        for (var i = 0; i < 6; i++)
+        {
+            try
+            {
+                await invoker.ExecuteAsync(DriverCapability.AlarmAcknowledge, "host",
+                    async c => await drv.AcknowledgeAsync(Unresolvable(), c), ct);
+            }
+            catch (ServiceResultException) { }
+        }
+
+        await invoker.ExecuteAsync(DriverCapability.AlarmAcknowledge, "host",
+            async c => await drv.AcknowledgeAsync(Ack(), c), ct);
+
+        session.Verify(s => s.CallAsync(It.IsAny<RequestHeader>(), It.IsAny<CallMethodRequestCollection>(), It.IsAny<CancellationToken>()),
+            Times.Once, "the genuine ack must still reach the server");
    }

    /// <summary>Review m4: an ack with no reply is a comms fault like a read or write — Degraded, stamp preserved.</summary>
@@ -217,4 +217,44 @@ public sealed class OpcUaClientLifecycleGenerationTests
        while ((current = Volatile.Read(ref target)) < value)
            if (Interlocked.CompareExchange(ref target, value, current) == current) return;
    }
+
+    /// <summary>
+    ///     r1 N-2: a subscribe that arrives while shutdown is in its delete phase must not create a subscription on the
+    ///     closing session (it would register after the registry was enumerated and outlive the shutdown). It waits for
+    ///     the teardown and then finds no session. Positive control: before the shutdown the same subscribe reaches the
+    ///     session.
+    /// </summary>
+    [Fact]
+    public async Task A_subscribe_during_the_shutdown_delete_phase_never_touches_the_closing_session()
+    {
+        using var drv = new OpcUaClientDriver(Options(), "opcua-n2");
+        var session = NewSession();
+        drv.SetSessionForTest(session.Object);
+        drv.SetNamespaceMapForTest(NamespaceMap.FromTable(new NamespaceTable(), Tags));
+
+        // Positive control: an ordinary subscribe does reach the session (the mock then fails the create).
+        await Should.ThrowAsync<Exception>(() =>
+            drv.SubscribeAsync([SpeedRef], TimeSpan.FromSeconds(1), TestContext.Current.CancellationToken));
+        session.Verify(s => s.AddSubscription(It.IsAny<Subscription>()), Times.Once);
+
+        var deleting = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
+        var releaseDelete = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
+        drv.DeleteSubscriptionAsync = async (_, _) =>
+        {
+            deleting.TrySetResult();
+            await releaseDelete.Task;
+        };
+        drv.AddSubscriptionForTest([SpeedRef]);
+
+        var shutdown = drv.ShutdownAsync(TestContext.Current.CancellationToken);
+        await deleting.Task.WaitAsync(TimeSpan.FromSeconds(10), TestContext.Current.CancellationToken);
+
+        var lateSubscribe = drv.SubscribeAsync([SpeedRef], TimeSpan.FromSeconds(1), TestContext.Current.CancellationToken);
+        releaseDelete.SetResult();
+        await shutdown.WaitAsync(TimeSpan.FromSeconds(10), TestContext.Current.CancellationToken);
+        await Should.ThrowAsync<Exception>(() => lateSubscribe.WaitAsync(TimeSpan.FromSeconds(10), TestContext.Current.CancellationToken));
+
+        session.Verify(s => s.AddSubscription(It.IsAny<Subscription>()), Times.Once,
+            "the late subscribe must not have created anything on the closing session");
+    }
 }