fix(inbound-api): ScriptLog durable write before the Live sink; prove the central write (Task 8 review)

This commit is contained in:
Joseph Doherty
2026-09-09 11:47:23 -04:00
parent 2eaaed559f
commit 7245c63c62
2 changed files with 61 additions and 14 deletions
@@ -435,24 +435,40 @@ public class InboundScriptExecutor
// Flow Debugger step logs (design 2026-09-09 D4/D5/D7): the script's Log global.
// Lines ALWAYS reach this node's logger; only a TRACED execution also builds
// ScriptTrace/ScriptLog rows, which are fanned out to the Live run's inline sink and
// written best-effort to the central store for Replay — exactly as RouteHelper does
// for its RouteCall row. The row cap comes from options when they are available
// (the sandbox/test providers that register none fall back to the documented default).
var maxLogLines = scope?.ServiceProvider
.GetService<IOptionsMonitor<InboundApiOptions>>()?.CurrentValue.MaxLogLinesPerRun
?? InboundApiOptions.DefaultMaxLogLinesPerRun;
var logTraceSink = route.TraceSink;
// ScriptTrace/ScriptLog rows, which are written best-effort to the central store for
// Replay and then handed to the Live run's inline sink — exactly as
// RouteHelper.EmitRouteCall orders its RouteCall row. An untraced request builds no
// delegate and resolves no extra service.
var methodName = method.Name;
scriptLogger = new InboundScriptLogger(
_logger,
emit: trace
? evt =>
var maxLogLines = InboundApiOptions.DefaultMaxLogLinesPerRun;
Action<AuditEvent>? logEmit = null;
if (trace)
{
// The row cap comes from options when they are available (a sandbox/test provider
// that registers none falls back to the documented default).
maxLogLines = scope?.ServiceProvider
.GetService<IOptionsMonitor<InboundApiOptions>>()?.CurrentValue.MaxLogLinesPerRun
?? InboundApiOptions.DefaultMaxLogLinesPerRun;
var logTraceSink = route.TraceSink;
logEmit = evt =>
{
// Durable first: the Replay row must never depend on the Live sink succeeding.
WriteScriptLogBestEffort(auditWriter, evt, methodName);
try
{
logTraceSink?.Invoke(evt);
WriteScriptLogBestEffort(auditWriter, evt, methodName);
}
: null,
catch (Exception)
{
// A debug observer must never fail the request: a misbehaving Live sink is
// swallowed here so it cannot mask the durable write that already happened.
}
};
}
scriptLogger = new InboundScriptLogger(
_logger,
emit: logEmit,
maxLines: maxLogLines,
methodName: methodName,
executionId: parentExecutionId,
@@ -937,6 +937,37 @@ public class InboundScriptExecutorTests
Assert.Null(extra.StepEventId);
}
[Fact]
public async Task Log_TracedRun_WritesTheScriptLogRowToTheCentralAuditStore()
{
// D5: the row must be DURABLE, not just inline — Replay reads it back from the central
// audit store, so the write happens even when no Live trace sink is attached, and it
// carries the emitting node exactly as the RouteCall row does.
var writer = Substitute.For<ICentralAuditWriter>();
writer.WriteAsync(Arg.Any<AuditEvent>(), Arg.Any<CancellationToken>()).Returns(Task.CompletedTask);
var nodeIdentity = Substitute.For<INodeIdentityProvider>();
nodeIdentity.NodeName.Returns("central-a");
var services = new ServiceCollection();
services.AddSingleton(writer);
services.AddSingleton(nodeIdentity);
using var provider = services.BuildServiceProvider();
var executor = new InboundScriptExecutor(NullLogger<InboundScriptExecutor>.Instance, provider);
var method = new ApiMethod("persisted", "Log.Info(\"persist\"); return 1;") { Id = 7, TimeoutSeconds = 10 };
var result = await executor.ExecuteAsync(
method, new Dictionary<string, object?>(), NewRoute(), TimeSpan.FromSeconds(10),
parentExecutionId: Guid.NewGuid(), trace: true);
Assert.True(result.Success, result.ErrorMessage);
await writer.Received(1).WriteAsync(
Arg.Is<AuditEvent>(e =>
AuditDetailsCodec.Deserialize(e.DetailsJson).Kind == nameof(AuditKind.ScriptLog)
&& e.SourceNode == "central-a"),
Arg.Any<CancellationToken>());
}
[Fact]
public async Task Log_UntracedRun_WritesOnlyToTheNodeLogger()
{