7a7d345b89
Six sleeps across four test files stood in for an observable edge. Each preceded an
ABSENCE assertion (or "settled" before one), so they failed toward false-pass rather than
flake: the assertion could not distinguish "the mechanism ran and correctly stayed quiet"
from "the mechanism had not run yet".
ScriptDeadlineAtEnqueueTests (two sleeps, the worst offender)
- :105 Thread.Sleep(2s) — now two explicit edges: the run must be observably QUEUED
(scheduler.QueueDepth >= 1, never checked before), then the wait polls until the 1 s
budget has elapsed, bailing early if the run leaves the queue, and asserts it is STILL
queued afterwards. The test now proves the design claim it was named for — queue wait
burns the run's budget — instead of assuming it.
- :128 Thread.Sleep(2s) + Assert.Equal(0, DetachedThreadCount) — replaced by a positive
control: a second script that genuinely wedges a worker, on the same scheduler, same
1 s timeout + 1 s grace, armed strictly later. Its stuck report is the edge; once it
lands, every watchdog armed at or before it has provably finished its grace delay. The
absence is then asserted per script name, and the detach counter is pinned at 1 (the
wedged run) rather than 0 — which a counter that never moves also satisfied.
DeploymentWarmThenGateTests (:117 plus two sibling Task.Delay(500) startup waits)
- The manager calls SetInstanceCounts unconditionally when its startup config load
completes, so a report counter on the test collector is the startup edge. The
empty-site zero is now the manager's own observation instead of an untouched field.
SiteAlarmLiveCacheServiceTests (:195, :216)
- Both sampled IsLive once after a fixed sleep. Now they poll continuously across three
linger windows on a new teardown observable (the mock client counts subscription
cancellations), so a stop at any instant inside the window is caught, and each closes
with a positive control proving that counter moves.
DataConnectionActorTests (:435)
- A Task.Delay(200) "settle" after an AwaitCondition on a connect counter. The counter
only proves ConnectAsync was CALLED; the actor is still Connecting until it processes
the piped result. Now waits for the Connected health publication that BecomeConnected
emits, so the subscribe under test provably runs against Connected rather than being
silently stashed. (The stash path keeps its own coverage in
WP6_ConnectingState_StashesSubscribeRequests.)
Negative controls (product broken in the working tree, old vs new test compared):
- Stuck-script watchdog disabled entirely: OLD test passed 2/2, NEW test failed. The
whole watchdog could be deleted and the old assertions were satisfied.
- Startup reporting a phantom instance count and taking longer than 500 ms: OLD passed
2/2, NEW failed (expected 0, actual 1).
- Linger cancellation disabled + the remaining-viewer guard dropped, so the stream is
torn down under a live viewer while IsLive keeps reporting true:
Resubscribe_Within_Linger OLD passed 2/2, NEW failed. (Last_Viewer_Leaving caught this
particular break in the old form too, via a later assertion — its strengthening is the
teardown observable and the positive control, not a false-pass fix.)
- DataConnectionActorTests :435 has no false-pass demo: the sleep guarded no assertion
there, and the change is determinism plus proving the claimed state.
Also fixes a latent race these timing changes exposed in
InstanceActorChildAttributeRaceTests: it resolved child actors single-shot immediately
after construction, but ResolveOne throws until the child's cell is published on the
parent AND the cell's Actor property stays null until the child's constructor has run on
its own mailbox thread. Neither is ordered against the test thread, so it failed both ways
under full-suite load (~1 run in 6 once the sleeps above stopped padding the schedule;
14/14 green on the unmodified tree, so it was latent, not new). Resolution now retries to
a bounded deadline; the assertion is unchanged.
Verification: SiteRuntime.Tests 8/8 green (605 tests), Communication.Tests 3/3 (717),
DataConnectionLayer.Tests 3/3 (319). Test-only change — no src/ modifications.
206 lines
11 KiB
C#
206 lines
11 KiB
C#
using Akka.Actor;
|
|
using Akka.TestKit.Xunit2;
|
|
using Microsoft.CodeAnalysis.CSharp.Scripting;
|
|
using Microsoft.CodeAnalysis.Scripting;
|
|
using Microsoft.Extensions.Logging.Abstractions;
|
|
using ZB.MOM.WW.ScadaBridge.Commons.Messages.ScriptExecution;
|
|
using ZB.MOM.WW.ScadaBridge.Commons.Types.Flattening;
|
|
using ZB.MOM.WW.ScadaBridge.SiteRuntime.Actors;
|
|
using ZB.MOM.WW.ScadaBridge.SiteRuntime.Scripts;
|
|
using ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests.TestSupport;
|
|
|
|
namespace ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests.Actors;
|
|
|
|
/// <summary>
|
|
/// WP3.1 test group 3 — a script's execution deadline is armed when the run is ENQUEUED, not
|
|
/// when it is dequeued.
|
|
///
|
|
/// <para>Before WP3.1 the deadline <see cref="CancellationTokenSource"/> was constructed inside
|
|
/// the queued body, so a run that spent ten minutes waiting behind blocked scripts still got a
|
|
/// fresh full 30 s budget when it finally started — and then ran work whose triggering
|
|
/// condition was long stale. Now queue wait consumes the run's own budget, and a body that
|
|
/// dequeues past its deadline is SHED at dequeue: it never executes, and takes the existing
|
|
/// timeout path (site event, script-error counter, error reply, completion message).</para>
|
|
/// </summary>
|
|
public class ScriptDeadlineAtEnqueueTests : TestKit, IDisposable
|
|
{
|
|
private readonly SharedScriptLibrary _sharedLibrary;
|
|
|
|
public ScriptDeadlineAtEnqueueTests()
|
|
{
|
|
var compilationService = new ScriptCompilationService(
|
|
NullLogger<ScriptCompilationService>.Instance);
|
|
_sharedLibrary = new SharedScriptLibrary(
|
|
compilationService, NullLogger<SharedScriptLibrary>.Instance);
|
|
DeadlineHooks.Gate = new SemaphoreSlim(0);
|
|
DeadlineHooks.SecondScriptRan = false;
|
|
}
|
|
|
|
void IDisposable.Dispose()
|
|
{
|
|
DeadlineHooks.Gate.Release(8);
|
|
Shutdown();
|
|
}
|
|
|
|
private static Script<object?> CompileRaw(string code)
|
|
{
|
|
var options = ScriptOptions.Default
|
|
.WithReferences(typeof(object).Assembly, typeof(Enumerable).Assembly,
|
|
typeof(DeadlineHooks).Assembly)
|
|
.WithImports("System", "System.Collections.Generic", "System.Linq", "System.Threading.Tasks");
|
|
var script = CSharpScript.Create<object?>(code, options, typeof(ScriptGlobals));
|
|
script.Compile();
|
|
return script;
|
|
}
|
|
|
|
private IActorRef BuildScriptActor(
|
|
string name, Script<object?> compiled, SiteRuntimeOptions options,
|
|
ScriptExecutionScheduler scheduler, IServiceProvider? serviceProvider)
|
|
{
|
|
var instance = CreateTestProbe().Ref;
|
|
var config = new ResolvedScript { CanonicalName = name, TriggerType = "Call" };
|
|
return ActorOf(Props.Create(() => new ScriptActor(
|
|
name, "Inst1", instance, compiled, config, _sharedLibrary, options,
|
|
NullLogger<ScriptActor>.Instance, null, null, null, serviceProvider, scheduler, null)));
|
|
}
|
|
|
|
[Fact]
|
|
public void ARunThatDequeuesPastItsDeadline_IsShedWithoutExecutingItsBody()
|
|
{
|
|
using var scheduler = new ScriptExecutionScheduler(1);
|
|
var siteLog = new FakeSiteEventLogger();
|
|
|
|
// The single worker is held by a first script for longer than the second script's
|
|
// entire timeout.
|
|
var blocker = BuildScriptActor(
|
|
"Blocker",
|
|
CompileRaw("ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests.Actors.DeadlineHooks.Gate.Wait(); return null;"),
|
|
new SiteRuntimeOptions { ScriptExecutionTimeoutSeconds = 120, StuckScriptGraceMs = 120_000 },
|
|
scheduler, null);
|
|
blocker.Tell(new ScriptCallRequest("Blocker", null, 0, "corr-blocker"), ActorRefs.NoSender);
|
|
AwaitAssert(() => Assert.Equal(1, scheduler.BusyThreadCount), TimeSpan.FromSeconds(15));
|
|
|
|
// A 1 s script queued behind it. Its grace is generous so that if the watchdog DID
|
|
// fire it would have ample opportunity to emit — the assertion below is that it does not.
|
|
var lateOptions = new SiteRuntimeOptions
|
|
{
|
|
ScriptExecutionTimeoutSeconds = 1,
|
|
StuckScriptGraceMs = 1000,
|
|
// WP3.2 defaults per-run Started/Completed events OFF, which would make the
|
|
// "no started event" assertion below vacuously true whether the body ran or not.
|
|
// Opt back in so that assertion actually discriminates: a body that reached the
|
|
// run loop WOULD emit "started" here, and its absence is therefore evidence.
|
|
PerRunScriptEvents = true
|
|
};
|
|
var late = BuildScriptActor(
|
|
"Late",
|
|
CompileRaw(
|
|
"ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests.Actors.DeadlineHooks.SecondScriptRan = true; return 1;"),
|
|
lateOptions, scheduler, new SingleServiceProvider(siteLog));
|
|
|
|
var caller = CreateTestProbe();
|
|
late.Tell(new ScriptCallRequest("Late", null, 0, "corr-late"), caller.Ref);
|
|
|
|
// Register row 40 — edge 1 (replaces a bare Thread.Sleep(2s)): the late run must
|
|
// actually be SITTING IN THE SCHEDULER QUEUE. The old test only slept and hoped;
|
|
// a blocker that failed to occupy the worker would have let the late run execute
|
|
// normally, and the shed-at-dequeue path under test would never have been reached.
|
|
AwaitCondition(() => scheduler.QueueDepth >= 1, TimeSpan.FromSeconds(15),
|
|
TimeSpan.FromMilliseconds(25));
|
|
|
|
// Register row 40 — edge 2: hold until the late run's 1 s budget has provably
|
|
// elapsed, re-reading the queue on every poll and bailing out early the instant the
|
|
// run leaves the queue. The post-condition below then proves the budget burned
|
|
// *while queued* — the actual design claim ("queue wait consumes the run's budget"),
|
|
// which a fixed sleep asserted nothing about.
|
|
var queuedFor = System.Diagnostics.Stopwatch.StartNew();
|
|
AwaitCondition(
|
|
() => queuedFor.Elapsed >= TimeSpan.FromSeconds(1.5) || scheduler.QueueDepth == 0,
|
|
TimeSpan.FromSeconds(15), TimeSpan.FromMilliseconds(25));
|
|
Assert.True(scheduler.QueueDepth >= 1,
|
|
"the late run left the queue before its budget elapsed, so this run never " +
|
|
"exercised the shed-at-dequeue path");
|
|
|
|
DeadlineHooks.Gate.Release();
|
|
|
|
var result = caller.ExpectMsg<ScriptCallResult>(TimeSpan.FromSeconds(15));
|
|
Assert.False(result.Success);
|
|
Assert.Contains("timed out", result.ErrorMessage);
|
|
|
|
// The body never ran: stale work is shed at dequeue rather than executed late.
|
|
Assert.False(DeadlineHooks.SecondScriptRan,
|
|
"the queued body executed even though its deadline had already passed");
|
|
|
|
AwaitAssert(() =>
|
|
{
|
|
var rows = siteLog.OfType("script");
|
|
// Timeout path only — no "started" Info event, because the body was skipped.
|
|
// Per-run events are ON for this script (see lateOptions), so this absence is a
|
|
// real signal rather than the global default.
|
|
Assert.Contains(rows, r => r.Severity == "Error" && r.Message.Contains("timed out"));
|
|
Assert.DoesNotContain(rows, r => r.Message.Contains("started", StringComparison.OrdinalIgnoreCase));
|
|
}, TimeSpan.FromSeconds(5));
|
|
|
|
// ── Register row 40 — the watchdog absence, proved by a positive control ──
|
|
//
|
|
// The claim is that the shed run was NOT reported as a stuck thread: it was cancelled
|
|
// while queued, so it never held a worker. The old test slept 2 s and asserted the
|
|
// absence, which false-passes whenever the watchdog simply had not got around to
|
|
// evaluating anything yet — the assertion could not distinguish "the watchdog looked
|
|
// and correctly stayed silent" from "the watchdog never looked".
|
|
//
|
|
// So: enqueue a script that genuinely wedges a worker, on the SAME scheduler and with
|
|
// the SAME 1 s timeout + 1 s grace, and armed strictly LATER than the late run's
|
|
// watchdog. Its stuck report is the observable edge — once it lands, every watchdog
|
|
// armed at or before it has provably run its grace delay and made its decision.
|
|
//
|
|
// The body blocks its worker SYNCHRONOUSLY (so the watchdog can detach the thread it
|
|
// holds) but for a BOUNDED 2.5 s that comfortably clears 1 s timeout + 1 s grace and
|
|
// then self-releases. A gate held until test teardown would work too, but it leaves a
|
|
// blocked OS thread alive past the test and perturbs timing-sensitive tests elsewhere
|
|
// in this assembly.
|
|
var wedged = BuildScriptActor(
|
|
"Wedged",
|
|
CompileRaw("System.Threading.Thread.Sleep(2500); return null;"),
|
|
new SiteRuntimeOptions { ScriptExecutionTimeoutSeconds = 1, StuckScriptGraceMs = 1000 },
|
|
scheduler, new SingleServiceProvider(siteLog));
|
|
wedged.Tell(new ScriptCallRequest("Wedged", null, 0, "corr-wedged"), ActorRefs.NoSender);
|
|
|
|
// Positive event, bounded wait: the watchdog fires, names the wedged script and
|
|
// detaches its worker.
|
|
AwaitAssert(() =>
|
|
{
|
|
Assert.Contains(siteLog.OfType("script"),
|
|
r => r.Message.Contains("'Wedged'", StringComparison.Ordinal) &&
|
|
r.Message.Contains("still executing", StringComparison.OrdinalIgnoreCase));
|
|
}, TimeSpan.FromSeconds(30), TimeSpan.FromMilliseconds(50));
|
|
|
|
// Negative control, evaluated only now that a later-armed watchdog has demonstrably
|
|
// completed its grace delay: the shed run was never reported stuck.
|
|
Assert.DoesNotContain(siteLog.OfType("script"),
|
|
r => r.Message.Contains("'Late'", StringComparison.Ordinal) &&
|
|
r.Message.Contains("still executing", StringComparison.OrdinalIgnoreCase));
|
|
|
|
// And the detach counter moved for exactly one run — the wedged one. The old
|
|
// `Assert.Equal(0, DetachedThreadCount)` was satisfied by a counter that never moves
|
|
// for any reason; this pins that it does move, and that the shed run did not move it.
|
|
Assert.Equal(1, scheduler.DetachedThreadCount);
|
|
|
|
// Wait for the positive control's body to unwind and its detached worker to exit
|
|
// BEFORE the scheduler is disposed at end of scope, so the test leaves no threads
|
|
// behind for the rest of the assembly to contend with.
|
|
AwaitCondition(() => scheduler.BusyThreadCount == 0 && scheduler.DetachedThreadCount == 0,
|
|
TimeSpan.FromSeconds(20), TimeSpan.FromMilliseconds(25));
|
|
}
|
|
}
|
|
|
|
/// <summary>Test hooks for the enqueue-anchored deadline test.</summary>
|
|
public static class DeadlineHooks
|
|
{
|
|
/// <summary>Gate the blocking first script waits on.</summary>
|
|
public static SemaphoreSlim Gate = new(0);
|
|
|
|
/// <summary>Set by the second script's body — must stay false when the run is shed at dequeue.</summary>
|
|
public static bool SecondScriptRan;
|
|
}
|