diff --git a/src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/FlowGraphBuilder.cs b/src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/FlowGraphBuilder.cs index af484b55..7f94d9b6 100644 --- a/src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/FlowGraphBuilder.cs +++ b/src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/FlowGraphBuilder.cs @@ -43,16 +43,43 @@ namespace ZB.MOM.WW.ScadaBridge.Commons.Types.Debugging; /// When an InboundRequest row carries a response summary, a Response step is /// synthesized as the final Central node, linked from the last non-async step of the inbound /// execution (the route call, or the inbound row itself), never from a cascaded site step. +/// Log lines are never steps (step-logs design 2026-09-09 D2). ScriptLog rows are +/// partitioned out before anything else — before the input-order index — and folded onto a step's +/// : the step its StepEventId names, else the anchor of its +/// execution (the InboundRequest, RouteCall or ScriptRun step, in that order), +/// else that execution's first non-Response step. A line whose execution has no step at all is +/// dropped and counted in . Within a step, lines are ordered +/// by OccurredAtUtc then Seq, with a null Seq sorting last, so same-millisecond +/// lines keep their emission order. /// /// public static class FlowGraphBuilder { - /// Builds the graph. is passed through to . - public static FlowGraph Build(IReadOnlyList events, bool truncated = false) + /// + /// Builds the graph. and are passed + /// through to / . + /// + public static FlowGraph Build(IReadOnlyList events, bool truncated = false, bool logsTruncated = false) { ArgumentNullException.ThrowIfNull(events); + + // D2: a ScriptLog row is a line, never a node. Partition BEFORE the input-order index below, so + // `seq` indexes only real step rows and a line can never shift an execution's display position. + var lines = new List(); + var stepEvents = new List(events.Count); + foreach (var e in events) + { + if (FlowStepProjector.IsLogLine(e)) + lines.Add(FlowStepProjector.ToLogLine(e)); + else + stepEvents.Add(e); + } + + events = stepEvents; + if (events.Count == 0) - return new FlowGraph(Array.Empty(), Array.Empty(), Predicted: false, Truncated: truncated); + return new FlowGraph(Array.Empty(), Array.Empty(), Predicted: false, Truncated: truncated, + LogsTruncated: logsTruncated, UnattachedLogLines: lines.Count); // Arch-review F5: a step's position in the input is the only cross-node ordering we can trust — // central rows carry central's clock, site rows the site's, and a 1-2 s skew used to sort a whole @@ -230,7 +257,65 @@ public static class FlowGraphBuilder edges.Add(new FlowEdge(origin.EventId, response.EventId, CrossesBoundary(origin, response), External: false)); } - return new FlowGraph(steps, edges, Predicted: false, Truncated: truncated); + // 5. Fold the log lines onto their owning steps (D2) — after the Response node joined `steps`, + // so a line naming it (none should) still resolves rather than counting as unattached. + AttachLogLines(steps, lines, out var unattached); + + return new FlowGraph(steps, edges, Predicted: false, Truncated: truncated, + LogsTruncated: logsTruncated, UnattachedLogLines: unattached); + } + + /// + /// Attaches each log line to its step (D2): the step named by , + /// else the anchor of the line's execution (InboundRequest before RouteCall before + /// ScriptRun — an inbound row and its route call share one central execution), else that + /// execution's first non-Response step. Lines that resolve to nothing are counted in + /// . Rewrites in place. + /// + private static void AttachLogLines(List steps, List lines, out int unattached) + { + unattached = 0; + if (lines.Count == 0) return; + + var byEventId = new Dictionary(steps.Count); + foreach (var step in steps) + byEventId[step.EventId] = step; + + var anchorByExecution = steps + .Where(s => s.ExecutionId is not null + && s.Kind is FlowStepKind.ScriptRun or FlowStepKind.InboundRequest or FlowStepKind.RouteCall) + .GroupBy(s => s.ExecutionId!.Value) + .ToDictionary(g => g.Key, g => g.OrderBy(s => KindRank(s.Kind)).First()); + var firstByExecution = steps + .Where(s => s.ExecutionId is not null && s.Kind != FlowStepKind.Response) + .GroupBy(s => s.ExecutionId!.Value) + .ToDictionary(g => g.Key, g => g.First()); + + var logsByStep = new Dictionary>(); + foreach (var line in lines) + { + FlowStep? owner = null; + if (line.StepEventId is { } stepId && byEventId.TryGetValue(stepId, out var named)) + owner = named; + else if (line.ExecutionId is { } execution + && (anchorByExecution.TryGetValue(execution, out var fallback) + || firstByExecution.TryGetValue(execution, out fallback))) + owner = fallback; + + if (owner is null) + { + unattached++; + continue; + } + + (logsByStep.TryGetValue(owner.EventId, out var l) ? l : logsByStep[owner.EventId] = []).Add(line); + } + + for (var i = 0; i < steps.Count; i++) + { + if (logsByStep.TryGetValue(steps[i].EventId, out var l)) + steps[i] = steps[i] with { Logs = l.OrderBy(x => x.OccurredAtUtc).ThenBy(x => x.Seq ?? int.MaxValue).ToList() }; + } } /// diff --git a/tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/FlowGraphBuilderLogLineTests.cs b/tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/FlowGraphBuilderLogLineTests.cs new file mode 100644 index 00000000..0a132fe0 --- /dev/null +++ b/tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/FlowGraphBuilderLogLineTests.cs @@ -0,0 +1,204 @@ +using ZB.MOM.WW.Audit; +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; + +/// +/// Step-logs design 2026-09-09 D2: a ScriptTrace.ScriptLog row is never a node — it folds onto the +/// step its StepEventId names, else onto its execution's anchor (ScriptRun / +/// InboundRequest / RouteCall), else its execution's first non-Response step, else it is +/// dropped and counted in . +/// +public class FlowGraphBuilderLogLineTests +{ + private static readonly DateTime T0 = new(2026, 9, 9, 12, 0, 0, DateTimeKind.Utc); + + private static AuditEvent Run(Guid execution, Guid? parent = null, int ms = 0) => + ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptRun, AuditStatus.Delivered, + occurredAtUtc: T0.AddMilliseconds(ms), actor: "SomeScript", target: "SomeScript", sourceNode: "node-a", + executionId: execution, parentExecutionId: parent, sourceSiteId: "site-a", sourceInstanceId: "M1", + durationMs: 100, extra: new ScriptTraceExtra { TriggerKind = "call" }.ToJson()); + + private static AuditEvent Write(Guid execution, Guid? eventId = null, int ms = 10) => + ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.AttributeWrite, AuditStatus.Delivered, + eventId: eventId, occurredAtUtc: T0.AddMilliseconds(ms), actor: "SomeScript", target: "M1.Flag", + sourceNode: "node-a", executionId: execution, sourceSiteId: "site-a", sourceInstanceId: "M1", durationMs: 2, + extra: new ScriptTraceExtra { Writes = [new AttributeWriteDetail("M1.Flag", "true", true, null)] }.ToJson()); + + private static AuditEvent Inbound(Guid execution, int ms = 0) => + ScadaBridgeAuditEventFactory.Create(AuditChannel.ApiInbound, AuditKind.InboundRequest, AuditStatus.Delivered, + occurredAtUtc: T0.AddMilliseconds(ms), actor: "some-key", target: "SomeMethod", sourceNode: "central-a", + executionId: execution, durationMs: 50, requestSummary: "{}", responseSummary: "{\"ok\":true}"); + + private static AuditEvent RouteCallRoot(Guid execution, int ms = 0) => + ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.RouteCall, AuditStatus.Delivered, + occurredAtUtc: T0.AddMilliseconds(ms), actor: "flow-debugger", target: "M1.SomeScript", sourceNode: "central-a", + executionId: execution, durationMs: 120); + + private static AuditEvent ApiOut(Guid execution, Guid eventId, int ms = 20) => + ScadaBridgeAuditEventFactory.Create(AuditChannel.ApiOutbound, AuditKind.ApiCall, AuditStatus.Delivered, + eventId: eventId, occurredAtUtc: T0.AddMilliseconds(ms), actor: "SomeScript", target: "ERP/orders", + sourceNode: "node-a", executionId: execution, sourceSiteId: "site-a", durationMs: 30); + + private static AuditEvent Line(Guid execution, Guid? step = null, int? seq = null, string level = "info", + int ms = 5, string message = "hello") => + ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptLog, AuditStatus.Delivered, + occurredAtUtc: T0.AddMilliseconds(ms), actor: "SomeScript", target: "SomeScript", sourceNode: "node-a", + executionId: execution, sourceSiteId: "site-a", sourceInstanceId: "M1", requestSummary: message, + extra: new ScriptTraceExtra { LogLevel = level, LogSource = "script", StepEventId = step, Seq = seq }.ToJson()); + + private static FlowStep StepOf(FlowGraph graph, FlowStepKind kind) => Assert.Single(graph.Steps, s => s.Kind == kind); + + [Fact] + public void LogLine_WithStepEventId_AttachesToThatStep() + { + var execution = Guid.NewGuid(); + var writeId = Guid.NewGuid(); + + var graph = FlowGraphBuilder.Build([Run(execution), Write(execution, writeId), Line(execution, step: writeId)]); + + var write = StepOf(graph, FlowStepKind.AttributeWrite); + var line = Assert.Single(write.Logs!); + Assert.Equal("hello", line.Message); + Assert.Null(StepOf(graph, FlowStepKind.ScriptRun).Logs); + } + + [Fact] + public void LogLine_WithoutStepId_AttachesToTheExecutionAnchor() + { + var execution = Guid.NewGuid(); + + var graph = FlowGraphBuilder.Build([Run(execution), Write(execution), Line(execution)]); + + Assert.Single(StepOf(graph, FlowStepKind.ScriptRun).Logs!); + Assert.Null(StepOf(graph, FlowStepKind.AttributeWrite).Logs); + } + + [Fact] + public void CentralLine_AttachesToInboundRow_NotResponse() + { + var execution = Guid.NewGuid(); + + var graph = FlowGraphBuilder.Build([Inbound(execution), Line(execution)]); + + Assert.Single(StepOf(graph, FlowStepKind.InboundRequest).Logs!); + Assert.Null(StepOf(graph, FlowStepKind.Response).Logs); + } + + [Fact] + public void ScriptEntryLine_AttachesToRouteCallRoot() + { + var execution = Guid.NewGuid(); + + var graph = FlowGraphBuilder.Build([RouteCallRoot(execution), Line(execution)]); + + Assert.Single(StepOf(graph, FlowStepKind.RouteCall).Logs!); + } + + [Fact] + public void LogLine_UnknownStepId_FallsBackToAnchor() + { + var execution = Guid.NewGuid(); + + var graph = FlowGraphBuilder.Build([Run(execution), Line(execution, step: Guid.NewGuid())]); + + Assert.Single(StepOf(graph, FlowStepKind.ScriptRun).Logs!); + Assert.Equal(0, graph.UnattachedLogLines); + } + + [Fact] + public void LogLine_NoAnchor_FallsBackToFirstStep() + { + var execution = Guid.NewGuid(); + + var graph = FlowGraphBuilder.Build([Write(execution), Line(execution)]); + + Assert.Single(StepOf(graph, FlowStepKind.AttributeWrite).Logs!); + Assert.Equal(0, graph.UnattachedLogLines); + } + + [Fact] + public void LogLine_NoStepInExecution_IsCountedUnattached() + { + var execution = Guid.NewGuid(); + + var graph = FlowGraphBuilder.Build([Run(execution), Line(Guid.NewGuid())]); + + Assert.Equal(1, graph.UnattachedLogLines); + Assert.All(graph.Steps, s => Assert.True(s.Logs is null or { Count: 0 })); + } + + [Fact] + public void Build_LinesOnly_ReturnsEmptyGraphWithUnattachedCount() + { + var graph = FlowGraphBuilder.Build([Line(Guid.NewGuid()), Line(Guid.NewGuid())], logsTruncated: true); + + Assert.Empty(graph.Steps); + Assert.Empty(graph.Edges); + Assert.Equal(2, graph.UnattachedLogLines); + Assert.True(graph.LogsTruncated); + } + + [Fact] + public void Lines_OrderBySeqWithinSameMillisecond_NullSeqLast() + { + var execution = Guid.NewGuid(); + + var graph = FlowGraphBuilder.Build( + [ + Run(execution), + Line(execution, seq: 3, ms: 5, message: "three"), + Line(execution, seq: 1, ms: 5, message: "one"), + Line(execution, seq: null, ms: 5, message: "null"), + Line(execution, seq: 2, ms: 5, message: "two"), + ]); + + var logs = StepOf(graph, FlowStepKind.ScriptRun).Logs!; + Assert.Equal(new int?[] { 1, 2, 3, null }, logs.Select(l => l.Seq).ToArray()); + Assert.Equal(new[] { "one", "two", "three", "null" }, logs.Select(l => l.Message).ToArray()); + } + + [Fact] + public void LogLines_NeverBecomeSteps() + { + var execution = Guid.NewGuid(); + var events = new List { Run(execution) }; + for (var i = 0; i < 5; i++) + events.Add(Line(execution, seq: i, ms: 1 + i, message: $"line {i}")); + var lineIds = events.Skip(1).Select(e => e.EventId).ToHashSet(); + + var graph = FlowGraphBuilder.Build(events); + + var step = Assert.Single(graph.Steps); + Assert.Equal(FlowStepKind.ScriptRun, step.Kind); + Assert.Equal(5, step.Logs!.Count); + Assert.DoesNotContain(graph.Edges, e => lineIds.Contains(e.FromEventId) || lineIds.Contains(e.ToEventId)); + } + + [Fact] + public void Build_PassesLogsTruncatedThrough() + { + var execution = Guid.NewGuid(); + + var graph = FlowGraphBuilder.Build([Run(execution)], truncated: false, logsTruncated: true); + + Assert.True(graph.LogsTruncated); + Assert.False(graph.Truncated); + } + + [Fact] + public void LogLine_OnFoldedOutboundStep_AttachesByFirstRowId() + { + var execution = Guid.NewGuid(); + var callId = Guid.NewGuid(); + + var graph = FlowGraphBuilder.Build([Run(execution), ApiOut(execution, callId), Line(execution, step: callId)]); + + var call = StepOf(graph, FlowStepKind.ApiCall); + Assert.Equal(callId, call.EventId); + Assert.Single(call.Logs!); + Assert.Null(StepOf(graph, FlowStepKind.ScriptRun).Logs); + } +}