From bd2dd05a0c1a470446e1c83eaa592a3724896485 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Wed, 10 Jun 2026 12:03:51 -0400 Subject: [PATCH] =?UTF-8?q?feat(scripting):=20evaluators=20log=20through?= =?UTF-8?q?=20root=20script=20logger=20=E2=86=92=20script-log=20page=20(F8?= =?UTF-8?q?)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../ScriptLoggerFactory.cs | 30 ++++++++ .../Engines/RoslynScriptedAlarmEvaluator.cs | 20 +++-- .../Engines/RoslynVirtualTagEvaluator.cs | 23 ++++-- src/Server/ZB.MOM.WW.OtOpcUa.Host/Program.cs | 8 +- .../ScriptLoggerFactoryTests.cs | 60 +++++++++++++++ .../RoslynScriptedAlarmEvaluatorTests.cs | 64 ++++++++++++++-- .../RoslynVirtualTagEvaluatorTests.cs | 76 +++++++++++++++---- 7 files changed, 245 insertions(+), 36 deletions(-) diff --git a/src/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting/ScriptLoggerFactory.cs b/src/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting/ScriptLoggerFactory.cs index 604ece8e..f14b5103 100644 --- a/src/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting/ScriptLoggerFactory.cs +++ b/src/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting/ScriptLoggerFactory.cs @@ -61,4 +61,34 @@ public sealed class ScriptLoggerFactory throw new ArgumentException("Script name is required.", nameof(scriptName)); return _rootLogger.ForContext(ScriptNameProperty, scriptName); } + + /// + /// Create a per-evaluation script logger bound with the supplied identity properties. + /// is always bound; , + /// , and are bound only + /// when the corresponding argument is non-null. Every event the returned logger emits + /// carries these properties so the can attribute each + /// line on the Script-log page. + /// + /// The Script row identifier; always bound. Required. + /// VirtualTag context, when the script runs against a virtual tag. + /// ScriptedAlarm context, when the script runs an alarm predicate. + /// Equipment scope, for per-equipment script evaluations. + /// An ILogger instance bound with the supplied identity properties. + /// Thrown when is null or whitespace. + public ILogger Create( + string scriptId, + string? virtualTagId = null, + string? alarmId = null, + string? equipmentId = null) + { + if (string.IsNullOrWhiteSpace(scriptId)) + throw new ArgumentException("Script id is required.", nameof(scriptId)); + + var logger = _rootLogger.ForContext(ScriptIdProperty, scriptId); + if (virtualTagId is not null) logger = logger.ForContext(VirtualTagIdProperty, virtualTagId); + if (alarmId is not null) logger = logger.ForContext(AlarmIdProperty, alarmId); + if (equipmentId is not null) logger = logger.ForContext(EquipmentIdProperty, equipmentId); + return logger; + } } diff --git a/src/Server/ZB.MOM.WW.OtOpcUa.Host/Engines/RoslynScriptedAlarmEvaluator.cs b/src/Server/ZB.MOM.WW.OtOpcUa.Host/Engines/RoslynScriptedAlarmEvaluator.cs index 0b625f6f..8a247381 100644 --- a/src/Server/ZB.MOM.WW.OtOpcUa.Host/Engines/RoslynScriptedAlarmEvaluator.cs +++ b/src/Server/ZB.MOM.WW.OtOpcUa.Host/Engines/RoslynScriptedAlarmEvaluator.cs @@ -5,7 +5,6 @@ using ZB.MOM.WW.OtOpcUa.Core.Abstractions; using ZB.MOM.WW.OtOpcUa.Core.ScriptedAlarms; using ZB.MOM.WW.OtOpcUa.Core.Scripting; using SerilogLogger = Serilog.ILogger; -using SerilogLog = Serilog.Log; namespace ZB.MOM.WW.OtOpcUa.Host.Engines; @@ -22,20 +21,24 @@ namespace ZB.MOM.WW.OtOpcUa.Host.Engines; /// public sealed class RoslynScriptedAlarmEvaluator : IScriptedAlarmEvaluator, IDisposable { - private static readonly SerilogLogger ScriptLogger = SerilogLog.ForContext(); - private readonly ConcurrentDictionary> _cache = new(StringComparer.Ordinal); private readonly ILogger _logger; + private readonly SerilogLogger _scriptRoot; private readonly TimeSpan _runTimeout; private bool _disposed; /// Initializes a new instance of the Roslyn scripted alarm evaluator. - /// Logger for diagnostic messages. + /// Logger for diagnostic messages (host diagnostics). + /// Root script logger; user ctx.Logger.* output flows through this to the Script-log page. /// Optional timeout for script evaluation; defaults to 2 seconds. - public RoslynScriptedAlarmEvaluator(ILogger logger, TimeSpan? runTimeout = null) + public RoslynScriptedAlarmEvaluator( + ILogger logger, + ScriptRootLogger scriptRoot, + TimeSpan? runTimeout = null) { _logger = logger; + _scriptRoot = (scriptRoot ?? throw new ArgumentNullException(nameof(scriptRoot))).Logger; _runTimeout = runTimeout ?? TimeSpan.FromSeconds(2); } @@ -71,7 +74,12 @@ public sealed class RoslynScriptedAlarmEvaluator : IScriptedAlarmEvaluator, IDis } var readCache = BuildReadCache(dependencies); - var context = new AlarmPredicateContext(readCache, ScriptLogger); + // Per-evaluation script logger: bind both ScriptId and AlarmId from the alarm id so the + // Script-log page can attribute each line to the owning scripted alarm. + var scriptLog = _scriptRoot + .ForContext(ScriptLoggerFactory.ScriptIdProperty, alarmId) + .ForContext(ScriptLoggerFactory.AlarmIdProperty, alarmId); + var context = new AlarmPredicateContext(readCache, scriptLog); try { diff --git a/src/Server/ZB.MOM.WW.OtOpcUa.Host/Engines/RoslynVirtualTagEvaluator.cs b/src/Server/ZB.MOM.WW.OtOpcUa.Host/Engines/RoslynVirtualTagEvaluator.cs index 4ec0049e..3bf96df3 100644 --- a/src/Server/ZB.MOM.WW.OtOpcUa.Host/Engines/RoslynVirtualTagEvaluator.cs +++ b/src/Server/ZB.MOM.WW.OtOpcUa.Host/Engines/RoslynVirtualTagEvaluator.cs @@ -5,7 +5,6 @@ using ZB.MOM.WW.OtOpcUa.Core.Abstractions; using ZB.MOM.WW.OtOpcUa.Core.Scripting; using ZB.MOM.WW.OtOpcUa.Core.VirtualTags; using SerilogLogger = Serilog.ILogger; -using SerilogLog = Serilog.Log; namespace ZB.MOM.WW.OtOpcUa.Host.Engines; @@ -23,20 +22,24 @@ namespace ZB.MOM.WW.OtOpcUa.Host.Engines; /// public sealed class RoslynVirtualTagEvaluator : IVirtualTagEvaluator, IDisposable { - private static readonly SerilogLogger ScriptLogger = SerilogLog.ForContext(); - private readonly ConcurrentDictionary> _cache = new(StringComparer.Ordinal); private readonly ILogger _logger; + private readonly SerilogLogger _scriptRoot; private readonly TimeSpan _runTimeout; private bool _disposed; - /// Initializes a new RoslynVirtualTagEvaluator with the given logger and optional timeout. - /// Logger for recording compilation and execution errors. + /// Initializes a new RoslynVirtualTagEvaluator with the given loggers and optional timeout. + /// Logger for recording compilation and execution errors (host diagnostics). + /// Root script logger; user ctx.Logger.* output flows through this to the Script-log page. /// Maximum execution time for each script; defaults to 2 seconds if not specified. - public RoslynVirtualTagEvaluator(ILogger logger, TimeSpan? runTimeout = null) + public RoslynVirtualTagEvaluator( + ILogger logger, + ScriptRootLogger scriptRoot, + TimeSpan? runTimeout = null) { _logger = logger; + _scriptRoot = (scriptRoot ?? throw new ArgumentNullException(nameof(scriptRoot))).Logger; _runTimeout = runTimeout ?? TimeSpan.FromSeconds(2); } @@ -84,12 +87,18 @@ public sealed class RoslynVirtualTagEvaluator : IVirtualTagEvaluator, IDisposabl } var readCache = BuildReadCache(dependencies); + // Per-evaluation script logger: bind both ScriptId and VirtualTagId from the virtual-tag id + // (in the live path the script id equals the virtual-tag id) so the Script-log page can + // attribute each line. EquipmentId stays unbound for now. + var scriptLog = _scriptRoot + .ForContext(ScriptLoggerFactory.ScriptIdProperty, virtualTagId) + .ForContext(ScriptLoggerFactory.VirtualTagIdProperty, virtualTagId); var context = new VirtualTagContext( readCache, setVirtualTag: (path, _) => _logger.LogDebug("VirtualTag {Id}: cross-tag write to {Path} dropped (single-tag adapter)", virtualTagId, path), - logger: ScriptLogger); + logger: scriptLog); try { diff --git a/src/Server/ZB.MOM.WW.OtOpcUa.Host/Program.cs b/src/Server/ZB.MOM.WW.OtOpcUa.Host/Program.cs index 66a02c3b..1c0cd98f 100644 --- a/src/Server/ZB.MOM.WW.OtOpcUa.Host/Program.cs +++ b/src/Server/ZB.MOM.WW.OtOpcUa.Host/Program.cs @@ -109,13 +109,17 @@ if (hasDriver) // Replaces the F8-default NullVirtualTagEvaluator so VirtualTagActor evaluates real user // scripts at runtime. builder.Services.AddSingleton(sp => - new RoslynVirtualTagEvaluator(sp.GetRequiredService().CreateLogger())); + new RoslynVirtualTagEvaluator( + sp.GetRequiredService().CreateLogger(), + sp.GetRequiredService())); builder.Services.AddSingleton(sp => sp.GetRequiredService()); // F9b — same pattern for scripted-alarm predicates. The actor preserves prior state on // any Failure result, so a misbehaving script can't flip Active/Inactive spuriously. builder.Services.AddSingleton(sp => - new RoslynScriptedAlarmEvaluator(sp.GetRequiredService().CreateLogger())); + new RoslynScriptedAlarmEvaluator( + sp.GetRequiredService().CreateLogger(), + sp.GetRequiredService())); builder.Services.AddSingleton(sp => sp.GetRequiredService()); // Script-log fan-out (Layer 0). The DPS publisher resolves the ActorSystem lazily so it never diff --git a/tests/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting.Tests/ScriptLoggerFactoryTests.cs b/tests/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting.Tests/ScriptLoggerFactoryTests.cs index 7aeb727d..09a335e9 100644 --- a/tests/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting.Tests/ScriptLoggerFactoryTests.cs +++ b/tests/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting.Tests/ScriptLoggerFactoryTests.cs @@ -101,4 +101,64 @@ public sealed class ScriptLoggerFactoryTests // this exact string. If it changes, the filter breaks silently. ScriptLoggerFactory.ScriptNameProperty.ShouldBe("ScriptName"); } + + /// + /// A logger from the identity overload, when written through a + /// , produces an entry carrying every bound id. + /// + [Fact] + public void Create_identity_overload_binds_ids_onto_published_entry() + { + var publisher = new FakePublisher(); + var root = new LoggerConfiguration() + .MinimumLevel.Verbose() + .WriteTo.Sink(new ScriptLogTopicSink(publisher, LogEventLevel.Information)) + .CreateLogger(); + var factory = new ScriptLoggerFactory(root); + + var logger = factory.Create( + scriptId: "S9", virtualTagId: "V9", alarmId: "A9", equipmentId: "EQ9"); + logger.Information("typed identity"); + + publisher.Published.Count.ShouldBe(1); + var entry = publisher.Published[0]; + entry.ScriptId.ShouldBe("S9"); + entry.VirtualTagId.ShouldBe("V9"); + entry.AlarmId.ShouldBe("A9"); + entry.EquipmentId.ShouldBe("EQ9"); + entry.Message.ShouldBe("typed identity"); + } + + /// + /// The identity overload leaves optional ids unbound (null on the entry) when not + /// supplied, binding only ScriptId. + /// + [Fact] + public void Create_identity_overload_leaves_optional_ids_null_when_absent() + { + var publisher = new FakePublisher(); + var root = new LoggerConfiguration() + .MinimumLevel.Verbose() + .WriteTo.Sink(new ScriptLogTopicSink(publisher, LogEventLevel.Information)) + .CreateLogger(); + var factory = new ScriptLoggerFactory(root); + + factory.Create(scriptId: "S10").Information("only script id"); + + var entry = publisher.Published[0]; + entry.ScriptId.ShouldBe("S10"); + entry.VirtualTagId.ShouldBeNull(); + entry.AlarmId.ShouldBeNull(); + entry.EquipmentId.ShouldBeNull(); + } + + /// Capturing publisher for the identity-overload sink tests. + private sealed class FakePublisher : IScriptLogPublisher + { + /// Gets the entries published so far. + public List Published { get; } = []; + + /// + public void Publish(Commons.Messages.Logging.ScriptLogEntry entry) => Published.Add(entry); + } } diff --git a/tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/RoslynScriptedAlarmEvaluatorTests.cs b/tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/RoslynScriptedAlarmEvaluatorTests.cs index 228991ad..cce8a271 100644 --- a/tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/RoslynScriptedAlarmEvaluatorTests.cs +++ b/tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/RoslynScriptedAlarmEvaluatorTests.cs @@ -1,6 +1,10 @@ using Microsoft.Extensions.Logging.Abstractions; +using Serilog; +using Serilog.Events; using Shouldly; using Xunit; +using ZB.MOM.WW.OtOpcUa.Commons.Messages.Logging; +using ZB.MOM.WW.OtOpcUa.Core.Scripting; using ZB.MOM.WW.OtOpcUa.Host.Engines; namespace ZB.MOM.WW.OtOpcUa.Host.IntegrationTests; @@ -13,11 +17,25 @@ namespace ZB.MOM.WW.OtOpcUa.Host.IntegrationTests; /// public sealed class RoslynScriptedAlarmEvaluatorTests { + /// Captures published records for assertion. + private sealed class FakePublisher : IScriptLogPublisher + { + /// Gets the entries published so far. + public List Published { get; } = []; + + /// + public void Publish(ScriptLogEntry entry) => Published.Add(entry); + } + + /// Builds a no-op for tests that don't assert on logging. + private static ScriptRootLogger NoOpScriptRoot() => + new(new LoggerConfiguration().CreateLogger()); + /// Verifies evaluation of predicate returning true reports Active. [Fact] public void Evaluate_predicate_returning_true_reports_Active() { - using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance); + using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance, NoOpScriptRoot()); var result = sut.Evaluate( alarmId: "alarm-hi", @@ -32,7 +50,7 @@ public sealed class RoslynScriptedAlarmEvaluatorTests [Fact] public void Evaluate_predicate_returning_false_reports_Inactive() { - using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance); + using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance, NoOpScriptRoot()); var result = sut.Evaluate( alarmId: "alarm-hi", @@ -47,7 +65,7 @@ public sealed class RoslynScriptedAlarmEvaluatorTests [Fact] public void Evaluate_caches_compiled_predicate_across_calls() { - using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance); + using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance, NoOpScriptRoot()); const string predicate = "return (bool)ctx.GetTag(\"door_open\").Value;"; var first = sut.Evaluate("alarm-door", predicate, new Dictionary { ["door_open"] = true }); @@ -61,7 +79,7 @@ public sealed class RoslynScriptedAlarmEvaluatorTests [Fact] public void Evaluate_compile_error_returns_Failure() { - using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance); + using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance, NoOpScriptRoot()); var result = sut.Evaluate("alarm-bad", "this isn't C#;", new Dictionary()); @@ -73,7 +91,7 @@ public sealed class RoslynScriptedAlarmEvaluatorTests [Fact] public void Evaluate_predicate_writing_virtual_tag_returns_Failure() { - using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance); + using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance, NoOpScriptRoot()); // AlarmPredicateContext.SetVirtualTag throws — wrapper catches + reports as Failure. var result = sut.Evaluate( @@ -89,7 +107,7 @@ public sealed class RoslynScriptedAlarmEvaluatorTests [Fact] public void Evaluate_empty_predicate_returns_Failure() { - using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance); + using var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance, NoOpScriptRoot()); sut.Evaluate("alarm-empty", "", new Dictionary()).Success.ShouldBeFalse(); } @@ -98,7 +116,7 @@ public sealed class RoslynScriptedAlarmEvaluatorTests [Fact] public void Evaluate_after_dispose_returns_Failure() { - var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance); + var sut = new RoslynScriptedAlarmEvaluator(NullLogger.Instance, NoOpScriptRoot()); sut.Dispose(); var result = sut.Evaluate("alarm", "return true;", new Dictionary()); @@ -106,4 +124,36 @@ public sealed class RoslynScriptedAlarmEvaluatorTests result.Success.ShouldBeFalse(); result.Reason!.ShouldContain("disposed"); } + + /// + /// A predicate's ctx.Logger.Warning(...) call flows through the injected root script + /// logger and out the , producing one + /// carrying the message, the bound AlarmId, and the + /// Warning level. + /// + [Fact] + public void Script_logger_call_publishes_entry_with_bound_alarm_identity() + { + var publisher = new FakePublisher(); + var root = new LoggerConfiguration() + .MinimumLevel.Verbose() + .WriteTo.Sink(new ScriptLogTopicSink(publisher, LogEventLevel.Information)) + .CreateLogger(); + using var sut = new RoslynScriptedAlarmEvaluator( + NullLogger.Instance, new ScriptRootLogger(root)); + + var result = sut.Evaluate( + alarmId: "alarm-log", + predicate: "ctx.Logger.Warning(\"alarm log\"); return true;", + dependencies: new Dictionary()); + + result.Success.ShouldBeTrue(result.Reason); + result.Active.ShouldBeTrue(); + publisher.Published.Count.ShouldBe(1); + var entry = publisher.Published[0]; + entry.Message.ShouldBe("alarm log"); + entry.AlarmId.ShouldBe("alarm-log"); + entry.ScriptId.ShouldBe("alarm-log"); + entry.Level.ShouldBe("Warning"); + } } diff --git a/tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/RoslynVirtualTagEvaluatorTests.cs b/tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/RoslynVirtualTagEvaluatorTests.cs index 085cd771..064c0fa9 100644 --- a/tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/RoslynVirtualTagEvaluatorTests.cs +++ b/tests/Server/ZB.MOM.WW.OtOpcUa.Host.IntegrationTests/RoslynVirtualTagEvaluatorTests.cs @@ -1,8 +1,12 @@ using System.Collections; using System.Reflection; using Microsoft.Extensions.Logging.Abstractions; +using Serilog; +using Serilog.Events; using Shouldly; using Xunit; +using ZB.MOM.WW.OtOpcUa.Commons.Messages.Logging; +using ZB.MOM.WW.OtOpcUa.Core.Scripting; using ZB.MOM.WW.OtOpcUa.Host.Engines; namespace ZB.MOM.WW.OtOpcUa.Host.IntegrationTests; @@ -15,11 +19,25 @@ namespace ZB.MOM.WW.OtOpcUa.Host.IntegrationTests; /// public sealed class RoslynVirtualTagEvaluatorTests { + /// Captures published records for assertion. + private sealed class FakePublisher : IScriptLogPublisher + { + /// Gets the entries published so far. + public List Published { get; } = []; + + /// + public void Publish(ScriptLogEntry entry) => Published.Add(entry); + } + + /// Builds a no-op for tests that don't assert on logging. + private static ScriptRootLogger NoOpScriptRoot() => + new(new LoggerConfiguration().CreateLogger()); + /// Verifies that simple addition expression is evaluated correctly. [Fact] public void Evaluate_simple_addition_returns_summed_value() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); var result = sut.Evaluate( virtualTagId: "vt-sum", @@ -34,7 +52,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Evaluate_caches_compiled_expression_across_calls() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); const string expr = "return (int)ctx.GetTag(\"x\").Value * 2;"; var first = sut.Evaluate("vt-cache", expr, new Dictionary { ["x"] = 5 }); @@ -50,7 +68,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Evaluate_compile_error_returns_Failure_with_reason() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); var result = sut.Evaluate("vt-bad", "this is not valid C#;", new Dictionary()); @@ -63,7 +81,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Evaluate_runtime_exception_returns_Failure_with_reason() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); var result = sut.Evaluate( virtualTagId: "vt-div0", @@ -79,7 +97,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Evaluate_empty_expression_returns_Failure() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); sut.Evaluate("vt-empty", "", new Dictionary()).Success.ShouldBeFalse(); sut.Evaluate("vt-empty", " ", new Dictionary()).Success.ShouldBeFalse(); @@ -89,7 +107,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Evaluate_after_dispose_returns_Failure() { - var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); sut.Dispose(); var result = sut.Evaluate("vt", "return 1;", new Dictionary()); @@ -105,7 +123,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Passthrough_returns_dependency_value_without_compiling() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); var result = sut.Evaluate( virtualTagId: "vt-mirror", @@ -121,7 +139,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Passthrough_returns_same_object_reference_as_dependency() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); var payload = new object(); var result = sut.Evaluate( @@ -137,7 +155,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Passthrough_whitespace_variants_match() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); var result = sut.Evaluate( virtualTagId: "vt-ws", @@ -152,7 +170,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Non_passthrough_falls_through_to_Roslyn() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); var result = sut.Evaluate( virtualTagId: "vt-plus1", @@ -169,7 +187,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Passthrough_missing_dependency_matches_Roslyn_behaviour() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); const string mirror = "return ctx.GetTag(\"missing\").Value;"; // Roslyn baseline: same source, but force a near-miss that compiles, to capture the @@ -187,7 +205,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Roslyn_missing_dependency_also_returns_Ok_null() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); // `(object?)...Value` forces the compiled path (not the mirror shape) but reads the same // missing tag; result must match the passthrough missing-dep result above. var result = sut.Evaluate( @@ -209,7 +227,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Passthrough_exact_mirror_missing_dep_matches_Roslyn_baseline() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); // Fast-path: exact mirror shape → passthrough returns Ok(null) for missing dep. var fastPath = sut.Evaluate( @@ -238,7 +256,7 @@ public sealed class RoslynVirtualTagEvaluatorTests [Fact] public void Passthrough_does_not_populate_the_compiled_script_cache() { - using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance); + using var sut = new RoslynVirtualTagEvaluator(NullLogger.Instance, NoOpScriptRoot()); // Mirror shape — must take the fast-path, leaving the Roslyn cache untouched. sut.Evaluate("vt-mirror", "return ctx.GetTag(\"a\").Value;", @@ -251,6 +269,36 @@ public sealed class RoslynVirtualTagEvaluatorTests CompiledCacheCount(sut).ShouldBe(1); } + /// + /// A script's ctx.Logger.* call flows through the injected root script logger and out + /// the , producing exactly one + /// carrying the message and the bound identity (ScriptId + VirtualTagId both + /// equal the virtual-tag id in the live path). + /// + [Fact] + public void Script_logger_call_publishes_entry_with_bound_identity() + { + var publisher = new FakePublisher(); + var root = new LoggerConfiguration() + .MinimumLevel.Verbose() + .WriteTo.Sink(new ScriptLogTopicSink(publisher, LogEventLevel.Information)) + .CreateLogger(); + using var sut = new RoslynVirtualTagEvaluator( + NullLogger.Instance, new ScriptRootLogger(root)); + + var result = sut.Evaluate( + virtualTagId: "vt-log", + expression: "ctx.Logger.Information(\"hi from script\"); return 1;", + dependencies: new Dictionary()); + + result.Success.ShouldBeTrue(result.Reason); + publisher.Published.Count.ShouldBe(1); + var entry = publisher.Published[0]; + entry.Message.ShouldBe("hi from script"); + entry.ScriptId.ShouldBe("vt-log"); + entry.VirtualTagId.ShouldBe("vt-log"); + } + /// Reads the count of the private compiled-script cache via reflection. private static int CompiledCacheCount(RoslynVirtualTagEvaluator sut) {