fix(site-runtime): TraceCapturingLogger rejects double-wrapping; ScriptLogger clip keeps surrogate pairs (Task 4 review)

src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptLogger.cs

@@ -165,7 +165,28 @@ public sealed class ScriptLogger
         }
     }
 
-    /// <summary>Applies the per-message cap, marking a truncated message with a trailing ellipsis.</summary>
-    private static string Clip(string? m) =>
-        m is null ? string.Empty : m.Length <= MaxMessageChars ? m : m[..MaxMessageChars] + "…";
+    /// <summary>
+    /// Applies the per-message cap, marking a truncated message with a trailing ellipsis.
+    ///
+    /// <para>Cuts one char short when the cap would land between the two halves of a surrogate
+    /// pair, so an emoji straddling the boundary is dropped whole rather than leaving a lone
+    /// surrogate that breaks JSON serialization downstream. Re-clipping an already-clipped message
+    /// is a no-op, which matters because the script path clips once before logging and again
+    /// before emitting.</para>
+    /// </summary>
+    private static string Clip(string? m)
+    {
+        if (m is null)
+        {
+            return string.Empty;
+        }
+
+        if (m.Length <= MaxMessageChars)
+        {
+            return m;
+        }
+
+        var keep = char.IsHighSurrogate(m[MaxMessageChars - 1]) ? MaxMessageChars - 1 : MaxMessageChars;
+        return m[..keep] + "…";
+    }
 }

src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/TraceCapturingLogger.cs

@@ -18,12 +18,31 @@ namespace ZB.MOM.WW.ScadaBridge.SiteRuntime.Scripts;
 ///
 /// <para>Installed only when the run is traced, so an untraced run keeps the bare inner logger.</para>
 /// </summary>
-/// <param name="inner">The node logger every entry is forwarded to.</param>
-/// <param name="sink">The run's <see cref="ScriptLogger"/>, which owns the caps and the row emitter.</param>
-public sealed class TraceCapturingLogger(ILogger inner, ScriptLogger sink) : ILogger
+public sealed class TraceCapturingLogger : ILogger
 {
+    private readonly ILogger _inner;
+    private readonly ScriptLogger _sink;
+
+    /// <summary>Wraps <paramref name="inner"/> so that Information and above also reach <paramref name="sink"/>.</summary>
+    /// <param name="inner">The node logger every entry is forwarded to.</param>
+    /// <param name="sink">The run's <see cref="ScriptLogger"/>, which owns the caps and the row emitter.</param>
+    /// <exception cref="ArgumentNullException"><paramref name="inner"/> or <paramref name="sink"/> is null.</exception>
+    /// <exception cref="ArgumentException"><paramref name="inner"/> is itself a <see cref="TraceCapturingLogger"/>.</exception>
+    public TraceCapturingLogger(ILogger inner, ScriptLogger sink)
+    {
+        ArgumentNullException.ThrowIfNull(inner);
+        ArgumentNullException.ThrowIfNull(sink);
+        if (inner is TraceCapturingLogger)
+        {
+            throw new ArgumentException("inner is already a TraceCapturingLogger — wrapping twice would emit two rows per script line", nameof(inner));
+        }
+
+        _inner = inner;
+        _sink = sink;
+    }
+
     /// <inheritdoc />
-    public IDisposable? BeginScope<TState>(TState state) where TState : notnull => inner.BeginScope(state);
+    public IDisposable? BeginScope<TState>(TState state) where TState : notnull => _inner.BeginScope(state);
 
     /// <summary>
     /// Information and above are always enabled — they are trace data even when the node's minimum
@@ -31,16 +50,16 @@ public sealed class TraceCapturingLogger(ILogger inner, ScriptLogger sink) : ILo
     /// </summary>
     /// <param name="level">The level being tested.</param>
     /// <returns><see langword="true"/> when the entry should be produced.</returns>
-    public bool IsEnabled(LogLevel level) => level >= LogLevel.Information || inner.IsEnabled(level);
+    public bool IsEnabled(LogLevel level) => level >= LogLevel.Information || _inner.IsEnabled(level);
 
     /// <inheritdoc />
     public void Log<TState>(LogLevel level, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
     {
         // Forward first, and only if the inner logger actually wants it: IsEnabled above lies
         // upward for trace capture, so the node's own minimum level must be re-checked here.
-        if (inner.IsEnabled(level))
+        if (_inner.IsEnabled(level))
         {
-            inner.Log(level, eventId, state, exception, formatter);
+            _inner.Log(level, eventId, state, exception, formatter);
         }
 
         if (level < LogLevel.Information || level == LogLevel.None)
@@ -55,6 +74,6 @@ public sealed class TraceCapturingLogger(ILogger inner, ScriptLogger sink) : ILo
             _ => "error",
         };
 
-        sink.Runtime(name, formatter(state, exception), exception);
+        _sink.Runtime(name, formatter(state, exception), exception);
     }
 }

tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptLoggerTests.cs

@@ -112,6 +112,32 @@ public class ScriptLoggerTests
         Assert.Null(rows[1].StepEventId);
     }
 
+    [Fact]
+    public void NestedStepScopes_Unwind_ToTheEnclosingStep()
+    {
+        // A helper calling another helper: the inner step owns its own lines, and the outer step
+        // gets its attribution back the moment the inner scope closes.
+        var (logger, _, rows) = MakeTraced();
+        var outer = Guid.NewGuid();
+        var inner = Guid.NewGuid();
+
+        using (TraceStepScope.Enter(outer))
+        {
+            using (TraceStepScope.Enter(inner))
+            {
+                Assert.Equal(inner, TraceStepScope.Current);
+                logger.Info("inner");
+            }
+
+            Assert.Equal(outer, TraceStepScope.Current);
+            logger.Info("outer");
+        }
+
+        Assert.Null(TraceStepScope.Current);
+        Assert.Equal(inner, rows[0].StepEventId);
+        Assert.Equal(outer, rows[1].StepEventId);
+    }
+
     [Fact]
     public void PastThePerRunCap_LinesAreDropped_AndFlushDroppedNamesTheCount_Once()
     {
@@ -164,6 +190,33 @@ public class ScriptLoggerTests
         Assert.EndsWith("…", message);
     }
 
+    [Fact]
+    public void AMessageExactlyAtTheCap_PassesThroughUnclipped()
+    {
+        var (logger, _, rows) = MakeTraced();
+        var exact = new string('x', ScriptLogger.MaxMessageChars);
+
+        logger.Info(exact);
+
+        Assert.Equal(exact, Assert.Single(rows).Message);
+    }
+
+    [Fact]
+    public void ASurrogatePairStraddlingTheCap_IsDroppedWhole()
+    {
+        // Cutting between the halves would leave a lone surrogate, which breaks JSON serialization
+        // of the audit row further down the pipe.
+        var (logger, _, rows) = MakeTraced();
+        var straddling = new string('x', ScriptLogger.MaxMessageChars - 1) + "🚀" + new string('y', 10);
+
+        logger.Info(straddling);
+
+        var message = Assert.Single(rows).Message;
+        Assert.Equal(ScriptLogger.MaxMessageChars, message.Length);
+        Assert.EndsWith("…", message);
+        Assert.DoesNotContain(message, static c => char.IsSurrogate(c));
+    }
+
     [Fact]
     public void AThrowingEmitter_NeverReachesTheScript_AndTheNodeLoggerStillGotTheLine()
     {

tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/TraceCapturingLoggerTests.cs

@@ -135,6 +135,27 @@ public class TraceCapturingLoggerTests
         Assert.Equal(stepId, Assert.Single(rows).StepEventId);
     }
 
+    [Fact]
+    public void Ctor_RejectsAnAlreadyDecoratedLogger()
+    {
+        // Wrapping twice would forward each script line through two capture stages and emit two
+        // runtime rows per line — and would burn the run's line cap at double rate.
+        var (already, _, _) = Make();
+        var sink = new ScriptLogger(new RecordingLogger(), emit: null, maxLines: 200, "i", "s", null);
+
+        var ex = Assert.Throws<ArgumentException>(() => new TraceCapturingLogger(already, sink));
+        Assert.Equal("inner", ex.ParamName);
+    }
+
+    [Fact]
+    public void Ctor_RequiresBothCollaborators()
+    {
+        var sink = new ScriptLogger(new RecordingLogger(), emit: null, maxLines: 200, "i", "s", null);
+
+        Assert.Throws<ArgumentNullException>(() => new TraceCapturingLogger(null!, sink));
+        Assert.Throws<ArgumentNullException>(() => new TraceCapturingLogger(new RecordingLogger(), null!));
+    }
+
     [Fact]
     public void BeginScope_DelegatesToTheInnerLogger()
     {