Merge wt/step-logs-t1: Task 1 Commons ScriptLog kind + FlowStep.ErrorDetail/Logs

This commit is contained in:
Joseph Doherty
2026-09-09 11:29:51 -04:00
7 changed files with 220 additions and 7 deletions
@@ -14,11 +14,15 @@ public sealed record FlowEdge(Guid FromEventId, Guid ToEventId, bool CrossesBoun
/// <param name="Edges">Edges between steps.</param>
/// <param name="Predicted">True when the graph came from static analysis rather than real events.</param>
/// <param name="Truncated">True when the inline event list was capped (the audit rows remain complete — Replay shows everything).</param>
/// <param name="LogsTruncated">True when the inline trace collector dropped low-priority log rows to keep room for the step rows — the audit rows remain complete, so Replay shows every line (design 2026-09-09 D7).</param>
/// <param name="UnattachedLogLines">Count of log lines the builder could not place on any step (design 2026-09-09 D2).</param>
public sealed record FlowGraph(
IReadOnlyList<FlowStep> Steps,
IReadOnlyList<FlowEdge> Edges,
bool Predicted,
bool Truncated)
bool Truncated,
bool LogsTruncated = false,
int UnattachedLogLines = 0)
{
/// <summary>An empty, non-predicted graph.</summary>
public static FlowGraph Empty { get; } = new(Array.Empty<FlowStep>(), Array.Empty<FlowEdge>(), false, false);
@@ -74,6 +74,32 @@ public sealed record FlowLifecycleRow(
string? ErrorMessage,
int? DurationMs);
/// <summary>
/// One log line folded onto a step (<see cref="FlowStep.Logs"/>; design 2026-09-09 D1/D8) — the
/// projection of a <c>ScriptTrace.ScriptLog</c> audit row, which is never drawn as a node of its own.
/// </summary>
/// <param name="EventId">The audit row's id.</param>
/// <param name="ExecutionId">Execution the line was written in.</param>
/// <param name="OccurredAtUtc">When the line was written.</param>
/// <param name="Level"><c>debug</c> | <c>info</c> | <c>warn</c> | <c>error</c>.</param>
/// <param name="Source"><c>script</c> (a <c>Log.*</c> call) | <c>runtime</c> (the context's own logger while traced).</param>
/// <param name="Message">The logged message.</param>
/// <param name="ExceptionMessage">Message of an attached exception, when the line carried one.</param>
/// <param name="ExceptionDetail">Full <c>ToString()</c> of that exception.</param>
/// <param name="StepEventId">Step the line belongs to; null = the execution's anchor step (design D2).</param>
/// <param name="Seq">Per-run emission counter, breaking same-millisecond ties in display order.</param>
public sealed record FlowLogLine(
Guid EventId,
Guid? ExecutionId,
DateTimeOffset OccurredAtUtc,
string Level,
string Source,
string Message,
string? ExceptionMessage,
string? ExceptionDetail,
Guid? StepEventId,
int? Seq);
/// <summary>
/// One node of the flow graph — a central-side projection of a <c>ScriptTrace</c> /
/// <c>ApiInbound.InboundRequest</c> <see cref="ZB.MOM.WW.Audit.AuditEvent"/>, or of one outbound
@@ -106,4 +132,6 @@ public sealed record FlowStep(
string? Target,
ScriptTraceExtra? Extra,
IReadOnlyList<FlowLifecycleRow>? Lifecycle = null,
Guid? CorrelationId = null);
Guid? CorrelationId = null,
string? ErrorDetail = null,
IReadOnlyList<FlowLogLine>? Logs = null);
@@ -43,7 +43,36 @@ public static class FlowStepProjector
Instance: d.SourceInstanceId,
Target: evt.Target,
Extra: extra,
CorrelationId: evt.CorrelationId);
CorrelationId: evt.CorrelationId,
ErrorDetail: d.ErrorDetail);
}
/// <summary>True for a <c>ScriptTrace.ScriptLog</c> row — a log line, never a step.</summary>
public static bool IsLogLine(AuditEvent evt)
{
ArgumentNullException.ThrowIfNull(evt);
var d = AuditDetailsCodec.Deserialize(evt.DetailsJson);
return string.Equals(d.Channel, nameof(AuditChannel.ScriptTrace), StringComparison.Ordinal)
&& string.Equals(d.Kind, nameof(AuditKind.ScriptLog), StringComparison.Ordinal);
}
/// <summary>Projects a <c>ScriptLog</c> row onto its line. Level/source default to <c>info</c>/<c>script</c> when the extra is missing.</summary>
public static FlowLogLine ToLogLine(AuditEvent evt)
{
ArgumentNullException.ThrowIfNull(evt);
var d = AuditDetailsCodec.Deserialize(evt.DetailsJson);
var x = ScriptTraceExtra.TryParse(d.Extra);
return new FlowLogLine(
EventId: evt.EventId,
ExecutionId: d.ExecutionId,
OccurredAtUtc: evt.OccurredAtUtc,
Level: x?.LogLevel ?? "info",
Source: x?.LogSource ?? "script",
Message: d.RequestSummary ?? string.Empty,
ExceptionMessage: d.ErrorMessage,
ExceptionDetail: d.ErrorDetail,
StepEventId: x?.StepEventId,
Seq: x?.Seq);
}
/// <summary>Projects one outbound audit row onto its lifecycle entry (<see cref="FlowStep.Lifecycle"/>).</summary>
@@ -49,6 +49,18 @@ public sealed record ScriptTraceExtra
/// <summary><c>flow-debugger</c> on rows the debugger synthesizes (the Live-run inbound row, the value-change root).</summary>
public string? Source { get; init; }
/// <summary>On a <c>ScriptLog</c> row: <c>debug</c> | <c>info</c> | <c>warn</c> | <c>error</c>.</summary>
public string? LogLevel { get; init; }
/// <summary>On a <c>ScriptLog</c> row: <c>script</c> (a <c>Log.*</c> call) | <c>runtime</c> (the context's own logger while traced).</summary>
public string? LogSource { get; init; }
/// <summary>On a <c>ScriptLog</c> row: the pre-minted <c>EventId</c> of the step the line belongs to; null = the execution's anchor step (design D2).</summary>
public Guid? StepEventId { get; init; }
/// <summary>On a <c>ScriptLog</c> row: per-run emission counter, breaks same-millisecond ties.</summary>
public int? Seq { get; init; }
/// <summary>Serializer options shared by every emitter and reader: camelCase, nulls omitted.</summary>
public static JsonSerializerOptions JsonOptions { get; } = new(JsonSerializerDefaults.Web)
{
@@ -61,5 +61,8 @@ public enum AuditKind
AttributeWrite,
/// <summary>One <c>WaitAsync</c>/<c>WaitForAsync</c> outcome in a traced script (traced executions only; <see cref="AuditChannel.ScriptTrace"/>).</summary>
AttributeWait
AttributeWait,
/// <summary>One log line a traced script (or the runtime on its behalf) wrote; folded into its owning step by the Flow Debugger, never a node (design 2026-09-09 D1).</summary>
ScriptLog
}
@@ -0,0 +1,137 @@
using ZB.MOM.WW.ScadaBridge.Commons.Types.Audit;
using ZB.MOM.WW.ScadaBridge.Commons.Types.Debugging;
using ZB.MOM.WW.ScadaBridge.Commons.Types.Enums;
namespace ZB.MOM.WW.ScadaBridge.Commons.Tests.Debugging;
/// <summary>
/// Flow Debugger step-logs plan (2026-09-09) Task 1: the Commons log-line vocabulary —
/// exception detail on a step (D3), and the <c>ScriptTrace.ScriptLog</c> row projecting
/// onto a <see cref="FlowLogLine"/> rather than a node (D1).
/// </summary>
public class FlowStepProjectorLogLineTests
{
[Fact]
public void Project_CarriesErrorDetail()
{
var evt = ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptRun, AuditStatus.Failed,
target: "S", executionId: Guid.NewGuid(), errorMessage: "boom", errorDetail: "System.InvalidOperationException: boom\n at X");
var step = FlowStepProjector.Project(evt);
Assert.Equal("boom", step.ErrorMessage);
Assert.StartsWith("System.InvalidOperationException", step.ErrorDetail);
}
[Fact]
public void Project_ErrorDetail_IsNullWhenAbsent()
{
var evt = ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptRun, AuditStatus.Delivered, target: "S");
Assert.Null(FlowStepProjector.Project(evt).ErrorDetail);
}
[Fact]
public void ScriptLog_ProjectsToUnknownKind_NeverItsOwnStepKind()
{
// Mixed-version rule (design §4): an old central renders a ScriptLog row as an Unknown node
// rather than dropping it. No FlowStepKind is added for it.
Assert.Equal(FlowStepKind.Unknown, FlowStepProjector.ResolveKind(nameof(AuditChannel.ScriptTrace), nameof(AuditKind.ScriptLog)));
Assert.False(Enum.GetNames<FlowStepKind>().Contains("ScriptLog"));
}
[Fact]
public void IsLogLine_TrueOnlyForScriptTraceScriptLog()
{
var log = ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptLog, AuditStatus.Delivered, target: "S");
var run = ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptRun, AuditStatus.Delivered, target: "S");
Assert.True(FlowStepProjector.IsLogLine(log));
Assert.False(FlowStepProjector.IsLogLine(run));
}
[Fact]
public void IsLogLine_FalseForOtherChannels()
{
var outbound = ScadaBridgeAuditEventFactory.Create(AuditChannel.ApiOutbound, AuditKind.ApiCall, AuditStatus.Delivered, target: "S");
Assert.False(FlowStepProjector.IsLogLine(outbound));
}
[Fact]
public void ToLogLine_ReadsLevelSourceAndException()
{
var exec = Guid.NewGuid();
var extra = new ScriptTraceExtra { LogLevel = "warn", LogSource = "runtime", StepEventId = Guid.NewGuid(), Seq = 3 };
var evt = ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptLog, AuditStatus.Delivered,
target: "S", executionId: exec, requestSummary: "acked Uncertain", errorMessage: "inner",
errorDetail: "System.Exception: inner", extra: extra.ToJson());
var line = FlowStepProjector.ToLogLine(evt);
Assert.Equal(evt.EventId, line.EventId);
Assert.Equal(exec, line.ExecutionId);
Assert.Equal(evt.OccurredAtUtc, line.OccurredAtUtc);
Assert.Equal("warn", line.Level);
Assert.Equal("runtime", line.Source);
Assert.Equal("acked Uncertain", line.Message);
Assert.Equal("inner", line.ExceptionMessage);
Assert.Equal("System.Exception: inner", line.ExceptionDetail);
Assert.Equal(extra.StepEventId, line.StepEventId);
Assert.Equal(3, line.Seq);
}
[Fact]
public void ToLogLine_DefaultsLevelAndSourceWhenExtraMissing()
{
var evt = ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptLog, AuditStatus.Delivered, target: "S");
var line = FlowStepProjector.ToLogLine(evt);
Assert.Equal("info", line.Level);
Assert.Equal("script", line.Source);
Assert.Equal(string.Empty, line.Message);
Assert.Null(line.ExceptionMessage);
Assert.Null(line.ExceptionDetail);
Assert.Null(line.StepEventId);
Assert.Null(line.Seq);
}
[Fact]
public void ScriptTraceExtra_LogMembers_RoundTripThroughJson()
{
var extra = new ScriptTraceExtra { LogLevel = "error", LogSource = "script", StepEventId = Guid.NewGuid(), Seq = 12 };
var parsed = ScriptTraceExtra.TryParse(extra.ToJson());
Assert.NotNull(parsed);
Assert.Equal("error", parsed!.LogLevel);
Assert.Equal("script", parsed.LogSource);
Assert.Equal(extra.StepEventId, parsed.StepEventId);
Assert.Equal(12, parsed.Seq);
}
[Fact]
public void FlowStep_LogsAndErrorDetail_DefaultToNull()
{
var step = new FlowStep(Guid.NewGuid(), null, null, FlowStepKind.ScriptRun, FlowLane.Site, "S", null,
DateTimeOffset.UnixEpoch, null, FlowStepOutcome.Ok, null, null, null, null, null, null, null, null);
Assert.Null(step.ErrorDetail);
Assert.Null(step.Logs);
var line = new FlowLogLine(Guid.NewGuid(), null, DateTimeOffset.UnixEpoch, "info", "script", "m", null, null, null, null);
Assert.Single((step with { Logs = [line] }).Logs!);
}
[Fact]
public void FlowGraph_LogTruncationMembers_DefaultToOff()
{
var graph = new FlowGraph([], [], false, false);
Assert.False(graph.LogsTruncated);
Assert.Equal(0, graph.UnattachedLogLines);
Assert.False(FlowGraph.Empty.LogsTruncated);
Assert.Equal(0, FlowGraph.Empty.UnattachedLogLines);
}
}
@@ -23,7 +23,7 @@ public class AuditEnumTests
}
[Fact]
public void AuditKind_HasExactlyTwentyOneExpectedMembers()
public void AuditKind_HasExactlyTwentyTwoExpectedMembers()
{
var expected = new[]
{
@@ -34,14 +34,14 @@ public class AuditEnumTests
"SecuredWriteExpire",
"ReconciliationAbandoned",
"ManualFailover",
"RouteCall", "ScriptRun", "AttributeWrite", "AttributeWait",
"RouteCall", "ScriptRun", "AttributeWrite", "AttributeWait", "ScriptLog",
};
var actual = Enum.GetValues(typeof(AuditKind))
.Cast<AuditKind>()
.Select(x => x.ToString())
.ToArray();
Assert.Equal(21, actual.Length);
Assert.Equal(22, actual.Length);
Assert.Equal(expected, actual);
}