From 081fa693af80ae7ae57d1b586f81dcc194beaf56 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Thu, 22 Oct 2026 15:57:53 -0400 Subject: [PATCH] fix(s7): access-denied is an answer; review round-1 minors (R07:H4 follow-through) I-1: a PUT/GET-disabled CPU (every read denied) stayed Faulted with LastSuccessfulRead frozen, so the comms-loss watchdog reconnected and re-subscribed it every 90 s forever. Both access-denied arms now also record an answer: Faulted is kept (worst state wins), the stamp advances, and the sticky write fault still clears only on a real success. Pinned end to end in Runtime.Tests: the real S7Driver under the real DriverInstanceActor watchdog is not reconnected across 2x the threshold; the control (every read timing out) is. Minors: - m-1: injectable pass clock (UtcNow); "LastSuccessfulRead advanced" is now asserted strictly, including the write-refusal case. - m-2: the editor uses S7TagShapeRules.IsByteAnchored instead of its own list. - m-3: a release that races an init publish also cancels the probe loop the publish started after the release took its snapshot. - m-4: a retained poll failing during a lifecycle operation writes no health. - m-5: a multi-var chunk that fell back memoises its members refused alone. - m-7: access-denied needs S7.Net's exact wording and no transport fault in the chain. - m-8: sync teardown clears the write-side Degraded owner; a sync Dispose racing a running shutdown is tested. Refs #742 Claude-Session: https://claude.ai/code/session_01Ub9hGmYLQvn9XETzw7CMsT --- docs/drivers/S7.md | 8 +- .../ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs | 80 +++++++++-- .../Uns/TagEditors/S7TagConfigModel.cs | 5 +- .../S7_1500/S7_1500RefusalTests.cs | 4 +- .../S7LifecycleGateTests.cs | 63 ++++++++ .../S7RefusalHealthTests.cs | 134 +++++++++++++++--- .../S7SpanRefusalFallbackTests.cs | 52 +++++++ .../Drivers/S7AccessDeniedWatchdogTests.cs | 123 ++++++++++++++++ .../ZB.MOM.WW.OtOpcUa.Runtime.Tests.csproj | 3 + 9 files changed, 438 insertions(+), 34 deletions(-) create mode 100644 tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/Drivers/S7AccessDeniedWatchdogTests.cs diff --git a/docs/drivers/S7.md b/docs/drivers/S7.md index 889d08be..39788f8c 100644 --- a/docs/drivers/S7.md +++ b/docs/drivers/S7.md @@ -314,7 +314,7 @@ Portal under *Protection & Security* for the CPU. | Tag not in config | `BadNodeIdUnknown` | unchanged | | Read-only tag written | `BadNotWritable` | unchanged | | Unimplemented data type | `BadNotSupported` | unchanged | -| PUT/GET denied | `BadNotSupported` | `Faulted` (config alert) | +| PUT/GET denied | `BadNotSupported` | `Faulted` (config alert) — also counts as *answered*, advances `LastSuccessfulRead` (no watchdog reconnect loop) | | CPU refusal of the item (object does not exist, address out of range, type inconsistent, hardware fault) | `BadDeviceFailure` | unchanged — counts as *answered*, advances `LastSuccessfulRead`; one Warning per tag | | Other device-layer fault (`PlcException` that is neither a refusal nor connection-fatal) | `BadDeviceFailure` | `Degraded` | | Socket / timeout | `BadCommunicationError` | `Degraded` | @@ -333,7 +333,11 @@ answers without a failure. **A refusal is an answer (R07:H4).** S7.Net's read paths raise the CPU's item error as a bare `Exception` ("Received error from PLC: Object does not exist." — live-probed on the snap7 fixture), its write paths as a `PlcException(WriteData)`; both are classified over the whole exception chain, and the -access-denied text inside either is the `Faulted` alert. A refusal is deterministic, so it neither +access-denied text inside either (S7.Net's exact "Accessing object not allowed", and never when the chain +also carries a transport fault) is the `Faulted` alert — which is ALSO an answer: it advances +`LastSuccessfulRead`, so a factory-default CPU with PUT/GET disabled stays `Faulted` instead of being +reconnected by the comms-loss watchdog every 90 s. A multi-var chunk that falls back per tag memoises the +members refused on their own, like a refused span. A refusal is deterministic, so it neither degrades health nor reopens the connection, and because it proves the CPU is reachable it advances `LastSuccessfulRead` and restores `Healthy` after an earlier comms fault. Before this, a driver whose every tag was refused (a wrong DB number) sat `Degraded` with a frozen timestamp and the comms-loss 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 9f0e98ae..cbf94e6b 100644 --- a/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs +++ b/src/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7/S7Driver.cs @@ -201,6 +201,12 @@ public sealed class S7Driver /// Clock the connect backoff is measured on. Internal so tests step it deterministically. internal Func BackoffClock { get; set; } = static () => DateTime.UtcNow; + /// + /// Clock the read/write passes and the init publish stamp timestamps and + /// LastSuccessfulRead with. Internal so a test can step it and assert a STRICT advance. + /// + internal Func UtcNow { get; set; } = static () => DateTime.UtcNow; + /// /// The sticky write-side config fault (access denied / PUT-GET disabled), or null. A read /// pass that finds everything readable must NOT erase it (reads can succeed while writes are @@ -364,7 +370,7 @@ public sealed class S7Driver _connectBackoff.RecordSuccess(); Volatile.Write(ref _negotiatedPduSize, Plc.MaxPduSize); _initialized = true; - TryWriteHealth(gen, new DriverHealth(DriverState.Healthy, DateTime.UtcNow, null)); + TryWriteHealth(gen, new DriverHealth(DriverState.Healthy, UtcNow(), null)); // Kick off the probe loop once the connection is up. Initial HostState stays Unknown // until the first probe tick succeeds — avoids broadcasting a premature Running @@ -509,9 +515,18 @@ public sealed class S7Driver if (ReferenceEquals(_probeCts, probeCts)) { probeCts?.Dispose(); - _probeCts = null; - _probeTask = null; } + else + { + // An initialize published (and started a probe loop) after this release took its + // snapshot — a teardown whose generation bump raced the publish block. Cancel that + // loop too; it exits on its next gate wait / delay. Not joined: it needs _gate, which + // we hold. Its CTS is left to the GC rather than disposed under a running loop. + try { _probeCts?.Cancel(); } catch { /* best-effort */ } + probeCts?.Dispose(); + } + _probeCts = null; + _probeTask = null; _initialized = false; _plcDead = false; try { Plc?.Dispose(); } catch { /* best-effort — tearing down anyway */ } @@ -693,7 +708,7 @@ public sealed class S7Driver // InvalidOperationException from the not-initialized check. ArgumentNullException.ThrowIfNull(fullReferences); RequireInitialized(); - var now = DateTime.UtcNow; + var now = UtcNow(); var results = new DataValueSnapshot[fullReferences.Count]; // Health is decided ONCE, at the end of the pass, from every outcome the pass observed — // never per item. See ReadPassOutcome. @@ -749,6 +764,8 @@ public sealed class S7Driver List? forcedPerTag = null; // Members of each span refused this pass, and which of them were then refused on their own. List>? refusedSpans = null; + // Members of each multi-var chunk that fell back per tag this pass (R07:P2's multi-var sibling). + List>? multiVarFallbacks = null; HashSet? refusedAlone = null; if (_options.SpanReadMaxGapBytes >= 0) @@ -820,7 +837,8 @@ public sealed class S7Driver if (_options.SpanReadMaxGapBytes >= 0) { perTag = await ReadLeftoversByMultiVarAsync( - plc, resolved, perTag, results, now, outcome, cancellationToken).ConfigureAwait(false); + plc, resolved, perTag, results, now, outcome, cancellationToken, + fallback => (multiVarFallbacks ??= []).Add(fallback)).ConfigureAwait(false); } if (forcedPerTag is not null) { @@ -856,13 +874,28 @@ public sealed class S7Driver } catch (Exception ex) { - if (refusedSpans is not null && IsRefusal(ex)) (refusedAlone ??= []).Add(i); + if ((refusedSpans is not null || multiVarFallbacks is not null) && IsRefusal(ex)) (refusedAlone ??= []).Add(i); results[i] = new DataValueSnapshot(null, RecordReadFailure(ex, outcome, [resolved[i]!.Name]), null, now); } } // Remember what must not be grouped again (R07:P2). Skipped when the handle died mid-pass: // the per-member reads then proved nothing about which member the CPU refuses. + // A multi-var chunk that fell back: memo only the members refused ON THEIR OWN — without one, + // the chunk's failure explains nothing about its members, and they keep batching. + if (multiVarFallbacks is not null && refusedAlone is not null && !_plcDead) + { + foreach (var members in multiVarFallbacks) + { + var bad = members.Where(refusedAlone.Contains).ToList(); + if (bad.Count == 0) continue; + foreach (var m in bad) _noGroup.Add(resolved[m]!.Name); + _logger.LogInformation( + "S7 CPU refused a multi-var read of {MemberCount} tag(s); reading {Tags} individually from now on. Driver={DriverInstanceId}", + members.Count, string.Join(", ", bad.Select(m => resolved[m]!.Name)), _driverInstanceId); + } + } + if (refusedSpans is not null && !_plcDead) { foreach (var members in refusedSpans) @@ -1092,6 +1125,8 @@ public sealed class S7Driver /// The batch timestamp, shared by every tag in the batch. /// The pass's outcome accumulator; every decoded item records into it. /// Cancellation token for the reads. + /// Receives the member indexes of each chunk that fell back per tag, so + /// the caller can memo the members then refused on their own (the multi-var sibling of R07:P2). /// The indexes still owed an individual read, ascending. private async Task> ReadLeftoversByMultiVarAsync( IS7Plc plc, @@ -1100,7 +1135,8 @@ public sealed class S7Driver DataValueSnapshot[] results, DateTime now, ReadPassOutcome outcome, - CancellationToken ct) + CancellationToken ct, + Action> onChunkFallback) { var stillPerTag = new List(); List<(int Index, S7TagDefinition Tag, S7ParsedAddress Addr)>? batchable = null; @@ -1180,6 +1216,7 @@ public sealed class S7Driver "S7 driver {DriverInstanceId}: multi-var read of {ItemCount} leftover tag(s) failed; " + "falling back to per-tag reads for that chunk", _driverInstanceId, chunk.Count); foreach (var (index, _, _) in chunk) stillPerTag.Add(index); + onChunkFallback([.. chunk.Select(c => c.Index)]); continue; } @@ -1429,6 +1466,11 @@ public sealed class S7Driver // BadNotSupported and flag the driver as a config alert (Faulted) rather than // Degraded — per driver-specs.md §5. Matched over the whole chain: S7.Net's READ // paths raise the CPU's item error as a bare Exception, not a PlcException. + // It is ALSO an answer from a reachable CPU: LastSuccessfulRead must advance, or a + // factory-default CPU (every read denied) trips the comms-loss watchdog into a + // reconnect + re-subscribe every 90 s that can never fix a PUT/GET setting. + // Faulted still wins the pass (worst state), so the config alert is kept. + outcome.RecordAnswered(); outcome.RecordFailure(DriverState.Faulted, "S7 access denied — enable PUT/GET communication in TIA Portal " + $"(Protection & Security) for this CPU. PLC reported: {ex.Message}"); @@ -2115,6 +2157,9 @@ public sealed class S7Driver // configuration fault as on read. BadNotSupported + // a config-alert health state, not a transient device failure. results[i] = new WriteResult(StatusBadNotSupported); + // An answer (see the read ladder): advances LastSuccessfulRead. RecordAnswered sets + // AnyAnswered only, so the sticky _writeFault still clears only on a real success. + outcome.RecordAnswered(); outcome.RecordFailure(DriverState.Faulted, "S7 access denied — enable PUT/GET communication in TIA Portal " + $"(Protection & Security) for this CPU. PLC reported: {ex.Message}"); @@ -2177,7 +2222,7 @@ public sealed class S7Driver else if (outcome.AnySuccess) _writeFault = null; // a write got through — the protection fault is gone - var answeredAt = outcome.AnyAnswered ? DateTime.UtcNow : (DateTime?)null; + var answeredAt = outcome.AnyAnswered ? UtcNow() : (DateTime?)null; if (worst == DriverState.Healthy) { // Clean batch (successes and/or refusals): the CPU answered, so LastSuccessfulRead @@ -2678,10 +2723,14 @@ public sealed class S7Driver internal static bool IsAccessDenied(Exception ex) { if (ex is not PlcException && !IsS7ItemError(ex)) return false; + // A transport fault wins over any wording in the chain: a socket error whose text happens to + // contain the phrase must reopen (Degraded), not latch a sticky config alert. + if (IsS7ConnectionFatal(ex) || HasCancellationInChain(ex)) return false; for (Exception? e = ex; e is not null; e = e.InnerException) { - if (e.Message.Contains("Accessing object not allowed", StringComparison.OrdinalIgnoreCase) - || e.Message.Contains("not allowed", StringComparison.OrdinalIgnoreCase)) + // S7.Net's exact wording for the S7 AccessingObjectNotAllowed status — not the loose "not + // allowed", which any unrelated exception text can contain. + if (e.Message.Contains("Accessing object not allowed", StringComparison.OrdinalIgnoreCase)) { return true; } @@ -2766,6 +2815,16 @@ public sealed class S7Driver /// The exception caught by the poll engine. private void HandlePollError(Exception ex) { + // A retained poll that ran into a teardown / re-initialize IN PROGRESS ("not initialized" while a + // lifecycle operation holds _lifecycleGate) belongs to no live generation: that operation owns + // health, and writing Degraded over its Initializing (or its final Unknown) would break the "old + // work never overwrites newer health" rule. A poll against a driver nobody is initializing (a + // subscribe before init, a failed init) still surfaces Degraded (Driver.S7-009). + if (!_initialized && _lifecycleGate.CurrentCount == 0) + { + _logger.LogDebug(ex, "S7 poll reader failed during a lifecycle operation; no health write. Driver={DriverInstanceId}", _driverInstanceId); + return; + } _logger.LogWarning(ex, "S7 poll reader failed. Driver={DriverInstanceId}", _driverInstanceId); TryUpdateHealth(CurrentGeneration, h => h.State == DriverState.Faulted ? null @@ -2957,6 +3016,7 @@ public sealed class S7Driver _initialized = false; _plcDead = false; _writeFault = null; + _writeOwnedError = null; _connectBackoff.RecordSuccess(); try { Plc?.Dispose(); } catch { /* best-effort — tearing down anyway */ } Plc = null; diff --git a/src/Server/ZB.MOM.WW.OtOpcUa.AdminUI/Uns/TagEditors/S7TagConfigModel.cs b/src/Server/ZB.MOM.WW.OtOpcUa.AdminUI/Uns/TagEditors/S7TagConfigModel.cs index 723cd369..d02db4d9 100644 --- a/src/Server/ZB.MOM.WW.OtOpcUa.AdminUI/Uns/TagEditors/S7TagConfigModel.cs +++ b/src/Server/ZB.MOM.WW.OtOpcUa.AdminUI/Uns/TagEditors/S7TagConfigModel.cs @@ -120,10 +120,7 @@ public sealed class S7TagConfigModel if (TagConfigJson.GetBool(_bag, "isArray")) { var dt = DataType; - if (dt is S7DataType.Int64 or S7DataType.UInt64 or S7DataType.Float64 - or S7DataType.String or S7DataType.DateTime or S7DataType.WString or S7DataType.Char - or S7DataType.WChar or S7DataType.Dtl or S7DataType.Date or S7DataType.Tod - or S7DataType.Time or S7DataType.S5Time) + if (S7TagShapeRules.IsByteAnchored(dt)) { return $"S7 does not support {dt} arrays — use Bool (read-only), Byte, Int16, UInt16, Int32, " + "UInt32 or Float32 for an array tag, or a scalar tag."; diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.IntegrationTests/S7_1500/S7_1500RefusalTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.IntegrationTests/S7_1500/S7_1500RefusalTests.cs index 709be4c2..79015983 100644 --- a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.IntegrationTests/S7_1500/S7_1500RefusalTests.cs +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.IntegrationTests/S7_1500/S7_1500RefusalTests.cs @@ -34,6 +34,8 @@ public sealed class S7_1500RefusalTests(Snap7ServerFixture sim) await using var drv = new S7Driver(options, driverInstanceId: "s7-refusal-live"); await drv.InitializeAsync("{}", ct); var before = drv.GetHealth().LastSuccessfulRead!.Value; + // Let the wall clock move past the init stamp so "advanced" is asserted strictly (review m-1). + while (DateTime.UtcNow <= before) await Task.Yield(); // Read the refused tag ALONE first: an all-refused pass is exactly the case that used to // freeze LastSuccessfulRead and latch Degraded. @@ -42,7 +44,7 @@ public sealed class S7_1500RefusalTests(Snap7ServerFixture sim) refused[0].Value.ShouldBeNull(); var health = drv.GetHealth(); health.State.ShouldBe(DriverState.Healthy, "a CPU refusal is not a comms fault"); - health.LastSuccessfulRead!.Value.ShouldBeGreaterThanOrEqualTo(before); + health.LastSuccessfulRead!.Value.ShouldBeGreaterThan(before, "the refusal is an answer: the stamp advances"); // Positive control: the same connection still serves the seeded neighbour. var good = await drv.ReadAsync([S7_1500Profile.ProbeTag], ct); diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7LifecycleGateTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7LifecycleGateTests.cs index d856e307..1c99a61e 100644 --- a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7LifecycleGateTests.cs +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7LifecycleGateTests.cs @@ -115,6 +115,69 @@ public sealed class S7LifecycleGateTests (await drv.ReadAsync(["W0"], ct))[0].StatusCode.ShouldBe(0u); } + /// + /// Review m-4: a retained poll that runs into a re-initialize in progress ("not initialized") + /// must not write Degraded over the new attempt's Initializing. Waits on the poll's own log line + /// (a counted signal), then asserts; the control is that a successful init then reports Healthy. + /// + [Fact] + public async Task A_retained_poll_does_not_overwrite_a_reinitialize_in_progress() + { + var ct = TestContext.Current.CancellationToken; + var factory = new ScriptedS7PlcFactory(); + var secondOpenEntered = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var releaseSecondOpen = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + factory.Open = async (index, token) => + { + if (index != 1) return; + secondOpenEntered.TrySetResult(); + await releaseSecondOpen.Task.WaitAsync(token); + }; + var log = new CapturingS7Logger(); + using var drv = new S7Driver(Options(), "s7-retained-poll", factory, log); + await drv.InitializeAsync("{}", ct); + await drv.SubscribeAsync(["W0"], TimeSpan.FromMilliseconds(100), ct); + + var reinit = drv.InitializeAsync("{}", ct); + await secondOpenEntered.Task.WaitAsync(Bound, ct); + + using (var cts = CancellationTokenSource.CreateLinkedTokenSource(ct)) + { + cts.CancelAfter(Bound); + while (log.Entries.Count(e => e.Message.Contains("during a lifecycle operation")) < 2) + await Task.Delay(20, cts.Token); // condition wait on the poll's counted log line + } + drv.GetHealth().State.ShouldBe(DriverState.Initializing, "a retained poll must not write over the new attempt"); + + releaseSecondOpen.SetResult(); + await reinit.WaitAsync(Bound, ct); + drv.GetHealth().State.ShouldBe(DriverState.Healthy); + } + + /// + /// Review m-8: the SYNCHRONOUS Dispose() racing a still-running ShutdownAsync is safe too + /// — neither throws, the superseded init publishes nothing, and the driver ends torn down. + /// + [Fact] + public async Task Sync_dispose_while_a_shutdown_is_still_running_is_safe() + { + var ct = TestContext.Current.CancellationToken; + var f = new FirstOpenBlocks(); + var drv = new S7Driver(Options(), "s7-sync-dispose-race", f.Factory) { LifecycleGateTimeout = TimeSpan.FromSeconds(1) }; + + var init = drv.InitializeAsync("{}", ct); + await f.FirstOpenEntered.Task.WaitAsync(Bound, ct); + + var shutdown = drv.ShutdownAsync(ct); // waits on the gate the blocked init holds + Should.NotThrow(() => drv.Dispose()); + await shutdown.WaitAsync(Bound, ct); + + f.ReleaseFirstOpen.SetResult(); + await Should.ThrowAsync(() => init.WaitAsync(Bound, ct)); + f.Factory.Created.ShouldHaveSingleItem().Disposed.ShouldBeTrue(); + drv.GetHealth().State.ShouldBe(DriverState.Unknown); + } + /// /// Dispose racing a shutdown that is still running is safe: neither throws, and the driver ends /// torn down. The semaphores are no longer disposed, so the running shutdown cannot hit an diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7RefusalHealthTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7RefusalHealthTests.cs index 06aa3277..8c7c5182 100644 --- a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7RefusalHealthTests.cs +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7RefusalHealthTests.cs @@ -38,13 +38,24 @@ public sealed class S7RefusalHealthTests new S7TagDefinition("Good", "DB1.DBW0", S7DataType.UInt16)), }; - private static async Task<(S7Driver Driver, ScriptedS7PlcFactory Factory, CapturingS7Logger Log)> StartAsync() + /// A stepped pass clock, so "LastSuccessfulRead advanced" is asserted STRICTLY. + private sealed class PassClock + { + public DateTime Now { get; private set; } = new(2026, 10, 22, 12, 0, 0, DateTimeKind.Utc); + + /// Moves the clock one second on and returns the new time. + public DateTime Step() => Now = Now.AddSeconds(1); + } + + private static async Task<(S7Driver Driver, ScriptedS7PlcFactory Factory, CapturingS7Logger Log, PassClock Clock)> StartAsync() { var factory = new ScriptedS7PlcFactory(); var log = new CapturingS7Logger(); - var drv = new S7Driver(Options(), "s7-refusal", factory, log); + var clock = new PassClock(); + var drv = new S7Driver(Options(), "s7-refusal", factory, log) { UtcNow = () => clock.Now }; await drv.InitializeAsync("{}", TestContext.Current.CancellationToken); - return (drv, factory, log); + drv.GetHealth().LastSuccessfulRead.ShouldBe(clock.Now, "init stamps the pass clock"); + return (drv, factory, log, clock); } /// A refused tag is Bad, health stays Healthy, LastSuccessfulRead advances, and it warns once. @@ -52,20 +63,19 @@ public sealed class S7RefusalHealthTests public async Task A_read_refusal_is_per_tag_bad_with_no_health_impact_and_one_warning() { var ct = TestContext.Current.CancellationToken; - var (drv, factory, log) = await StartAsync(); + var (drv, factory, log, clock) = await StartAsync(); using var _ = drv; factory.Read = (addr, _) => addr == "DB99.DBW0" ? throw ReadRefusal() : Task.FromResult((ushort)7); - var before = drv.GetHealth().LastSuccessfulRead!.Value; for (var pass = 0; pass < 3; pass++) { + var at = clock.Step(); var r = await drv.ReadAsync(["Missing"], ct); r[0].StatusCode.ShouldBe(BadDeviceFailure); drv.GetHealth().State.ShouldBe(DriverState.Healthy, "a refusal is not a comms fault"); + drv.GetHealth().LastSuccessfulRead.ShouldBe(at, + "the CPU answered, so the all-refused pass advances LastSuccessfulRead to the pass time"); } - - drv.GetHealth().LastSuccessfulRead!.Value.ShouldBeGreaterThanOrEqualTo(before, - "the CPU answered, so the all-refused pass still advances LastSuccessfulRead"); log.Warnings.Count(w => w.Contains("Missing")).ShouldBe(1, "one Warning per refused tag, not one per poll"); // Positive control: the good tag still reads, and nothing reopened the connection. @@ -82,21 +92,25 @@ public sealed class S7RefusalHealthTests public async Task A_refusal_after_a_comms_fault_restores_healthy() { var ct = TestContext.Current.CancellationToken; - var (drv, factory, _) = await StartAsync(); + var (drv, factory, _, clock) = await StartAsync(); using var __ = drv; - // Positive control: a genuine comms fault DOES degrade. + // Positive control: a genuine comms fault DOES degrade, and leaves LastSuccessfulRead frozen. + var initStamp = clock.Now; + clock.Step(); factory.Read = (_, _) => throw new TimeoutException("frozen peer"); await drv.ReadAsync(["Missing"], ct); var degraded = drv.GetHealth(); degraded.State.ShouldBe(DriverState.Degraded); + degraded.LastSuccessfulRead.ShouldBe(initStamp); + var at = clock.Step(); factory.Read = (addr, _) => addr == "DB99.DBW0" ? throw ReadRefusal() : Task.FromResult((ushort)7); var r = await drv.ReadAsync(["Missing"], ct); r[0].StatusCode.ShouldBe(BadDeviceFailure); var after = drv.GetHealth(); after.State.ShouldBe(DriverState.Healthy); - after.LastSuccessfulRead!.Value.ShouldBeGreaterThanOrEqualTo(degraded.LastSuccessfulRead!.Value); + after.LastSuccessfulRead.ShouldBe(at); } /// The ReadData-wrapped shape of a refusal is classified the same way. @@ -104,7 +118,7 @@ public sealed class S7RefusalHealthTests public async Task A_read_data_wrapped_refusal_is_also_a_refusal() { var ct = TestContext.Current.CancellationToken; - var (drv, factory, _) = await StartAsync(); + var (drv, factory, _, clock) = await StartAsync(); using var __ = drv; factory.Read = (_, _) => throw new PlcException(ErrorCode.ReadData, ReadRefusal()); @@ -121,7 +135,7 @@ public sealed class S7RefusalHealthTests public async Task A_bare_access_denied_read_is_the_faulted_config_alert() { var ct = TestContext.Current.CancellationToken; - var (drv, factory, _) = await StartAsync(); + var (drv, factory, _, clock) = await StartAsync(); using var __ = drv; factory.Read = (_, _) => throw new Exception("Received error from PLC: Accessing object not allowed."); @@ -130,12 +144,93 @@ public sealed class S7RefusalHealthTests drv.GetHealth().LastError!.ShouldContain("PUT/GET"); } + /// + /// Review I-1: an access-denied CPU (PUT/GET left at its factory default — EVERY read denied) is + /// reachable and answering, so each pass advances LastSuccessfulRead while staying Faulted. + /// Before, the pass stayed Faulted with the stamp frozen — the comms-loss watchdog's trip + /// condition, so the actor reconnected + re-subscribed every 90 s, forever, which can never fix + /// a PUT/GET setting. The control: a comms fault afterwards leaves the stamp frozen. + /// + [Fact] + public async Task An_all_access_denied_pass_stays_faulted_but_advances_last_successful_read() + { + var ct = TestContext.Current.CancellationToken; + var (drv, factory, _, clock) = await StartAsync(); + using var __ = drv; + factory.Read = (_, _) => throw new Exception("Received error from PLC: Accessing object not allowed."); + + DateTime last = default; + for (var pass = 0; pass < 2; pass++) + { + last = clock.Step(); + await drv.ReadAsync(["Good", "Missing"], ct); + var h = drv.GetHealth(); + h.State.ShouldBe(DriverState.Faulted, "the config alert is kept"); + h.LastSuccessfulRead.ShouldBe(last, "the CPU answered, so the stamp advances every pass"); + } + + // Positive control: a real comms loss does NOT advance it (and the sticky Faulted outranks it). + clock.Step(); + factory.Read = (_, _) => throw new TimeoutException("frozen peer"); + await drv.ReadAsync(["Good"], ct); + drv.GetHealth().LastSuccessfulRead.ShouldBe(last); + } + + /// The write-side access-denied is an answer too, and its sticky Faulted still clears only on a real success. + [Fact] + public async Task A_write_access_denied_advances_last_successful_read_and_stays_sticky() + { + var ct = TestContext.Current.CancellationToken; + var (drv, factory, _, clock) = await StartAsync(); + using var __ = drv; + factory.Write = (_, _, _) => throw new PlcException(ErrorCode.WriteData, + new Exception("Received error from PLC: Accessing object not allowed.")); + + var at = clock.Step(); + (await drv.WriteAsync([new WriteRequest("Good", (ushort)1)], ct))[0].StatusCode.ShouldBe(0x803D0000u); + drv.GetHealth().State.ShouldBe(DriverState.Faulted); + drv.GetHealth().LastSuccessfulRead.ShouldBe(at); + + // A clean read leaves the write-side Faulted in place (sticky) … + clock.Step(); + await drv.ReadAsync(["Good"], ct); + drv.GetHealth().State.ShouldBe(DriverState.Faulted); + + // … and a real write success clears it. + factory.Write = (_, _, _) => Task.CompletedTask; + clock.Step(); + await drv.WriteAsync([new WriteRequest("Good", (ushort)1)], ct); + drv.GetHealth().State.ShouldBe(DriverState.Healthy); + } + + /// + /// Review m-7: a transport fault whose text happens to contain "not allowed" reopens (Degraded), + /// and only S7.Net's exact "Accessing object not allowed" is the access-denied alert. + /// + [Fact] + public async Task Only_the_exact_access_denied_wording_without_a_transport_fault_is_access_denied() + { + var ct = TestContext.Current.CancellationToken; + var (drv, factory, _, clock) = await StartAsync(); + using var __ = drv; + + clock.Step(); + factory.Write = (_, _, _) => throw new PlcException(ErrorCode.WriteData, + new System.IO.IOException("Accessing object not allowed: socket closed by peer")); + (await drv.WriteAsync([new WriteRequest("Good", (ushort)1)], ct))[0].StatusCode + .ShouldNotBe(0x803D0000u, "not the access-denied BadNotSupported"); + drv.GetHealth().State.ShouldBe(DriverState.Degraded, "a transport fault is not a config alert"); + + S7Driver.IsAccessDenied(new PlcException(ErrorCode.WriteData, new Exception("operation not allowed"))).ShouldBeFalse(); + S7Driver.IsAccessDenied(new Exception("Received error from PLC: Accessing object not allowed.")).ShouldBeTrue(); + } + /// A ReadData wrapping a socket fault is still a comms fault (Degraded), not a refusal. [Fact] public async Task A_read_data_wrapping_a_socket_fault_still_degrades() { var ct = TestContext.Current.CancellationToken; - var (drv, factory, _) = await StartAsync(); + var (drv, factory, _, clock) = await StartAsync(); using var __ = drv; factory.Read = (_, _) => throw new PlcException(ErrorCode.ReadData, new System.IO.IOException("connection reset")); @@ -148,7 +243,7 @@ public sealed class S7RefusalHealthTests public async Task A_write_refusal_is_per_tag_bad_and_counts_as_answered() { var ct = TestContext.Current.CancellationToken; - var (drv, factory, log) = await StartAsync(); + var (drv, factory, log, clock) = await StartAsync(); using var _ = drv; factory.Write = (addr, _, _) => addr == "DB99.DBW0" ? throw WriteRefusal() : Task.CompletedTask; @@ -160,12 +255,17 @@ public sealed class S7RefusalHealthTests for (var i = 0; i < 2; i++) { + var at = clock.Step(); var w = await drv.WriteAsync([new WriteRequest("Missing", (ushort)1)], ct); w[0].StatusCode.ShouldBe(BadDeviceFailure); + var h = drv.GetHealth(); + h.LastSuccessfulRead.ShouldBe(at, "a write refusal is an answer: the stamp advances strictly"); + // The Degraded was written by the READ side (its own message), so it is the read pass's to clear. + h.State.ShouldBe(DriverState.Degraded); } var after = drv.GetHealth(); - after.LastSuccessfulRead!.Value.ShouldBeGreaterThanOrEqualTo(degraded.LastSuccessfulRead!.Value); + after.LastSuccessfulRead!.Value.ShouldBeGreaterThan(degraded.LastSuccessfulRead!.Value); log.Warnings.Count(m => m.Contains("Missing")).ShouldBe(1); } @@ -177,7 +277,7 @@ public sealed class S7RefusalHealthTests public async Task A_good_write_clears_a_write_side_degraded() { var ct = TestContext.Current.CancellationToken; - var (drv, factory, _) = await StartAsync(); + var (drv, factory, _, clock) = await StartAsync(); using var _ = drv; factory.Write = (_, _, _) => throw new System.IO.IOException("connection reset"); diff --git a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7SpanRefusalFallbackTests.cs b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7SpanRefusalFallbackTests.cs index ce6ff0ca..11b7358d 100644 --- a/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7SpanRefusalFallbackTests.cs +++ b/tests/Drivers/ZB.MOM.WW.OtOpcUa.Driver.S7.Tests/S7SpanRefusalFallbackTests.cs @@ -139,6 +139,58 @@ public sealed class S7SpanRefusalFallbackTests drv.GetHealth().State.ShouldBe(DriverState.Degraded); } + /// + /// Review m-5, the multi-var sibling: a leftover chunk holding one refused scalar used to fall back + /// per tag on EVERY poll (1 + N requests). The member refused on its own is now memoised, so the + /// next pass batches the rest and reads only the bad one alone. + /// + [Fact] + public async Task A_refused_multi_var_chunk_memoises_only_the_member_refused_alone() + { + var ct = TestContext.Current.CancellationToken; + var factory = new ScriptedS7PlcFactory(); + var multiCalls = 0; + factory.ReadMulti = (items, _) => + { + Interlocked.Increment(ref multiCalls); + if (items.Any(i => i.DB == 3)) + // The live snap7 shape of a multi-var request with one refused item. + throw new global::S7.Net.PlcException(global::S7.Net.ErrorCode.ReadData, + new global::S7.Net.PlcException(global::S7.Net.ErrorCode.WrongNumberReceivedBytes)); + foreach (var i in items) i.Value = (ushort)5; + return Task.FromResult>(items); + }; + factory.Read = (addr, _) => addr.StartsWith("DB3.", StringComparison.Ordinal) + ? throw new Exception("Received error from PLC: Object does not exist.") + : Task.FromResult((ushort)5); + using var drv = new S7Driver(new S7DriverOptions + { + Host = "192.0.2.1", + Probe = new S7ProbeOptions { Enabled = false }, + RawTags = S7RawTags.Entries( + new S7TagDefinition("A", "DB1.DBW0", S7DataType.UInt16, Writable: false), + new S7TagDefinition("B", "DB2.DBW0", S7DataType.UInt16, Writable: false), + new S7TagDefinition("Bad", "DB3.DBW0", S7DataType.UInt16, Writable: false)), + }, "s7-mv-memo", factory); + await drv.InitializeAsync("{}", ct); + string[] refs = ["A", "B", "Bad"]; + + var before = factory.WireOps; + var r1 = await drv.ReadAsync(refs, ct); + r1[0].StatusCode.ShouldBe(0u); + r1[1].StatusCode.ShouldBe(0u); + r1[2].StatusCode.ShouldBe(BadDeviceFailure); + (factory.WireOps - before).ShouldBe(4, "pass 1: one refused multi-var, then one per-tag read each"); + + before = factory.WireOps; + var r2 = await drv.ReadAsync(refs, ct); + r2[0].StatusCode.ShouldBe(0u); + r2[1].StatusCode.ShouldBe(0u); + r2[2].StatusCode.ShouldBe(BadDeviceFailure); + (factory.WireOps - before).ShouldBe(2, "pass 2: A+B ride one multi-var, Bad reads alone"); + Volatile.Read(ref multiCalls).ShouldBe(2); + } + /// The memo is per generation: a re-initialize (e.g. a corrected DB) groups everything again. [Fact] public async Task Reinitialize_clears_the_do_not_group_memo() diff --git a/tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/Drivers/S7AccessDeniedWatchdogTests.cs b/tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/Drivers/S7AccessDeniedWatchdogTests.cs new file mode 100644 index 00000000..b7ace6d4 --- /dev/null +++ b/tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/Drivers/S7AccessDeniedWatchdogTests.cs @@ -0,0 +1,123 @@ +using Akka.Actor; +using Shouldly; +using Xunit; +using ZB.MOM.WW.OtOpcUa.Core.Abstractions; +using ZB.MOM.WW.OtOpcUa.Driver.S7; +using ZB.MOM.WW.OtOpcUa.Runtime.Drivers; +using ZB.MOM.WW.OtOpcUa.Runtime.Tests.Harness; +using S7DataItem = global::S7.Net.Types.DataItem; +using S7NetDataType = global::S7.Net.DataType; + +namespace ZB.MOM.WW.OtOpcUa.Runtime.Tests.Drivers; + +/// +/// Lane S7 review I-1, end to end: the REAL under the REAL +/// comms-loss watchdog. A CPU with PUT/GET disabled denies every +/// read but is reachable and answering; the driver reports Faulted (the config alert) and must +/// still advance LastSuccessfulRead, so the watchdog's "non-Healthy AND silent for the +/// threshold" conjunction is never met and the actor does NOT reconnect + re-subscribe. The +/// positive control is the same rig with a real comms loss, which DOES trip it. +/// +public sealed class S7AccessDeniedWatchdogTests : RuntimeActorTestBase +{ + private static readonly TimeSpan FastPoll = TimeSpan.FromMilliseconds(50); + + /// The watchdog threshold — an order of magnitude above the poll so the window is a decision, not a race. + private static readonly TimeSpan Threshold = TimeSpan.FromMilliseconds(1500); + + private sealed class ScriptedPlcFactory(Func readFault) : IS7PlcFactory + { + public IS7Plc Create(S7CpuType cpuType, string host, int port, short rack, short slot, TimeSpan timeout) + => new ScriptedPlc(readFault); + } + + private sealed class ScriptedPlc(Func readFault) : IS7Plc + { + public bool IsConnected { get; private set; } + public Task OpenAsync(CancellationToken cancellationToken) { IsConnected = true; return Task.CompletedTask; } + public void Close() => IsConnected = false; + public Task ReadAsync(string address, CancellationToken cancellationToken) => Task.FromException(readFault()); + public Task ReadBytesAsync(S7NetDataType area, int db, int startByteAdr, int count, CancellationToken cancellationToken) + => Task.FromException(readFault()); + public Task> ReadMultipleVarsAsync(List items, CancellationToken cancellationToken) + => Task.FromException>(readFault()); + public Task WriteAsync(string address, object value, CancellationToken cancellationToken) => Task.CompletedTask; + public Task WriteBytesAsync(S7NetDataType area, int db, int startByteAdr, byte[] value, CancellationToken cancellationToken) => Task.CompletedTask; + public Task ReadStatusAsync(CancellationToken cancellationToken) => Task.CompletedTask; + public void Dispose() => IsConnected = false; + } + + private (S7Driver Driver, Akka.TestKit.TestProbe Parent) Connect(Func readFault) + { + var driver = new S7Driver(new S7DriverOptions + { + Host = "192.0.2.1", + Probe = new S7ProbeOptions { Enabled = false }, + SpanReadMaxGapBytes = -1, + RawTags = + [ + new RawTagEntry("W0", S7TagDefinitionFactory.ToTagConfig(new S7TagDefinition("W0", "DB1.DBW0", S7DataType.UInt16, Writable: false)), false), + new RawTagEntry("W2", S7TagDefinitionFactory.ToTagConfig(new S7TagDefinition("W2", "DB1.DBW2", S7DataType.UInt16, Writable: false)), false), + ], + }, "s7-watchdog", new ScriptedPlcFactory(readFault)); + + var parent = CreateTestProbe(); + var actor = parent.ChildActorOf(DriverInstanceActor.Props( + driver, + reconnectInterval: TimeSpan.FromSeconds(30), + healthPollInterval: FastPoll, + commsLossTimeout: Threshold)); + actor.Tell(new DriverInstanceActor.InitializeRequested("{}")); + parent.ExpectMsg(TimeSpan.FromSeconds(5)).Connected.ShouldBeTrue(); + return (driver, parent); + } + + /// Drives read passes (the poll the actor would schedule) until . + private static async Task<(int Passes, int FaultedPasses)> PollUntilAsync(S7Driver driver, DateTime until) + { + var passes = 0; + var faulted = 0; + while (DateTime.UtcNow < until) + { + try + { +#pragma warning disable OTOPCUA0001 // the watchdog's reading of driver health is under test, not resilience wrapping + await driver.ReadAsync(["W0", "W2"], CancellationToken.None); +#pragma warning restore OTOPCUA0001 + passes++; + if (driver.GetHealth().State == DriverState.Faulted) faulted++; + } + catch (InvalidOperationException) { /* the actor tore the driver down (control case) */ } + await Task.Delay(100); // pacing the simulated poll, not an assertion + } + return (passes, faulted); + } + + /// An all-access-denied CPU is left connected across more than twice the watchdog threshold. + [Fact] + public async Task An_access_denied_cpu_is_not_reconnected_by_the_watchdog() + { + var (driver, parent) = Connect(() => new Exception("Received error from PLC: Accessing object not allowed.")); + + var (passes, faulted) = await PollUntilAsync(driver, DateTime.UtcNow + Threshold + Threshold + TimeSpan.FromMilliseconds(500)); + + // Positive controls: the window really ran past the threshold with the driver Faulted throughout, + // so "no reconnect" below cannot pass merely because nothing happened. + passes.ShouldBeGreaterThanOrEqualTo(10); + faulted.ShouldBe(passes, "every pass reports the PUT/GET config alert"); + + parent.ExpectNoMsg(TimeSpan.FromMilliseconds(300)); + driver.GetHealth().State.ShouldBe(DriverState.Faulted); + } + + /// The control: a real comms loss (every read times out) on the same rig IS reconnected. + [Fact] + public async Task A_real_comms_loss_is_reconnected_by_the_watchdog() + { + var (driver, parent) = Connect(() => new TimeoutException("frozen peer")); + + var poll = PollUntilAsync(driver, DateTime.UtcNow + Threshold + Threshold + TimeSpan.FromMilliseconds(500)); + parent.ExpectMsg(PresenceBudget).Connected.ShouldBeFalse(); + await poll; + } +} diff --git a/tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/ZB.MOM.WW.OtOpcUa.Runtime.Tests.csproj b/tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/ZB.MOM.WW.OtOpcUa.Runtime.Tests.csproj index 554d3e15..bc5bdb83 100644 --- a/tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/ZB.MOM.WW.OtOpcUa.Runtime.Tests.csproj +++ b/tests/Server/ZB.MOM.WW.OtOpcUa.Runtime.Tests/ZB.MOM.WW.OtOpcUa.Runtime.Tests.csproj @@ -39,6 +39,9 @@ re-statement end-to-end tests prove what reaches the host's /alerts rows and Part 9 conditions. --> + +