merge: Calculation + OpcUaClient.Session code review — warm-up gate before evaluation (spurious script-throw warnings), evaluator logger wiring, probe JSON-leniency parity; 7 findings

2026-08-10 07:00:33 -04:00
parent c58e833aee 416c471809
commit 147b624437
8 changed files with 529 additions and 15 deletions
@@ -0,0 +1,72 @@
+using Shouldly;
+using Xunit;
+
+namespace ZB.MOM.WW.OtOpcUa.Driver.Calculation.Tests;
+
+/// <summary>
+///     Unit tests for <see cref="CalculationDriverProbe"/> — the Calculation pseudo-driver's Test-Connect
+///     probe (parse-only, since there is no backend to reach).
+/// </summary>
+public sealed class CalculationDriverProbeTests
+{
+    private static readonly CalculationDriverProbe Sut = new();
+
+    [Fact]
+    public async Task Empty_config_json_fails()
+    {
+        var result = await Sut.ProbeAsync("", TimeSpan.FromSeconds(1), TestContext.Current.CancellationToken);
+        result.Ok.ShouldBeFalse();
+        result.Message.ShouldNotBeNullOrWhiteSpace();
+    }
+
+    [Fact]
+    public async Task Malformed_json_fails()
+    {
+        var result = await Sut.ProbeAsync("not json", TimeSpan.FromSeconds(1), TestContext.Current.CancellationToken);
+        result.Ok.ShouldBeFalse();
+        result.Message.ShouldNotBeNullOrWhiteSpace();
+    }
+
+    [Fact]
+    public async Task A_config_with_no_rawTags_array_is_still_valid()
+    {
+        var result = await Sut.ProbeAsync("{}", TimeSpan.FromSeconds(1), TestContext.Current.CancellationToken);
+        result.Ok.ShouldBeTrue(result.Message);
+    }
+
+    [Fact]
+    public async Task A_well_formed_rawTags_config_is_valid()
+    {
+        const string json = """{"rawTags":[{"rawPath":"calc/e/x","tagConfig":"{}","writeIdempotent":false}]}""";
+        var result = await Sut.ProbeAsync(json, TimeSpan.FromSeconds(1), TestContext.Current.CancellationToken);
+        result.Ok.ShouldBeTrue(result.Message);
+    }
+
+    /// <summary>
+    ///     The probe must not be STRICTER than the real spawn/reinit path: both
+    ///     <c>CalculationDriverFactoryExtensions.JsonOptions</c> and <c>CalculationDriver.ReinitJsonOptions</c>
+    ///     set <c>AllowTrailingCommas</c> + <c>ReadCommentHandling.Skip</c>. Before this pin the probe's own
+    ///     options omitted both, so a config a real deploy would accept could fail Test-Connect as "invalid".
+    /// </summary>
+    [Fact]
+    public async Task Tolerates_trailing_commas_like_the_real_spawn_and_reinit_paths()
+    {
+        const string json = """{"rawTags":[{"rawPath":"calc/e/x","tagConfig":"{}","writeIdempotent":false},],}""";
+        var result = await Sut.ProbeAsync(json, TimeSpan.FromSeconds(1), TestContext.Current.CancellationToken);
+        result.Ok.ShouldBeTrue(result.Message);
+    }
+
+    /// <summary>Same parity claim for comments, which the spawn/reinit path also tolerates.</summary>
+    [Fact]
+    public async Task Tolerates_comments_like_the_real_spawn_and_reinit_paths()
+    {
+        const string json = """
+            {
+                // a hand-edited config comment
+                "rawTags": []
+            }
+            """;
+        var result = await Sut.ProbeAsync(json, TimeSpan.FromSeconds(1), TestContext.Current.CancellationToken);
+        result.Ok.ShouldBeTrue(result.Message);
+    }
+}
@@ -1,4 +1,5 @@
 using System.Collections.Concurrent;
+using Microsoft.Extensions.Logging;
 using Serilog;
 using Serilog.Events;
 using Shouldly;
@@ -74,6 +75,27 @@ public sealed class CalculationDriverTests
        e.Snapshot.StatusCode.ShouldBe(StatusGood);
    }

+    /// <summary>
+    ///     The change-gate must hold BEFORE the script ever runs, not just before the publish. A
+    ///     multi-dependency script that casts a missing dep's <c>.Value</c> to a non-nullable type (the
+    ///     common idiom used throughout this file) throws when evaluated against a partial snapshot, so
+    ///     evaluating anyway during ordinary warm-up produced a spurious "script threw" script-log Warning
+    ///     on every partial dependency arrival — even though nothing is actually wrong with the script.
+    /// </summary>
+    [Fact]
+    public async Task No_evaluation_or_script_log_while_a_declared_dep_is_still_missing()
+    {
+        var (driver, published, logs) = Build(
+            CalcTag("calc/e/sum", "return (double)ctx.GetTag(\"src/a\").Value + (double)ctx.GetTag(\"src/b\").Value;"));
+        await driver.InitializeAsync("{}", TestContext.Current.CancellationToken);
+
+        driver.OnDependencyValue("src/a", 10.0, StatusGood, DateTime.UtcNow);
+
+        published.ShouldBeEmpty();
+        logs.ShouldBeEmpty("a still-missing declared dependency must hold the gate BEFORE evaluation, " +
+                            "not merely before the publish");
+    }
+
    // ── dedup + recompute ─────────────────────────────────────────────────────────────────────

    [Fact]
@@ -209,6 +231,102 @@ public sealed class CalculationDriverTests
        driver.GetHealth().State.ShouldBe(DriverState.Unknown);
    }

+    // ── evaluator diagnostics reach the driver's own logger ──────────────────────────────────────
+
+    /// <summary>
+    ///     The <see cref="CalculationEvaluator"/> the driver constructs internally must log its host-side
+    ///     diagnostics (compile errors, sandbox violations, execution throws) through the SAME
+    ///     <c>ILogger&lt;CalculationDriver&gt;</c> the driver itself was given — not silently into a
+    ///     no-op logger. A timer-triggered tag with a deliberately broken script is the vehicle: it
+    ///     evaluates on its own cadence with no dependency needed to arrive first.
+    /// </summary>
+    [Fact]
+    public async Task Evaluator_compile_diagnostics_flow_through_to_the_drivers_own_logger()
+    {
+        var logger = new CapturingLogger();
+        var scriptRoot = new ScriptRootLogger(new LoggerConfiguration().CreateLogger());
+        var driver = new CalculationDriver(
+            new CalculationDriverOptions
+            {
+                RawTags = [CalcTag("calc/e/bad", "this is not valid C#;", changeTriggered: false, timerMs: 50)],
+            },
+            "calc-drv", scriptRoot, logger);
+        await driver.InitializeAsync("{}", TestContext.Current.CancellationToken);
+
+        var fired = await WaitUntil(
+            () => logger.Entries.Any(e => e.Level == LogLevel.Warning && e.Message.Contains("Roslyn compile failed")),
+            TimeSpan.FromSeconds(3));
+
+        fired.ShouldBeTrue("the evaluator's compile-failure diagnostic should reach the driver-supplied logger");
+
+        await driver.ShutdownAsync(TestContext.Current.CancellationToken);
+    }
+
+    // ── skipped-tag reporting (Gitea #541) ────────────────────────────────────────────────────────
+
+    [Fact]
+    public async Task GetSkippedTags_reports_a_raw_tag_with_no_scriptId_alongside_the_authored_total()
+    {
+        var noScriptId = new RawTagEntry("calc/e/nogood", "{\"foo\":\"bar\"}", WriteIdempotent: false);
+        var good = CalcTag("calc/e/good", "return 1.0;", changeTriggered: false);
+        var (driver, _, _) = Build(noScriptId, good);
+        await driver.InitializeAsync("{}", TestContext.Current.CancellationToken);
+
+        var report = driver.GetSkippedTags();
+
+        report.ShouldNotBeNull();
+        report!.AuthoredCount.ShouldBe(2);
+        report.SkippedCount.ShouldBe(1);
+        report.Sample.ShouldContain(s => s.RawPath == "calc/e/nogood");
+    }
+
+    [Fact]
+    public async Task GetSkippedTags_has_no_skips_when_every_authored_tag_maps()
+    {
+        var (driver, _, _) = Build(CalcTag("calc/e/good", "return 1.0;", changeTriggered: false));
+        await driver.InitializeAsync("{}", TestContext.Current.CancellationToken);
+
+        var report = driver.GetSkippedTags();
+
+        report.ShouldNotBeNull();
+        report!.AuthoredCount.ShouldBe(1);
+        report.SkippedCount.ShouldBe(0);
+        report.HasSkips.ShouldBeFalse();
+    }
+
+    /// <summary>The skip ledger must be REBUILT on ReinitializeAsync, not just at construction — an
+    /// ApplyDelta that drops a tag's scriptId (or adds a new tag with none) must be reflected immediately,
+    /// since RebuildTagTable is the one routine both the ctor and reinit share.</summary>
+    [Fact]
+    public async Task GetSkippedTags_updates_after_reinitialize()
+    {
+        var (driver, _, _) = Build(CalcTag("calc/e/x", "return 1.0;", changeTriggered: false));
+        await driver.InitializeAsync("{}", TestContext.Current.CancellationToken);
+        driver.GetSkippedTags()!.SkippedCount.ShouldBe(0);
+
+        const string reinitJson = """{"rawTags":[{"rawPath":"calc/e/x","tagConfig":"{}","writeIdempotent":false}]}""";
+        await driver.ReinitializeAsync(reinitJson, TestContext.Current.CancellationToken);
+
+        var report = driver.GetSkippedTags();
+        report!.AuthoredCount.ShouldBe(1);
+        report.SkippedCount.ShouldBe(1, "the reinit payload's tag has no scriptId, so it is no longer a calc tag");
+    }
+
+    /// <summary>Minimal capturing <see cref="ILogger{T}"/> so a test can assert on what the driver's own
+    /// logger received (mirrors the equivalent helper in CalculationEvaluatorTests).</summary>
+    private sealed class CapturingLogger : ILogger<CalculationDriver>
+    {
+        public List<(LogLevel Level, string Message)> Entries { get; } = [];
+
+        public IDisposable? BeginScope<TState>(TState state) where TState : notnull => null;
+
+        public bool IsEnabled(LogLevel logLevel) => true;
+
+        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception,
+            Func<TState, Exception?, string> formatter) =>
+            Entries.Add((logLevel, formatter(state, exception)));
+    }
+
    private sealed class CapturingPublisher(List<ScriptLogEntry> sink) : IScriptLogPublisher
    {
        private readonly object _lock = new();