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; /// /// WP3.1 test group 3 — a script's execution deadline is armed when the run is ENQUEUED, not /// when it is dequeued. /// /// Before WP3.1 the deadline 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). /// public class ScriptDeadlineAtEnqueueTests : TestKit, IDisposable { private readonly SharedScriptLibrary _sharedLibrary; public ScriptDeadlineAtEnqueueTests() { var compilationService = new ScriptCompilationService( NullLogger.Instance); _sharedLibrary = new SharedScriptLibrary( compilationService, NullLogger.Instance); DeadlineHooks.Gate = new SemaphoreSlim(0); DeadlineHooks.SecondScriptRan = false; } void IDisposable.Dispose() { DeadlineHooks.Gate.Release(8); Shutdown(); } private static Script 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(code, options, typeof(ScriptGlobals)); script.Compile(); return script; } private IActorRef BuildScriptActor( string name, Script 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.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(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)); } } /// Test hooks for the enqueue-anchored deadline test. public static class DeadlineHooks { /// Gate the blocking first script waits on. public static SemaphoreSlim Gate = new(0); /// Set by the second script's body — must stay false when the run is shed at dequeue. public static bool SecondScriptRan; }