fix(drivers): harden operator TimeoutMs handling + AbLegacy evict parity
v2-ci / build (pull_request) Successful in 4m5s
v2-ci / unit-tests (pull_request) Failing after 10m45s

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.
This commit is contained in:
Joseph Doherty
2026-07-15 07:35:17 -04:00
parent c21e21423f
commit a5a0f96d49
7 changed files with 254 additions and 9 deletions
@@ -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
};
}
/// <summary>
/// Maps an operator-supplied timeout (ms) to a positive <see cref="TimeSpan"/>, substituting
/// <paramref name="defaultMs"/> for a null / zero / negative value. libplctag's managed
/// <c>Tag.Timeout</c> setter throws <see cref="ArgumentOutOfRangeException"/> for a
/// non-positive value, which would otherwise fault tag creation on every read/write; clamping
/// here keeps a misconfigured <c>TimeoutMs: 0</c> running on the default bound instead. (Driver
/// timeout hardening, sibling of the S7 R2-01 read-leg fix.)
/// </summary>
/// <param name="ms">The operator-supplied timeout in milliseconds, or null.</param>
/// <param name="defaultMs">The default applied when <paramref name="ms"/> is null or non-positive.</param>
/// <returns>A strictly positive timeout.</returns>
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(
@@ -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
}
}
/// <summary>
/// Evict the runtime for <paramref name="tagName"/> 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 <c>AbCipDriver.EvictRuntime</c> 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).
/// </summary>
/// <param name="device">The device whose runtime cache holds the stale handle.</param>
/// <param name="tagName">The tag name key of the runtime to evict.</param>
private static void EvictRuntime(DeviceState device, string tagName)
{
if (device.Runtimes.TryRemove(tagName, out var stale))
{
try { stale.Dispose(); } catch { /* best-effort */ }
}
}
/// <summary>
/// Synchronous teardown. Mirrors the body of
/// <see cref="ShutdownAsync"/> but never wraps the async path in
@@ -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<AbLegacyDriver>());
}
/// <summary>
/// Maps an operator-supplied timeout (ms) to a positive <see cref="TimeSpan"/>, substituting
/// <paramref name="defaultMs"/> for a null / zero / negative value. libplctag's managed
/// <c>Tag.Timeout</c> setter throws <see cref="ArgumentOutOfRangeException"/> for a
/// non-positive value, which would otherwise fault tag creation on every read/write; clamping
/// here keeps a misconfigured <c>TimeoutMs: 0</c> running on the default bound instead. (Driver
/// timeout hardening, sibling of the S7 R2-01 read-leg fix.)
/// </summary>
/// <param name="ms">The operator-supplied timeout in milliseconds, or null.</param>
/// <param name="defaultMs">The default applied when <paramref name="ms"/> is null or non-positive.</param>
/// <returns>A strictly positive timeout.</returns>
private static TimeSpan PositiveTimeoutOrDefault(int? ms, int defaultMs) =>
TimeSpan.FromMilliseconds(ms is int v and > 0 ? v : defaultMs);
private static T ParseEnum<T>(string? raw, string driverInstanceId, string field,
string? tagName = null, T? fallback = null) where T : struct, Enum
{
@@ -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);
}
/// <summary>
/// Maps an operator-supplied timeout (ms) to a positive <see cref="TimeSpan"/>, substituting
/// <paramref name="defaultMs"/> for a null / zero / negative value. A non-positive
/// <c>Timeout</c> would make <see cref="SynchronizedFocasClient"/> 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.
/// </summary>
/// <param name="ms">The operator-supplied timeout in milliseconds, or null.</param>
/// <param name="defaultMs">The default applied when <paramref name="ms"/> is null or non-positive.</param>
/// <returns>A strictly positive timeout.</returns>
private static TimeSpan PositiveTimeoutOrDefault(int? ms, int defaultMs) =>
TimeSpan.FromMilliseconds(ms is int v and > 0 ? v : defaultMs);
/// <summary>
/// Builds the appropriate <see cref="IFocasClientFactory"/> based on the config DTO's backend selection.
/// </summary>
@@ -17,6 +17,33 @@ namespace ZB.MOM.WW.OtOpcUa.Driver.AbCip.Tests;
[Trait("Category", "Unit")]
public sealed class AbCipFactoryArrayTagTests
{
/// <summary>
/// A non-positive <c>TimeoutMs</c> clamps to the 2 s default rather than reaching libplctag's
/// <c>Tag.Timeout</c> setter (which throws <see cref="ArgumentOutOfRangeException"/> for a
/// non-positive value, faulting every read/write). Driver timeout hardening.
/// </summary>
[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));
}
/// <summary>A positive <c>TimeoutMs</c> is honoured verbatim.</summary>
[Fact]
public void ParseOptions_honours_a_positive_TimeoutMs()
{
var opts = AbCipDriverFactoryExtensions.ParseOptions("drv-1", """{"TimeoutMs":500}""");
opts.Timeout.ShouldBe(TimeSpan.FromMilliseconds(500));
}
/// <summary>A driver-config tag declaring isArray/elementCount produces an array definition.</summary>
[Fact]
public void ParseOptions_threads_isArray_and_elementCount_into_tag_definition()
@@ -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;
/// <summary>
/// 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).
/// </summary>
[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);
}
/// <summary>A non-zero libplctag status on read evicts the runtime; the next read creates a fresh handle and recovers.</summary>
[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
}
/// <summary>A transport exception on read evicts the runtime; the next read creates a fresh handle and recovers.</summary>
[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);
}
/// <summary>A non-zero libplctag status on write evicts the runtime; the next write creates a fresh handle and recovers.</summary>
[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);
}
}
@@ -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 ----
/// <summary>
/// A misconfigured <c>TimeoutMs: 0</c> (or negative) must clamp to the 2 s default, NOT map to
/// <see cref="TimeSpan.Zero"/> — a zero/negative <c>Timeout</c> makes <c>SynchronizedFocasClient</c>
/// 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.
/// </summary>
[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));
}
/// <summary>A positive <c>TimeoutMs</c> is honoured verbatim (the clamp only rewrites non-positive values).</summary>
[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));
}
/// <summary>Verifies that the AlarmProjection configuration section is mapped to driver options.</summary>
[Fact]
public void CreateInstance_maps_AlarmProjection_section_onto_options()