From e74c3aef23a18d1324b50b7a56232b74dd549a0d Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Mon, 15 Jun 2026 12:33:31 -0400 Subject: [PATCH] feat(siteeventlog): emit script started/completed Info events (M1.8) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ScriptExecutionActor previously emitted only an Error 'script' event on failure. It now also fire-and-forgets an Info 'script' event when execution starts (right before RunAsync) and when it completes successfully — giving the operational log the full started/completed/failed lifecycle. Uses the already-resolved siteEventLogger; fire-and-forget so the event log can never block or fault the script's own run. Extends the SingleServiceProvider test helper to also serve IServiceScopeFactory (returning a self-scope) so ScriptExecutionActor's serviceProvider.CreateScope() reaches the logging hot path in tests instead of throwing into the catch. --- .../Actors/ScriptExecutionActor.cs | 12 ++++ .../Actors/ExecutionActorTests.cs | 66 +++++++++++++++++++ .../TestSupport/FakeSiteEventLogger.cs | 27 +++++++- 3 files changed, 102 insertions(+), 3 deletions(-) diff --git a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Actors/ScriptExecutionActor.cs b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Actors/ScriptExecutionActor.cs index 77d2e58f..22cc6034 100644 --- a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Actors/ScriptExecutionActor.cs +++ b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Actors/ScriptExecutionActor.cs @@ -217,6 +217,13 @@ public class ScriptExecutionActor : ReceiveActor Scope = scope }; + // M1.8: 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 @@ -225,6 +232,11 @@ public class ScriptExecutionActor : ReceiveActor replyTo.Tell(new ScriptCallResult(correlationId, true, state.ReturnValue, null)); } + // M1.8: operational `script` event — execution completed successfully. + _ = siteEventLogger?.LogEventAsync( + "script", "Info", instanceName, $"ScriptActor:{scriptName}", + $"Script '{scriptName}' on instance '{instanceName}' completed"); + // Notify parent of completion parent.Tell(new ScriptActor.ScriptExecutionCompleted(scriptName, true, null)); } diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/ExecutionActorTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/ExecutionActorTests.cs index 8d28de6d..22fe87c6 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/ExecutionActorTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/ExecutionActorTests.cs @@ -8,6 +8,7 @@ using ZB.MOM.WW.ScadaBridge.Commons.Types.Enums; using ZB.MOM.WW.ScadaBridge.Commons.Types.Scripts; 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; @@ -71,6 +72,71 @@ public class ExecutionActorTests : TestKit, IDisposable ExpectTerminated(exec, TimeSpan.FromSeconds(5)); } + // ── M1.8: site event log `script` started/completed ──────────────────── + + [Fact] + public void ScriptExecutionActor_Success_EmitsScriptStartedAndCompletedInfoEvents() + { + var compiled = CompileScript("return 7 * 6;"); + var replyTo = CreateTestProbe(); + var instanceActor = CreateTestProbe(); + var siteLog = new FakeSiteEventLogger(); + + var exec = ActorOf(Props.Create(() => new ScriptExecutionActor( + "Answer", "Inst1", compiled, null, 0, + instanceActor.Ref, _sharedLibrary, Options(), + replyTo.Ref, "corr-evt-1", NullLogger.Instance, + ScriptScope.Root, null, new SingleServiceProvider(siteLog)))); + + Watch(exec); + replyTo.ExpectMsg(TimeSpan.FromSeconds(10)); + ExpectTerminated(exec, TimeSpan.FromSeconds(5)); + + AwaitAssert(() => + { + var rows = siteLog.OfType("script"); + // started + completed, both Info, in order. + Assert.Equal(2, rows.Count); + Assert.All(rows, r => + { + Assert.Equal("Info", r.Severity); + Assert.Equal("Inst1", r.InstanceId); + Assert.Equal("ScriptActor:Answer", r.Source); + }); + Assert.Contains("started", rows[0].Message, StringComparison.OrdinalIgnoreCase); + Assert.Contains("completed", rows[1].Message, StringComparison.OrdinalIgnoreCase); + }, TimeSpan.FromSeconds(2)); + } + + [Fact] + public void ScriptExecutionActor_Failure_EmitsStartedInfoThenErrorEvent() + { + var compiled = CompileScript("throw new InvalidOperationException(\"boom\");"); + var replyTo = CreateTestProbe(); + var instanceActor = CreateTestProbe(); + var siteLog = new FakeSiteEventLogger(); + + var exec = ActorOf(Props.Create(() => new ScriptExecutionActor( + "Bad", "Inst1", compiled, null, 0, + instanceActor.Ref, _sharedLibrary, Options(), + replyTo.Ref, "corr-evt-2", NullLogger.Instance, + ScriptScope.Root, null, new SingleServiceProvider(siteLog)))); + + Watch(exec); + replyTo.ExpectMsg(TimeSpan.FromSeconds(10)); + ExpectTerminated(exec, TimeSpan.FromSeconds(5)); + + AwaitAssert(() => + { + var rows = siteLog.OfType("script"); + // started (Info) + failed (Error) — no completed. + Assert.Equal(2, rows.Count); + Assert.Equal("Info", rows[0].Severity); + Assert.Contains("started", rows[0].Message, StringComparison.OrdinalIgnoreCase); + Assert.Equal("Error", rows[1].Severity); + }, TimeSpan.FromSeconds(2)); + } + [Fact] public void ScriptExecutionActor_ScriptThrows_RepliesFailureAndStops() { diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/TestSupport/FakeSiteEventLogger.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/TestSupport/FakeSiteEventLogger.cs index 49239928..7617fe14 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/TestSupport/FakeSiteEventLogger.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/TestSupport/FakeSiteEventLogger.cs @@ -1,4 +1,5 @@ using System.Collections.Concurrent; +using Microsoft.Extensions.DependencyInjection; using ZB.MOM.WW.ScadaBridge.SiteEventLogging; namespace ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests.TestSupport; @@ -51,12 +52,32 @@ public sealed class FakeSiteEventLogger : ISiteEventLogger /// — enough for the actors' optional /// _serviceProvider?.GetService<ISiteEventLogger>() resolution /// without pulling a full DI container into the actor tests. +/// +/// Also serves (returning a scope that just +/// re-exposes this provider) so callers that do +/// serviceProvider.CreateScope() — e.g. ScriptExecutionActor — +/// don't throw before they reach the logging hot path. +/// /// -public sealed class SingleServiceProvider(ISiteEventLogger logger) : IServiceProvider +public sealed class SingleServiceProvider(ISiteEventLogger logger) + : IServiceProvider, IServiceScopeFactory, IServiceScope { private readonly ISiteEventLogger _logger = logger; /// - public object? GetService(Type serviceType) => - serviceType == typeof(ISiteEventLogger) ? _logger : null; + public object? GetService(Type serviceType) + { + if (serviceType == typeof(ISiteEventLogger)) return _logger; + if (serviceType == typeof(IServiceScopeFactory)) return this; + return null; + } + + /// + public IServiceScope CreateScope() => this; + + /// + public IServiceProvider ServiceProvider => this; + + /// + public void Dispose() { } }