perf(runtime): split trigger evals from the blocking pool; bounded, deadline-aware execution

This commit is contained in:
Joseph Doherty
2026-08-14 22:36:15 -04:00
parent 312216ff2b
commit c4fc1f8ecd
42 changed files with 3673 additions and 1251 deletions
@@ -0,0 +1,570 @@
using Akka.Actor;
using Microsoft.CodeAnalysis.Scripting;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using ZB.MOM.WW.ScadaBridge.Commons.Interfaces;
using ZB.MOM.WW.ScadaBridge.Commons.Interfaces.Services;
using ZB.MOM.WW.ScadaBridge.Commons.Messages.ScriptExecution;
using ZB.MOM.WW.ScadaBridge.Commons.Types;
using ZB.MOM.WW.ScadaBridge.Commons.Types.Enums;
using ZB.MOM.WW.ScadaBridge.Commons.Types.Scripts;
using ZB.MOM.WW.ScadaBridge.HealthMonitoring;
using ZB.MOM.WW.ScadaBridge.SiteEventLogging;
using ZB.MOM.WW.ScadaBridge.SiteRuntime.Actors;
using ZB.MOM.WW.ScadaBridge.StoreAndForward;
namespace ZB.MOM.WW.ScadaBridge.SiteRuntime.Scripts;
/// <summary>
/// WP3.1: launches one script or alarm on-trigger run directly from its owning coordinator
/// (<see cref="ScriptActor"/> / <see cref="AlarmActor"/>), replacing the short-lived
/// <c>ScriptExecutionActor</c> and <c>AlarmExecutionActor</c>.
///
/// <para>Those actors were already inert shells: neither declared a single <c>Receive</c>
/// handler (they executed from their constructor), neither had a <c>PostStop</c>, state, or
/// stash, and their <c>IActorRef</c> was never a message target — the whole lifecycle lived
/// inside a detached <see cref="Task"/> the actor never observed. What they cost was a real
/// actor cell, mailbox, and name registration per run, plus a per-spawn expression-tree
/// <c>Props.Create</c>. Removing them changes no semantics; the run body below is the former
/// <c>ExecuteScript</c>/<c>ExecuteAlarmScript</c> body, unified.</para>
///
/// <para>Two behaviours DID change, both deliberately:</para>
/// <list type="number">
/// <item>The deadline <see cref="CancellationTokenSource"/> is now armed by the CALLER,
/// before the body is queued to the <see cref="ScriptExecutionScheduler"/>, so queue wait
/// consumes the script's own budget. A body that dequeues past its deadline skips execution
/// entirely and takes the timeout path — a saturated pool sheds stale work instead of
/// running it late.</item>
/// <item>The stuck-script watchdog now DETACHES and replaces the worker thread a wedged
/// script is holding (<see cref="ScriptExecutionScheduler.TryDetachWorker"/>) instead of
/// only naming it, so the pool recovers its capacity.</item>
/// </list>
///
/// <para>Ordering, supervision, telemetry, DI scoping, Ask replies, completion messages, and
/// the audit <c>ExecutionId</c>/<c>ParentExecutionId</c> threading are all unchanged. The
/// launch call itself can throw only if the target scheduler is unusable (e.g. disposed); the
/// caller wraps it so that failure replies to the Ask caller and decrements the in-flight
/// counter rather than escalating to the coordinator's supervisor.</para>
/// </summary>
internal static class ScriptRunLauncher
{
/// <summary>
/// Launches an instance script run. Returns as soon as the body is queued; the run reports
/// completion to <paramref name="completionTarget"/>.
/// </summary>
/// <param name="scriptName">Name of the script being executed.</param>
/// <param name="instanceName">Name of the instance that owns the script.</param>
/// <param name="compiledScript">Compiled Roslyn script to execute.</param>
/// <param name="parameters">Optional named parameter values for the script.</param>
/// <param name="callDepth">Current call-nesting depth (used to enforce the max-depth limit).</param>
/// <param name="instanceActor">Instance actor reference for attribute access.</param>
/// <param name="sharedScriptLibrary">Library of shared scripts available during execution.</param>
/// <param name="options">Site runtime options applied during execution.</param>
/// <param name="replyTo">Actor reference that receives the script result; <c>Nobody</c> for fire-and-forget.</param>
/// <param name="correlationId">Application-level correlation id threaded through the execution.</param>
/// <param name="completionTarget">The owning <see cref="ScriptActor"/>, which receives the completion message.</param>
/// <param name="siteCommunicationActor">Site communication actor (resolved on the actor thread) for <c>Notify.Status</c>.</param>
/// <param name="logger">Logger for script execution events.</param>
/// <param name="scope">Script scope controlling which APIs are available.</param>
/// <param name="runId">Per-script run counter, used only in log messages (replaces the former per-run actor name).</param>
/// <param name="healthCollector">Optional health collector for recording execution metrics.</param>
/// <param name="serviceProvider">Optional DI service provider for script execution services.</param>
/// <param name="parentExecutionId">ExecutionId of the spawning execution for audit correlation; null for root runs.</param>
/// <param name="executionTimeoutSeconds">Per-script execution timeout in seconds. Null or non-positive falls back to the global value.</param>
/// <param name="scheduler">Script-execution scheduler seam (#18); null selects the process-wide shared instance.</param>
public static void LaunchScript(
string scriptName,
string instanceName,
Script<object?> compiledScript,
IReadOnlyDictionary<string, object?>? parameters,
int callDepth,
IActorRef instanceActor,
SharedScriptLibrary sharedScriptLibrary,
SiteRuntimeOptions options,
IActorRef replyTo,
string correlationId,
IActorRef completionTarget,
ICanTell? siteCommunicationActor,
ILogger logger,
ScriptScope scope,
long runId,
ISiteHealthCollector? healthCollector,
IServiceProvider? serviceProvider,
Guid? parentExecutionId,
int? executionTimeoutSeconds,
ScriptExecutionScheduler? scheduler)
{
var timeout = ResolveTimeout(executionTimeoutSeconds, options);
var executionScheduler = scheduler ?? ScriptExecutionScheduler.Shared(options);
// Armed HERE, on the caller's (actor) thread, not inside the queued body: queue wait
// must consume the script's own budget, otherwise a saturated pool silently grants
// every backlogged run a fresh full timeout.
var cts = new CancellationTokenSource(timeout);
try
{
_ = Task.Factory.StartNew(
() => RunScriptAsync(
scriptName, instanceName, compiledScript, parameters, callDepth,
instanceActor, sharedScriptLibrary, options, replyTo, correlationId,
completionTarget, siteCommunicationActor, logger, scope, runId,
healthCollector, serviceProvider, parentExecutionId, timeout,
executionScheduler, cts),
CancellationToken.None, TaskCreationOptions.DenyChildAttach, executionScheduler)
.Unwrap();
}
catch
{
// The body never got queued, so nothing will ever dispose the CTS.
cts.Dispose();
throw;
}
}
/// <summary>
/// Launches an alarm on-trigger run. Same contract as <see cref="LaunchScript"/>, with the
/// firing alarm's level/priority/message exposed to the body through the <c>Alarm</c> global.
/// </summary>
/// <param name="alarmName">The canonical name of the alarm that triggered.</param>
/// <param name="instanceName">The name of the owning instance.</param>
/// <param name="level">The alarm severity level at the time of triggering.</param>
/// <param name="priority">The alarm priority value.</param>
/// <param name="message">The alarm message to pass to the script.</param>
/// <param name="compiledScript">The pre-compiled on-trigger script to execute.</param>
/// <param name="instanceActor">Reference to the instance actor for attribute/script calls.</param>
/// <param name="sharedScriptLibrary">Shared script library providing common utilities.</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="logger">Logger for execution diagnostics.</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="parentExecutionId">
/// ParentExecutionId tag-cascade: the <c>ExecutionId</c> of the execution whose attribute
/// write fired this alarm. Null when the firing value came from the Data Connection Layer
/// (external data has no spawning execution) — that on-trigger run is a tree ROOT.
/// </param>
/// <param name="scheduler">Script-execution scheduler seam (#18); null selects the process-wide shared instance.</param>
public static void LaunchAlarmScript(
string alarmName,
string instanceName,
AlarmLevel level,
int priority,
string message,
Script<object?> compiledScript,
IActorRef instanceActor,
SharedScriptLibrary sharedScriptLibrary,
SiteRuntimeOptions options,
IActorRef completionTarget,
ILogger logger,
long runId,
int? executionTimeoutSeconds,
Guid? parentExecutionId,
ScriptExecutionScheduler? scheduler)
{
var timeout = ResolveTimeout(executionTimeoutSeconds, options);
var executionScheduler = scheduler ?? ScriptExecutionScheduler.Shared(options);
// Enqueue-anchored deadline; see LaunchScript.
var cts = new CancellationTokenSource(timeout);
try
{
_ = Task.Factory.StartNew(
() => RunAlarmScriptAsync(
alarmName, instanceName, level, priority, message, compiledScript,
instanceActor, sharedScriptLibrary, options, completionTarget, logger,
runId, parentExecutionId, timeout, cts),
CancellationToken.None, TaskCreationOptions.DenyChildAttach, executionScheduler)
.Unwrap();
}
catch
{
cts.Dispose();
throw;
}
}
/// <summary>
/// Per-script timeout overrides the global default. A null or non-positive per-script
/// value (≤ 0) falls back to the global.
/// </summary>
private static TimeSpan ResolveTimeout(int? executionTimeoutSeconds, SiteRuntimeOptions options)
=> TimeSpan.FromSeconds(
executionTimeoutSeconds is { } perScript && perScript > 0
? perScript
: options.ScriptExecutionTimeoutSeconds);
private static async Task RunScriptAsync(
string scriptName,
string instanceName,
Script<object?> compiledScript,
IReadOnlyDictionary<string, object?>? parameters,
int callDepth,
IActorRef instanceActor,
SharedScriptLibrary sharedScriptLibrary,
SiteRuntimeOptions options,
IActorRef replyTo,
string correlationId,
IActorRef completionTarget,
ICanTell? siteCommunicationActor,
ILogger logger,
ScriptScope scope,
long runId,
ISiteHealthCollector? healthCollector,
IServiceProvider? serviceProvider,
Guid? parentExecutionId,
TimeSpan timeout,
ScriptExecutionScheduler executionScheduler,
CancellationTokenSource cts)
{
IServiceScope? serviceScope = null;
// ISiteEventLogger is a singleton; resolve from the root provider so
// it is available to the catch blocks regardless of scope state.
var siteEventLogger = serviceProvider?.GetService<ISiteEventLogger>();
// WP3.1: identify the worker this body is holding, so the watchdog can detach and
// replace it if the body wedges. Read in the FIRST synchronous segment — a script
// that later hops threads on an await no longer holds this worker, and the run-stamp
// guard in TryDetachWorker will (correctly) refuse to detach it.
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,
$"Script '{scriptName}' on instance '{instanceName}'",
instanceName, $"ScriptActor:{scriptName}");
try
{
// WP3.1 shed-at-dequeue: the deadline was armed at ENQUEUE, so an already-cancelled
// token here means this run spent its entire budget queueing. Running it now would
// burn a scarce script thread on work that is already stale — throw straight into
// the existing timeout path instead, BEFORE the "started" event and before the body.
cts.Token.ThrowIfCancellationRequested();
// Resolve integration services from DI (scoped lifetime)
IExternalSystemClient? externalSystemClient = null;
IDatabaseGateway? databaseGateway = null;
// Notification Outbox: the S&F engine is a singleton; the site identity
// provider supplies the site id stamped on enqueued notifications.
StoreAndForwardService? storeAndForward = null;
var siteId = string.Empty;
// The writer is a singleton (FallbackAuditWriter
// composes the SQLite hot-path + drop-oldest ring); null in tests / hosts
// that haven't called AddAuditLog, which the helper handles as a no-op.
IAuditWriter? auditWriter = null;
// Site-local tracking store
// backing Tracking.Status(id). Singleton; null in tests / hosts
// that haven't wired the store, which the helper handles by
// throwing on access.
IOperationTrackingStore? operationTrackingStore = null;
// Site-side cached-call
// telemetry forwarder. Singleton bound to the AuditLog
// composition root; null in tests / hosts that haven't called
// AddAuditLog, in which case the cached-call helpers degrade
// to the no-emission path (the underlying S&F handoff still
// happens and a TrackedOperationId is still returned).
ICachedCallTelemetryForwarder? cachedForwarder = null;
// SourceNode-stamping: the local node name
// resolved from INodeIdentityProvider — node-a/node-b on site
// hosts. Null in tests / hosts that haven't registered the
// provider, in which case NotificationSubmit.SourceNode and
// SiteCallOperational.SourceNode stay null and central
// persists the rows with SourceNode NULL.
string? sourceNode = null;
if (serviceProvider != null)
{
serviceScope = serviceProvider.CreateScope();
externalSystemClient = serviceScope.ServiceProvider.GetService<IExternalSystemClient>();
databaseGateway = serviceScope.ServiceProvider.GetService<IDatabaseGateway>();
storeAndForward = serviceScope.ServiceProvider.GetService<StoreAndForwardService>();
siteId = serviceScope.ServiceProvider.GetService<ISiteIdentityProvider>()?.SiteId
?? string.Empty;
auditWriter = serviceScope.ServiceProvider.GetService<IAuditWriter>();
operationTrackingStore = serviceScope.ServiceProvider.GetService<IOperationTrackingStore>();
cachedForwarder = serviceScope.ServiceProvider.GetService<ICachedCallTelemetryForwarder>();
sourceNode = serviceScope.ServiceProvider.GetService<INodeIdentityProvider>()?.NodeName;
}
var context = new ScriptRuntimeContext(
instanceActor,
sharedScriptLibrary,
callDepth,
options.MaxScriptCallDepth,
timeout,
instanceName,
logger,
externalSystemClient,
databaseGateway,
storeAndForward,
siteCommunicationActor,
siteId,
// Notification Outbox (FU3): stamp the executing script onto outbound
// notifications using the Site Event Logging "Source" convention.
sourceScript: $"ScriptActor:{scriptName}",
// Emit one ApiOutbound/ApiCall row per
// ExternalSystem.Call. Writer is best-effort; failures are logged
// and swallowed inside the helper so the script's call path is
// never aborted by an audit failure.
auditWriter: auditWriter,
// Site-local tracking store
// backing Tracking.Status(id). Authoritative source of truth for
// cached-call status — read directly by the script API.
operationTrackingStore: operationTrackingStore,
// Cached-call telemetry
// forwarder for ExternalSystem.CachedCall / Database.CachedWrite
// CachedSubmit emission + the immediate-success terminal-row
// emission. Best-effort: null degrades the helpers to a
// no-emission path; the S&F handoff and TrackedOperationId
// return are unaffected.
cachedForwarder: cachedForwarder,
// The spawning execution's
// id for an inbound-API-routed call. The routed script still
// mints its own fresh ExecutionId — this records the spawner.
// Null for normal (tag-change / timer) runs.
parentExecutionId: parentExecutionId,
// SourceNode-stamping: the local node name
// (node-a/node-b on a site) — threaded down so Notify.Send
// and the four cached-call telemetry constructors can stamp
// it onto NotificationSubmit.SourceNode and
// SiteCallOperational.SourceNode respectively.
sourceNode: sourceNode,
// Thread the singleton site event logger so
// recursion-limit violations at CallScript/CallShared emit a
// script Error site event in addition to ILogger.LogError.
siteEventLogger: siteEventLogger,
// WaitForAttribute (spec §4.3/§4.4): thread the per-script
// execution-timeout token so Attributes.WaitAsync's Ask is
// bounded by the script's own ExecutionTimeoutSeconds — a
// shorter script deadline wins over the wait's own timeout.
scriptTimeoutToken: cts.Token);
var globals = new ScriptGlobals
{
Instance = context,
Parameters = new ScriptParameters(parameters ?? new Dictionary<string, object?>()),
CancellationToken = cts.Token,
Scope = scope
};
// Operational `script` event — execution started. Fire-and-forget
// (the `_ =` discards the task) so the event log can never block or
// fault the script's own run; mirrors the existing Error-path emit.
_ = siteEventLogger?.LogEventAsync(
"script", "Info", instanceName, $"ScriptActor:{scriptName}",
$"Script '{scriptName}' on instance '{instanceName}' started");
var state = await compiledScript.RunAsync(globals, cts.Token);
// Send result to requester if this was an Ask-based call
if (!replyTo.IsNobody())
{
replyTo.Tell(new ScriptCallResult(correlationId, true, state.ReturnValue, null));
}
// Operational `script` event — execution completed successfully.
_ = siteEventLogger?.LogEventAsync(
"script", "Info", instanceName, $"ScriptActor:{scriptName}",
$"Script '{scriptName}' on instance '{instanceName}' completed");
// Notify the owning ScriptActor of completion (also releases its in-flight slot).
completionTarget.Tell(new ScriptActor.ScriptExecutionCompleted(scriptName, true, null));
}
catch (OperationCanceledException)
{
healthCollector?.IncrementScriptError();
var errorMsg = $"Script '{scriptName}' on instance '{instanceName}' timed out after {timeout.TotalSeconds}s";
logger.LogWarning("{Message} (run {RunId})", errorMsg, runId);
// Failures recorded to site event log; script NOT disabled after failure.
_ = siteEventLogger?.LogEventAsync(
"script", "Error", instanceName, $"ScriptActor:{scriptName}", errorMsg);
if (!replyTo.IsNobody())
{
replyTo.Tell(new ScriptCallResult(correlationId, false, null, errorMsg));
}
completionTarget.Tell(new ScriptActor.ScriptExecutionCompleted(scriptName, false, errorMsg));
}
catch (Exception ex)
{
healthCollector?.IncrementScriptError();
// Failures recorded to site event log; script NOT disabled after failure.
var errorMsg = $"Script '{scriptName}' on instance '{instanceName}' failed: {ex.Message}";
logger.LogError(ex, "Script execution failed: {Script} on {Instance} (run {RunId})",
scriptName, instanceName, runId);
_ = siteEventLogger?.LogEventAsync(
"script", "Error", instanceName, $"ScriptActor:{scriptName}", errorMsg, ex.ToString());
if (!replyTo.IsNobody())
{
replyTo.Tell(new ScriptCallResult(correlationId, false, null, errorMsg));
}
completionTarget.Tell(new ScriptActor.ScriptExecutionCompleted(scriptName, false, errorMsg));
}
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);
// Dispose the DI scope (and scoped services) after script execution completes
serviceScope?.Dispose();
cts.Dispose();
}
}
private static async Task RunAlarmScriptAsync(
string alarmName,
string instanceName,
AlarmLevel level,
int priority,
string message,
Script<object?> compiledScript,
IActorRef instanceActor,
SharedScriptLibrary sharedScriptLibrary,
SiteRuntimeOptions options,
IActorRef completionTarget,
ILogger logger,
long runId,
Guid? parentExecutionId,
TimeSpan timeout,
CancellationTokenSource cts)
{
try
{
// Enqueue-anchored deadline: an already-cancelled token means this on-trigger run
// spent its whole budget queueing behind other script bodies. Shed it rather than
// run it late — the alarm it would react to is already stale.
cts.Token.ThrowIfCancellationRequested();
// An alarm on-trigger run can call Instance.CallScript()
// via the ScriptRuntimeContext injected into globals
var context = new ScriptRuntimeContext(
instanceActor,
sharedScriptLibrary,
currentCallDepth: 0,
options.MaxScriptCallDepth,
timeout,
instanceName,
logger,
// ParentExecutionId tag-cascade: the
// alarm on-trigger run mints its own fresh ExecutionId (the
// ctor's `?? NewGuid()` fallback) and records the firing
// execution's id as its ParentExecutionId — null (a root)
// only when the firing value came from the DCL.
parentExecutionId: parentExecutionId,
// WaitForAttribute (spec §4.4): thread the alarm on-trigger
// script's per-script execution-timeout token so a
// Attributes.WaitAsync inside an on-trigger script is bounded
// by the same script deadline.
scriptTimeoutToken: cts.Token);
var globals = new ScriptGlobals
{
Instance = context,
Parameters = new ScriptParameters(),
CancellationToken = cts.Token,
Alarm = new AlarmContext
{
Name = alarmName,
Level = level,
Priority = priority,
Message = message
}
};
await compiledScript.RunAsync(globals, cts.Token);
completionTarget.Tell(new AlarmActor.AlarmExecutionCompleted(alarmName, true));
}
catch (OperationCanceledException)
{
logger.LogWarning(
"Alarm on-trigger script for {Alarm} on {Instance} timed out (run {RunId})",
alarmName, instanceName, runId);
completionTarget.Tell(new AlarmActor.AlarmExecutionCompleted(alarmName, false));
}
catch (Exception ex)
{
// Failures logged, alarm continues
logger.LogError(ex,
"Alarm on-trigger script for {Alarm} on {Instance} failed (run {RunId})",
alarmName, instanceName, runId);
completionTarget.Tell(new AlarmActor.AlarmExecutionCompleted(alarmName, false));
}
finally
{
cts.Dispose();
}
}
/// <summary>
/// Arms the stuck-script watchdog (S2, extended by WP3.1).
///
/// <para>The CTS firing only REQUESTS cooperative cancellation; it does NOT free a thread
/// blocked in synchronous I/O. When the deadline elapses, this waits
/// <see cref="SiteRuntimeOptions.StuckScriptGraceMs"/> and, if the body still has not
/// returned, (a) names the script loudly on the site event log and (b) DETACHES the worker
/// thread it is holding and starts a replacement — so a wedged script costs the pool one
/// thread only until the watchdog fires, not forever. At the detach cap it logs an Error
/// instead of growing threads without bound.</para>
///
/// <para>The <c>Task.Run</c>/<c>Task.Delay</c> run on the shared thread pool, never on the
/// (possibly saturated) script scheduler — deliberate, and the whole point of the watchdog.
/// <c>Register</c> fires on cancellation only; a normally-completing run disposes its CTS
/// with no callback. A run cancelled while still QUEUED flips its completed flag in the
/// body's <c>finally</c> long before the grace elapses, so it is correctly not reported.</para>
/// </summary>
private static void ArmStuckScriptWatchdog(
CancellationTokenSource cts,
SiteRuntimeOptions options,
ILogger logger,
ISiteEventLogger? siteEventLogger,
ScriptExecutionScheduler scheduler,
int? workerSlot,
long workerRunStamp,
TimeSpan timeout,
Func<bool> isCompleted,
string subject,
string instanceName,
string source)
{
var graceMs = options.StuckScriptGraceMs;
cts.Token.Register(() => _ = Task.Run(async () =>
{
await Task.Delay(graceMs);
if (isCompleted()) return;
var stuckMsg = $"{subject} exceeded its {timeout.TotalSeconds:F0}s timeout and is STILL EXECUTING — " +
"its dedicated script-execution thread is blocked (cooperative cancellation not observed).";
var outcome = workerSlot is { } slot
? scheduler.TryDetachWorker(slot, workerRunStamp)
: WorkerDetachOutcome.NotRunning;
switch (outcome)
{
case WorkerDetachOutcome.Detached:
stuckMsg += " The worker thread has been DETACHED and replaced; it will exit when the body returns.";
break;
case WorkerDetachOutcome.AtCap:
stuckMsg += $" The script-execution pool already holds {scheduler.DetachedThreadCount} detached " +
"stuck threads (at cap); NOT replacing this one.";
break;
case WorkerDetachOutcome.NotRunning:
// The body is not on a worker thread (it hopped threads on an await), so no
// dedicated thread is lost — report it, but there is nothing to replace.
break;
}
logger.LogError(stuckMsg);
_ = siteEventLogger?.LogEventAsync("script", "Error", instanceName, source, stuckMsg);
}));
}
}