From 88e0977ae6c6ade5469f4be98b2e32e84c54a327 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Wed, 15 Jul 2026 07:11:42 -0400 Subject: [PATCH] fix(s7): bound async wire ops with a wall-clock deadline (R2-01 read leg) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The R2-01 live gate (S7_1500ConnectTimeoutOutageTests, docker-pause blackhole) surfaced a real gap the offline fakes couldn't: S7.Net's ReadTimeout/WriteTimeout map to the TcpClient's ReceiveTimeout/SendTimeout, which govern only SYNCHRONOUS socket calls — the async read/write paths S7.Net uses ignore them. On an established-but-frozen peer (frozen PLC / firewall DROP / cable pulled mid-flow, TCP session still open) a read blocked until the OS TCP stack gave up (minutes), silently wedging the poll loop: no Bad tick, no reconnect. STAB-14 fixed only the CONNECT leg (EnsureConnectedAsync CancelAfter); this is its READ-leg sibling. - New S7OperationDeadline: bounds every data-plane wire op with a wall-clock ceiling (= _options.Timeout), surfacing an overrun as TimeoutException. Applied in S7PlcAdapter to Read/ReadBytes/Write/WriteBytes/ReadStatus. OpenAsync is left to EnsureConnectedAsync's own CancelAfter (not double-bounded). - IsS7ConnectionFatal now classifies TimeoutException fatal → handle marked dead → next EnsureConnectedAsync reopens (connect-timeout fix takes over from there). - Tests: 5 S7OperationDeadline unit tests (deadline / token-honouring / caller- cancel-passthrough / resultless), 1 driver-reaction test (read TimeoutException → reopen). Driver.S7.Tests 260/260. - Live gate S7_1500ConnectTimeoutOutageTests now GREEN against the real snap7 sim (8s: baseline Good -> pause blackhole -> Bad tick -> unpause -> recovered Good). --- .../ZB.MOM.WW.OtOpcUa.Driver.S7/IS7Plc.cs | 27 ++++-- .../ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs | 11 ++- .../S7OperationDeadline.cs | 80 ++++++++++++++++ .../S7DriverReconnectTests.cs | 34 +++++++ .../S7OperationDeadlineTests.cs | 95 +++++++++++++++++++ 5 files changed, 239 insertions(+), 8 deletions(-) create mode 100644 src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7OperationDeadline.cs create mode 100644 tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7OperationDeadlineTests.cs diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/IS7Plc.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/IS7Plc.cs index 8707a9a1..ca367d95 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/IS7Plc.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/IS7Plc.cs @@ -87,6 +87,7 @@ public interface IS7PlcFactory internal sealed class S7PlcAdapter : IS7Plc { private readonly Plc _plc; + private readonly TimeSpan _operationTimeout; /// Initializes a new instance of the class. /// The CPU family. @@ -98,9 +99,14 @@ internal sealed class S7PlcAdapter : IS7Plc public S7PlcAdapter(S7CpuType cpuType, string host, int port, short rack, short slot, TimeSpan timeout) { _plc = new Plc(S7CpuTypeMap.ToS7Net(cpuType), host, port, rack, slot); + _operationTimeout = timeout; // S7netplus writes timeouts into the underlying TcpClient via ReadTimeout / WriteTimeout // (milliseconds). Set before OpenAsync so the handshake itself honours the bound — matches - // the original inline construction in S7Driver.InitializeAsync. + // the original inline construction in S7Driver.InitializeAsync. NOTE: these map to the + // TcpClient's ReceiveTimeout / SendTimeout, which govern only SYNCHRONOUS socket calls; the + // async read/write paths S7.Net actually uses ignore them, so every data-plane op below is + // additionally bounded by S7OperationDeadline (a real wall-clock ceiling). OpenAsync is left + // to S7Driver.EnsureConnectedAsync's own CancelAfter, so it is not double-bounded here. var ms = (int)timeout.TotalMilliseconds; _plc.ReadTimeout = ms; _plc.WriteTimeout = ms; @@ -117,23 +123,30 @@ internal sealed class S7PlcAdapter : IS7Plc /// public Task ReadAsync(string address, CancellationToken cancellationToken) => - _plc.ReadAsync(address, cancellationToken)!; + S7OperationDeadline.RunAsync( + t => _plc.ReadAsync(address, t)!, _operationTimeout, $"read of '{address}'", cancellationToken); /// public Task ReadBytesAsync(S7NetDataType area, int db, int startByteAdr, int count, CancellationToken cancellationToken) => - _plc.ReadBytesAsync(area, db, startByteAdr, count, cancellationToken); + S7OperationDeadline.RunAsync( + t => _plc.ReadBytesAsync(area, db, startByteAdr, count, t), + _operationTimeout, $"block read of {area} db{db} @{startByteAdr}+{count}", cancellationToken); /// public Task WriteAsync(string address, object value, CancellationToken cancellationToken) => - _plc.WriteAsync(address, value, cancellationToken); + S7OperationDeadline.RunAsync( + t => _plc.WriteAsync(address, value, t), _operationTimeout, $"write of '{address}'", cancellationToken); /// public Task WriteBytesAsync(S7NetDataType area, int db, int startByteAdr, byte[] value, CancellationToken cancellationToken) => - _plc.WriteBytesAsync(area, db, startByteAdr, value, cancellationToken); + S7OperationDeadline.RunAsync( + t => _plc.WriteBytesAsync(area, db, startByteAdr, value, t), + _operationTimeout, $"block write of {area} db{db} @{startByteAdr}", cancellationToken); /// - public async Task ReadStatusAsync(CancellationToken cancellationToken) => - _ = await _plc.ReadStatusAsync(cancellationToken).ConfigureAwait(false); + public Task ReadStatusAsync(CancellationToken cancellationToken) => + S7OperationDeadline.RunAsync( + t => _plc.ReadStatusAsync(t), _operationTimeout, "status read", cancellationToken); /// // Plc implements IDisposable explicitly, so cast to invoke it; disposal tears down the TcpClient. diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs index 829d28d8..476fc283 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs @@ -1287,7 +1287,9 @@ public sealed class S7Driver /// True when (or any inner exception) is a socket-level / connection /// loss OR an ISO-on-TCP framing/desync fault that a reopen can repair — a /// / / - /// ; an S7.Net framing violation + /// ; a from a wire op that + /// blew its wall-clock ceiling (an unresponsive but still + /// TCP-established peer — the READ-leg sibling of the connect-timeout fix, STAB-14); an S7.Net framing violation /// ( / / /// ); or a carrying /// or . @@ -1314,6 +1316,13 @@ public sealed class S7Driver { if (e is System.Net.Sockets.SocketException or System.IO.IOException or ObjectDisposedException) return true; + // A wire op that blew its wall-clock deadline (S7OperationDeadline — the async read/write + // ceiling S7.Net's ignored socket ReadTimeout/WriteTimeout can't provide) means the + // connection is unresponsive: discard + reopen. This is the READ-leg sibling of the + // connect-timeout fix (STAB-14) — without it a frozen-but-established peer wedges the + // poll loop forever instead of surfacing Bad + reconnecting. + if (e is TimeoutException) + return true; // ISO-on-TCP framing/desync surface (STAB-15a): the stream position is untrustworthy — // a half-read PDU left by a timeout/cancellation makes every later response mis-frame. // NOTE: deliberately NOT System.IO.InvalidDataException — ReinterpretRawValue throws it diff --git a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7OperationDeadline.cs b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7OperationDeadline.cs new file mode 100644 index 00000000..de1e4b53 --- /dev/null +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7OperationDeadline.cs @@ -0,0 +1,80 @@ +namespace ZB.MOM.WW.OtOpcUa.Driver.S7; + +/// +/// Bounds a single S7 wire operation with a wall-clock deadline, surfacing an overrun as a +/// . +/// +/// +/// +/// S7.Net's ReadTimeout / WriteTimeout set the underlying +/// 's ReceiveTimeout / SendTimeout, +/// which govern only synchronous socket calls — the async read/write paths +/// S7.Net actually uses ignore them entirely. Without an explicit ceiling, a read on an +/// established-but-frozen connection (a frozen PLC, a firewall DROP, or a cable pulled +/// mid-flow — where the TCP session stays open but no reply ever arrives) blocks until +/// the OS TCP stack gives up, which can be minutes. That silently wedges the driver's poll +/// loop: no Bad tick, no reconnect — the STAB-14 "silently killed poll loop" failure, on the +/// READ leg that the connect-timeout fix (S7Driver.EnsureConnectedAsync's +/// CancelAfter) never covered. +/// +/// +/// The timed-out operation surfaces as a , which +/// S7Driver.IsS7ConnectionFatal classifies connection-fatal → the handle is marked +/// dead → the next EnsureConnectedAsync reopens. The end-to-end proof is the live gate +/// S7_1500ConnectTimeoutOutageTests (a real snap7 sim frozen with docker pause). +/// +/// +internal static class S7OperationDeadline +{ + /// Runs under a wall-clock ceiling. + /// The operation result type. + /// The wire operation; receives a token cancelled at the deadline. + /// The wall-clock ceiling for the operation. + /// A short description of the operation for the timeout message (e.g. read of 'DB1.DBW0'). + /// The caller's cancellation token — its cancellation propagates as an , not a timeout. + /// The operation result when it completes within the deadline. + /// The operation did not complete within . + public static async Task RunAsync( + Func> operation, TimeSpan timeout, string what, CancellationToken ct) + { + ArgumentNullException.ThrowIfNull(operation); + using var opCts = CancellationTokenSource.CreateLinkedTokenSource(ct); + opCts.CancelAfter(timeout); + try + { + // WaitAsync guarantees control returns at the deadline even if the underlying op ignores + // its token; passing opCts.Token additionally lets an op that DOES honour cancellation + // unwind cleanly instead of leaking a wedged socket read behind an abandoned task. + return await operation(opCts.Token).WaitAsync(timeout, ct).ConfigureAwait(false); + } + catch (TimeoutException) + { + // WaitAsync's own deadline fired (the op ignored the token). + throw new TimeoutException(FormatMessage(what, timeout)); + } + catch (OperationCanceledException) when (opCts.IsCancellationRequested && !ct.IsCancellationRequested) + { + // OUR deadline fired and the op honoured opCts.Token — not the caller's cancellation. + throw new TimeoutException(FormatMessage(what, timeout)); + } + } + + /// Runs a result-less under a wall-clock ceiling. + /// The wire operation; receives a token cancelled at the deadline. + /// The wall-clock ceiling for the operation. + /// A short description of the operation for the timeout message. + /// The caller's cancellation token. + /// A task that completes when the operation completes within the deadline. + /// The operation did not complete within . + public static Task RunAsync( + Func operation, TimeSpan timeout, string what, CancellationToken ct) + { + ArgumentNullException.ThrowIfNull(operation); + return RunAsync( + async token => { await operation(token).ConfigureAwait(false); return true; }, + timeout, what, ct); + } + + private static string FormatMessage(string what, TimeSpan timeout) => + $"S7 {what} did not complete within {(int)timeout.TotalMilliseconds} ms."; +} diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7DriverReconnectTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7DriverReconnectTests.cs index c9372b3c..989d5f22 100644 --- a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7DriverReconnectTests.cs +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7DriverReconnectTests.cs @@ -63,6 +63,40 @@ public sealed class S7DriverReconnectTests factory.Created[1].Disposed.ShouldBeFalse(); } + /// + /// R2-01 read-leg gate. A — what S7OperationDeadline + /// raises when a wire read blows its wall-clock ceiling on an established-but-frozen peer + /// (the async read S7.Net's ignored socket ReadTimeout can't bound) — is classified + /// connection-fatal: the handle is marked dead and the NEXT read reopens a fresh connection, + /// exactly like a socket drop. Before the fix a read-timeout was NOT fatal, so the wedged + /// handle was reused and the poll loop never recovered (Created.Count pinned at 1). + /// + [Fact] + public async Task Read_reopens_after_a_wire_operation_timeout() + { + var factory = new FakeS7PlcFactory(); + using var drv = new S7Driver(Options(), "s7-read-timeout-fatal", factory); + await drv.InitializeAsync("{}", TestContext.Current.CancellationToken); + factory.Created.Count.ShouldBe(1); + + // The next read blows its deadline — surfaces as a TimeoutException, the shape + // S7OperationDeadline raises for a frozen-but-established peer. + factory.Created[0].NextReadThrows = new TimeoutException("S7 read of 'DB1.DBW0' did not complete within 250 ms."); + + // Read #1 — timeout → Degraded, handle marked dead, no reopen yet. + var bad = await drv.ReadAsync(["W0"], TestContext.Current.CancellationToken); + bad[0].StatusCode.ShouldNotBe(0u); + drv.GetHealth().State.ShouldBe(DriverState.Degraded); + factory.Created.Count.ShouldBe(1); + + // Read #2 — disposes the dead handle, opens a SECOND connection, reads Good, recovers. + var recovered = await drv.ReadAsync(["W0"], TestContext.Current.CancellationToken); + recovered[0].StatusCode.ShouldBe(0u); + drv.GetHealth().State.ShouldBe(DriverState.Healthy); + factory.Created.Count.ShouldBe(2); + factory.Created[0].Disposed.ShouldBeTrue(); + } + /// /// A protocol / data-address error (S7.Net ) is NOT a /// connection loss — the driver keeps the same connection and does not churn a reopen. diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7OperationDeadlineTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7OperationDeadlineTests.cs new file mode 100644 index 00000000..6e787c61 --- /dev/null +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7OperationDeadlineTests.cs @@ -0,0 +1,95 @@ +using System.Diagnostics; +using Shouldly; +using Xunit; + +namespace ZB.MOM.WW.OtOpcUa.Driver.S7.Tests; + +/// +/// Unit tests for — the wall-clock ceiling that bounds every +/// S7 async wire op (R2-01 read-leg gate). Async S7.Net reads/writes ignore the socket +/// ReadTimeout/WriteTimeout, so a frozen-but-established peer would otherwise block for minutes; +/// these pin the deadline behaviour without a live PLC. +/// +[Trait("Category", "Unit")] +public sealed class S7OperationDeadlineTests +{ + private static readonly TimeSpan ShortTimeout = TimeSpan.FromMilliseconds(150); + + /// An operation that completes within the deadline returns its value untouched. + [Fact] + public async Task Completes_within_deadline_returns_value() + { + var result = await S7OperationDeadline.RunAsync( + _ => Task.FromResult(42), ShortTimeout, "read", TestContext.Current.CancellationToken); + result.ShouldBe(42); + } + + /// + /// An operation that ignores its token and never completes is cut at the deadline and + /// surfaces a — the frozen-established-peer shape. Uses a bare + /// that never completes, so the token is genuinely ignored. + /// + [Fact] + public async Task Token_ignoring_hang_times_out() + { + var neverCompletes = new TaskCompletionSource().Task; + var sw = Stopwatch.StartNew(); + + var ex = await Should.ThrowAsync(async () => + await S7OperationDeadline.RunAsync( + _ => neverCompletes, ShortTimeout, "read of 'DB1.DBW0'", TestContext.Current.CancellationToken)); + + sw.Elapsed.ShouldBeLessThan(TimeSpan.FromSeconds(5)); + ex.Message.ShouldContain("did not complete within 150 ms"); + } + + /// + /// An operation that honours its token (the well-behaved async-read case) is cancelled at the + /// deadline; the resulting cancellation is normalised to a , + /// NOT surfaced as an . + /// + [Fact] + public async Task Token_honouring_hang_times_out_as_timeout_not_cancel() + { + await Should.ThrowAsync(async () => + await S7OperationDeadline.RunAsync( + async token => + { + await Task.Delay(Timeout.Infinite, token); + return 0; + }, + ShortTimeout, "read", TestContext.Current.CancellationToken)); + } + + /// + /// Caller cancellation (as opposed to the deadline firing) propagates as an + /// — the deadline wrapper must not swallow genuine + /// cancellation into a timeout. + /// + [Fact] + public async Task Caller_cancellation_propagates_as_operation_cancelled() + { + using var cts = new CancellationTokenSource(); + cts.CancelAfter(50); + + // A long deadline so the CALLER token fires first, not the internal deadline. + await Should.ThrowAsync(async () => + await S7OperationDeadline.RunAsync( + async token => + { + await Task.Delay(Timeout.Infinite, token); + return 0; + }, + TimeSpan.FromSeconds(30), "read", cts.Token)); + } + + /// The result-less overload also bounds a hang and surfaces a . + [Fact] + public async Task Resultless_overload_times_out() + { + var neverCompletes = new TaskCompletionSource().Task; + await Should.ThrowAsync(async () => + await S7OperationDeadline.RunAsync( + _ => neverCompletes, ShortTimeout, "write of 'DB1.DBW0'", TestContext.Current.CancellationToken)); + } +} -- 2.52.0