using System.Collections.Concurrent; using Microsoft.Extensions.Logging; 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.Abstractions; using ZB.MOM.WW.OtOpcUa.Core.Scripting; namespace ZB.MOM.WW.OtOpcUa.Driver.Calculation.Tests; /// /// Review 07 Calculation remediation: a compile failure is negative-cached by source hash and its /// Warning/script-log fires on the Good→Bad transition only (P4); inputs are recorded before /// InitializeAsync so a Restart computes from current inputs (H6); array results dedup /// structurally (H8); ShutdownAsync drops the compiled scripts (L2). /// public sealed class CalculationDriverRemediationTests { private const uint StatusGood = 0u; private const uint StatusBadInternalError = 0x80020000u; private static RawTagEntry CalcTag(string rawPath, string source, bool changeTriggered = true, int? timerMs = null) { var timer = timerMs is { } ms ? $",\"timerIntervalMs\":{ms}" : ""; var json = $"{{\"scriptId\":\"s-{rawPath}\",\"changeTriggered\":{(changeTriggered ? "true" : "false")}{timer}," + $"\"scriptSource\":{System.Text.Json.JsonSerializer.Serialize(source)}}}"; return new RawTagEntry(rawPath, json, WriteIdempotent: false); } private static (CalculationDriver Driver, ConcurrentQueue Published, List Logs, CapturingLogger HostLog) Build(params RawTagEntry[] tags) { var logs = new List(); var sink = new ScriptLogTopicSink(new CapturingPublisher(logs), LogEventLevel.Information); var scriptRoot = new ScriptRootLogger(new LoggerConfiguration().WriteTo.Sink(sink).CreateLogger()); var hostLog = new CapturingLogger(); var driver = new CalculationDriver(new CalculationDriverOptions { RawTags = tags }, "calc-drv", scriptRoot, hostLog); var published = new ConcurrentQueue(); driver.OnDataChange += (_, e) => published.Enqueue(e); return (driver, published, logs, hostLog); } private static async Task Settle(CalculationDriver driver) { var deadline = DateTime.UtcNow.AddSeconds(30); while (!driver.IsEvaluationIdle && DateTime.UtcNow < deadline) await Task.Delay(10); driver.IsEvaluationIdle.ShouldBeTrue("the calc driver's evaluation pump should have drained"); } /// Fix round 1 minor: Dispose releases the evaluation gate and its cancellation source — even /// with a runaway run in flight (the guard lets the caller's cancel win, so the awaited run returns /// promptly) — and a trigger arriving after Dispose is harmless. [Fact] public async Task Dispose_with_a_run_in_flight_disposes_the_eval_gate_and_a_late_trigger_is_harmless() { var (driver, _, _, _) = Build( CalcTag("calc/e/spin", "var v = ctx.GetTag(\"src/a\").Value; var end = System.DateTime.UtcNow.AddSeconds(6); while (System.DateTime.UtcNow < end) { } return 1;")); await driver.InitializeAsync("{}", TestContext.Current.CancellationToken); driver.OnDependencyValue("src/a", 1, StatusGood, DateTime.UtcNow); var deadline = DateTime.UtcNow.AddSeconds(10); while (driver.IsEvaluationIdle && DateTime.UtcNow < deadline) await Task.Delay(5); driver.IsEvaluationIdle.ShouldBeFalse("positive control: a run is in flight when Dispose lands"); var sw = System.Diagnostics.Stopwatch.StartNew(); driver.Dispose(); sw.Elapsed.ShouldBeLessThan(TimeSpan.FromSeconds(5), "the caller's cancel releases the awaited run; Dispose is not held for the 6 s spin"); driver.EvalResourcesDisposedForTest.ShouldBeTrue(); Should.NotThrow(() => driver.OnDependencyValue("src/a", 2, StatusGood, DateTime.UtcNow)); Should.NotThrow(() => driver.Dispose()); } [Fact] public async Task A_compile_failure_is_remembered_and_logged_once_across_repeated_triggers() { var (driver, published, logs, hostLog) = Build( CalcTag("calc/e/broken", "var x = (double)ctx.GetTag(\"src/a\").Value; this is not valid C#;")); await driver.InitializeAsync("{}", TestContext.Current.CancellationToken); for (var i = 0; i < 5; i++) { driver.OnDependencyValue("src/a", i, StatusGood, DateTime.UtcNow); await Settle(driver); } published.Count.ShouldBe(1, "Bad is published once per transition"); published.TryDequeue(out var bad).ShouldBeTrue(); bad!.Snapshot.StatusCode.ShouldBe(StatusBadInternalError); logs.Count.ShouldBe(1, "the script-log entry fires on the Good→Bad transition only"); hostLog.Entries.Count(e => e.Level == LogLevel.Warning && e.Message.Contains("compile failed")).ShouldBe(1, "Roslyn is consulted once per source; later triggers hit the negative cache"); driver.CompileFailureCountForTest.ShouldBe(1); } [Fact] public async Task A_changed_failure_reason_is_logged_even_while_already_Bad() { // Throws with a different message depending on the input, so the failure REASON changes while the // published status stays Bad — the operator must see the new reason. var (driver, published, logs, _) = Build( CalcTag("calc/e/thrower", "throw new System.InvalidOperationException(\"boom \" + (int)ctx.GetTag(\"src/a\").Value);")); await driver.InitializeAsync("{}", TestContext.Current.CancellationToken); driver.OnDependencyValue("src/a", 1, StatusGood, DateTime.UtcNow); await Settle(driver); driver.OnDependencyValue("src/a", 1, StatusGood, DateTime.UtcNow); // same reason → no new log await Settle(driver); driver.OnDependencyValue("src/a", 2, StatusGood, DateTime.UtcNow); // new reason → logged await Settle(driver); published.Count.ShouldBe(1); logs.Count.ShouldBe(2); logs[0].Message.ShouldContain("boom 1"); logs[1].Message.ShouldContain("boom 2"); } [Fact] public async Task Inputs_delivered_before_InitializeAsync_are_kept_so_the_first_trigger_computes() { // H6: a Restart is a new driver whose adapter registers interest at construction; the mux's // retained-value replay therefore lands BEFORE InitializeAsync. It used to be dropped. var (driver, published, _, _) = Build( CalcTag("calc/e/sum", "return (double)ctx.GetTag(\"src/a\").Value + (double)ctx.GetTag(\"src/b\").Value;")); driver.OnDependencyValue("src/a", 10.0, StatusGood, DateTime.UtcNow); // replayed, pre-init driver.OnDependencyValue("src/b", 20.0, StatusGood, DateTime.UtcNow); published.ShouldBeEmpty("evaluation is gated on running"); await driver.InitializeAsync("{}", TestContext.Current.CancellationToken); driver.OnDependencyValue("src/a", 12.0, StatusGood, DateTime.UtcNow); // only ONE input moves after init await Settle(driver); published.Count.ShouldBe(1, "src/b's pre-init value satisfied the change-gate"); published.TryDequeue(out var e).ShouldBeTrue(); e!.Snapshot.Value.ShouldBe(32.0); } [Fact] public async Task An_equal_array_result_is_deduped_structurally() { var (driver, published, _, _) = Build( CalcTag("calc/e/arr", "var v = (double)ctx.GetTag(\"src/a\").Value; return new double[] { v, v * 2 };")); await driver.InitializeAsync("{}", TestContext.Current.CancellationToken); driver.OnDependencyValue("src/a", 1.0, StatusGood, DateTime.UtcNow); await Settle(driver); driver.OnDependencyValue("src/a", 1.0, StatusGood, DateTime.UtcNow); // same array contents await Settle(driver); published.Count.ShouldBe(1, "a structurally equal array is not a change"); driver.OnDependencyValue("src/a", 2.0, StatusGood, DateTime.UtcNow); await Settle(driver); published.Count.ShouldBe(2, "a different array still publishes"); published.Last().Snapshot.Value.ShouldBe(new double[] { 2.0, 4.0 }); } [Fact] public async Task ShutdownAsync_drops_the_compiled_scripts() { var (driver, published, _, _) = Build(CalcTag("calc/e/x", "return (double)ctx.GetTag(\"src/a\").Value * 2.0;")); await driver.InitializeAsync("{}", TestContext.Current.CancellationToken); driver.OnDependencyValue("src/a", 1.0, StatusGood, DateTime.UtcNow); await Settle(driver); published.Count.ShouldBe(1); driver.CompiledScriptCountForTest.ShouldBe(1); await driver.ShutdownAsync(TestContext.Current.CancellationToken); driver.CompiledScriptCountForTest.ShouldBe(0, "the collectible ALCs must not survive the generation"); } private sealed class CapturingPublisher(List entries) : IScriptLogPublisher { public void Publish(ScriptLogEntry entry) { lock (entries) entries.Add(entry); } } internal sealed class CapturingLogger : ILogger { public ConcurrentBag<(LogLevel Level, string Message)> Entries { get; } = new(); public IDisposable? BeginScope(TState state) where TState : notnull => null; public bool IsEnabled(LogLevel logLevel) => true; public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) => Entries.Add((logLevel, formatter(state, exception))); } }