diff --git a/docs/drivers/OpcUaClient.md b/docs/drivers/OpcUaClient.md index fd7014681..b2914dace 100644 --- a/docs/drivers/OpcUaClient.md +++ b/docs/drivers/OpcUaClient.md @@ -75,7 +75,10 @@ measurements; they are not fresh SDK 2.0.1 interoperability evidence. `EndpointUrls` (a list) takes precedence over the single-URL `EndpointUrl` and provides ordered **failover** — the driver tries each candidate in turn at every `InitializeAsync` (including the comms-loss watchdog's re-initialise), and the first to connect wins (e.g. a hot-standby pair on -4840 / 4841). See +4840 / 4841). Each candidate gets `PerEndpointConnectTimeout` (default 3 s) for discovery + secure channel + session. That +budget includes **client-side** work (certificate load/validation, the asymmetric handshake), so a cold process on a busy +host can exceed it against a healthy server; an expiry is reported as `TimeoutException: … PerEndpointConnectTimeout (3 s)` +(#910 — the SDK alone says `BadRequestInterrupted`, which reads like a server fault). See `src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.Contracts/OpcUaClientDriverOptions.cs` for every field (security policy/mode, auth type, session timeout, keep-alive, browse root, node/depth caps). `ReconnectPeriod` was **deleted** (#676 — unused since #670 removed the SDK reconnect 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 acba83198..4635e95fd 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient/OpcUaClientDriver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient/OpcUaClientDriver.cs @@ -1053,8 +1053,33 @@ public sealed class OpcUaClientDriver : IDriver, ITagDiscovery, IReadable, IWrit using var cts = CancellationTokenSource.CreateLinkedTokenSource(ct); cts.CancelAfter(_options.PerEndpointConnectTimeout); + try + { + return await OpenSessionWithinBudgetAsync(appConfig, endpointUrl, policy, mode, identity, cts.Token) + .ConfigureAwait(false); + } + catch (Exception ex) when (cts.IsCancellationRequested && !ct.IsCancellationRequested) + { + // Gitea #910: the SDK reports a wait cut short by this budget as BadRequestInterrupted (or a bare + // TaskCanceledException), which reads like a server or network fault. Name the budget instead. It also + // covers CLIENT-side work (loading the application certificate, validating the server's, the asymmetric + // crypto of OpenSecureChannel), so a cold process on a busy host can exceed it with a healthy server. + throw new TimeoutException( + "The connect did not complete within PerEndpointConnectTimeout " + + $"({_options.PerEndpointConnectTimeout.TotalSeconds:0.###} s); the SDK reported: {ex.Message}", ex); + } + } + + private async Task OpenSessionWithinBudgetAsync( + ApplicationConfiguration appConfig, + string endpointUrl, + OpcUaSecurityPolicy policy, + OpcUaSecurityMode mode, + UserIdentity identity, + CancellationToken budget) + { var selected = await SelectMatchingEndpointAsync( - appConfig, endpointUrl, policy, mode, cts.Token).ConfigureAwait(false); + appConfig, endpointUrl, policy, mode, budget).ConfigureAwait(false); var endpointConfig = EndpointConfiguration.Create(appConfig); endpointConfig.OperationTimeout = (int)_options.Timeout.TotalMilliseconds; var endpoint = new ConfiguredEndpoint(null, selected, endpointConfig); @@ -1073,7 +1098,7 @@ public sealed class OpcUaClientDriver : IDriver, ITagDiscovery, IReadable, IWrit (uint)_options.SessionTimeout.TotalMilliseconds, identity, default, // preferredLocales - cts.Token).ConfigureAwait(false); + budget).ConfigureAwait(false); session.KeepAliveInterval = (int)_options.KeepAliveInterval.TotalMilliseconds; return session; diff --git a/tests/Core/ZB.MOM.WW.OtOpcUa.Core.ScriptedAlarms.Tests/ScriptedAlarmEngineRunGuardTests.cs b/tests/Core/ZB.MOM.WW.OtOpcUa.Core.ScriptedAlarms.Tests/ScriptedAlarmEngineRunGuardTests.cs index 3e472fe1a..cd2264cb7 100644 --- a/tests/Core/ZB.MOM.WW.OtOpcUa.Core.ScriptedAlarms.Tests/ScriptedAlarmEngineRunGuardTests.cs +++ b/tests/Core/ZB.MOM.WW.OtOpcUa.Core.ScriptedAlarms.Tests/ScriptedAlarmEngineRunGuardTests.cs @@ -45,9 +45,13 @@ public sealed class ScriptedAlarmEngineRunGuardTests eng.OnEvent += (_, e) => { lock (events) events.Add(e); }; // The load itself evaluates once (startup recovery) — that is the first, abandoned run. + // The healthy predicate deliberately spins ~100 ms (well inside the 500 ms budget) so every run of it + // is observably in flight for a while. That keeps the #911 window open on EVERY run of this test + // instead of only under CPU load: the guard counts a run on StartedRunCount AND InFlightCount the + // moment it is admitted, but releases InFlightCount only when the run finishes. await eng.LoadAsync( [Alarm("runaway", $"var t = ctx.GetTag(\"Temp\"); {SpinPredicate}"), - Alarm("healthy", """return (int)ctx.GetTag("Temp").Value > 100;""")], + Alarm("healthy", $$"""{{HealthySpin}} return (int)ctx.GetTag("Temp").Value > 100;""")], TestContext.Current.CancellationToken); // N more pushes while the orphan runs: every one is refused (a refusal is not a strike — I1), and @@ -59,24 +63,41 @@ public sealed class ScriptedAlarmEngineRunGuardTests var expected = i + 1; await WaitForAsync(() => eng.RunGuard.RefusedWhileRunningCount >= expected); } - await WaitForAsync(() => eng.RunGuard.StartedRunCount >= 1 + 1 + pushes); + + // #911: wait for the sibling's last run to FINISH, not merely to start. StartedRunCount reaching 6 only + // proves the healthy alarm's 4th-push run was admitted — it is still executing (InFlightCount 2: the + // orphan plus that run) until its finally releases the slot. Waiting on the started count and then + // asserting the in-flight count was the race. + await WaitForAsync(() => eng.RunGuard.StartedRunCount >= 1 + 1 + pushes && eng.RunGuard.InFlightCount == 1); eng.RunGuard.IsQuarantined("runaway", out _).ShouldBeFalse("refusals are not strikes"); eng.RunGuard.StartedRunCount.ShouldBe(1 + 1 + pushes, "one dispatch for the runaway alarm, one per evaluation for the healthy one"); - eng.RunGuard.InFlightCount.ShouldBe(1); - - // The frozen condition is annotated Bad out of band — the operator sees WHY it is not moving — - // exactly once across the whole run of non-completions. - ScriptedAlarmEvent[] snapshot; - lock (events) snapshot = events.ToArray(); - var quality = snapshot.Where(e => e.AlarmId == "runaway" && e.Emission == EmissionKind.QualityChanged).ToArray(); - quality.Length.ShouldBe(1); - quality[0].WorstInputStatusCode.ShouldBe(StatusBadInternalError); + eng.RunGuard.InFlightCount.ShouldBe(1, "exactly one orphan, never one per push"); eng.GetState("runaway")!.Active.ShouldBe(AlarmActiveState.Inactive, "state is held, never invented"); - // Positive control: the healthy sibling still transitions on the same engine. + // Positive control: the healthy sibling still transitions on the same engine. The same push re-evaluates + // the runaway alarm too, and it must be refused once more — proving the single in-flight run counted + // above is the runaway's orphan (still holding its slot), not a leftover healthy run. up.Push("Temp", 150); - await WaitForAsync(() => eng.GetState("healthy")!.Active == AlarmActiveState.Active); + await WaitForAsync(() => SnapshotOf(events).Any(e => e.AlarmId == "healthy" && e.Emission == EmissionKind.Activated)); + eng.RunGuard.RefusedWhileRunningCount.ShouldBe(pushes + 1); + eng.RunGuard.StartedRunCount.ShouldBe(1 + 1 + pushes + 1, "only the healthy alarm was dispatched"); + + // The frozen condition is annotated Bad out of band — the operator sees WHY it is not moving — + // exactly once across the whole run of non-completions. Checked only AFTER the healthy Activated event + // arrived: the single drainer fires each pass's events in push order, so every earlier refusal's + // emissions have already been delivered and a per-push re-annotation could not still be in transit. + var quality = SnapshotOf(events).Where(e => e.AlarmId == "runaway" && e.Emission == EmissionKind.QualityChanged).ToArray(); + quality.Length.ShouldBe(1); + quality[0].WorstInputStatusCode.ShouldBe(StatusBadInternalError); + } + + private const string HealthySpin = + "var spinUntil = System.DateTime.UtcNow.AddMilliseconds(100); while (System.DateTime.UtcNow < spinUntil) { }"; + + private static ScriptedAlarmEvent[] SnapshotOf(List events) + { + lock (events) return events.ToArray(); } /// I3 — a QUARANTINED predicate is re-attempted on every push and refused before dispatch; the diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.IntegrationTests/ServerHostNameValidationTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.IntegrationTests/ServerHostNameValidationTests.cs index 6c84ec382..3a2eeaccb 100644 --- a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.IntegrationTests/ServerHostNameValidationTests.cs +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.IntegrationTests/ServerHostNameValidationTests.cs @@ -35,6 +35,12 @@ public sealed class ServerHostNameValidationTests(OpcPlcFixture sim) : IDisposab SecurityMode = OpcUaSecurityMode.SignAndEncrypt, AutoAcceptCertificates = false, CertificateValidation = new OpcUaCertificateValidationOptions { ValidateServerHostName = validateHostName }, + // Gitea #910: the default 3 s per-endpoint budget covers client-side work too — loading the fresh throwaway + // certificate, validating the server's, the first Basic256Sha256 handshake in a cold test process. The first + // test in this assembly (the validate:null case) paid that cold cost, and in the full-solution run it ran out: + // opc-plc answered OpenSecureChannel at once, but the client reached it only after 3 s of local work and + // cancelled 48 ms later (BadRequestInterrupted). What is under test is the host check, not connect latency. + PerEndpointConnectTimeout = TimeSpan.FromSeconds(15), }; /// Trust the fixture's server certificate (as advertised on its secure endpoint) in the throwaway PKI. diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.Tests/OpcUaClientFailoverTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.Tests/OpcUaClientFailoverTests.cs index 733fba179..0cc58552d 100644 --- a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.Tests/OpcUaClientFailoverTests.cs +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.OpcUaClient.Tests/OpcUaClientFailoverTests.cs @@ -83,4 +83,30 @@ public sealed class OpcUaClientFailoverTests ex.Message.ShouldContain("127.0.0.1:3"); drv.GetHealth().State.ShouldBe(DriverState.Faulted); } + + /// + /// Gitea #910: an endpoint that accepts TCP but never answers runs out the per-endpoint budget. The SDK reports + /// that as BadRequestInterrupted / a bare cancellation; the failover aggregate must name the budget instead. + /// + [Fact] + public async Task A_per_endpoint_budget_expiry_is_reported_as_that_budget() + { + using var silent = new System.Net.Sockets.TcpListener(System.Net.IPAddress.Loopback, 0); + silent.Start(); // accepts (kernel backlog) but never reads or replies + var port = ((System.Net.IPEndPoint)silent.LocalEndpoint).Port; + var opts = new OpcUaClientDriverOptions + { + EndpointUrl = $"opc.tcp://127.0.0.1:{port}", + PerEndpointConnectTimeout = TimeSpan.FromMilliseconds(400), + Timeout = TimeSpan.FromSeconds(30), + AutoAcceptCertificates = true, + }; + using var drv = new OpcUaClientDriver(opts, "opcua-budget"); + + var ex = await Should.ThrowAsync(async () => + await drv.InitializeAsync("{}", TestContext.Current.CancellationToken)); + + ex.Message.ShouldContain("TimeoutException"); + ex.Message.ShouldContain("PerEndpointConnectTimeout (0.4 s)"); + } }