dohertj2/ScadaBridge
1
0
Fork 0
Code Issues 2 Pull Requests Actions Packages Projects Releases Wiki Activity

feat(cli): flow-debug logs column and --show-logs

Browse Source
This commit is contained in:
Joseph Doherty
2026-09-09 12:03:42 -04:00
parent a45857ddd6
commit c6529fa996
4 changed files with 154 additions and 13 deletions
Download Patch File Download Diff File Expand all files Collapse all files
src/ZB.MOM.WW.ScadaBridge.CLI/Commands/FlowDebugCommands.cs
+16 -4
View File
@@ -51,13 +51,16 @@ public static class FlowDebugCommands
+ "(default 5 min), so a larger value still 504s at that ceiling",
DefaultValueFactory = _ => 120,
};
var showLogsOption = new Option<bool>("--show-logs") { Description = "Print each step's ScriptLog lines and exception detail as indented lines under its row" };
var cmd = new Command("run-method") { Description = "Run an inbound API method on the active central node with full tracing and print the flow's steps" };
cmd.Add(methodIdOption);
cmd.Add(paramsOption);
cmd.Add(timeoutOption);
cmd.Add(showLogsOption);
cmd.SetAction(async (ParseResult result) =>
{
var timeoutSeconds = result.GetValue(timeoutOption);
var showLogs = result.GetValue(showLogsOption);
if (timeoutSeconds <= 0)
{
OutputFormatter.WriteError("--timeout-seconds must be greater than zero.", "INVALID_ARGUMENT");
@@ -79,7 +82,7 @@ public static class FlowDebugCommands
result, urlOption, formatOption, usernameOption, passwordOption,
new FlowDebugRunMethodCommand(result.GetValue(methodIdOption), parameters),
timeout: TimeSpan.FromSeconds(timeoutSeconds),
tableProjector: FlowDebugTableProjection.ProjectEvents);
tableProjector: json => FlowDebugTableProjection.ProjectEvents(json, showLogs));
});
return cmd;
}
@@ -102,6 +105,7 @@ public static class FlowDebugCommands
+ "(default 5 min), so a larger value still 504s at that ceiling",
DefaultValueFactory = _ => 120,
};
var showLogsOption = new Option<bool>("--show-logs") { Description = "Print each step's ScriptLog lines and exception detail as indented lines under its row" };
var cmd = new Command("run-script") { Description = "Run one site script with tracing — a ValueChange/Conditional script is fired by writing its trigger attribute (--value); any other script is called directly (--params)" };
cmd.Add(instanceIdOption);
cmd.Add(scriptOption);
@@ -109,10 +113,12 @@ public static class FlowDebugCommands
cmd.Add(valueOption);
cmd.Add(waitOption);
cmd.Add(timeoutOption);
cmd.Add(showLogsOption);
cmd.SetAction(async (ParseResult result) =>
{
var waitSeconds = result.GetValue(waitOption);
var timeoutSeconds = result.GetValue(timeoutOption);
var showLogs = result.GetValue(showLogsOption);
if (waitSeconds <= 0)
{
OutputFormatter.WriteError("--wait-seconds must be greater than zero.", "INVALID_ARGUMENT");
@@ -145,7 +151,7 @@ public static class FlowDebugCommands
result.GetValue(valueOption),
waitSeconds),
timeout: TimeSpan.FromSeconds(Math.Max(timeoutSeconds, waitSeconds + ClientSlackSeconds)),
tableProjector: FlowDebugTableProjection.ProjectEvents);
tableProjector: json => FlowDebugTableProjection.ProjectEvents(json, showLogs));
});
return cmd;
}
@@ -156,14 +162,17 @@ public static class FlowDebugCommands
var attributeOption = new Option<string>("--attribute") { Description = "Canonical attribute name to write", Required = true };
var valueOption = new Option<string>("--value") { Description = "Value to write (canonical string form)", Required = true };
var waitOption = new Option<int>("--wait-seconds") { Description = "How long to wait for a triggered script run before reporting NO_TRIGGER_WITHIN_WINDOW", DefaultValueFactory = _ => 45 };
var showLogsOption = new Option<bool>("--show-logs") { Description = "Print each step's ScriptLog lines and exception detail as indented lines under its row" };
var cmd = new Command("run-value-change") { Description = "Write an attribute through the traced path and capture the script run(s) the change triggers — the attribute-level path (also fires Expression triggers); prefer run-script to run a named script" };
cmd.Add(instanceIdOption);
cmd.Add(attributeOption);
cmd.Add(valueOption);
cmd.Add(waitOption);
cmd.Add(showLogsOption);
cmd.SetAction(async (ParseResult result) =>
{
var waitSeconds = result.GetValue(waitOption);
var showLogs = result.GetValue(showLogsOption);
if (waitSeconds <= 0)
{
OutputFormatter.WriteError("--wait-seconds must be greater than zero.", "INVALID_ARGUMENT");
@@ -178,7 +187,7 @@ public static class FlowDebugCommands
result.GetValue(valueOption)!,
waitSeconds),
timeout: TimeSpan.FromSeconds(waitSeconds + ClientSlackSeconds),
tableProjector: FlowDebugTableProjection.ProjectEvents);
tableProjector: json => FlowDebugTableProjection.ProjectEvents(json, showLogs));
});
return cmd;
}
@@ -186,14 +195,17 @@ public static class FlowDebugCommands
private static Command BuildReplay(Option<string> urlOption, Option<string> formatOption, Option<string> usernameOption, Option<string> passwordOption)
{
var executionIdOption = new Option<Guid>("--execution-id") { Description = "Any execution ID in the chain (from an audit row)", Required = true };
var showLogsOption = new Option<bool>("--show-logs") { Description = "Print each step's ScriptLog lines and exception detail as indented lines under its row" };
var cmd = new Command("replay") { Description = "Replay a past flow from the central audit store" };
cmd.Add(executionIdOption);
cmd.Add(showLogsOption);
cmd.SetAction(async (ParseResult result) =>
{
var showLogs = result.GetValue(showLogsOption);
return await CommandHelpers.ExecuteCommandAsync(
result, urlOption, formatOption, usernameOption, passwordOption,
new FlowDebugReplayCommand(result.GetValue(executionIdOption)),
tableProjector: FlowDebugTableProjection.ProjectEvents);
tableProjector: json => FlowDebugTableProjection.ProjectEvents(json, showLogs));
});
return cmd;
}
src/ZB.MOM.WW.ScadaBridge.CLI/Commands/FlowDebugTableProjection.cs
+44 -3
View File
@@ -37,8 +37,14 @@ internal static class FlowDebugTableProjection
/// renderer's own fallbacks still apply.
/// </summary>
/// <param name="json">The raw success JSON body from the management API.</param>
/// <param name="showLogs">
/// When true, prints each step's <c>ScriptLog</c> lines and (on a failed step) the first
/// three lines of its exception detail as additional indented <c>note</c> rows immediately
/// following that step's row (step-logs design 2026-09-09, CLI Task 14). The <c>logs</c>
/// column (a count of attached log lines) is always present, independent of this flag.
/// </param>
/// <returns>Compact JSON suitable for table rendering.</returns>
internal static string ProjectEvents(string json)
internal static string ProjectEvents(string json, bool showLogs = false)
{
JsonDocument doc;
try
@@ -62,7 +68,7 @@ internal static class FlowDebugTableProjection
var truncated = TryGetPropertyCI(root, "truncated", out var t) && t.ValueKind == JsonValueKind.True;
var rows = ProjectSteps(events, truncated);
var rows = ProjectSteps(events, truncated, showLogs);
if (rows == null)
{
// The event array did not deserialize as canonical audit events (a future wire
@@ -103,7 +109,7 @@ internal static class FlowDebugTableProjection
/// Builds the flow graph from the canonical events and projects one row per step. Returns
/// null when the array is not a list of canonical audit events.
/// </summary>
private static JsonArray? ProjectSteps(JsonElement events, bool truncated)
private static JsonArray? ProjectSteps(JsonElement events, bool truncated, bool showLogs)
{
List<AuditEvent>? list;
try
@@ -148,12 +154,47 @@ internal static class FlowDebugTableProjection
["lifecycle"] = lifecycle is { Count: > 0 } ? $"{lifecycle.Count} {(lifecycle.Count == 1 ? "row" : "rows")}" : null,
["correlation"] = step.CorrelationId?.ToString("D"),
["error"] = step.ErrorMessage,
["logs"] = step.Logs?.Count ?? 0,
});
if (!showLogs)
continue;
if (step.Logs is { Count: > 0 } logs)
{
foreach (var line in logs)
rows.Add(new JsonObject { ["note"] = JsonValue.Create(FormatLogLine(line)) });
}
if (!string.IsNullOrWhiteSpace(step.ErrorDetail))
{
foreach (var line in FormatErrorDetailLines(step.ErrorDetail))
rows.Add(new JsonObject { ["note"] = JsonValue.Create(line) });
}
}
return rows;
}
/// <summary>Formats one <see cref="FlowLogLine"/> as <c> HH:mm:ss.fff LEVEL source message</c> (UTC, level upper-cased and padded to 5 chars).</summary>
private static string FormatLogLine(FlowLogLine line)
{
var time = line.OccurredAtUtc.UtcDateTime.ToString("HH:mm:ss.fff", CultureInfo.InvariantCulture);
var level = (line.Level ?? "info").ToUpperInvariant().PadRight(5);
return $" {time} {level} {line.Source} {line.Message}";
}
/// <summary>
/// Formats the first three lines of an exception's <c>ToString()</c> detail — the first
/// prefixed <c> exception: </c>, the rest indented four spaces.
/// </summary>
private static IEnumerable<string> FormatErrorDetailLines(string errorDetail)
{
var lines = errorDetail.Replace("\r\n", "\n").Split('\n');
for (var i = 0; i < Math.Min(3, lines.Length); i++)
yield return i == 0 ? $" exception: {lines[i]}" : $" {lines[i]}";
}
/// <summary>Projects one canonical audit event (camelCase JSON) to its compact row (fallback path).</summary>
private static JsonNode ProjectEvent(JsonElement evt)
{
src/ZB.MOM.WW.ScadaBridge.CLI/README.md
+18 -6
View File
@@ -2293,23 +2293,31 @@ Trace steps are ordinary audit rows: a run leaves them in the central `AuditLog`
chain after the fact.
Table output prints one row per step in chronological order —
`occurred | kind | lane | target | durationMs | status | lifecycle | correlation | error` — the same
`occurred | kind | lane | target | durationMs | status | lifecycle | correlation | error | logs` — the same
projection the Flow Debugger page draws (`FlowGraphBuilder`): an outbound `ExternalSystem.*`,
`Database.*` or `Notify` call is ONE row on the `External` lane (kinds `ApiCall` / `DbCall` /
`Notify`), and a cached call's or notification's later rows (Forwarded → Attempted → Delivered /
Parked) fold into it — `lifecycle` counts them and `status` is the latest row's (`Submitted`
while the operation is still in flight; re-run `replay` to see it settle). A trailing `note`
while the operation is still in flight; re-run `replay` to see it settle). `logs` is the count
of `ScriptLog` lines a step's script emitted (step-logs design 2026-09-09). A trailing `note`
row reports a run that did not complete (the error code verbatim) or a truncated inline event
list. `--format json` returns the raw `FlowDebugRunResult` (`rootExecutionId`,
`completed`, `error`, `errorCode`, `events`, `truncated`, `startedAtUtc`, `finishedAtUtc`).
Pass `--show-logs` (on `run-method`, `run-script`, `run-value-change` and `replay`) to print
each step's log lines immediately under its row, as additional indented `note` rows —
` HH:mm:ss.fff LEVEL source message` (UTC, level upper-cased) — and, for a failed step whose
error carries an exception detail, the first three lines of it (` exception: <first line>`,
then two more lines indented four spaces). Off by default; the `logs` count column is always
shown regardless of this flag.
#### `flow-debug run-method`
Run an inbound API method with the given parameters, exactly as an external caller would,
and print the traced flow.
```sh
scadabridge --url <url> flow-debug run-method --method-id <int> [--params <json>] [--timeout-seconds 120]
scadabridge --url <url> flow-debug run-method --method-id <int> [--params <json>] [--timeout-seconds 120] [--show-logs]
```
| Option | Required | Description |
@@ -2317,6 +2325,7 @@ scadabridge --url <url> flow-debug run-method --method-id <int> [--params <json>
| `--method-id` | yes | Inbound API method ID (`api-method list`) |
| `--params` | no | Flat JSON object of parameters, validated against the method's parameter schema. Omit for a parameterless method. |
| `--timeout-seconds` | no | Client-side wait for the run (default 120). Raise this above the method's own `TimeoutSeconds + 25` for a long-running method, or the client gives up before the server's own run grace does. **Server ceiling:** the management endpoint applies `ScadaBridge:ManagementService:LongRunningCommandTimeout` (default 5 min) to `flow-debug run-method`, so a value above that still returns `504` at the server's ceiling — raise the server setting too if a method legitimately runs longer. |
| `--show-logs` | no | Print each step's `ScriptLog` lines and exception detail as indented lines under its row (table output only; default off) |
Parameters that fail schema validation are reported as `VALIDATION_FAILED` without running
the script.
@@ -2331,7 +2340,7 @@ method. The runner resolves the script from the instance's flattened configurati
the branch itself — the client does not need to know the script's trigger kind ahead of time.
```sh
scadabridge --url <url> flow-debug run-script --instance-id <int> --script <name> [--params <json>] [--value <string>] [--wait-seconds 45] [--timeout-seconds 120]
scadabridge --url <url> flow-debug run-script --instance-id <int> --script <name> [--params <json>] [--value <string>] [--wait-seconds 45] [--timeout-seconds 120] [--show-logs]
```
| Option | Required | Description |
@@ -2342,6 +2351,7 @@ scadabridge --url <url> flow-debug run-script --instance-id <int> --script <name
| `--value` | no | Value to write to the trigger attribute of a ValueChange/Conditional script, in canonical string form |
| `--wait-seconds` | no | Write kinds: how long to wait for the triggered run before reporting `NO_TRIGGER_WITHIN_WINDOW` (default 45) |
| `--timeout-seconds` | no | Client-side wait for the run (default 120). Raise this above the script's own `ExecutionTimeoutSeconds + 25` for a long-running script. **Server ceiling:** the management endpoint applies `ScadaBridge:ManagementService:LongRunningCommandTimeout` (default 5 min) to `flow-debug run-script`, so a value above that still returns `504` at the server's ceiling — raise the server setting too if a script legitimately runs longer. |
| `--show-logs` | no | Print each step's `ScriptLog` lines and exception detail as indented lines under its row (table output only; default off) |
A missing `--value` on a write-kind script, or `--params` that fail schema validation on a
call-kind script, are reported as `VALIDATION_FAILED` without running the script. An unknown
@@ -2355,7 +2365,7 @@ attribute-level path (it is also the way to fire an `Expression` trigger, which
attribute of its own); prefer `run-script` to run a script by name.
```sh
scadabridge --url <url> flow-debug run-value-change --instance-id <int> --attribute <name> --value <string> [--wait-seconds 45]
scadabridge --url <url> flow-debug run-value-change --instance-id <int> --attribute <name> --value <string> [--wait-seconds 45] [--show-logs]
```
| Option | Required | Description |
@@ -2364,6 +2374,7 @@ scadabridge --url <url> flow-debug run-value-change --instance-id <int> --attrib
| `--attribute` | yes | Canonical attribute name to write |
| `--value` | yes | Value to write, in canonical string form |
| `--wait-seconds` | no | How long to wait for a triggered run before reporting `NO_TRIGGER_WITHIN_WINDOW` (default 45) |
| `--show-logs` | no | Print each step's `ScriptLog` lines and exception detail as indented lines under its row (table output only; default off) |
The client waits `--wait-seconds` + 25 (no separate option — the client's HTTP wait always
derives from `--wait-seconds`). The write itself is real — the attribute changes — and is the root step of the flow.
@@ -2376,12 +2387,13 @@ default 30) correlates back to this run.
Rebuild a past flow from the central audit store.
```sh
scadabridge --url <url> flow-debug replay --execution-id <guid>
scadabridge --url <url> flow-debug replay --execution-id <guid> [--show-logs]
```
| Option | Required | Description |
|--------|----------|-------------|
| `--execution-id` | yes | Any execution ID in the chain — the root is resolved server-side |
| `--show-logs` | no | Print each step's `ScriptLog` lines and exception detail as indented lines under its row (table output only; default off) |
Only flows whose site legs were traced (a Live run, or a method with `--trace-all-calls`
set) have site steps to replay; an untraced call shows its central `RouteCall` step plus the
tests/ZB.MOM.WW.ScadaBridge.CLI.Tests/FlowDebugCommandsTests.cs
+76
View File
@@ -302,4 +302,80 @@ public class FlowDebugCommandsTests
Assert.Equal(JsonValueKind.Null, rows[1].GetProperty("lifecycle").ValueKind);
Assert.Equal(JsonValueKind.Null, rows[1].GetProperty("correlation").ValueKind);
}
/// <summary>Builds a run whose script step carries two <c>ScriptLog</c> rows and fails with an exception detail (step-logs plan 2026-09-09, Task 14).</summary>
private static string StepLogsPayload(out DateTime log1Time, out DateTime log2Time)
{
var root = Guid.NewGuid();
var child = Guid.NewGuid();
var t0 = new DateTime(2026, 9, 9, 10, 0, 0, 0, DateTimeKind.Utc);
log1Time = t0.AddMilliseconds(30);
log2Time = t0.AddMilliseconds(31);
var events = new List<AuditEvent>
{
ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.RouteCall, AuditStatus.Delivered,
occurredAtUtc: t0, target: "DelmiaSim01.ProcessRecipeDownload", executionId: root, durationMs: 100,
extra: new ScriptTraceExtra { ChildExecutionId = child }.ToJson()),
ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptRun, AuditStatus.Failed,
occurredAtUtc: t0.AddMilliseconds(10), target: "ProcessRecipeDownload", executionId: child, parentExecutionId: root,
sourceSiteId: "site-a", sourceInstanceId: "DelmiaSim01", sourceScript: "ProcessRecipeDownload", durationMs: 50,
errorMessage: "boom", errorDetail: "System.InvalidOperationException: boom\n at X\n at Y\n at Z"),
ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptLog, AuditStatus.Delivered,
occurredAtUtc: log1Time, target: "ProcessRecipeDownload", executionId: child,
requestSummary: "hello", extra: new ScriptTraceExtra { LogLevel = "warn", LogSource = "script", Seq = 1 }.ToJson()),
ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptLog, AuditStatus.Delivered,
occurredAtUtc: log2Time, target: "ProcessRecipeDownload", executionId: child,
requestSummary: "world", extra: new ScriptTraceExtra { LogLevel = "warn", LogSource = "script", Seq = 2 }.ToJson()),
};
var result = new FlowDebugRunResult(root, true, null, null, events, false, new DateTimeOffset(t0), new DateTimeOffset(t0.AddSeconds(1)));
return JsonSerializer.Serialize(result, CamelCase);
}
[Fact]
public void Projection_LogsColumn_CountsAttachedLogLines()
{
var projected = FlowDebugTableProjection.ProjectEvents(StepLogsPayload(out _, out _));
using var doc = JsonDocument.Parse(projected);
var rows = doc.RootElement.EnumerateArray().ToList();
Assert.Equal(2, rows.Count); // RouteCall + ScriptRun — no note rows without --show-logs
Assert.Equal(0, rows[0].GetProperty("logs").GetInt32());
Assert.Equal(2, rows[1].GetProperty("logs").GetInt32());
Assert.All(rows, r => Assert.False(r.TryGetProperty("note", out _)));
}
[Fact]
public void Projection_ShowLogsTrue_PrintsIndentedLogLinesAndExceptionDetail_UnderTheStepRow()
{
var json = StepLogsPayload(out var log1Time, out var log2Time);
var projected = FlowDebugTableProjection.ProjectEvents(json, showLogs: true);
using var doc = JsonDocument.Parse(projected);
var rows = doc.RootElement.EnumerateArray().ToList();
// RouteCall, ScriptRun, 2 log lines, 3 exception-detail lines (capped at 3 of the 4 available).
Assert.Equal(7, rows.Count);
var expectedLog1 = $" {log1Time:HH:mm:ss.fff} WARN script hello";
var expectedLog2 = $" {log2Time:HH:mm:ss.fff} WARN script world";
Assert.Equal(expectedLog1, rows[2].GetProperty("note").GetString());
Assert.Equal(expectedLog2, rows[3].GetProperty("note").GetString());
Assert.Equal(" exception: System.InvalidOperationException: boom", rows[4].GetProperty("note").GetString());
Assert.Equal(" " + " at X", rows[5].GetProperty("note").GetString());
Assert.Equal(" " + " at Y", rows[6].GetProperty("note").GetString());
Assert.DoesNotContain("at Z", projected);
}
[Fact]
public void Projection_ShowLogsFalse_OmitsLogAndExceptionDetailLines()
{
var projected = FlowDebugTableProjection.ProjectEvents(StepLogsPayload(out _, out _), showLogs: false);
Assert.DoesNotContain("WARN", projected);
Assert.DoesNotContain("exception:", projected);
}
}