From ec9011429c92f3717080a9151498e17ad21b225f Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Sun, 6 Sep 2026 01:57:09 -0400 Subject: [PATCH] =?UTF-8?q?fix(site-runtime):=20trace=20sink=20is=20guarde?= =?UTF-8?q?d=20=E2=80=94=20a=20throwing=20observer=20can=20neither=20fail?= =?UTF-8?q?=20a=20call=20nor=20skip=20the=20audit=20write?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review of Task 3: the sink invoke sat before WriteAsync/ForwardAsync inside the best-effort try, so a throwing sink would have silently dropped the durable row. GuardTraceSink wraps the delegate in every helper ctor (and Collect guards EmitTrace); pinned by a throwing-sink test. ScriptRunLauncher no longer allocates a collector for a traced run with no reply target (Nobody) — the list would never be read. FlowTraceCollector.Complete pinned at unit level; Snapshot documented as a non-closing peek. Claude-Session: https://claude.ai/code/session_01NcMG6xXdsJbmD2wYAgkK29 --- .../Scripts/FlowTraceCollector.cs | 6 ++- .../Scripts/ScriptRunLauncher.cs | 6 ++- .../Scripts/ScriptRuntimeContext.cs | 42 ++++++++++++++++--- .../Scripts/FlowTraceCollectorTests.cs | 30 +++++++++++++ .../ScriptRuntimeContextTraceEmissionTests.cs | 16 +++++++ 5 files changed, 92 insertions(+), 8 deletions(-) diff --git a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/FlowTraceCollector.cs b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/FlowTraceCollector.cs index 46a92f1b..101b561e 100644 --- a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/FlowTraceCollector.cs +++ b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/FlowTraceCollector.cs @@ -72,7 +72,11 @@ public sealed class FlowTraceCollector /// Current event count. public int Count { get { lock (_gate) return _events.Count; } } - /// Copies the collected events in emission order. + /// + /// Copies the collected events in emission order WITHOUT closing the collector — a diagnostic / + /// test-only peek. A reply path must use , otherwise an un-awaited call + /// finishing after the reply could mutate the list the reply was built from. + /// public IReadOnlyList Snapshot() { lock (_gate) return _events.ToArray(); diff --git a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs index f5a2b297..77b46ef1 100644 --- a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs +++ b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs @@ -243,9 +243,11 @@ internal static class ScriptRunLauncher ScriptTraceExtra? triggerExtra = null) { IServiceScope? serviceScope = null; - // Flow Debugger (design §5.4): the inline sink exists only for a traced run; the + // Flow Debugger (design §5.4): the inline sink exists only for a traced run that has a + // caller to reply to — a trace-armed trigger run (replyTo == Nobody) writes every row to the + // audit writer for PullTraceEvents and would only keep a never-read list alive. The // ScriptRun row itself is emitted below on every exit path of a traced run. - var collector = trace ? new FlowTraceCollector() : null; + var collector = trace && !replyTo.IsNobody() ? new FlowTraceCollector() : null; var startedUtc = DateTime.UtcNow; ScriptRuntimeContext? context = null; IAuditWriter? auditWriter = null; diff --git a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRuntimeContext.cs b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRuntimeContext.cs index 04a773b8..425ea5ae 100644 --- a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRuntimeContext.cs +++ b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRuntimeContext.cs @@ -306,7 +306,39 @@ public class ScriptRuntimeContext /// outbound rows the helpers emit — passes through here; a no-op when untraced or once /// the launcher has d the run. /// - private void Collect(AuditEvent evt) => _traceCollector?.Add(evt); + private void Collect(AuditEvent evt) + { + try + { + _traceCollector?.Add(evt); + } + catch (Exception ex) + { + // The collector is a debug-only observer: it must never fail a script call, and it + // must never keep the durable audit row from reaching the writer (review, 2026-09-06). + _logger.LogWarning(ex, "Flow trace collector rejected {Action} ({EventId})", evt.Action, evt.EventId); + } + } + + /// + /// Wraps a trace sink so a throwing observer can neither fail the script call nor skip the + /// durable audit write that follows it. Null in, null out — an untraced run allocates nothing. + /// + internal static Action? GuardTraceSink(Action? sink, ILogger logger) + { + if (sink is null) return null; + return evt => + { + try + { + sink(evt); + } + catch (Exception ex) + { + logger.LogWarning(ex, "Flow trace sink rejected {Action} ({EventId})", evt.Action, evt.EventId); + } + }; + } /// Flow Debugger (design 2026-09-05 §5.2): whether this run emits ScriptTrace rows. public bool IsTraced => _isTraced; @@ -1146,7 +1178,7 @@ public class ScriptRuntimeContext _cachedForwarder = cachedForwarder; _parentExecutionId = parentExecutionId; _sourceNode = sourceNode; - _traceSink = traceSink; + _traceSink = GuardTraceSink(traceSink, logger); } /// @@ -1850,7 +1882,7 @@ public class ScriptRuntimeContext _cachedForwarder = cachedForwarder; _parentExecutionId = parentExecutionId; _sourceNode = sourceNode; - _traceSink = traceSink; + _traceSink = GuardTraceSink(traceSink, logger); } /// @@ -2279,7 +2311,7 @@ public class ScriptRuntimeContext _auditWriter = auditWriter; _parentExecutionId = parentExecutionId; _sourceNode = sourceNode; - _traceSink = traceSink; + _traceSink = GuardTraceSink(traceSink, logger); } /// @@ -2455,7 +2487,7 @@ public class ScriptRuntimeContext _auditWriter = auditWriter; _parentExecutionId = parentExecutionId; _sourceNode = sourceNode; - _traceSink = traceSink; + _traceSink = GuardTraceSink(traceSink, logger); } /// diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/FlowTraceCollectorTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/FlowTraceCollectorTests.cs index c5a18319..a9b56210 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/FlowTraceCollectorTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/FlowTraceCollectorTests.cs @@ -64,4 +64,34 @@ public class FlowTraceCollectorTests Assert.Equal(500, FlowTraceCollector.DefaultMaxEvents); Assert.Throws(() => new FlowTraceCollector(0)); } + + [Fact] + public void Complete_ClosesTheCollector_LaterAddsAreIgnored_AndNeverTruncate() + { + var c = new FlowTraceCollector(maxEvents: 2); + var first = NewEvent(); + c.Add(first); + Assert.False(c.Completed); + + var snapshot = c.Complete(); + + Assert.True(c.Completed); + Assert.Same(first, Assert.Single(snapshot)); + c.Add(NewEvent()); + c.Add(NewEvent()); + c.Add(NewEvent()); + Assert.Equal(1, c.Count); + Assert.False(c.Truncated); + Assert.Equal(snapshot, c.Complete()); // idempotent + } + + private static AuditEvent NewEvent() => new() + { + EventId = Guid.NewGuid(), + OccurredAtUtc = DateTimeOffset.UtcNow, + Actor = "t", + Action = "ScriptTrace.ScriptRun", + Outcome = AuditOutcome.Success, + DetailsJson = "{}", + }; } diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRuntimeContextTraceEmissionTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRuntimeContextTraceEmissionTests.cs index 409b99c8..718abd7a 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRuntimeContextTraceEmissionTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRuntimeContextTraceEmissionTests.cs @@ -507,4 +507,20 @@ public class ScriptRuntimeContextTraceEmissionTests : TestKit writer.Events.Select(e => Row(e).Kind)); Assert.Equal(AuditKind.CachedSubmit, Row(Assert.Single(forwarder.Telemetry).Audit).Kind); } + + [Fact] + public async Task ThrowingTraceSink_NeverFailsTheCall_AndTheWriterStillGetsTheRow() + { + var writer = new CapturingAuditWriter(); + var helper = new ScriptRuntimeContext.ExternalSystemHelper( + SyncClient(new ExternalCallResult(true, "{}", null)).Object, InstanceName, NullLogger.Instance, Guid.NewGuid(), + auditWriter: writer, siteId: "site-a", sourceScript: "S", + traceSink: _ => throw new InvalidOperationException("observer broke")); + + var result = await helper.Call("ERP", "GetOrder"); + + Assert.True(result.Success); + var written = Assert.Single(writer.Events); + Assert.Equal(AuditKind.ApiCall, Row(written).Kind); + } }