From a5a0f96d49a71a5c2b5cb53bdf289db45f73b809 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Wed, 15 Jul 2026 07:35:17 -0400 Subject: [PATCH] fix(drivers): harden operator TimeoutMs handling + AbLegacy evict parity MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Follow-ups from the fleet-wide read-timeout audit that the S7 R2-01 read-leg fix (PR #453) prompted. The audit confirmed S7 was the ONLY driver with the async-read-ignores-socket-timeout hang; these are the two adjacent (non-hang) findings it surfaced. 1. FOCAS TimeoutMs:0 footgun (the risky one): a non-positive Timeout made SynchronizedFocasClient DISABLE its per-call wall-clock ceiling, reverting to the caller's long-lived poll token — reintroducing exactly the frozen-peer wedge S7 just eliminated, under misconfig. Clamp non-positive TimeoutMs to the 2s default at the config boundary so the deadline can never be authored away. 2. TimeoutMs validation symmetry: apply the same clamp in the AbCip + AbLegacy factories. libplctag's Tag.Timeout setter throws on <=0, faulting tag creation on every read/write; clamping keeps a misconfigured TimeoutMs:0 running on the default bound instead. (Shared PositiveTimeoutOrDefault helper per factory.) 3. AbLegacy reconnect parity with AbCip: AbLegacy evicted the cached libplctag runtime on neither the non-zero-status nor transport-exception read/write path (AbCip evicts on both), so a data-path fault recovered only via the probe loop / libplctag internals. Added EvictRuntime + wired it into both read and write failure paths so a fresh handle is created on the next call. Tests: FOCAS 265->269 (clamp theory + positive), AbCip 336->339 (clamp theory + positive), AbLegacy 209->212 (read-nonzero / read-exception / write-nonzero evict). No production regressions; all three driver suites green. --- .../AbCipDriverFactoryExtensions.cs | 18 ++- .../AbLegacyDriver.cs | 39 ++++++- .../AbLegacyDriverFactoryExtensions.cs | 18 ++- .../FocasDriverFactoryExtensions.cs | 18 ++- .../AbCipFactoryArrayTagTests.cs | 27 +++++ .../AbLegacyEvictOnFailureTests.cs | 109 ++++++++++++++++++ .../FocasFactoryConfigTests.cs | 34 ++++++ 7 files changed, 254 insertions(+), 9 deletions(-) create mode 100644 tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy.Tests/AbLegacyEvictOnFailureTests.cs diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip/AbCipDriverFactoryExtensions.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip/AbCipDriverFactoryExtensions.cs index 8ff8f366..5761cb95 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip/AbCipDriverFactoryExtensions.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip/AbCipDriverFactoryExtensions.cs @@ -75,10 +75,10 @@ public static class AbCipDriverFactoryExtensions { Enabled = dto.Probe?.Enabled ?? true, Interval = TimeSpan.FromMilliseconds(dto.Probe?.IntervalMs ?? 5_000), - Timeout = TimeSpan.FromMilliseconds(dto.Probe?.TimeoutMs ?? 2_000), + Timeout = PositiveTimeoutOrDefault(dto.Probe?.TimeoutMs, 2_000), ProbeTagPath = dto.Probe?.ProbeTagPath, }, - Timeout = TimeSpan.FromMilliseconds(dto.TimeoutMs ?? 2_000), + Timeout = PositiveTimeoutOrDefault(dto.TimeoutMs, 2_000), EnableControllerBrowse = dto.EnableControllerBrowse ?? false, EnableAlarmProjection = dto.EnableAlarmProjection ?? false, AlarmPollInterval = TimeSpan.FromMilliseconds(dto.AlarmPollIntervalMs ?? 1_000), @@ -86,6 +86,20 @@ public static class AbCipDriverFactoryExtensions }; } + /// + /// Maps an operator-supplied timeout (ms) to a positive , substituting + /// for a null / zero / negative value. libplctag's managed + /// Tag.Timeout setter throws for a + /// non-positive value, which would otherwise fault tag creation on every read/write; clamping + /// here keeps a misconfigured TimeoutMs: 0 running on the default bound instead. (Driver + /// timeout hardening, sibling of the S7 R2-01 read-leg fix.) + /// + /// The operator-supplied timeout in milliseconds, or null. + /// The default applied when is null or non-positive. + /// A strictly positive timeout. + private static TimeSpan PositiveTimeoutOrDefault(int? ms, int defaultMs) => + TimeSpan.FromMilliseconds(ms is int v and > 0 ? v : defaultMs); + private static AbCipTagDefinition BuildTag(AbCipTagDto t, string driverInstanceId) => new( Name: t.Name ?? throw new InvalidOperationException( diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriver.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriver.cs index b5f21f9c..5c7caf65 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriver.cs @@ -264,6 +264,8 @@ public sealed class AbLegacyDriver : IDriver, IReadable, IWritable, ITagDiscover if (status != 0) { + // Evict the stale handle so the next call re-creates it (mirrors AbCip). + EvictRuntime(device, def.Name); results[i] = new DataValueSnapshot(null, AbLegacyStatusMapper.MapLibplctagStatus(status), null, now); _health = new DriverHealth(DriverState.Degraded, _health.LastSuccessfulRead, @@ -287,6 +289,8 @@ public sealed class AbLegacyDriver : IDriver, IReadable, IWritable, ITagDiscover catch (OperationCanceledException) { throw; } catch (Exception ex) { + // Transport exception — evict so the next read creates a fresh handle (mirrors AbCip). + EvictRuntime(device, def.Name); results[i] = new DataValueSnapshot(null, AbLegacyStatusMapper.BadCommunicationError, null, now); _health = new DriverHealth(DriverState.Degraded, _health.LastSuccessfulRead, ex.Message); @@ -360,9 +364,16 @@ public sealed class AbLegacyDriver : IDriver, IReadable, IWritable, ITagDiscover opLock.Release(); } - results[i] = new WriteResult(status == 0 - ? AbLegacyStatusMapper.Good - : AbLegacyStatusMapper.MapLibplctagStatus(status)); + if (status != 0) + { + // Evict the stale handle so the next call re-creates it (mirrors AbCip). + EvictRuntime(device, def.Name); + results[i] = new WriteResult(AbLegacyStatusMapper.MapLibplctagStatus(status)); + } + else + { + results[i] = new WriteResult(AbLegacyStatusMapper.Good); + } } catch (OperationCanceledException) { throw; } catch (NotSupportedException nse) @@ -380,6 +391,8 @@ public sealed class AbLegacyDriver : IDriver, IReadable, IWritable, ITagDiscover } catch (Exception ex) { + // Transport exception — evict so the next write/read creates a fresh handle (mirrors AbCip). + EvictRuntime(device, def.Name); results[i] = new WriteResult(AbLegacyStatusMapper.BadCommunicationError); _health = new DriverHealth(DriverState.Degraded, _health.LastSuccessfulRead, ex.Message); } @@ -685,6 +698,26 @@ public sealed class AbLegacyDriver : IDriver, IReadable, IWritable, ITagDiscover } } + /// + /// Evict the runtime for from the device's cache and dispose it so + /// the next read/write call re-creates and re-initializes a fresh libplctag handle. Called + /// after a non-zero libplctag status or a transport exception on a read/write — a non-zero + /// status can mean the controller dropped the connection or the handle became permanently + /// invalid (e.g. after a PLC download), and reusing it would return the same failure forever. + /// Mirrors AbCipDriver.EvictRuntime and the probe loop's recreate-on-failure behaviour + /// (previously AbLegacy leaned only on the probe loop + libplctag's internal recovery, so a + /// data-path fault recovered more slowly than in AbCip). + /// + /// The device whose runtime cache holds the stale handle. + /// The tag name key of the runtime to evict. + private static void EvictRuntime(DeviceState device, string tagName) + { + if (device.Runtimes.TryRemove(tagName, out var stale)) + { + try { stale.Dispose(); } catch { /* best-effort */ } + } + } + /// /// Synchronous teardown. Mirrors the body of /// but never wraps the async path in diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriverFactoryExtensions.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriverFactoryExtensions.cs index eaf42dda..bd96cc71 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriverFactoryExtensions.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy/AbLegacyDriverFactoryExtensions.cs @@ -83,10 +83,10 @@ public static class AbLegacyDriverFactoryExtensions { Enabled = dto.Probe?.Enabled ?? true, Interval = TimeSpan.FromMilliseconds(dto.Probe?.IntervalMs ?? 5_000), - Timeout = TimeSpan.FromMilliseconds(dto.Probe?.TimeoutMs ?? 2_000), + Timeout = PositiveTimeoutOrDefault(dto.Probe?.TimeoutMs, 2_000), ProbeAddress = dto.Probe?.ProbeAddress ?? "S:0", }, - Timeout = TimeSpan.FromMilliseconds(dto.TimeoutMs ?? 2_000), + Timeout = PositiveTimeoutOrDefault(dto.TimeoutMs, 2_000), }; return new AbLegacyDriver( @@ -95,6 +95,20 @@ public static class AbLegacyDriverFactoryExtensions logger: loggerFactory?.CreateLogger()); } + /// + /// Maps an operator-supplied timeout (ms) to a positive , substituting + /// for a null / zero / negative value. libplctag's managed + /// Tag.Timeout setter throws for a + /// non-positive value, which would otherwise fault tag creation on every read/write; clamping + /// here keeps a misconfigured TimeoutMs: 0 running on the default bound instead. (Driver + /// timeout hardening, sibling of the S7 R2-01 read-leg fix.) + /// + /// The operator-supplied timeout in milliseconds, or null. + /// The default applied when is null or non-positive. + /// A strictly positive timeout. + private static TimeSpan PositiveTimeoutOrDefault(int? ms, int defaultMs) => + TimeSpan.FromMilliseconds(ms is int v and > 0 ? v : defaultMs); + private static T ParseEnum(string? raw, string driverInstanceId, string field, string? tagName = null, T? fallback = null) where T : struct, Enum { diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS/FocasDriverFactoryExtensions.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS/FocasDriverFactoryExtensions.cs index d8f90458..e878c7a1 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS/FocasDriverFactoryExtensions.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS/FocasDriverFactoryExtensions.cs @@ -84,9 +84,9 @@ public static class FocasDriverFactoryExtensions { Enabled = dto.Probe?.Enabled ?? true, Interval = TimeSpan.FromMilliseconds(dto.Probe?.IntervalMs ?? 5_000), - Timeout = TimeSpan.FromMilliseconds(dto.Probe?.TimeoutMs ?? 2_000), + Timeout = PositiveTimeoutOrDefault(dto.Probe?.TimeoutMs, 2_000), }, - Timeout = TimeSpan.FromMilliseconds(dto.TimeoutMs ?? 2_000), + Timeout = PositiveTimeoutOrDefault(dto.TimeoutMs, 2_000), FixedTree = BuildFixedTree(dto.FixedTree), AlarmProjection = BuildAlarmProjection(dto.AlarmProjection), HandleRecycle = BuildHandleRecycle(dto.HandleRecycle), @@ -96,6 +96,20 @@ public static class FocasDriverFactoryExtensions return new FocasDriver(options, driverInstanceId, clientFactory); } + /// + /// Maps an operator-supplied timeout (ms) to a positive , substituting + /// for a null / zero / negative value. A non-positive + /// Timeout would make DISABLE its per-call + /// wall-clock ceiling (falling back to the caller's long-lived poll token), reintroducing the + /// exact unbounded-read-on-a-frozen-peer wedge the S7 R2-01 read-leg fix eliminated. Clamping + /// here at the config boundary guarantees the deadline can never be authored away. + /// + /// The operator-supplied timeout in milliseconds, or null. + /// The default applied when is null or non-positive. + /// A strictly positive timeout. + private static TimeSpan PositiveTimeoutOrDefault(int? ms, int defaultMs) => + TimeSpan.FromMilliseconds(ms is int v and > 0 ? v : defaultMs); + /// /// Builds the appropriate based on the config DTO's backend selection. /// diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip.Tests/AbCipFactoryArrayTagTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip.Tests/AbCipFactoryArrayTagTests.cs index 92f0ca7a..bda261fc 100644 --- a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip.Tests/AbCipFactoryArrayTagTests.cs +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbCip.Tests/AbCipFactoryArrayTagTests.cs @@ -17,6 +17,33 @@ namespace ZB.MOM.WW.OtOpcUa.Driver.AbCip.Tests; [Trait("Category", "Unit")] public sealed class AbCipFactoryArrayTagTests { + /// + /// A non-positive TimeoutMs clamps to the 2 s default rather than reaching libplctag's + /// Tag.Timeout setter (which throws for a + /// non-positive value, faulting every read/write). Driver timeout hardening. + /// + [Theory] + [InlineData(0)] + [InlineData(-1)] + public void ParseOptions_clamps_non_positive_TimeoutMs_to_the_default(int timeoutMs) + { + var json = $$$"""{"TimeoutMs":{{{timeoutMs}}},"Probe":{"TimeoutMs":{{{timeoutMs}}}}}"""; + + var opts = AbCipDriverFactoryExtensions.ParseOptions("drv-1", json); + + opts.Timeout.ShouldBe(TimeSpan.FromMilliseconds(2_000)); + opts.Timeout.ShouldBeGreaterThan(TimeSpan.Zero); + opts.Probe.Timeout.ShouldBe(TimeSpan.FromMilliseconds(2_000)); + } + + /// A positive TimeoutMs is honoured verbatim. + [Fact] + public void ParseOptions_honours_a_positive_TimeoutMs() + { + var opts = AbCipDriverFactoryExtensions.ParseOptions("drv-1", """{"TimeoutMs":500}"""); + opts.Timeout.ShouldBe(TimeSpan.FromMilliseconds(500)); + } + /// A driver-config tag declaring isArray/elementCount produces an array definition. [Fact] public void ParseOptions_threads_isArray_and_elementCount_into_tag_definition() diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy.Tests/AbLegacyEvictOnFailureTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy.Tests/AbLegacyEvictOnFailureTests.cs new file mode 100644 index 00000000..fbc2850c --- /dev/null +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy.Tests/AbLegacyEvictOnFailureTests.cs @@ -0,0 +1,109 @@ +using libplctag; +using Shouldly; +using Xunit; +using ZB.MOM.WW.OtOpcUa.Core.Abstractions; +using ZB.MOM.WW.OtOpcUa.Driver.AbLegacy; + +namespace ZB.MOM.WW.OtOpcUa.Driver.AbLegacy.Tests; + +/// +/// Driver-timeout-hardening parity with AbCip: a read/write that fails with a non-zero libplctag +/// status or a transport exception must EVICT the cached runtime so the next call re-creates a +/// fresh handle — rather than returning the same failure forever until the probe loop happens to +/// recycle it. Previously AbLegacy evicted on neither path (unlike AbCip). +/// +[Trait("Category", "Unit")] +public sealed class AbLegacyEvictOnFailureTests +{ + private const string Device = "ab://10.0.0.5/1,0"; + + // Probe disabled — the probe loop also calls _tagFactory.Create, which would perturb the + // creation count these tests assert on. + private static (AbLegacyDriver drv, FakeAbLegacyTagFactory factory) NewDriver(params AbLegacyTagDefinition[] tags) + { + var factory = new FakeAbLegacyTagFactory(); + var drv = new AbLegacyDriver(new AbLegacyDriverOptions + { + Devices = [new AbLegacyDeviceOptions(Device)], + Tags = tags, + Probe = new AbLegacyProbeOptions { Enabled = false }, + }, "drv-1", factory); + return (drv, factory); + } + + /// A non-zero libplctag status on read evicts the runtime; the next read creates a fresh handle and recovers. + [Fact] + public async Task Read_nonzero_status_evicts_runtime_so_next_read_creates_fresh_handle() + { + var (drv, factory) = NewDriver( + new AbLegacyTagDefinition("Counter", Device, "N7:0", AbLegacyDataType.Int)); + var callCount = 0; + factory.Customise = p => + { + callCount++; + return callCount == 1 + ? new FakeAbLegacyTag(p) { Status = (int)Status.ErrorBadConnection } + : new FakeAbLegacyTag(p) { Status = 0, Value = 42 }; + }; + await drv.InitializeAsync("{}", CancellationToken.None); + + // First read — bad status → runtime evicted, no reuse. + var first = await drv.ReadAsync(["Counter"], CancellationToken.None); + first.Single().StatusCode.ShouldNotBe(AbLegacyStatusMapper.Good); + + // Second read — fresh handle, succeeds. + var second = await drv.ReadAsync(["Counter"], CancellationToken.None); + second.Single().StatusCode.ShouldBe(AbLegacyStatusMapper.Good); + second.Single().Value.ShouldBe(42); + callCount.ShouldBe(2); // one failed handle + one fresh handle + } + + /// A transport exception on read evicts the runtime; the next read creates a fresh handle and recovers. + [Fact] + public async Task Read_transport_exception_evicts_runtime_so_next_read_creates_fresh_handle() + { + var (drv, factory) = NewDriver( + new AbLegacyTagDefinition("Counter", Device, "N7:0", AbLegacyDataType.Int)); + var callCount = 0; + factory.Customise = p => + { + callCount++; + return callCount == 1 + ? new FakeAbLegacyTag(p) { ThrowOnRead = true, Exception = new System.Net.Sockets.SocketException() } + : new FakeAbLegacyTag(p) { Status = 0, Value = 7 }; + }; + await drv.InitializeAsync("{}", CancellationToken.None); + + var first = await drv.ReadAsync(["Counter"], CancellationToken.None); + first.Single().StatusCode.ShouldBe(AbLegacyStatusMapper.BadCommunicationError); + + var second = await drv.ReadAsync(["Counter"], CancellationToken.None); + second.Single().StatusCode.ShouldBe(AbLegacyStatusMapper.Good); + second.Single().Value.ShouldBe(7); + callCount.ShouldBe(2); + } + + /// A non-zero libplctag status on write evicts the runtime; the next write creates a fresh handle and recovers. + [Fact] + public async Task Write_nonzero_status_evicts_runtime_so_next_write_creates_fresh_handle() + { + var (drv, factory) = NewDriver( + new AbLegacyTagDefinition("Counter", Device, "N7:0", AbLegacyDataType.Int)); + var callCount = 0; + factory.Customise = p => + { + callCount++; + return callCount == 1 + ? new FakeAbLegacyTag(p) { Status = (int)Status.ErrorBadConnection } + : new FakeAbLegacyTag(p) { Status = 0 }; + }; + await drv.InitializeAsync("{}", CancellationToken.None); + + var first = await drv.WriteAsync([new WriteRequest("Counter", (short)5)], CancellationToken.None); + first.Single().StatusCode.ShouldNotBe(AbLegacyStatusMapper.Good); + + var second = await drv.WriteAsync([new WriteRequest("Counter", (short)5)], CancellationToken.None); + second.Single().StatusCode.ShouldBe(AbLegacyStatusMapper.Good); + callCount.ShouldBe(2); + } +} diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Tests/FocasFactoryConfigTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Tests/FocasFactoryConfigTests.cs index 852ab00d..b0dae0d0 100644 --- a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Tests/FocasFactoryConfigTests.cs +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Tests/FocasFactoryConfigTests.cs @@ -57,6 +57,40 @@ public sealed class FocasFactoryConfigTests drv.Options.Devices[0].Series.ShouldBe(FocasCncSeries.Thirty_i); } + // ---- Driver timeout hardening: a non-positive TimeoutMs must not disable the per-call ceiling ---- + + /// + /// A misconfigured TimeoutMs: 0 (or negative) must clamp to the 2 s default, NOT map to + /// — a zero/negative Timeout makes SynchronizedFocasClient + /// disable its per-call wall-clock ceiling, reintroducing the unbounded-read-on-a-frozen-peer + /// wedge the S7 R2-01 read-leg fix eliminated. Guards the factory clamp. + /// + [Theory] + [InlineData(0)] + [InlineData(-1)] + [InlineData(-5000)] + public void CreateInstance_clamps_non_positive_TimeoutMs_to_the_default(int timeoutMs) + { + var json = $$$"""{"Backend":"unimplemented","TimeoutMs":{{{timeoutMs}}},"Probe":{"TimeoutMs":{{{timeoutMs}}}}}"""; + + var drv = FocasDriverFactoryExtensions.CreateInstance("drv-1", json); + + drv.Options.Timeout.ShouldBe(TimeSpan.FromMilliseconds(2_000)); + drv.Options.Timeout.ShouldBeGreaterThan(TimeSpan.Zero); + drv.Options.Probe.Timeout.ShouldBe(TimeSpan.FromMilliseconds(2_000)); + } + + /// A positive TimeoutMs is honoured verbatim (the clamp only rewrites non-positive values). + [Fact] + public void CreateInstance_honours_a_positive_TimeoutMs() + { + const string json = """{"Backend":"unimplemented","TimeoutMs":750}"""; + + var drv = FocasDriverFactoryExtensions.CreateInstance("drv-1", json); + + drv.Options.Timeout.ShouldBe(TimeSpan.FromMilliseconds(750)); + } + /// Verifies that the AlarmProjection configuration section is mapped to driver options. [Fact] public void CreateInstance_maps_AlarmProjection_section_onto_options()