diff --git a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Actors/AlarmActor.cs b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Actors/AlarmActor.cs index e7ba30c2..85479ae8 100644 --- a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Actors/AlarmActor.cs +++ b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Actors/AlarmActor.cs @@ -825,6 +825,11 @@ public class AlarmActor : ReceiveActor // Context.Parent.Tell from the execution actor. Self, _logger, + // arch-review 2026-08-19 P1-3: same health collector + service provider as + // the instance-script path, so the alarm on-trigger run gets the same + // stuck-script watchdog, script-error counting, and run-summary threading. + _healthCollector, + _serviceProvider, runId, // Per-script timeout from the on-trigger script (null = global). _onTriggerExecutionTimeoutSeconds, diff --git a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs index 5a3c99ea..95395553 100644 --- a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs +++ b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs @@ -138,6 +138,18 @@ internal static class ScriptRunLauncher /// Site runtime configuration options, including the execution timeout. /// The owning , which receives the completion message. /// Logger for execution diagnostics. + /// + /// Optional health collector for recording execution metrics (arch-review 2026-08-19 + /// P1-3): the alarm on-trigger run shares the script-error counter with + /// so a wedged/failed alarm body is visible the same way a + /// wedged/failed instance script is. + /// + /// + /// Optional DI service provider (arch-review 2026-08-19 P1-3): resolves the singleton + /// (stuck-watchdog reporting) and + /// (aggregate run counters), exactly like the + /// instance-script path. + /// /// Per-alarm run counter, used only in log messages. /// The on-trigger script's per-script timeout in seconds. Null or non-positive falls back to the global value. /// @@ -158,6 +170,8 @@ internal static class ScriptRunLauncher SiteRuntimeOptions options, IActorRef completionTarget, ILogger logger, + ISiteHealthCollector? healthCollector, + IServiceProvider? serviceProvider, long runId, int? executionTimeoutSeconds, Guid? parentExecutionId, @@ -174,7 +188,8 @@ internal static class ScriptRunLauncher () => RunAlarmScriptAsync( alarmName, instanceName, level, priority, message, compiledScript, instanceActor, sharedScriptLibrary, options, completionTarget, logger, - runId, parentExecutionId, timeout, cts), + healthCollector, serviceProvider, runId, parentExecutionId, timeout, + executionScheduler, cts), CancellationToken.None, TaskCreationOptions.DenyChildAttach, executionScheduler) .Unwrap(); } @@ -463,11 +478,42 @@ internal static class ScriptRunLauncher SiteRuntimeOptions options, IActorRef completionTarget, ILogger logger, + ISiteHealthCollector? healthCollector, + IServiceProvider? serviceProvider, long runId, Guid? parentExecutionId, TimeSpan timeout, + ScriptExecutionScheduler executionScheduler, CancellationTokenSource cts) { + // arch-review 2026-08-19 P1-3: singletons resolved from the root provider up front, + // exactly like RunScriptAsync, so they are available to the catch blocks regardless + // of scope state. Null in tests that pass no serviceProvider — degrades the same way + // the instance-script path does (no site event log / no aggregate counters). + var siteEventLogger = serviceProvider?.GetService(); + var summaryRecorder = serviceProvider?.GetService(); + + // The on-trigger run has no per-script name of its own in the site-event/summary + // sense — key it under the alarm, mirroring the "AlarmActor:{name}" source + // convention already used for this alarm's other site events. + var scriptName = $"AlarmActor:{alarmName}"; + var runStopwatch = Stopwatch.StartNew(); + + // arch-review 2026-08-19 P1-3: identify the worker this body is holding, so the + // stuck-script watchdog can detach and replace it if the body wedges — same + // mechanism, same gauge, as the instance-script path. Read in the FIRST synchronous + // segment, before any await. + var workerSlot = ScriptExecutionScheduler.CurrentWorkerSlot; + var workerRunStamp = workerSlot is { } slot ? executionScheduler.CurrentRunStamp(slot) : 0L; + + var completed = 0; + ArmStuckScriptWatchdog( + cts, options, logger, siteEventLogger, executionScheduler, + workerSlot, workerRunStamp, timeout, + () => Volatile.Read(ref completed) != 0, + $"Alarm on-trigger script for '{alarmName}' on instance '{instanceName}'", + instanceName, scriptName); + try { // Enqueue-anchored deadline: an already-cancelled token means this on-trigger run @@ -511,12 +557,17 @@ internal static class ScriptRunLauncher } }; + summaryRecorder?.RecordStarted(instanceName, scriptName); + await compiledScript.RunAsync(globals, cts.Token); + summaryRecorder?.RecordCompleted(instanceName, scriptName, runStopwatch.ElapsedMilliseconds); completionTarget.Tell(new AlarmActor.AlarmExecutionCompleted(alarmName, true)); } catch (OperationCanceledException) { + healthCollector?.IncrementScriptError(); + summaryRecorder?.RecordTimedOut(instanceName, scriptName, runStopwatch.ElapsedMilliseconds); logger.LogWarning( "Alarm on-trigger script for {Alarm} on {Instance} timed out (run {RunId})", alarmName, instanceName, runId); @@ -524,6 +575,8 @@ internal static class ScriptRunLauncher } catch (Exception ex) { + healthCollector?.IncrementScriptError(); + summaryRecorder?.RecordFailed(instanceName, scriptName, runStopwatch.ElapsedMilliseconds); // Failures logged, alarm continues logger.LogError(ex, "Alarm on-trigger script for {Alarm} on {Instance} failed (run {RunId})", @@ -532,6 +585,9 @@ internal static class ScriptRunLauncher } finally { + // Mark the body finished so the stuck-script watchdog (registered on + // cts.Token above) treats a timely cancellation as NOT stuck. + Interlocked.Exchange(ref completed, 1); cts.Dispose(); } } diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/AlarmScriptWatchdogTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/AlarmScriptWatchdogTests.cs new file mode 100644 index 00000000..c38de82a --- /dev/null +++ b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/AlarmScriptWatchdogTests.cs @@ -0,0 +1,237 @@ +using Akka.Actor; +using Akka.TestKit; +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.Streaming; +using ZB.MOM.WW.ScadaBridge.Commons.Types.Flattening; +using ZB.MOM.WW.ScadaBridge.HealthMonitoring; +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; + +/// +/// arch-review 2026-08-19 P1-3 — alarm on-trigger runs used to bypass the stuck-script +/// watchdog, the script-error health counter, and +/// entirely: ScriptRunLauncher.RunAlarmScriptAsync carried none of the machinery its +/// sibling RunScriptAsync (the instance-script path) carries, on the SAME bounded +/// pool. A wedged alarm body cost a pool thread +/// forever with no site event, no detach/replace, and DetachedScriptThreads stayed 0; +/// a timed-out or failed on-trigger run never touched the health collector or the run-summary +/// counters either. +/// +/// These tests mirror and +/// exactly, but drive an +/// on-trigger run (via a ValueMatch raise) instead of a +/// Call. +/// +public class AlarmScriptWatchdogTests : TestKit, IDisposable +{ + private readonly SharedScriptLibrary _sharedLibrary; + + public AlarmScriptWatchdogTests() + { + var compilationService = new ScriptCompilationService( + NullLogger.Instance); + _sharedLibrary = new SharedScriptLibrary( + compilationService, NullLogger.Instance); + AlarmWatchdogHooks.Gate = new SemaphoreSlim(0); + } + + void IDisposable.Dispose() + { + // Free any still-wedged worker before tearing down, so no test leaves a blocked thread. + AlarmWatchdogHooks.Gate.Release(8); + Shutdown(); + } + + private static Script CompileRaw(string code) + { + var scriptOptions = ScriptOptions.Default + .WithReferences(typeof(object).Assembly, typeof(Enumerable).Assembly, + typeof(AlarmWatchdogHooks).Assembly) + .WithImports("System", "System.Collections.Generic", "System.Linq", "System.Threading.Tasks"); + var script = CSharpScript.Create(code, scriptOptions, typeof(ScriptGlobals)); + script.Compile(); + return script; + } + + /// A body that blocks its worker thread outright — cooperative cancellation is never observed. + private static Script WedgeScript() => CompileRaw( + "ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests.Actors.AlarmWatchdogHooks.Gate.Wait(); return null;"); + + private TestActorRef BuildAlarmActor( + string alarmName, + Script compiled, + SiteRuntimeOptions options, + ScriptExecutionScheduler scheduler, + IServiceProvider? serviceProvider, + ISiteHealthCollector? healthCollector = null) + { + var instance = CreateTestProbe().Ref; + var config = new ResolvedAlarm + { + CanonicalName = alarmName, + TriggerType = "ValueMatch", + TriggerConfiguration = "{\"attributeName\":\"Status\",\"matchValue\":\"Critical\"}", + PriorityLevel = 100 + }; + return ActorOfAsTestActorRef( + Props.Create(() => new AlarmActor( + alarmName, "Inst1", instance, config, compiled, _sharedLibrary, options, + NullLogger.Instance, null, null, healthCollector, serviceProvider, + null, scheduler, null)), + "alarm-watchdog-" + Guid.NewGuid().ToString("N")); + } + + /// Raises the ValueMatch condition (Normal → Active), spawning the on-trigger run. + private static void Raise(IActorRef alarm, string instanceName = "Inst1") => + alarm.Tell(new AttributeValueChanged( + instanceName, "Status", "Status", "Critical", "Good", DateTimeOffset.UtcNow)); + + private static SiteRuntimeOptions WatchdogOptions() => new() + { + ScriptExecutionTimeoutSeconds = 1, + StuckScriptGraceMs = 200, + MaxScriptCallDepth = 10 + }; + + [Fact] + public void WedgedAlarmScript_DetachesItsWorker_StartsAReplacement_AndDrainsWhenFreed() + { + using var scheduler = new ScriptExecutionScheduler(1); + var siteLog = new FakeSiteEventLogger(); + var options = WatchdogOptions(); + + var wedged = BuildAlarmActor("Wedged", WedgeScript(), options, scheduler, + new SingleServiceProvider(siteLog)); + Raise(wedged); + + // Timeout (1 s) + grace (200 ms) later the watchdog fires: the worker is detached and + // a replacement thread starts — exactly like the instance-script path. + AwaitAssert( + () => Assert.Equal(1, scheduler.DetachedThreadCount), + TimeSpan.FromSeconds(15)); + + AwaitAssert( + () => Assert.Contains(siteLog.OfType("script"), r => + r.Severity == "Error" && + r.Message.Contains("still executing", StringComparison.OrdinalIgnoreCase) && + r.Message.Contains("Wedged") && + r.Message.Contains("DETACHED")), + TimeSpan.FromSeconds(5)); + + // The replacement worker is live: a fresh alarm on-trigger run completes even though + // the pool's only original thread is still blocked. Before this fix there was no + // detach at all, so a second wedge would have starved the whole pool. + var healthy = BuildAlarmActor("Healthy", CompileRaw("return 7;"), options, scheduler, null); + Raise(healthy); + AwaitAssert( + () => Assert.Equal(0, healthy.UnderlyingActor.RunsInFlight), + TimeSpan.FromSeconds(15)); + + // Freeing the wedged body lets the detached worker exit rather than pull more work, + // so the pool does not silently end up double-sized. + AlarmWatchdogHooks.Gate.Release(); + AwaitAssert( + () => Assert.Equal(0, scheduler.DetachedThreadCount), + TimeSpan.FromSeconds(15)); + Assert.Equal(1, scheduler.MaximumConcurrencyLevel); + } + + [Fact] + public void AlarmRunTimedOutAtDequeue_IncrementsHealthCollectorScriptErrorCount() + { + using var scheduler = new ScriptExecutionScheduler(1); + var siteLog = new FakeSiteEventLogger(); + var health = new SiteHealthCollector(); + + // Occupy the sole worker with a first alarm's on-trigger run, so the second alarm's + // run is queued behind it (mirrors ScriptDeadlineAtEnqueueTests' proven pattern). + var blockerOptions = new SiteRuntimeOptions + { ScriptExecutionTimeoutSeconds = 120, StuckScriptGraceMs = 120_000 }; + var blocker = BuildAlarmActor("Blocker", WedgeScript(), blockerOptions, scheduler, null); + Raise(blocker); + AwaitAssert(() => Assert.Equal(1, scheduler.BusyThreadCount), TimeSpan.FromSeconds(15)); + + // The target alarm has a 1 s budget — by the time the blocker frees the worker, this + // run's deadline has already passed, so it takes the timeout (OperationCanceledException) + // path at dequeue without ever executing its body. + var lateOptions = new SiteRuntimeOptions + { ScriptExecutionTimeoutSeconds = 1, StuckScriptGraceMs = 1000 }; + var late = BuildAlarmActor("Late", CompileRaw("return 1;"), lateOptions, scheduler, + new SingleServiceProvider(siteLog), health); + Raise(late); + + AwaitCondition(() => scheduler.QueueDepth >= 1, TimeSpan.FromSeconds(15), + TimeSpan.FromMilliseconds(25)); + + 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 alarm run left the queue before its budget elapsed, so this run never " + + "exercised the timeout-at-dequeue path"); + + AlarmWatchdogHooks.Gate.Release(); + + // Before this fix, RunAlarmScriptAsync's OperationCanceledException catch never + // touched the health collector at all — this stayed 0 forever regardless of how many + // alarm on-trigger runs timed out. + AwaitAssert( + () => Assert.Equal(1, health.CollectReport("site-1").ScriptErrorCount), + TimeSpan.FromSeconds(15)); + + // The shed-at-dequeue run never held a worker (it was cancelled before its body ran), + // so — unlike the wedged-worker test above — it must NOT be reported as stuck. + Assert.DoesNotContain(siteLog.OfType("script"), + r => r.Message.Contains("'Late'", StringComparison.Ordinal) && + r.Message.Contains("still executing", StringComparison.OrdinalIgnoreCase)); + + AwaitCondition(() => scheduler.BusyThreadCount == 0 && scheduler.DetachedThreadCount == 0, + TimeSpan.FromSeconds(20), TimeSpan.FromMilliseconds(25)); + } + + [Fact] + public async Task AlarmRunCompletion_IsRecordedByScriptRunSummaryRecorder() + { + using var scheduler = new ScriptExecutionScheduler(2); + var siteLog = new FakeSiteEventLogger(); + var recorder = new ScriptRunSummaryRecorder(); + var options = new SiteRuntimeOptions + { ScriptExecutionTimeoutSeconds = 30, StuckScriptGraceMs = 30_000 }; + + // Before this fix, RunAlarmScriptAsync never resolved or touched + // ScriptRunSummaryRecorder at all — a flush after any number of alarm runs would + // always report zero activity for them. + var alarm = BuildAlarmActor("Recorded", CompileRaw("return 42;"), options, scheduler, + new SingleServiceProvider(siteLog, summaryRecorder: recorder)); + Raise(alarm); + + AwaitAssert(() => Assert.Equal(0, alarm.UnderlyingActor.RunsInFlight), TimeSpan.FromSeconds(15)); + + var emitted = await recorder.FlushAsync(siteLog); + Assert.True(emitted); + + var rows = siteLog.OfType("script"); + var summaryRow = Assert.Single(rows, r => r.Source == "ScriptRunSummary"); + Assert.Equal("1 runs: 1 completed, 0 failed, 0 timed out across 1 scripts", summaryRow.Message); + Assert.NotNull(summaryRow.Details); + Assert.Contains("AlarmActor:Recorded", summaryRow.Details); + } +} + +/// +/// Test hook the alarm stuck-script watchdog tests use to block a script-execution thread +/// deterministically: the compiled body waits on , which the test releases +/// once it has observed the detach (or at teardown). +/// +public static class AlarmWatchdogHooks +{ + /// Gate a blocking test script waits on; reset per test. + public static SemaphoreSlim Gate = new(0); +}