diff --git a/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Integration/SyncCallEmissionEndToEndTests.cs b/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Integration/SyncCallEmissionEndToEndTests.cs index aa1278ce..2e7633ad 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Integration/SyncCallEmissionEndToEndTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.AuditLog.Tests/Integration/SyncCallEmissionEndToEndTests.cs @@ -213,14 +213,32 @@ public class SyncCallEmissionEndToEndTests : TestKit, IClassFixture= 2, $"Expected at least one failed push + one successful push; saw {stubClient.CallCount} total client calls."); // The site SQLite row must have flipped to Forwarded after the // successful retry. ReadPendingAsync only returns Pending rows; the // row should NOT show up there anymore. - var stillPending = await sqliteWriter.ReadPendingAsync(64); - Assert.DoesNotContain(stillPending, p => p.EventId == evt.EventId); + // + // AwaitAssert, not a bare Assert: the drain marks rows forwarded only + // AFTER the push returns and its ack is parsed — SiteAuditTelemetryActor + // pushes via IngestAuditEventsAsync (which is what writes the central + // row) and only then calls MarkForwardedAsync. Observing the central row + // above therefore establishes no happens-before edge with the site-side + // state flip; on a loaded run the post-push continuation can be scheduled + // after the poll that saw the row, leaving it still Pending. Reproduced + // deterministically by delaying only that post-push step, which fails + // exactly this test with "Assert.DoesNotContain() Failure: Filter matched + // in collection". The bounded wait removes the ordering assumption only — + // the row must still actually leave Pending or the test fails as before. + await AwaitAssertAsync(async () => + { + var stillPending = await sqliteWriter.ReadPendingAsync(64); + Assert.DoesNotContain(stillPending, p => p.EventId == evt.EventId); + }, TimeSpan.FromSeconds(15)); } [SkippableFact] diff --git a/tests/ZB.MOM.WW.ScadaBridge.Communication.Tests/Grpc/DebugStreamBridgeActorTests.cs b/tests/ZB.MOM.WW.ScadaBridge.Communication.Tests/Grpc/DebugStreamBridgeActorTests.cs index dc652363..ad589474 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.Communication.Tests/Grpc/DebugStreamBridgeActorTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.Communication.Tests/Grpc/DebugStreamBridgeActorTests.cs @@ -964,18 +964,26 @@ public class DebugStreamBridgeActorTests : TestKit t.AddMilliseconds(-1)); ctx.BridgeActor.Tell(snapshot); - AwaitCondition(() => + // One awaited block, gated on the EXACT final count. This used to gate on + // "Count >= cap" and then assert "Count == cap + 1" bare — a gate strictly + // weaker than the assertion it guards, which therefore orders nothing with + // respect to the last event. FlushBuffer delivers the buffered events one + // by one via _onEvent inside a single loop, so the poll can legitimately + // observe the count crossing `cap` while the loop still has an event to + // go. Reproduced deterministically by parking that loop for 3 s after its + // 19,999th delivery: the bare form failed with "Expected: 20001 / Actual: + // 20000". The claims are unchanged — exactly the snapshot plus the capped + // retained events, with the newest survivor last. + AwaitAssert(() => { - lock (ctx.ReceivedEvents) { return ctx.ReceivedEvents.Count >= cap; } + lock (ctx.ReceivedEvents) + { + // Snapshot + exactly the retained (capped) events, and the newest survived. + Assert.Equal(cap + 1, ctx.ReceivedEvents.Count); + var lastAttr = ctx.ReceivedEvents.OfType().Last(); + Assert.Equal($"Attr{cap + overflow - 1}", lastAttr.AttributeName); + } }, TimeSpan.FromSeconds(10)); - - lock (ctx.ReceivedEvents) - { - // Snapshot + exactly the retained (capped) events, and the newest survived. - Assert.Equal(cap + 1, ctx.ReceivedEvents.Count); - var lastAttr = ctx.ReceivedEvents.OfType().Last(); - Assert.Equal($"Attr{cap + overflow - 1}", lastAttr.AttributeName); - } } [Fact] diff --git a/tests/ZB.MOM.WW.ScadaBridge.Host.Tests/GrpcCentralTransportTests.cs b/tests/ZB.MOM.WW.ScadaBridge.Host.Tests/GrpcCentralTransportTests.cs index 3446bf90..d564e168 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.Host.Tests/GrpcCentralTransportTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.Host.Tests/GrpcCentralTransportTests.cs @@ -249,6 +249,13 @@ public class GrpcCentralTransportTests : IAsyncLifetime SourceScript: null, SiteEnqueuedAt: DateTimeOffset.UtcNow); + /// + /// Spins until holds, then asserts it — a bare + /// return on timeout would make every future caller's wait silently + /// vacuous. Today's single caller happens to re-assert immediately after, + /// so this only sharpens the failure message; it is here so the next caller + /// does not have to remember to. + /// private static async Task WaitUntil(Func condition, TimeSpan timeout) { var deadline = DateTime.UtcNow + timeout; @@ -261,6 +268,8 @@ public class GrpcCentralTransportTests : IAsyncLifetime await Task.Delay(25); } + + Assert.True(condition(), $"Condition was still false after waiting {timeout}."); } /// diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/ScriptRunShedTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/ScriptRunShedTests.cs index 18024441..da2fb127 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/ScriptRunShedTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/ScriptRunShedTests.cs @@ -177,17 +177,41 @@ public class ScriptRunShedTests : TestKit, IDisposable Flap(4); Flap(5); + // The shed COUNT assertion lives inside the awaited block, not after it. + // ShedAlarmRun increments the counter and only then emits the (rate-limited) + // site event, and that event fires on the FIRST shed only — so an awaited + // gate on the event observes Flap(4)'s shed and orders nothing whatsoever + // with respect to Flap(5)'s, which is a separate mailbox message with no + // observable of its own on this path (an alarm on-trigger run has no Ask + // caller to reply to — AlarmActor.ShedAlarmRun). Asserting the count bare + // after the gate assumed both sheds had been dequeued by the time the + // first one's event landed; under load the second can still be pending and + // the count reads 1. Reproduced deterministically by deferring Flap(5) by + // 2 s: the bare form failed with "Expected: 2 / Actual: 1", while the + // ScriptActor sibling above — which IS ordered, because ShedRun replies + // ScriptCallResult after incrementing — kept passing. + // + // The count is ACCUMULATED across polls rather than re-read, because + // SiteHealthCollector.CollectReport DRAINS the interval counters + // (Interlocked.Exchange(ref _scriptRunShedCount, 0)) — a poll loop that + // simply re-read it would consume the first shed and never see 2. + var shedCounted = 0; AwaitAssert(() => { + shedCounted += health.CollectReport("site-1").ScriptRunShedCount; + var shedEvents = siteLog.OfType("script") .Where(r => r.Severity == "Warning" && r.Message.Contains("shed")) .ToArray(); + + // Both sheds counted, even though the event is rate-limited to one. + Assert.Equal(2, shedCounted); Assert.Single(shedEvents); Assert.Equal("AlarmActor:Flapper", shedEvents[0].Source); - }, TimeSpan.FromSeconds(10)); - Assert.Equal(4, alarm.UnderlyingActor.RunsInFlight); - Assert.Equal(2, health.CollectReport("site-1").ScriptRunShedCount); + // ...and neither shed run was ever launched: still exactly four in flight. + Assert.Equal(4, alarm.UnderlyingActor.RunsInFlight); + }, TimeSpan.FromSeconds(10)); } } diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/SandboxTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/SandboxTests.cs index eb5aa9f8..fabd199b 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/SandboxTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/SandboxTests.cs @@ -216,14 +216,57 @@ public class SandboxTests Assert.True(result.IsSuccess); } - // ── Execution timeout ── + // ── Execution cancellation ── + // + // These two tests used to arm a wall-clock CancellationTokenSource + // (500 ms / 100 ms) and hope it expired while the script body was still + // running. That is a race between a fixed timer and a fixed amount of + // work, not a synchronization, and it is wrong in both directions: + // + // * Too slow a timer relative to the work and the script simply + // FINISHES first, so nothing is cancelled and ThrowsAnyAsync fails + // with "No exception was thrown". The bounded loop below was measured + // at 298 ms against a 100 ms pin on this machine — a 3x margin, which + // a faster host (or any change to the scripting OptimizationLevel, + // which is Debug today) closes. Reproduced deterministically by + // shrinking the loop to 1M iterations: it then ran in 76 ms and the + // test failed with exactly that message while all 27 siblings passed. + // * Too fast a timer and the token is ALREADY cancelled before the body + // is entered — Roslyn's runner throws OperationCanceledException up + // front (verified), so the test goes GREEN without the script's own + // in-loop ThrowIfCancellationRequested ever being reached. A vacuous + // pass is worse than a flake: it asserts nothing. + // + // Both are replaced with a deterministic edge. The script triggers the + // cancellation itself, synchronously, from inside its own loop via an + // Action handed in through Parameters. When that call returns, the token + // is already cancelled ON THE SAME THREAD, so the next in-loop check is + // guaranteed to observe it — with iterations to spare and no reliance on + // wall-clock time, host speed or scheduler behaviour. Sandbox_UncancelledScript_RunsToCompletion + // is the negative control for the bounded case. + + /// Builds globals whose "cancelNow" parameter cancels when the script invokes it. + private static ScriptGlobals GlobalsWithCancelHook(CancellationTokenSource cts, Action? onSignal = null) + => new() + { + Instance = null!, + Parameters = new ScriptParameters(new Dictionary + { + ["cancelNow"] = onSignal ?? (() => cts.Cancel()) + }), + CancellationToken = cts.Token + }; [Fact] public async Task Sandbox_InfiniteLoop_CancelledByToken() { - // Compile a script that loops forever + // An unbounded loop that cancels itself on the first pass, so the + // check on that same pass is the one that throws. var code = """ + var spins = 0; while (true) { + spins++; + if (spins == 1) ((Action)Parameters["cancelNow"]!)(); CancellationToken.ThrowIfCancellationRequested(); } return null; @@ -232,14 +275,8 @@ public class SandboxTests var result = _service.Compile("infinite", code); Assert.True(result.IsSuccess, "Infinite loop compiles but should be cancelled at runtime"); - // Execute with a short timeout - using var cts = new CancellationTokenSource(TimeSpan.FromMilliseconds(500)); - var globals = new ScriptGlobals - { - Instance = null!, - Parameters = new ScriptParameters(), - CancellationToken = cts.Token - }; + using var cts = new CancellationTokenSource(); + var globals = GlobalsWithCancelHook(cts); await Assert.ThrowsAnyAsync(async () => { @@ -250,11 +287,16 @@ public class SandboxTests [Fact] public async Task Sandbox_LongRunningScript_TimesOut() { - // A script that does heavy computation with cancellation checks + // Heavy bounded computation with periodic cancellation checks. It + // cancels itself at i == 1, leaving ~100M iterations and ~10,000 + // cancellation checks still ahead of it, so interruption is certain + // however fast the host runs — the point being that a long script + // does not get to run to completion once its deadline has fired. var code = """ - var sum = 0; + var sum = 0L; for (var i = 0; i < 100_000_000; i++) { sum += i; + if (i == 1) ((Action)Parameters["cancelNow"]!)(); if (i % 10000 == 0) CancellationToken.ThrowIfCancellationRequested(); } return sum; @@ -263,13 +305,8 @@ public class SandboxTests var result = _service.Compile("heavy", code); Assert.True(result.IsSuccess); - using var cts = new CancellationTokenSource(TimeSpan.FromMilliseconds(100)); - var globals = new ScriptGlobals - { - Instance = null!, - Parameters = new ScriptParameters(), - CancellationToken = cts.Token - }; + using var cts = new CancellationTokenSource(); + var globals = GlobalsWithCancelHook(cts); await Assert.ThrowsAnyAsync(async () => { @@ -277,6 +314,38 @@ public class SandboxTests }); } + [Fact] + public async Task Sandbox_UncancelledScript_RunsToCompletion() + { + // Negative control for Sandbox_LongRunningScript_TimesOut: the SAME + // script shape, with the signal wired to a no-op instead of Cancel(). + // It must run every iteration and return the closed-form sum. This is + // what proves the sibling's OperationCanceledException is caused by + // the cancellation and not by the loop being unreachable, the trust + // model rejecting the body, or the runner failing for its own reasons. + var code = """ + var sum = 0L; + for (var i = 0; i < 100_000_000; i++) { + sum += i; + if (i == 1) ((Action)Parameters["cancelNow"]!)(); + if (i % 10000 == 0) CancellationToken.ThrowIfCancellationRequested(); + } + return sum; + """; + + var result = _service.Compile("heavy-control", code); + Assert.True(result.IsSuccess); + + using var cts = new CancellationTokenSource(); + var signalled = false; + var globals = GlobalsWithCancelHook(cts, onSignal: () => signalled = true); + + var value = await result.CompiledScript!.RunAsync(globals, cts.Token); + + Assert.True(signalled, "The script's in-loop signal must actually fire."); + Assert.Equal(4999999950000000L, value.ReturnValue); + } + // ── Combined adversarial attempts ── [Fact]