using Serilog; using Serilog.Core; using Serilog.Events; using Shouldly; using Xunit; using ZB.MOM.WW.OtOpcUa.Core.Scripting; namespace ZB.MOM.WW.OtOpcUa.Core.Scripting.Tests; /// /// Verifies the sink that mirrors script Error+ events to the main log at Warning /// level. Ensures script noise (Debug/Info/Warning) doesn't reach the main log /// while genuine script failures DO surface there so operators see them without /// watching a separate log file. /// [Trait("Category", "Unit")] public sealed class ScriptLogCompanionSinkTests { private sealed class CapturingSink : ILogEventSink { public List Events { get; } = []; public void Emit(LogEvent logEvent) => Events.Add(logEvent); } private static (ILogger script, CapturingSink scriptSink, CapturingSink mainSink) BuildPipeline() { // Main logger captures companion forwards. var mainSink = new CapturingSink(); var mainLogger = new LoggerConfiguration() .MinimumLevel.Verbose().WriteTo.Sink(mainSink).CreateLogger(); // Script logger fans out to scripts file (here: capture sink) + the companion sink. var scriptSink = new CapturingSink(); var scriptLogger = new LoggerConfiguration() .MinimumLevel.Verbose() .WriteTo.Sink(scriptSink) .WriteTo.Sink(new ScriptLogCompanionSink(mainLogger)) .CreateLogger(); return (scriptLogger, scriptSink, mainSink); } [Fact] public void Info_event_lands_in_scripts_sink_but_not_in_main() { var (script, scriptSink, mainSink) = BuildPipeline(); script.ForContext(ScriptLoggerFactory.ScriptNameProperty, "Test").Information("just info"); scriptSink.Events.Count.ShouldBe(1); mainSink.Events.Count.ShouldBe(0); } [Fact] public void Warning_event_lands_in_scripts_sink_but_not_in_main() { var (script, scriptSink, mainSink) = BuildPipeline(); script.ForContext(ScriptLoggerFactory.ScriptNameProperty, "Test").Warning("just a warning"); scriptSink.Events.Count.ShouldBe(1); mainSink.Events.Count.ShouldBe(0); } [Fact] public void Error_event_mirrored_to_main_at_Warning_level() { var (script, scriptSink, mainSink) = BuildPipeline(); script.ForContext(ScriptLoggerFactory.ScriptNameProperty, "MyAlarm") .Error("condition script failed"); scriptSink.Events[0].Level.ShouldBe(LogEventLevel.Error); mainSink.Events.Count.ShouldBe(1); mainSink.Events[0].Level.ShouldBe(LogEventLevel.Warning, "Error+ is downgraded to Warning in the main log"); } [Fact] public void Mirrored_event_includes_ScriptName_and_original_level() { var (script, _, mainSink) = BuildPipeline(); script.ForContext(ScriptLoggerFactory.ScriptNameProperty, "HighTemp") .Error("temp exceeded limit"); var forwarded = mainSink.Events[0]; forwarded.Properties.ShouldContainKey("ScriptName"); ((ScalarValue)forwarded.Properties["ScriptName"]).Value.ShouldBe("HighTemp"); forwarded.Properties.ShouldContainKey("OriginalLevel"); ((ScalarValue)forwarded.Properties["OriginalLevel"]).Value.ShouldBe(LogEventLevel.Error); } [Fact] public void Mirrored_event_preserves_exception_for_main_log_stack_trace() { var (script, _, mainSink) = BuildPipeline(); var ex = new InvalidOperationException("user code threw"); script.ForContext(ScriptLoggerFactory.ScriptNameProperty, "BadScript").Error(ex, "boom"); mainSink.Events.Count.ShouldBe(1); mainSink.Events[0].Exception.ShouldBeSameAs(ex); } [Fact] public void Fatal_event_mirrored_just_like_Error() { var (script, _, mainSink) = BuildPipeline(); script.ForContext(ScriptLoggerFactory.ScriptNameProperty, "Fatal_Script").Fatal("catastrophic"); mainSink.Events.Count.ShouldBe(1); mainSink.Events[0].Level.ShouldBe(LogEventLevel.Warning); } [Fact] public void Missing_ScriptName_property_falls_back_to_unknown() { var (_, _, mainSink) = BuildPipeline(); // Log without the ScriptName property to simulate a direct root-logger call // that bypassed the factory (defensive — shouldn't normally happen). var mainLogger = new LoggerConfiguration().CreateLogger(); var companion = new ScriptLogCompanionSink(Log.Logger); // Build an event manually so we can omit the property. var ev = new LogEvent( timestamp: DateTimeOffset.UtcNow, level: LogEventLevel.Error, exception: null, messageTemplate: new Serilog.Parsing.MessageTemplateParser().Parse("naked error"), properties: []); // Direct test: sink should not throw + message should be well-formed. Should.NotThrow(() => companion.Emit(ev)); } [Fact] public void Null_main_logger_rejected() { Should.Throw(() => new ScriptLogCompanionSink(null!)); } [Fact] public void Custom_mirror_threshold_applied() { // Caller can raise the mirror threshold to Fatal if they want only // catastrophic events in the main log. var mainSink = new CapturingSink(); var mainLogger = new LoggerConfiguration() .MinimumLevel.Verbose().WriteTo.Sink(mainSink).CreateLogger(); var scriptLogger = new LoggerConfiguration() .MinimumLevel.Verbose() .WriteTo.Sink(new ScriptLogCompanionSink(mainLogger, LogEventLevel.Fatal)) .CreateLogger(); scriptLogger.ForContext(ScriptLoggerFactory.ScriptNameProperty, "X").Error("error"); mainSink.Events.Count.ShouldBe(0, "Error below configured Fatal threshold — not mirrored"); scriptLogger.ForContext(ScriptLoggerFactory.ScriptNameProperty, "X").Fatal("fatal"); mainSink.Events.Count.ShouldBe(1); } [Fact] public void Factory_plus_companion_sink_integration_surfaces_script_error_in_both_logs() { // End-to-end Core.Scripting-011 coverage: an Error-level emission from a logger // built by ScriptLoggerFactory must land in BOTH the per-script sink (acting as // the scripts-*.log substitute here) AND the main-log companion at Warning level, // tagged with the originating ScriptName property. This is the integration the // server's logger pipeline relies on so operators see script failures in the // primary log without monitoring the scripts file separately. var scriptsSink = new CapturingSink(); var mainSink = new CapturingSink(); // Main pipeline — receives only Error+ events forwarded by the companion sink. var mainLogger = new LoggerConfiguration() .MinimumLevel.Verbose().WriteTo.Sink(mainSink).CreateLogger(); // Root script pipeline — fans out to the scripts sink (stand-in for the // rolling scripts-*.log file) AND the companion sink that forwards Error+ // to the main logger. var rootScriptLogger = new LoggerConfiguration() .MinimumLevel.Verbose() .WriteTo.Sink(scriptsSink) .WriteTo.Sink(new ScriptLogCompanionSink(mainLogger)) .CreateLogger(); // Factory binds the per-script ScriptName property — this is the only way the // mirror knows which script raised the event. var factory = new ScriptLoggerFactory(rootScriptLogger); var perScript = factory.Create("HighTemp"); perScript.Error("threshold exceeded"); // Scripts sink saw the Error at its original level with the ScriptName bound. scriptsSink.Events.Count.ShouldBe(1); scriptsSink.Events[0].Level.ShouldBe(LogEventLevel.Error); ((ScalarValue)scriptsSink.Events[0].Properties[ScriptLoggerFactory.ScriptNameProperty]).Value.ShouldBe("HighTemp"); // Main sink saw a Warning-level companion entry tagged with the same ScriptName. mainSink.Events.Count.ShouldBe(1); mainSink.Events[0].Level.ShouldBe(LogEventLevel.Warning); ((ScalarValue)mainSink.Events[0].Properties[ScriptLoggerFactory.ScriptNameProperty]).Value.ShouldBe("HighTemp"); ((ScalarValue)mainSink.Events[0].Properties["OriginalLevel"]).Value.ShouldBe(LogEventLevel.Error); } }