fix(siteruntime): arm stuck-script watchdog + health/summary on alarm runs (arch-review 2026-08-19 P1-3)

Alarm on-trigger runs (ScriptRunLauncher.RunAlarmScriptAsync) bypassed the
stuck-script watchdog, the script-error health counter, and
ScriptRunSummaryRecorder entirely, even though they run on the same bounded
ScriptExecutionScheduler pool as instance scripts. A wedged alarm body cost a
pool thread forever with no site event and no detach/replace, and a timed-out
or failed on-trigger run was invisible to health monitoring and the run
summary.

Bring the alarm path to parity with the instance-script path (RunScriptAsync):
capture the worker slot/run stamp in the first synchronous segment and arm
ArmStuckScriptWatchdog with the same detach-and-replace semantics and gauge;
resolve ScriptRunSummaryRecorder/ISiteEventLogger from the same DI provider and
thread RecordStarted/RecordCompleted/RecordFailed/RecordTimedOut; increment
ISiteHealthCollector.IncrementScriptError on both the timeout and general
failure catch blocks. LaunchAlarmScript/RunAlarmScriptAsync now take
healthCollector and serviceProvider parameters, passed from AlarmActor's
existing _healthCollector/_serviceProvider fields. No change to the
enqueue-anchored deadline, the shed cap, or "a stop does NOT cancel an
in-flight run" semantics.

Adds AlarmScriptWatchdogTests (previously zero coverage of LaunchAlarmScript):
wedged-worker detach + replacement, timeout-at-dequeue health counter
increment, and successful-completion summary recording. All three fail
against the pre-fix code (verified via stash) and pass after.
This commit is contained in:
Joseph Doherty
2026-08-19 14:37:24 -04:00
parent 91fcb5b951
commit fd4cb30273
3 changed files with 299 additions and 1 deletions
@@ -825,6 +825,11 @@ public class AlarmActor : ReceiveActor
// Context.Parent.Tell from the execution actor. // Context.Parent.Tell from the execution actor.
Self, Self,
_logger, _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, runId,
// Per-script timeout from the on-trigger script (null = global). // Per-script timeout from the on-trigger script (null = global).
_onTriggerExecutionTimeoutSeconds, _onTriggerExecutionTimeoutSeconds,
@@ -138,6 +138,18 @@ internal static class ScriptRunLauncher
/// <param name="options">Site runtime configuration options, including the execution timeout.</param> /// <param name="options">Site runtime configuration options, including the execution timeout.</param>
/// <param name="completionTarget">The owning <see cref="AlarmActor"/>, which receives the completion message.</param> /// <param name="completionTarget">The owning <see cref="AlarmActor"/>, which receives the completion message.</param>
/// <param name="logger">Logger for execution diagnostics.</param> /// <param name="logger">Logger for execution diagnostics.</param>
/// <param name="healthCollector">
/// 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
/// <see cref="RunScriptAsync"/> so a wedged/failed alarm body is visible the same way a
/// wedged/failed instance script is.
/// </param>
/// <param name="serviceProvider">
/// Optional DI service provider (arch-review 2026-08-19 P1-3): resolves the singleton
/// <see cref="ISiteEventLogger"/> (stuck-watchdog reporting) and
/// <see cref="ScriptRunSummaryRecorder"/> (aggregate run counters), exactly like the
/// instance-script path.
/// </param>
/// <param name="runId">Per-alarm run counter, used only in log messages.</param> /// <param name="runId">Per-alarm run counter, used only in log messages.</param>
/// <param name="executionTimeoutSeconds">The on-trigger script's per-script timeout in seconds. Null or non-positive falls back to the global value.</param> /// <param name="executionTimeoutSeconds">The on-trigger script's per-script timeout in seconds. Null or non-positive falls back to the global value.</param>
/// <param name="parentExecutionId"> /// <param name="parentExecutionId">
@@ -158,6 +170,8 @@ internal static class ScriptRunLauncher
SiteRuntimeOptions options, SiteRuntimeOptions options,
IActorRef completionTarget, IActorRef completionTarget,
ILogger logger, ILogger logger,
ISiteHealthCollector? healthCollector,
IServiceProvider? serviceProvider,
long runId, long runId,
int? executionTimeoutSeconds, int? executionTimeoutSeconds,
Guid? parentExecutionId, Guid? parentExecutionId,
@@ -174,7 +188,8 @@ internal static class ScriptRunLauncher
() => RunAlarmScriptAsync( () => RunAlarmScriptAsync(
alarmName, instanceName, level, priority, message, compiledScript, alarmName, instanceName, level, priority, message, compiledScript,
instanceActor, sharedScriptLibrary, options, completionTarget, logger, instanceActor, sharedScriptLibrary, options, completionTarget, logger,
runId, parentExecutionId, timeout, cts), healthCollector, serviceProvider, runId, parentExecutionId, timeout,
executionScheduler, cts),
CancellationToken.None, TaskCreationOptions.DenyChildAttach, executionScheduler) CancellationToken.None, TaskCreationOptions.DenyChildAttach, executionScheduler)
.Unwrap(); .Unwrap();
} }
@@ -463,11 +478,42 @@ internal static class ScriptRunLauncher
SiteRuntimeOptions options, SiteRuntimeOptions options,
IActorRef completionTarget, IActorRef completionTarget,
ILogger logger, ILogger logger,
ISiteHealthCollector? healthCollector,
IServiceProvider? serviceProvider,
long runId, long runId,
Guid? parentExecutionId, Guid? parentExecutionId,
TimeSpan timeout, TimeSpan timeout,
ScriptExecutionScheduler executionScheduler,
CancellationTokenSource cts) 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<ISiteEventLogger>();
var summaryRecorder = serviceProvider?.GetService<ScriptRunSummaryRecorder>();
// 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 try
{ {
// Enqueue-anchored deadline: an already-cancelled token means this on-trigger run // 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); await compiledScript.RunAsync(globals, cts.Token);
summaryRecorder?.RecordCompleted(instanceName, scriptName, runStopwatch.ElapsedMilliseconds);
completionTarget.Tell(new AlarmActor.AlarmExecutionCompleted(alarmName, true)); completionTarget.Tell(new AlarmActor.AlarmExecutionCompleted(alarmName, true));
} }
catch (OperationCanceledException) catch (OperationCanceledException)
{ {
healthCollector?.IncrementScriptError();
summaryRecorder?.RecordTimedOut(instanceName, scriptName, runStopwatch.ElapsedMilliseconds);
logger.LogWarning( logger.LogWarning(
"Alarm on-trigger script for {Alarm} on {Instance} timed out (run {RunId})", "Alarm on-trigger script for {Alarm} on {Instance} timed out (run {RunId})",
alarmName, instanceName, runId); alarmName, instanceName, runId);
@@ -524,6 +575,8 @@ internal static class ScriptRunLauncher
} }
catch (Exception ex) catch (Exception ex)
{ {
healthCollector?.IncrementScriptError();
summaryRecorder?.RecordFailed(instanceName, scriptName, runStopwatch.ElapsedMilliseconds);
// Failures logged, alarm continues // Failures logged, alarm continues
logger.LogError(ex, logger.LogError(ex,
"Alarm on-trigger script for {Alarm} on {Instance} failed (run {RunId})", "Alarm on-trigger script for {Alarm} on {Instance} failed (run {RunId})",
@@ -532,6 +585,9 @@ internal static class ScriptRunLauncher
} }
finally 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(); cts.Dispose();
} }
} }
@@ -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;
/// <summary>
/// arch-review 2026-08-19 P1-3 — alarm on-trigger runs used to bypass the stuck-script
/// watchdog, the script-error health counter, and <see cref="ScriptRunSummaryRecorder"/>
/// entirely: <c>ScriptRunLauncher.RunAlarmScriptAsync</c> carried none of the machinery its
/// sibling <c>RunScriptAsync</c> (the instance-script path) carries, on the SAME bounded
/// <see cref="ScriptExecutionScheduler"/> pool. A wedged alarm body cost a pool thread
/// forever with no site event, no detach/replace, and <c>DetachedScriptThreads</c> stayed 0;
/// a timed-out or failed on-trigger run never touched the health collector or the run-summary
/// counters either.
///
/// <para>These tests mirror <see cref="StuckScriptWatchdogTests"/> and
/// <see cref="ScriptDeadlineAtEnqueueTests"/> exactly, but drive an <see cref="AlarmActor"/>
/// on-trigger run (via a <c>ValueMatch</c> raise) instead of a <see cref="ScriptActor"/>
/// <c>Call</c>.</para>
/// </summary>
public class AlarmScriptWatchdogTests : TestKit, IDisposable
{
private readonly SharedScriptLibrary _sharedLibrary;
public AlarmScriptWatchdogTests()
{
var compilationService = new ScriptCompilationService(
NullLogger<ScriptCompilationService>.Instance);
_sharedLibrary = new SharedScriptLibrary(
compilationService, NullLogger<SharedScriptLibrary>.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<object?> 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<object?>(code, scriptOptions, typeof(ScriptGlobals));
script.Compile();
return script;
}
/// <summary>A body that blocks its worker thread outright — cooperative cancellation is never observed.</summary>
private static Script<object?> WedgeScript() => CompileRaw(
"ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests.Actors.AlarmWatchdogHooks.Gate.Wait(); return null;");
private TestActorRef<AlarmActor> BuildAlarmActor(
string alarmName,
Script<object?> 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<AlarmActor>(
Props.Create(() => new AlarmActor(
alarmName, "Inst1", instance, config, compiled, _sharedLibrary, options,
NullLogger<AlarmActor>.Instance, null, null, healthCollector, serviceProvider,
null, scheduler, null)),
"alarm-watchdog-" + Guid.NewGuid().ToString("N"));
}
/// <summary>Raises the ValueMatch condition (Normal → Active), spawning the on-trigger run.</summary>
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);
}
}
/// <summary>
/// Test hook the alarm stuck-script watchdog tests use to block a script-execution thread
/// deterministically: the compiled body waits on <see cref="Gate"/>, which the test releases
/// once it has observed the detach (or at teardown).
/// </summary>
public static class AlarmWatchdogHooks
{
/// <summary>Gate a blocking test script waits on; reset per test.</summary>
public static SemaphoreSlim Gate = new(0);
}