Files
ScadaBridge/docs/plans/2026-09-09-flow-debugger-step-logs.md
T

44 KiB
Raw Blame History

Flow Debugger — Step Logs and Exceptions Implementation Plan

For Claude: REQUIRED SUB-SKILL: Use superpowers-extended-cc:executing-plans to implement this plan task-by-task.

Status: all 15 tasks complete 2026-09-09 (branch feat/flow-debugger-step-logs); every task spec- and code-reviewed; 7 test projects green (4 499 tests); rig rebuilt via docker/deploy.sh, verify-delmia-notifier.sh H/H2/I/J all YES (J root 5793ddc2-5273-4e62-86c2-ccfc8de0e080); browser-verified. Deviations from the plan text: FlowTraceCollector.Add(evt, lowPriority:) instead of AddLowPriority (Commons 3-public-method constraint); inline shared scripts share the caller's ScriptLogger (design §5, not a per-child logger); LogsTruncated clears once a refresh merges in more log rows; the inbound editor host InboundScriptHost also mirrors Log.

Goal: A traced Flow Debugger run shows, on the node that produced them, the exception a failing step threw (type, message, stack) and every log line the script or the runtime wrote during that step — in Live and in Replay.

Architecture: One new audit kind, ScriptTrace.ScriptLog, one row per line, riding the existing collector (Live) and audit store (Replay); FlowGraphBuilder folds the rows into their owning step (stepEventId, else the execution's anchor step) and never draws them as nodes. Scripts get a Log global on all four compile surfaces; the site context wraps its own logger while traced so runtime warnings inside a helper step land on that step. Exception detail is the errorDetail field that already exists on AuditDetails — populated on the site ScriptRun row and the central inbound row, projected onto FlowStep.ErrorDetail.

Tech Stack: .NET 10, Akka.NET site runtime, ZB.MOM.WW.Audit AuditEvent, Roslyn script surfaces, Blazor Server custom SVG (FlowGraphView), xunit + NSubstitute + bUnit.

Design: docs/plans/2026-09-09-flow-debugger-step-logs-design.md (decisions D1–D9). Mockup: docs/plans/2026-09-09-flow-debugger-step-logs-mockup.html.

Conventions for every task: work in a dedicated worktree (see memory: isolation:worktree agents are not isolated — pre-create one git worktree per concurrent task; never git stash). Build the touched projects only; run the named test filter; full dotnet build ZB.MOM.WW.ScadaBridge.slnx at the end of Task 15. Commit with pathspecs (git add <files>), never -a, when several tasks run concurrently.


Task 1: Commons — ScriptLog kind, trace extra fields, FlowStep.ErrorDetail / Logs

Classification: standard Estimated implement time: ~5 min Parallelizable with: Task 2

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.Commons/Types/Enums/AuditKind.cs:64 (append ScriptLog AFTER AttributeWait — stored ordinals never move)
  • Modify: src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/ScriptTraceExtra.cs (add LogLevel, LogSource, StepEventId, Seq)
  • Modify: src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/FlowStep.cs (add FlowLogLine, FlowStep.ErrorDetail, FlowStep.Logs)
  • Modify: src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/FlowGraph.cs (add LogsTruncated, UnattachedLogLines)
  • Modify: src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/FlowStepProjector.cs (project ErrorDetail; add IsLogLine; ScriptLog still resolves to Unknown in ResolveKind so an old-central mixed-version behaves as the design records)
  • Test: tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/FlowStepProjectorTests.cs
  • Test: tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/FlowStepProjectorLogLineTests.cs (create)

Step 1: Write the failing tests

[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 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 ToLogLine_ReadsLevelSourceAndException()
{
    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", requestSummary: "acked Uncertain", errorMessage: "inner", errorDetail: "System.Exception: inner", extra: extra.ToJson());
    var line = FlowStepProjector.ToLogLine(evt);
    Assert.Equal("warn", line.Level); Assert.Equal("runtime", line.Source);
    Assert.Equal("acked Uncertain", line.Message); Assert.Equal("inner", line.ExceptionMessage);
    Assert.Equal(extra.StepEventId, line.StepEventId); Assert.Equal(3, line.Seq);
}

Step 2: Run to verify failure — dotnet test tests/ZB.MOM.WW.ScadaBridge.Commons.Tests --filter "FullyQualifiedName~FlowStepProjector" -v q → compile errors (ScriptLog, ErrorDetail, IsLogLine, ToLogLine missing).

Step 3: Implement

AuditKind.cs — append after AttributeWait (keep the trailing-comma style of the file):

    /// <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

ScriptTraceExtra.cs — add after Source:

    /// <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; }

FlowStep.cs — add the record and two trailing optional members on FlowStep:

/// <summary>One log line folded onto a step (<see cref="FlowStep.Logs"/>; design 2026-09-09 D1/D8).</summary>
public sealed record FlowLogLine(
    Guid EventId, Guid? ExecutionId, DateTimeOffset OccurredAtUtc, string Level, string Source, string Message,
    string? ExceptionMessage, string? ExceptionDetail, Guid? StepEventId, int? Seq);

FlowStep(... , IReadOnlyList<FlowLifecycleRow>? Lifecycle = null, Guid? CorrelationId = null, string? ErrorDetail = null, IReadOnlyList<FlowLogLine>? Logs = null).

FlowGraph.cs — FlowGraph(..., bool Truncated = false, bool LogsTruncated = false, int UnattachedLogLines = 0) (keep existing positional order; append).

FlowStepProjector.cs — in Project: ErrorDetail: d.ErrorDetail. Add:

    /// <summary>True for a <c>ScriptTrace.ScriptLog</c> row — a log line, never a step.</summary>
    public static bool IsLogLine(AuditEvent 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)
    {
        var d = AuditDetailsCodec.Deserialize(evt.DetailsJson);
        var x = ScriptTraceExtra.TryParse(d.Extra);
        return new FlowLogLine(evt.EventId, d.ExecutionId, evt.OccurredAtUtc, x?.LogLevel ?? "info", x?.LogSource ?? "script",
            d.RequestSummary ?? string.Empty, d.ErrorMessage, d.ErrorDetail, x?.StepEventId, x?.Seq);
    }

Step 4: Run the filter → PASS. Also dotnet test tests/ZB.MOM.WW.ScadaBridge.Commons.Tests --filter "FullyQualifiedName~Audit" -v q — there is an enum-count lock-in test for AuditKind (PLAN-07 found one); update its expected count.

Step 5: Commit — git add src/ZB.MOM.WW.ScadaBridge.Commons tests/ZB.MOM.WW.ScadaBridge.Commons.Tests && git commit -m "feat(commons): ScriptLog audit kind, log-line trace extra, FlowStep.ErrorDetail/Logs (flow-debugger step logs D1/D3)".


Task 2: Commons — FlowTraceCollector.AddLowPriority + LogsTruncated

Classification: small Estimated implement time: ~3 min Parallelizable with: Task 1

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/FlowTraceCollector.cs
  • Test: tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/FlowTraceCollectorTests.cs

Step 1: Failing tests

[Fact]
public void AddLowPriority_StopsBeforeTheReserve_AndSetsLogsTruncated()
{
    var c = new FlowTraceCollector(maxEvents: 60, maxBytes: 1_000_000);   // reserve = 50 → low-priority stops at 10
    for (var i = 0; i < 12; i++) c.AddLowPriority(Evt());
    Assert.Equal(10, c.Count); Assert.True(c.LogsTruncated); Assert.False(c.Truncated);
    c.Add(Evt());                                                          // a step row still fits
    Assert.Equal(11, c.Count);
}

[Fact]
public void AddLowPriority_RespectsByteShare()
{
    var c = new FlowTraceCollector(maxEvents: 500, maxBytes: 1_000);       // 75 % = 750 chars
    c.AddLowPriority(Evt(details: new string('x', 700)));
    c.AddLowPriority(Evt(details: new string('x', 100)));
    Assert.Equal(1, c.Count); Assert.True(c.LogsTruncated);
}

(Evt(details:) — build via ScadaBridgeAuditEventFactory.Create(..., requestSummary: details).)

Step 2: Run --filter "FullyQualifiedName~FlowTraceCollectorTests" → compile failure.

Step 3: Implement — constants public const int LowPriorityReserveEvents = 50; and public const double LowPriorityByteShare = 0.75;; public bool LogsTruncated { get; private set; }; refactor Add into private void AddCore(AuditEvent evt, bool lowPriority) where the bound check is

var maxCount = lowPriority ? Math.Max(1, _max - LowPriorityReserveEvents) : _max;
var maxBytes = lowPriority ? (int)(_maxBytes * LowPriorityByteShare) : _maxBytes;
if (_events.Count >= maxCount || _bytes + size > maxBytes) { if (lowPriority) LogsTruncated = true; else Truncated = true; return; }

public void Add(AuditEvent evt) => AddCore(evt, false); public void AddLowPriority(AuditEvent evt) => AddCore(evt, true);. Update the type remarks (log rows are low-priority so the run-end step rows are never crowded out — D7).

Step 4: Run → PASS. Step 5: Commit — git add src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/FlowTraceCollector.cs tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/FlowTraceCollectorTests.cs && git commit -m "feat(commons): FlowTraceCollector low-priority lane for log lines (D7)".


Task 3: Commons — FlowGraphBuilder attaches log lines to steps

Classification: standard Estimated implement time: ~5 min Parallelizable with: Task 4, Task 6, Task 7

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/FlowGraphBuilder.cs (Build signature + attachment pass)
  • Test: tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/FlowGraphBuilderLogLineTests.cs (create)

Step 1: Failing tests (helpers: Run(exec) = a ScriptRun row, Write(exec, id) = an AttributeWrite row with a chosen eventId, Line(exec, step?, seq, level) = a ScriptLog row)

[Fact] public void LogLine_WithStepEventId_AttachesToThatStep()
// Run(A) + Write(A, w) + Line(A, step: w) → the Write step has Logs.Count == 1, the Run step has none.
[Fact] public void LogLine_WithoutStepId_AttachesToTheExecutionAnchor()
// Run(A) + Write(A) + Line(A, null) → Run.Logs.Count == 1.
[Fact] public void CentralLine_AttachesToInboundRow()
// InboundRequest(exec R) + Line(R, null) → the InboundRequest step carries it (not the synthesized Response).
[Fact] public void LogLine_UnknownStepId_FallsBackToAnchor_ThenFirstStep()
// Line(A, step: unknownGuid) with Run(A) → Run; with only Write(A) (no ScriptRun) → the Write (first step of A).
[Fact] public void LogLine_NoStepInExecution_IsCountedUnattached()
// Line(Z, null) alone with Run(A) → graph.UnattachedLogLines == 1, no Logs anywhere.
[Fact] public void Lines_OrderBySeqWithinSameMillisecond()
// three lines with the same OccurredAtUtc and seq 3,1,2 → Logs[0].Seq == 1.
[Fact] public void LogLines_NeverBecomeSteps()
// Run(A) + 5 lines → graph.Steps has exactly 1 step (no Unknown nodes).
[Fact] public void Build_PassesLogsTruncatedThrough()

Step 2: Run --filter "FullyQualifiedName~FlowGraphBuilderLogLineTests" → FAIL (compile / Unknown nodes).

Step 3: Implement — Build(IReadOnlyList<AuditEvent> events, bool truncated = false, bool logsTruncated = false). At the top, partition: var lines = events.Where(FlowStepProjector.IsLogLine).Select(FlowStepProjector.ToLogLine).ToList(); events = events.Where(e => !FlowStepProjector.IsLogLine(e)).ToList(); (keep seq indexing on the filtered list). After the Response synthesis and before return, attach:

var byEventId = steps.ToDictionary(s => s.EventId);
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<Guid, List<FlowLogLine>>();
var unattached = 0;
foreach (var line in lines)
{
    FlowStep? owner = null;
    if (line.StepEventId is { } sid && byEventId.TryGetValue(sid, out var s)) owner = s;
    else if (LineExecution(line) is { } exec && (anchorByExecution.TryGetValue(exec, out var a) || firstByExecution.TryGetValue(exec, out a))) owner = a;
    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() };

LineExecution(line) is simply line.ExecutionId (Task 1's record carries it). The RouteCall anchor covers the debugger's script-entry root (design D2). Return new FlowGraph(steps, edges, Predicted: false, Truncated: truncated, LogsTruncated: logsTruncated, UnattachedLogLines: unattached). Update the class remarks with the attachment rule.

Step 4: Run the new tests + --filter "FullyQualifiedName~FlowGraphBuilder" → all PASS. Step 5: Commit — git add src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging && git commit -m "feat(commons): FlowGraphBuilder folds ScriptLog rows onto their owning step (D2)".


Task 4: SiteRuntime — ScriptLogger, TraceStepScope, TraceCapturingLogger (new files)

Classification: standard Estimated implement time: ~5 min Parallelizable with: Task 3, Task 6, Task 7

Files:

  • Create: src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptLogger.cs
  • Create: src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/TraceStepScope.cs
  • Create: src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/TraceCapturingLogger.cs
  • Test: tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptLoggerTests.cs (create)
  • Test: tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/TraceCapturingLoggerTests.cs (create)

These types take a delegate for emission so they are testable without a ScriptRuntimeContext:

/// <summary>The row-emitting callback a <see cref="ScriptLogger"/> uses: level, source, message, exception, step id.</summary>
public delegate void ScriptLogEmitter(string level, string source, string message, Exception? exception, Guid? stepEventId);

TraceStepScope.cs:

/// <summary>Ambient "which step is running" marker for runtime log attribution (design 2026-09-09 D6). AsyncLocal so it flows through the helper's awaits and nowhere else.</summary>
public static class TraceStepScope
{
    private static readonly AsyncLocal<Guid?> _current = new();
    public static Guid? Current => _current.Value;
    /// <summary>Sets the current step for the scope's lifetime; restores the previous value on dispose.</summary>
    public static IDisposable Enter(Guid stepEventId) { var prev = _current.Value; _current.Value = stepEventId; return new Restore(prev); }
    private sealed class Restore(Guid? prev) : IDisposable { public void Dispose() => _current.Value = prev; }
}

ScriptLogger.cs — the Log global:

/// <summary>
/// The <c>Log</c> global (design 2026-09-09 D4/D5/D7). Always forwards to the node's ILogger; emits a
/// <c>ScriptLog</c> trace row only while the run is traced (<paramref name="emit"/> non-null). Bounded by
/// <see cref="MaxLines"/> per run (shared with inline shared scripts) and <see cref="MaxMessageChars"/>; past
/// the line cap lines are dropped and <see cref="FlushDropped"/> writes one closing runtime warning. Never throws into the script.
/// </summary>
public sealed class ScriptLogger
{
    public const int MaxMessageChars = 2_000;
    private readonly ILogger _logger; private readonly ScriptLogEmitter? _emit; private readonly int _maxLines;
    private readonly string _instance, _script; private readonly Guid? _executionId;
    private int _emitted, _dropped;

    public ScriptLogger(ILogger logger, ScriptLogEmitter? emit, int maxLines, string instance, string script, Guid? executionId) { … }

    public void Debug(string message, Exception? exception = null) => Write(LogLevel.Debug, "debug", message, exception);
    public void Info(string message, Exception? exception = null)  => Write(LogLevel.Information, "info", message, exception);
    public void Warn(string message, Exception? exception = null)  => Write(LogLevel.Warning, "warn", message, exception);
    public void Error(string message, Exception? exception = null) => Write(LogLevel.Error, "error", message, exception);

    /// <summary>Runtime-sourced line (the capturing logger); same caps, source "runtime".</summary>
    internal void Runtime(string level, string message, Exception? exception) => WriteRow(level, "runtime", message, exception);

    private void Write(LogLevel level, string name, string message, Exception? exception)
    {
        message = Clip(message);
        try { _logger.Log(level, exception, "[script] {Instance}/{Script} {ExecutionId}: {Message}", _instance, _script, _executionId, message); } catch { /* never into the script */ }
        WriteRow(name, "script", message, exception);
    }

    private void WriteRow(string level, string source, string message, Exception? exception)
    {
        if (_emit is null) return;
        if (Interlocked.Increment(ref _emitted) > _maxLines) { Interlocked.Increment(ref _dropped); return; }
        try { _emit(level, source, Clip(message), exception, TraceStepScope.Current); } catch { }
    }

    /// <summary>Run end: one closing warning naming the dropped count (nothing when none were dropped).</summary>
    public void FlushDropped()
    {
        var n = Volatile.Read(ref _dropped);
        if (n == 0 || _emit is null) return;
        try { _emit("warn", "runtime", $"Log truncated: {n} line(s) dropped past the per-run cap of {_maxLines}", null, null); } catch { }
    }

    private static string Clip(string? m) => m is null ? string.Empty : m.Length <= MaxMessageChars ? m : m[..MaxMessageChars] + "…";
}

(Note the closing row bypasses the counter on purpose — it must be the one row that always lands.)

TraceCapturingLogger.cs:

/// <summary>Decorates the context's ILogger while traced: forwards everything, and copies Information+ into runtime log rows (design D6).</summary>
public sealed class TraceCapturingLogger(ILogger inner, ScriptLogger sink) : ILogger
{
    public IDisposable? BeginScope<TState>(TState state) where TState : notnull => inner.BeginScope(state);
    public bool IsEnabled(LogLevel level) => level >= LogLevel.Information || inner.IsEnabled(level);
    public void Log<TState>(LogLevel level, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
    {
        if (inner.IsEnabled(level)) inner.Log(level, eventId, state, exception, formatter);
        if (level < LogLevel.Information) return;
        var name = level switch { LogLevel.Information => "info", LogLevel.Warning => "warn", _ => "error" };
        sink.Runtime(name, formatter(state, exception), exception);
    }
}

Tests (ScriptLoggerTests): untraced (emit: null) → ILogger receives the entry, nothing emitted; traced → emitter gets ("info","script",msg,null,null); inside TraceStepScope.Enter(id) → stepEventId == id; cap 3 + 5 calls → 3 emits, FlushDropped emits one warn naming 2; message > 2 000 chars is clipped with …; an emitter that throws does not propagate. (TraceCapturingLoggerTests): Debug forwarded but not captured; Warning captured as "warn"/"runtime" with the exception; IsEnabled(Information) true even when inner says false.

Run: dotnet test tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests --filter "FullyQualifiedName~ScriptLoggerTests|FullyQualifiedName~TraceCapturingLoggerTests" -v q → PASS. Commit — git add src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptLogger.cs src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/TraceStepScope.cs src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/TraceCapturingLogger.cs tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptLoggerTests.cs tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/TraceCapturingLoggerTests.cs && git commit -m "feat(site-runtime): ScriptLogger (Log global), TraceStepScope, TraceCapturingLogger (D4-D7)".


Task 5: SiteRuntime — wire Log into ScriptRuntimeContext + ScriptGlobals

Classification: high-risk (script execution path, actor-adjacent) Estimated implement time: ~5 min Parallelizable with: none (after Tasks 1, 4)

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRuntimeContext.cs (ctor :265-300; EmitTrace :414-456; SetAttribute :~700-730, WriteBatchAndWait :~760-790, WaitInternal :~620-665, sync ExternalSystem.Call emit :~1651; new Log property + EmitLog)
  • Modify: src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptCompilationService.cs:269-350 (ScriptGlobals.Log => Instance.Log)
  • Test: tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRuntimeContextTraceEmissionTests.cs (extend; it already builds a traced context with a fake IAuditWriter + collector)

Steps:

  1. Failing tests (extend the existing fixture): (a) traced Log.Info("x") → the collector holds one ScriptLog row with RequestSummary == "x", Extra.logLevel == "info", logSource == "script", stepEventId == null, and the writer received the same instance; (b) untraced context: Log.Info emits nothing to writer or collector; (c) traced SetAttribute whose Ask fault path logs a warning → the collector holds an AttributeWrite row and a ScriptLog row whose stepEventId equals that write row's EventId (logSource == "runtime"); (d) Log.Warn("m", new Exception("e")) → row ErrorMessage == "e", ErrorDetail starts with System.Exception; (e) ScriptLog rows go through AddLowPriority — use a tiny collector (maxEvents: 51) and check the row is dropped with LogsTruncated while EmitTrace rows still land.
  2. Implement:
    • ctor: new optional parameter int maxLogLinesPerRun = 200 (last, defaulted — the launcher passes the option in Task 6); build Log = new ScriptLogger(_logger, isTraced ? EmitLog : null, maxLogLinesPerRun, instanceName, sourceScript, _executionId); then, when traced, _logger = new TraceCapturingLogger(_logger, Log) (make the field non-readonly or assign in one expression — keep the untraced path byte-identical).
    • public ScriptLogger Log { get; } beside Alarms.
    • EmitTrace(..., Guid? eventId = null) → pass eventId: to the factory. Collect unchanged.
    • private void EmitLog(string level, string source, string message, Exception? exception, Guid? stepEventId) — builds AuditChannel.ScriptTrace / AuditKind.ScriptLog / Delivered, target: _sourceScript-derived script name (same as the ScriptRun target), requestSummary: message, errorMessage: exception?.Message, errorDetail: exception?.ToString(), extra: new ScriptTraceExtra { LogLevel, LogSource, StepEventId = stepEventId, Seq = Interlocked.Increment(ref _logSeq) }.ToJson(); then _traceCollector?.AddLowPriority(evt) (guarded like Collect) and the same best-effort _auditWriter.WriteAsync continuation pattern as EmitTrace.
    • Step scopes: in SetAttribute, WriteBatchAndWait, WaitInternal and the sync ExternalSystem.Call path — var stepId = Guid.NewGuid(); using var _ = TraceStepScope.Enter(stepId); around the body, and pass eventId: stepId to the step's EmitTrace (for the ES sync call, to the ScadaBridgeAuditEventFactory.Create at :~1651). Only when _isTraced (skip the allocation otherwise).
    • ScriptGlobals: /// <summary>Leveled per-run logging (design 2026-09-09). Usage: <c>Log.Info("…")</c>, <c>Log.Warn("…", ex)</c>.</summary> public ScriptLogger Log => Instance.Log;
  3. Run --filter "FullyQualifiedName~ScriptRuntimeContextTraceEmissionTests|FullyQualifiedName~CompileSurfaceParityTests" → the trace tests PASS; the parity test will FAIL until Task 7 adds the mirror — that is expected and noted in the commit.
  4. Commit — git add src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRuntimeContext.cs src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptCompilationService.cs tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRuntimeContextTraceEmissionTests.cs && git commit -m "feat(site-runtime): Log global on ScriptRuntimeContext/ScriptGlobals; runtime lines attributed by TraceStepScope (D4-D6)".

Task 6: SiteRuntime — launcher errorDetail, dropped-lines flush, MaxLogLinesPerRun option

Classification: standard Estimated implement time: ~4 min Parallelizable with: Task 7, Task 8 (after Task 5)

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs:255-260 (collector creation), :400-405 (context ctor call — pass the option), :430-506 (call context?.Log.FlushDropped() before every collector?.Complete() / EmitScriptRun; exception path passes ex.ToString()), :568-608 (EmitScriptRun gains string? errorDetail = null → errorDetail:)
  • Modify: src/ZB.MOM.WW.ScadaBridge.SiteRuntime/SiteRuntimeOptions.cs:245 (add MaxLogLinesPerRun { get; set; } = 200; + the existing options validator: > 0)
  • Test: tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRunLauncherTraceTests.cs (create, modelled on how ScriptRuntimeContextTraceEmissionTests builds a launcher/collector — reuse its helpers if they are shared; otherwise the smallest real ScriptRunLauncher.RunScriptAsync invocation with a script body that throws)

Steps: failing tests — (a) a throwing traced script → the ScriptRun row has Status == Failed, ErrorMessage contains the message, ErrorDetail starts with the exception type name and contains at ; (b) a timeout → ErrorDetail == null; (c) a script that logs 5 lines under MaxLogLinesPerRun = 2 → exactly 2 ScriptLog rows + 1 closing warn runtime row, all present in the reply's TraceEvents before the ScriptRun row; (d) SiteRuntimeOptions validation rejects 0. Implement; run --filter "FullyQualifiedName~ScriptRunLauncherTraceTests|FullyQualifiedName~SiteRuntimeOptions" → PASS. Commit — git commit -m "feat(site-runtime): ScriptRun rows carry exception detail; per-run log line cap (D3/D7)" (pathspec the four files).


Task 7: Script surfaces — ScriptCompileSurface.Log, sandbox mirrors, trust pin

Classification: standard Estimated implement time: ~5 min Parallelizable with: Task 6, Task 8

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.ScriptAnalysis/ScriptCompileSurface.cs:67-70 (add public CompileLog Log => throw new NotSupportedException(CompileOnly); + nested CompileLog with the four void methods (string message, Exception? exception = null))
  • Modify: src/ZB.MOM.WW.ScadaBridge.CentralUI/ScriptAnalysis/SandboxScriptHost.cs:85-90 (add public SandboxLog Log { get; } = new();) and create the SandboxLog class in the same file: each method writes "[level] message" (+ exception on a following line) through Console.Out, which the sandbox already captures into SandboxRunResult.ConsoleOutput (SandboxConsoleCapture)
  • Modify: src/ZB.MOM.WW.ScadaBridge.CentralUI/ScriptAnalysis/SandboxInboundScriptHost.cs:27 (same Log property)
  • Test: tests/ZB.MOM.WW.ScadaBridge.ScriptAnalysis.Tests/RoslynScriptCompilerTests.cs (a script calling Log.Info("a"); Log.Warn("b", new Exception()); Log.Error("c"); Log.Debug("d"); compiles)
  • Test: tests/ZB.MOM.WW.ScadaBridge.ScriptAnalysis.Tests/ScriptTrustValidatorTests.cs (Log.Info("x") passes the gate — pins that Log is not on the deny list)
  • Test: tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/CompileSurfaceParityTests.cs (make it green again: Log on both sides)
  • Test: tests/ZB.MOM.WW.ScadaBridge.CentralUI.Tests/ScriptAnalysis/ScriptAnalysisServiceTests.cs (a Test Run script with Log.Info("hello") returns ConsoleOutput containing [info] hello; an inbound-sandbox script likewise)

Run the three projects' filters → PASS. Commit — git commit -m "feat(scripts): Log global on the compile surface and both Test Run sandboxes; trust-gate pin (D4)".


Task 8: InboundAPI — InboundScriptContext.Log + MaxLogLinesPerRun

Classification: standard Estimated implement time: ~5 min Parallelizable with: Task 6, Task 7

Files:

  • Create: src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundScriptLogger.cs (same shape as the site ScriptLogger — copy the class, do not reference SiteRuntime; emitter builds the central ScriptLog row via ScadaBridgeAuditEventFactory.Create(..., sourceNode: nodeIdentity.NodeName, executionId: inboundExecutionId), pushes it to the inline traceSink and, when traced, to ICentralAuditWriter)
  • Modify: src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundScriptExecutor.cs:338-440 (ExecuteAsync: build the logger with trace, route.TraceSink, the execution id; pass it to the context), :585-625 (InboundScriptContext + public InboundScriptLogger Log { get; }, ctor parameter with a null-safe default so existing constructions compile), and the script-globals declaration so Log binds at top level exactly like Route/Database
  • Modify: src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundApiOptions.cs (MaxLogLinesPerRun = 200, validated > 0 in the existing validator)
  • Test: tests/ZB.MOM.WW.ScadaBridge.InboundAPI.Tests/InboundScriptExecutorTests.cs (traced execute of a method whose body calls Log.Info("central") → the trace sink received a ScriptLog row with the inbound execution id and stepEventId == null; untraced → sink empty, ILogger got the entry)

Steps as Task 4/5. Commit — git commit -m "feat(inbound-api): Log global for method scripts, central ScriptLog rows when traced (D4/D5)".


Task 9: InboundAPI — exception detail on the inbound row

Classification: standard Estimated implement time: ~4 min Parallelizable with: none (after Task 8 — same executor file)

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundScriptExecutor.cs:548-552 (return new InboundScriptResult(false, null, "Internal script error", "SCRIPT_ERROR", ErrorDetail: ex.ToString());), :640-644 (InboundScriptResult + string? ErrorDetail = null)
  • Modify: src/ZB.MOM.WW.ScadaBridge.InboundAPI/EndpointExtensions.cs:276-290 (after scriptResult: if (scriptResult.ErrorDetail is { } detail) httpContext.Items[AuditWriteMiddleware.ErrorDetailItemKey] = detail;)
  • Modify: src/ZB.MOM.WW.ScadaBridge.InboundAPI/Middleware/AuditWriteMiddleware.cs:264-350 (public const string ErrorDetailItemKey = "ScadaBridge.Audit.ErrorDetail"; and errorDetail: thrown?.ToString() ?? httpContext.Items[ErrorDetailItemKey] as string)
  • Test: tests/ZB.MOM.WW.ScadaBridge.InboundAPI.Tests/InboundScriptExecutorTests.cs (a throwing method → ErrorMessage == "Internal script error", ErrorDetail contains the real message — and the HTTP body test still shows only SCRIPT_ERROR)
  • Test: tests/ZB.MOM.WW.ScadaBridge.InboundAPI.Tests/Middleware/AuditWriteMiddlewareTests.cs (an item-key detail lands on the row's ErrorDetail; absent → null)

Commit — git commit -m "feat(inbound-api): method-script exception detail on the inbound audit row, never on the HTTP body (D3)".


Task 10: ManagementService — runner inbound row carries ErrorDetail; results pass LogsTruncated

Classification: small Estimated implement time: ~3 min Parallelizable with: Task 11, Task 12 (after Task 9)

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.ManagementService/FlowDebug/FlowDebugRunner.cs:180-192 (errorDetail: result.ErrorDetail), :145 / :307 and the result construction lines (FlowDebugRunResult.LogsTruncated = collector.LogsTruncated)
  • Modify: src/ZB.MOM.WW.ScadaBridge.Commons/Messages/Management/FlowDebugCommands.cs:64-72 (FlowDebugRunResult + bool LogsTruncated = false, trailing)
  • Test: tests/ZB.MOM.WW.ScadaBridge.ManagementService.Tests/FlowDebugRunnerTests.cs (a SCRIPT_ERROR executor result with detail → the written inbound row's AuditDetails.ErrorDetail equals it; LogsTruncated round-trips)

Commit — git commit -m "feat(management): Flow Debugger inbound row carries exception detail; LogsTruncated on the run result".


Task 11: CentralUI — FlowGraphView log badge + failed-node exception subtitle

Classification: standard Estimated implement time: ~5 min Parallelizable with: Task 10, Task 12

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Shared/FlowGraphView.razor:88-101 (footer: wrap subtitle/pill and the new badge in <div class="fg-foot">; badge <span class="fg-logs" data-test="flow-node-logs" title="@LogTitle(node)"> with up to three <i> counts, highest severity first)
  • Modify: src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Shared/FlowGraphView.razor.cs (internal static (int Errors, int Warnings, int Info) LogCounts(FlowStep? s) — error→Errors, warn→Warnings, everything else→Info; internal static string? ExceptionSubtitle(FlowStep s) → "{TypeNameWithoutNamespace}: {message}" parsed from the first line of ErrorDetail, else ErrorMessage, only when Outcome is Failed or TimedOut; DisplaySubtitle uses it for failed real steps)
  • Modify: src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Shared/FlowGraphView.razor.css (.fg-foot flex row; .fg-logs i.e/.w/.i colours from the kit tokens exactly as the pills; .fg-node.failed .fg-subtitle { color: var(--bad, var(--bs-danger)); font-family: var(--mono); })
  • Test: tests/ZB.MOM.WW.ScadaBridge.CentralUI.Tests/Shared/FlowGraphViewTests.cs (no lines → no flow-node-logs; 1 error + 2 warn + 3 info → badge text ✕ 1 ! 2 ≡ 3 in that order; failed step with ErrorDetail "System.InvalidOperationException: Recipe 42 rejected\n at X" → subtitle InvalidOperationException: Recipe 42 rejected; failed step without detail → the ErrorMessage)

Commit — git commit -m "feat(central-ui): FlowGraphView log-count badge and exception subtitle on failed nodes (D8)".


Task 12: CentralUI — FlowStepDetail Log tab

Classification: standard Estimated implement time: ~5 min Parallelizable with: Task 10, Task 11

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Deployment/FlowStepDetail.razor (tabs: insert "Log" after "Output" in both tab arrays, label Log (n) where n = Logs.Count, hidden when the step has neither lines nor ErrorDetail; pane: exception block data-test="flow-step-exception" — <div class="fsd-exc"> with type line, message, <pre> detail, Copy button (JS navigator.clipboard.writeText, IJSRuntime, swallow failures); level filter All | Warn + (data-test="flow-step-log-filter"); table data-test="flow-step-log-lines" columns Time (UTC, HH:mm:ss.fff) · Level pill · Source · Message, an attached exception rendered as a second line in the Message cell; a hint n more on <step title> when other steps of the same execution carry lines, rendered as a button that invokes the new [Parameter] EventCallback<FlowStep> OnSelectStep; the Output tab's alert gains <a @onclick="() => _tab = \"Log\"">see exception</a> when ErrorDetail is set; OnParametersSet: when the selected step changes (track _lastStepId) and the new step has ErrorDetail, _tab = "Log", else "Input" if the current tab is not visible)
  • Modify: src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Deployment/FlowStepDetail.razor.css (if the component has one; otherwise the styles live in the page's .razor.css — check which exists and follow it: .fsd-exc red left stripe on --bad-bg, .fsd-lvl.info/.warn/.error/.debug)
  • Test: tests/ZB.MOM.WW.ScadaBridge.CentralUI.Tests/Deployment/FlowStepDetailTests.cs (tab absent without lines/detail; present with count; failed-with-detail step opens on Log and shows type + message + pre; Warn + hides info/debug rows; the cross-step hint invokes OnSelectStep with the other step; the Output alert's link switches to Log)

Commit — git commit -m "feat(central-ui): FlowStepDetail Log tab — exception block, level-filtered lines, cross-step hint (D8)".


Task 13: CentralUI — Flow Debugger page: strip counts, truncation notes, selection hookup

Classification: standard Estimated implement time: ~4 min Parallelizable with: none (after Tasks 11, 12)

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Pages/Deployment/FlowDebugger.razor:153-194 (after Writes: <span class="new"><span class="fd-label">Log</span><span class="fd-mono" data-test="flow-log-counts">@LogSummary</span></span> when any line exists; <span class="badge bg-warning text-dark" data-test="flow-logs-truncated">log lines truncated inline — Replay is complete</span> when _graph?.LogsTruncated == true; <span class="text-muted small" data-test="flow-unattached-logs">@n log line(s) could not be placed on a step</span> when UnattachedLogLines > 0), :283-287 (<FlowStepDetail … OnSelectStep="OnSelectStep" />)
  • Modify: src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Pages/Deployment/FlowDebugger.razor.cs (LogSummary = "{e} errors · {w} warnings · {i} info" summed over Steps.SelectMany(s => s.Logs ?? []); every FlowGraphBuilder.Build(...) call passes logsTruncated: _raw?.LogsTruncated ?? false; MergeRefreshedGraph keeps it)
  • Modify: src/ZB.MOM.WW.ScadaBridge.CentralUI/Services/FlowDebugService.cs + IFlowDebugService.cs:18-25 (FlowDebugOutcome carries LogsTruncated from FlowDebugRunResult)
  • Test: tests/ZB.MOM.WW.ScadaBridge.CentralUI.Tests/Deployment/FlowDebuggerPageTests.cs (counts render; truncation badge on LogsTruncated; unattached note; the state chip stays Completed for a run whose only errors are Log.Error lines on Ok steps — the log level never changes the run state)

Commit — git commit -m "feat(central-ui): Flow Debugger status strip log counts + inline-truncation notes".


Task 14: CLI — logs column and --show-logs

Classification: small Estimated implement time: ~4 min Parallelizable with: Task 13

Files:

  • Modify: src/ZB.MOM.WW.ScadaBridge.CLI/Commands/FlowDebugTableProjection.cs:85-115 (add a logs column = step.Logs?.Count ?? 0; a showLogs flag prints each line indented under its step as HH:mm:ss.fff LEVEL source message and, for a failed step with ErrorDetail, the first three lines of the detail indented)
  • Modify: the flow-debug command definitions (run-method, run-script, run-value-change, replay) — add --show-logs (find them next to the projection: grep -rn "flow-debug" src/ZB.MOM.WW.ScadaBridge.CLI/Commands/*.cs)
  • Modify: src/ZB.MOM.WW.ScadaBridge.CLI/README.md (### flow-debug table columns + the flag)
  • Test: tests/ZB.MOM.WW.ScadaBridge.CLI.Tests/FlowDebugCommandsTests.cs (a result with two lines on the script step renders logs 2 and, with --show-logs, the two indented lines)

Commit — git commit -m "feat(cli): flow-debug logs column and --show-logs".


Task 15: Specs, register, rig demo + verification step J, full build

Classification: standard Estimated implement time: ~5 min Parallelizable with: none

Files:

  • Modify: docs/requirements/Component-CentralUI.md:218-220 (Flow Debugger bullet: log badge, Log tab, strip counts), docs/requirements/Component-SiteRuntime.md (Log global beside Alarms; TraceCapturingLogger; MaxLogLinesPerRun; the process-global Console.Out note from design §9), docs/requirements/Component-InboundAPI.md (Log; InboundScriptResult.ErrorDetail never on the body), docs/requirements/Component-AuditLog.md:58-62 (ScriptLog kind row; per-channel retention covers it), docs/requirements/Component-ScriptAnalysis.md (compile surface Log), docs/plans/2026-09-05-flow-debugger-design.md (status line: v1.4 pointer), CLAUDE.md (Flow Debugger bullet: v1.4 one sentence — Log global, ScriptLog rows folded onto steps, exception detail, caps, "never await audit writes" still holds because emission is fire-and-continue), docs/plans/2026-07-08-deferred-work-register.md (row 110: strike the console half, keep Direction B; new row: node-logger execution-id enrichment for other actors' lines — design §9)
  • Create: docker/seed-flow-log-demo.sh (a Call script FlowLogDemo on SimMachine at site-a: Log.Info, Log.Debug, a static write, Log.Warn, then throw new InvalidOperationException("demo failure"); idempotent like seed-flow-outbound-demo.sh)
  • Modify: docker/verify-delmia-notifier.sh (step J: flow-debug run-script … FlowLogDemo --show-logs --json; assert the ScriptRun step has outcome Failed, errorDetail containing InvalidOperationException, and ≥ 3 log lines with levels ⊇ {info, debug, warn}; then flow-debug replay <root> asserts the same counts; prints J step logs live+replay -> YES), docker/README.md (one line)

Steps: write the docs; dotnet build ZB.MOM.WW.ScadaBridge.slnx -nologo -v q (0 errors); dotnet test per touched project (Commons, SiteRuntime, ScriptAnalysis, InboundAPI, ManagementService, CentralUI, CLI — Playwright excluded); bash docker/deploy.sh; bash docker/seed-flow-log-demo.sh; DELMIA_API_KEY=… bash docker/verify-delmia-notifier.sh → H, I and J all YES; open /deployment/flow-debugger?executionId=<J root> and confirm the script node shows the red exception subtitle and a ✕ 1 ! 1 ≡ 2 badge, the Log tab opens first with the exception block, and the write node carries no badge (no runtime warning on a clean write). Paste the J line into the commit — git commit -m "docs+rig(flow-debugger): step logs v1.4 specs, register rows, FlowLogDemo seed + verification step J".


Verification (whole plan)

  1. Solution build clean; all seven test projects green (the pre-existing Communication gRPC gauge flake and env-only Playwright E2E excepted, as recorded in memory).
  2. Rig steps H, I, J YES.
  3. Browser: a Live run of FlowLogDemo renders the exception on the script node and its lines under Log; Replay of the same root shows identical badges and lines; an untraced real call to a method whose script calls Log.* writes no ScriptLog rows (scadabridge audit query --channel ScriptTrace --kind ScriptLog returns nothing for it) but the line appears in the central container log.