From 9fb52153fde8c61c88303f5e095e199103f904c2 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Sat, 15 Aug 2026 03:37:35 -0400 Subject: [PATCH] fix(test): order three more unsynchronized assertions behind the observables they follow MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Deferred flake-pattern sweep of tests/ for the class fixed in c4caebe9 and cfa6acbf — a bounded wait on observable A followed by a bare assert on an observable B that the product only reaches strictly after A. Three clear instances, each reproduced deterministically by delaying only the later step and each re-verified green with that same delay still injected. AlarmOnTriggerRuns_ShedAtTheSameCap_WithAnAlarmScopedSiteEvent gated on the rate-limited shed site event and then asserted the shed COUNT bare. AlarmActor.ShedAlarmRun increments the counter and only then emits the event, and the event fires on the first shed only — so the gate observed Flap(4)'s shed and ordered nothing with respect to Flap(5)'s, which is a separate mailbox message with no observable of its own (an alarm on-trigger run has no Ask caller to reply to, unlike ScriptActor.ShedRun, whose sibling test is correctly ordered by its ScriptCallResult and is left alone). Deferring Flap(5) by 2 s failed it with "Expected: 2 / Actual: 1". The count is now ACCUMULATED across polls rather than re-read, because SiteHealthCollector.CollectReport DRAINS the interval counters — a poll loop that simply re-read it would consume the first shed and never reach 2. EndToEnd_GrpcStubError_RowStays_Pending_NextTick_Succeeds gated on the central row arriving and then asserted bare that the site SQLite row had left Pending. SiteAuditTelemetryActor pushes via IngestAuditEventsAsync (which is what writes the central row) and calls MarkForwardedAsync only after parsing the ack. Delaying just that post-push step failed it with "Assert.DoesNotContain() Failure: Filter matched in collection". PreSnapshotBuffer_IsCapped_DropsOldest_AndCountsTheDrops gated on "Count >= cap" and then asserted "Count == cap + 1" bare — a gate strictly weaker than the assertion it guards, so it ordered nothing with respect to the last event of a FlushBuffer loop that delivers one at a time. Parking that loop after its 19,999th delivery failed it with "Expected: 20001 / Actual: 20000". Also hardens GrpcCentralTransportTests.WaitUntil, which returned silently on timeout; today's single caller re-asserts immediately, so this only sharpens the message rather than fixing a live flake. Cleared with evidence, not guessed: SiteAlarmLiveCacheService's LingerStop removes the site entry inside one lock, so IsLive and GetCurrentAlarms flip atomically; and SiteReconciliationActor walks response.Gap with a sequential foreach in which the asserted "Gone" log precedes the awaited "Good" row, the inverse of this class. Test-only; every ordering named above is correct as written. --- .../SyncCallEmissionEndToEndTests.cs | 22 ++++++++++++-- .../Grpc/DebugStreamBridgeActorTests.cs | 28 ++++++++++------- .../GrpcCentralTransportTests.cs | 9 ++++++ .../Actors/ScriptRunShedTests.cs | 30 +++++++++++++++++-- 4 files changed, 74 insertions(+), 15 deletions(-) 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)); } }