feat(logging): stamp ExecutionId/InstanceName/ScriptName on the Serilog LogContext per run (ScadaBridge#56)

The site script and alarm on-trigger launchers push the run identity onto LogContext for the run's lifetime and the host now enables Enrich.FromLogContext(), so log lines written on the run's own async call chain carry the id. Bounded part only: LogContext does not cross an Akka message hop, so Instance Actor/DCL/S&F lines and a site_events execution-id column remain open (documented in the step-logs design doc section 9). Claude-Session: https://claude.ai/code/session_01GT67AEHd2Acv1YPwGfXEoV
2026-11-09 14:20:02 -05:00
parent 5ef27fd9a3
commit 7f479f3a5c
7 changed files with 144 additions and 2 deletions
@@ -98,6 +98,54 @@ public class ScriptRunLauncherTraceTests : TestKit, IDisposable
    private static AuditEvent ScriptRunRow(ScriptCallResult result)
        => Assert.Single(result.TraceEvents!, e => Row(e).Kind == AuditKind.ScriptRun);

+    // ── ScadaBridge#56: run identity is on the Serilog LogContext while the run executes ──
+
+    /// <summary>Forwards every call to a Serilog logger so LogContext enrichment is observable at the time of the call.</summary>
+    private sealed class SerilogForwardingLogger(Serilog.ILogger inner) : Microsoft.Extensions.Logging.ILogger
+    {
+        public IDisposable? BeginScope<TState>(TState state) where TState : notnull => null;
+        public bool IsEnabled(Microsoft.Extensions.Logging.LogLevel logLevel) => true;
+        public void Log<TState>(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId,
+            TState state, Exception? exception, Func<TState, Exception?, string> formatter)
+            => inner.Write(Serilog.Events.LogEventLevel.Information, "forwarded");
+    }
+
+    private sealed class CaptureSink : Serilog.Core.ILogEventSink
+    {
+        public System.Collections.Concurrent.ConcurrentQueue<Serilog.Events.LogEvent> Events { get; } = new();
+        public void Emit(Serilog.Events.LogEvent logEvent) => Events.Enqueue(logEvent);
+    }
+
+    /// <summary>Verifies a line logged during a run carries the run's ExecutionId/InstanceName/ScriptName, and the scope is popped afterwards.</summary>
+    [Fact]
+    public void RunningScript_StampsExecutionIdentityOnTheLogContext()
+    {
+        var sink = new CaptureSink();
+        var serilog = new Serilog.LoggerConfiguration().Enrich.FromLogContext().WriteTo.Sink(sink).CreateLogger();
+        var caller = CreateTestProbe();
+        ScriptRunLauncher.LaunchScript(
+            scriptName: "Runner", instanceName: "Inst1",
+            compiledScript: CompileScript("Log.Info(\"hello\"); return null;"),
+            parameters: null, callDepth: 0, instanceActor: CreateTestProbe().Ref,
+            sharedScriptLibrary: _sharedLibrary, options: Options(), replyTo: caller.Ref,
+            correlationId: "corr-1", completionTarget: CreateTestProbe().Ref,
+            siteCommunicationActor: null, logger: new SerilogForwardingLogger(serilog),
+            scope: ScriptScope.Root, runId: 1, healthCollector: null, serviceProvider: null,
+            parentExecutionId: null, executionTimeoutSeconds: null, scheduler: _scheduler,
+            trace: false, triggerExtra: null);
+        var result = caller.ExpectMsg<ScriptCallResult>(TimeSpan.FromSeconds(20));
+
+        Assert.True(result.Success);
+        var evt = Assert.Single(sink.Events);
+        Assert.Equal(result.ExecutionId!.Value.ToString(), evt.Properties["ExecutionId"].ToString().Trim('"'));
+        Assert.Equal("Inst1", evt.Properties["InstanceName"].ToString().Trim('"'));
+        Assert.Equal("Runner", evt.Properties["ScriptName"].ToString().Trim('"'));
+
+        // Not leaked past the run on this thread's context.
+        serilog.Information("after");
+        Assert.False(sink.Events.Last().Properties.ContainsKey("ExecutionId"));
+    }
+
    // ── (a) a throwing run carries the exception's full detail ───────────────────

    /// <summary>Verifies that a traced run that throws records the full exception detail on its script-run row.</summary>