fix(site-runtime): trace sink is guarded — a throwing observer can neither fail a call nor skip the audit write

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
This commit is contained in:
Joseph Doherty
2026-09-06 01:57:09 -04:00
parent 69feb40e65
commit ec9011429c
5 changed files with 92 additions and 8 deletions
@@ -72,7 +72,11 @@ public sealed class FlowTraceCollector
/// <summary>Current event count.</summary>
public int Count { get { lock (_gate) return _events.Count; } }
/// <summary>Copies the collected events in emission order.</summary>
/// <summary>
/// Copies the collected events in emission order WITHOUT closing the collector — a diagnostic /
/// test-only peek. A reply path must use <see cref="Complete"/>, otherwise an un-awaited call
/// finishing after the reply could mutate the list the reply was built from.
/// </summary>
public IReadOnlyList<AuditEvent> Snapshot()
{
lock (_gate) return _events.ToArray();
@@ -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;
@@ -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 <see cref="FlowTraceCollector.Complete"/>d the run.
/// </summary>
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);
}
}
/// <summary>
/// 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.
/// </summary>
internal static Action<AuditEvent>? GuardTraceSink(Action<AuditEvent>? 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);
}
};
}
/// <summary>Flow Debugger (design 2026-09-05 §5.2): whether this run emits <c>ScriptTrace</c> rows.</summary>
public bool IsTraced => _isTraced;
@@ -1146,7 +1178,7 @@ public class ScriptRuntimeContext
_cachedForwarder = cachedForwarder;
_parentExecutionId = parentExecutionId;
_sourceNode = sourceNode;
_traceSink = traceSink;
_traceSink = GuardTraceSink(traceSink, logger);
}
/// <summary>
@@ -1850,7 +1882,7 @@ public class ScriptRuntimeContext
_cachedForwarder = cachedForwarder;
_parentExecutionId = parentExecutionId;
_sourceNode = sourceNode;
_traceSink = traceSink;
_traceSink = GuardTraceSink(traceSink, logger);
}
/// <summary>
@@ -2279,7 +2311,7 @@ public class ScriptRuntimeContext
_auditWriter = auditWriter;
_parentExecutionId = parentExecutionId;
_sourceNode = sourceNode;
_traceSink = traceSink;
_traceSink = GuardTraceSink(traceSink, logger);
}
/// <summary>
@@ -2455,7 +2487,7 @@ public class ScriptRuntimeContext
_auditWriter = auditWriter;
_parentExecutionId = parentExecutionId;
_sourceNode = sourceNode;
_traceSink = traceSink;
_traceSink = GuardTraceSink(traceSink, logger);
}
/// <summary>
@@ -64,4 +64,34 @@ public class FlowTraceCollectorTests
Assert.Equal(500, FlowTraceCollector.DefaultMaxEvents);
Assert.Throws<ArgumentOutOfRangeException>(() => 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 = "{}",
};
}
@@ -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);
}
}