docs(plans): Flow Debugger step logs + exceptions — design, mockup, 15-task plan (v1.4)
This commit is contained in:
Joseph Doherty
@@ -0,0 +1,143 @@
|
||||
# Flow Debugger — Step Logs and Exceptions (design)
|
||||
|
||||
**Date:** 2026-09-09
|
||||
**Status:** proposed (autonomous brainstorm; decisions below are assumptions to confirm), implementation plan `2026-09-09-flow-debugger-step-logs.md`
|
||||
**Extends:** `2026-09-05-flow-debugger-design.md` (§5 trace model, §7 central components), `2026-09-06-flow-debugger-outbound-calls.md` (folded nodes), register row 110 (console capture on `ScriptRun`)
|
||||
**Mockup:** `docs/plans/2026-09-09-flow-debugger-step-logs-mockup.html` (published as a Claude artifact — link in the session recap)
|
||||
|
||||
## 1. What changes
|
||||
|
||||
A traced Flow Debugger run shows, **on the node that produced them**:
|
||||
|
||||
1. **The exception a failing step threw** — type, message, stack, inner exception — not just the one-line
|
||||
`Script 'X' on instance 'Y' failed: …` summary the `ScriptRun` row carries today.
|
||||
2. **Log lines** — a new `Log` global every script surface exposes (`Log.Debug/Info/Warn/Error(message,
|
||||
exception?)`), plus the warnings the runtime logs on the script's behalf while a helper step runs.
|
||||
|
||||
Rendering: a per-level count badge in the node footer; a failed node's subtitle becomes `ExceptionType:
|
||||
message`; a **Log** tab in the detail panel (exception block first, then the lines, `All | Warn +` filter,
|
||||
copy); run-wide `n errors · n warnings · n info` in the status strip. Live and Replay read the same rows.
|
||||
|
||||
## 2. What exists (verified 2026-09-09)
|
||||
|
||||
- **Scripts cannot log.** `ScriptGlobals` (site) and `InboundScriptContext` (central) expose no `Log`,
|
||||
`Logger` or `ILogger`; the four script imports have no `Console`. `ScriptRuntimeContext._logger` and
|
||||
`_siteEventLogger` are private. So "logger messages" needs a new API surface, not a rewiring.
|
||||
- **The failure row exists but lacks the detail.** `ScriptRunLauncher.RunScriptAsync` emits a Failed
|
||||
`ScriptRun` row on both catch paths (`ScriptRunLauncher.cs:458-506`) with `errorMessage` only;
|
||||
`errorDetail` is never passed (`:588`) although `ScadaBridgeAuditEventFactory.Create` accepts it and the
|
||||
DB helpers already fill it with `ex.ToString()`. `FlowStepProjector.Project` drops `AuditDetails.ErrorDetail`.
|
||||
Centrally, `InboundScriptExecutor.ExecuteAsync` swallows the exception into `"Internal script error"` /
|
||||
`SCRIPT_ERROR` (`InboundScriptExecutor.cs:548-552`) and the runner's inbound row gets that text.
|
||||
- **No execution-id enrichment on node loggers.** Zero `LogContext.PushProperty` calls; `Enrich.FromLogContext`
|
||||
is not configured; the `TraceContextEnricher` stamps W3C ids only. `site_events` has no execution-id column.
|
||||
Capturing what *other* actors log for a run is therefore out of reach without a separate enrichment
|
||||
initiative (§9).
|
||||
- **The plumbing to reuse:** `ScriptRuntimeContext.EmitTrace` (collector first, writer second, same
|
||||
`AuditEvent` both ways); `FlowTraceCollector` (500 events / 1 MB, redacted, `Complete()` at reply time);
|
||||
`RouteHelper.TraceSink` and the runner's central collector; `GetTraceEventsAsync` already returns every
|
||||
`ScriptTrace` row of the tree; `FlowGraphBuilder.Fold` already folds multi-row operations into one step;
|
||||
the Test Run sandbox already has a `ConsoleOutput` pane (`SandboxRunResult.ConsoleOutput`).
|
||||
|
||||
## 3. Decisions
|
||||
|
||||
| # | Decision | Rejected / why |
|
||||
|---|----------|----------------|
|
||||
| D1 | **A log line is an audit row:** new `AuditKind.ScriptLog` in channel `ScriptTrace` (appended last in the enum), one row per line, never a node — `FlowGraphBuilder` folds it into its owning step's new `Logs` list. | A side channel on the reply (`RouteToCallResponse.LogLines`) — Replay would have nothing; a second store to redact/retain/purge. Folding into the `ScriptRun` row's `Extra` (register row 110's sketch) — the 8 KB payload cap on that row would silently drop lines, and helper-step attribution would need every helper to buffer. |
|
||||
| D2 | **Attribution is explicit.** `Extra.stepEventId` names the step; absent, the line belongs to the execution's **anchor** (site: the `ScriptRun` row of that `ExecutionId`; central: the `InboundRequest` row, or the debugger's synthesized `RouteCall` root for a script entry). No anchor and no matching step id → the first step of that execution; no step at all → dropped and counted (`FlowGraph.UnattachedLogLines`, shown in the strip). | Attribution by time window (`OccurredAtUtc` inside a step's `[start, start+duration]`) — step rows record different instants per kind and a 1 ms burst of writes makes it a coin toss. |
|
||||
| D3 | **Exception detail rides `errorDetail`.** Site: `EmitScriptRun` passes `ex.ToString()` on the exception path (timeouts stay detail-less — an `OperationCanceledException` stack is noise). Central: `InboundScriptResult` gains an internal `ErrorDetail` (never returned to the HTTP caller); `FlowDebugRunner` puts it on the inbound row, and the HTTP path stashes it in `HttpContext.Items` for `AuditWriteMiddleware` so a `TraceAllCalls` Replay has it too. `FlowStep` gains `ErrorDetail`. | A separate `ScriptLog` row for the throw — duplicates the failure row and needs an ordering rule against it. |
|
||||
| D4 | **`Log` global on every surface:** `ScriptGlobals.Log` and `InboundScriptContext.Log` at runtime; `ScriptCompileSurface.Log` (`CompileLog`) and `SandboxScriptHost.Log` / `SandboxInboundScriptHost.Log` for parity (the sandbox mirror appends to the Test Run `ConsoleOutput`). Signature `void Debug/Info/Warn/Error(string message, Exception? exception = null)`; synchronous; never throws into the script. `Log` is not on `ScriptTrustPolicy`'s deny list (it is a deny-list over API roots), pinned by a test that `Log.Info(...)` passes the gate and binds on all surfaces. | A `Console.WriteLine` shim — `Console` is not imported today and a stdout metaphor has no level. |
|
||||
| D5 | **Untraced runs pay nothing.** `Log.*` always forwards to the node's `ILogger` (category `ScadaBridge.ScriptLog`, structured `Instance`/`Script`/`ExecutionId`/`Level`) and emits a `ScriptLog` row only when `_isTraced`. No site event. `TraceAllCalls` methods gain lines in Replay at ~1 row per line. | Always auditing lines (volume: timer/value-change scripts run at high rates). A no-op when untraced (authors would lose the messages they wrote). |
|
||||
| D6 | **Runtime lines through one seam.** When traced, `ScriptRuntimeContext` wraps its `_logger` in a `TraceCapturingLogger` that forwards everything and copies **Information and above** into `ScriptLog` rows with `logSource = "runtime"`. Attribution uses an ambient `TraceStepScope` (`AsyncLocal<Guid?>`): the three attribute helpers (`SetAttribute`, `WriteBatchAndWait`, `WaitInternal`) and the sync `ExternalSystem.Call` pre-mint their step's `EventId`, open the scope for their body, and pass the id to `EmitTrace` (new optional `eventId` parameter). Everything else falls back to the anchor (D2). The launcher's own `LogError` for the run's exception is **not** captured as a line — it is already the exception block (D3). | Editing every `_logger.LogWarning` call site to also emit a row. Capturing Debug (internal chatter). |
|
||||
| D7 | **Bounded.** `MaxLogLinesPerRun` (default 200; `SiteRuntimeOptions` + `InboundApiOptions`, validated `> 0`) and a 2 000-char message cap at the API; past the line cap, lines are dropped and one closing runtime `warn` row names the dropped count at run end. Inline, `ScriptLog` rows use `FlowTraceCollector.AddLowPriority`: they stop at `max − 50` events / 75 % of the byte budget so the step rows emitted at run end (the `ScriptRun` anchor is written **last**) are never crowded out; a dropped low-priority row sets `LogsTruncated`, surfaced separately from `Truncated` as *log lines truncated inline — Replay is complete*. | Raising the collector cap (the reply also carries the return value under the 4 MB gRPC limit). |
|
||||
| D8 | **UI rules.** Badge: highest severity first, `✕ n` danger, `! n` warn, `≡ n` faint; hidden when no lines. Failed subtitle: `Type: message` (type without namespace). Detail: **Log (n)** tab after Output; a step with an exception opens on Log, every other step on Input; the Output tab's existing alert stays and links to Log. Strip: `Log: n errors · n warnings · n info` counting lines, not steps. Ordering inside a step: `(OccurredAtUtc, Extra.seq)` — one clock per execution, `seq` breaks same-ms ties. | Drawing lines as nodes (a 40-line script would be unreadable). |
|
||||
| D9 | **Replay and CLI.** `GetTraceEventsAsync` needs no change (channel filter already includes all of `ScriptTrace`). CLI `flow-debug run-*|replay` table gains a `logs` column (count) and `--show-logs` prints lines indented under their step. | — |
|
||||
|
||||
## 4. Trace model (additive)
|
||||
|
||||
`ScriptLog` row: `OccurredAtUtc` = line time; `Status = Delivered`; `Target` = script name (as `ScriptRun`);
|
||||
`RequestSummary` = message; `ErrorMessage` / `ErrorDetail` = the attached exception's message / `ToString()`;
|
||||
`ExecutionId` / `ParentExecutionId` / `SourceSiteId` / `SourceInstanceId` / `SourceNode` as the run's other
|
||||
rows. `ScriptTraceExtra` gains `LogLevel` (`debug|info|warn|error`), `LogSource` (`script|runtime`),
|
||||
`StepEventId` (`Guid?`), `Seq` (`int?`). Redaction (payload caps, header/body regexes) applies unchanged;
|
||||
`AuditLog:PerChannelRetentionDays:ScriptTrace` covers the new kind.
|
||||
|
||||
`FlowStep` gains `ErrorDetail` (`string?`) and `Logs` (`IReadOnlyList<FlowLogLine>?`);
|
||||
`FlowLogLine(EventId, OccurredAtUtc, Level, Source, Message, ExceptionMessage, ExceptionDetail)`.
|
||||
`FlowGraph` gains `LogsTruncated` (`bool`) and `UnattachedLogLines` (`int`). None of this is on the wire.
|
||||
|
||||
**Mixed versions.** An OLD central ingesting `ScriptLog` rows from a NEW site projects them to
|
||||
`FlowStepKind.Unknown` **nodes** (the projector renders unknown kinds rather than dropping them) — the
|
||||
existing rule *upgrade central first* covers it. An old site sends no lines; the page is unchanged.
|
||||
|
||||
## 5. Site runtime
|
||||
|
||||
- `ScriptLogger` (`SiteRuntime/Scripts/`), created by `ScriptRuntimeContext` and exposed as `Log`; holds the
|
||||
context's `EmitTrace` delegate, the `ILogger`, the caps and a per-run counter (`CallShared` shares the
|
||||
context, so inline shared scripts share the counter and the anchor).
|
||||
- `EmitTrace(kind, …, eventId: Guid? = null)`; `TraceStepScope.Current` (`AsyncLocal<Guid?>`) read when
|
||||
building a `ScriptLog` row and no explicit step id is given.
|
||||
- `TraceCapturingLogger : ILogger` — decorator installed only when `_isTraced`; `IsEnabled` delegates to the
|
||||
inner logger OR `level >= Information`, so a node whose Serilog minimum is Warning still captures
|
||||
Information lines into the trace (they are trace data, not node log output).
|
||||
- `ScriptRunLauncher`: pass `errorDetail: ex.ToString()` on the exception path; before `collector?.Complete()`
|
||||
ask the context to flush its "dropped lines" closing row.
|
||||
|
||||
## 6. Central
|
||||
|
||||
- `InboundScriptContext.Log` → `InboundScriptLogger` writing through the executor's existing inline sink
|
||||
(`route.TraceSink`) and `ICentralAuditWriter` when traced (`InboundScriptExecutor.ExecuteAsync(...,
|
||||
trace)` already knows); ILogger always.
|
||||
- `InboundScriptResult` `+ string? ErrorDetail` (positional-last, default null). `FlowDebugRunner` inbound row
|
||||
`errorDetail: result.ErrorDetail`. `EndpointExtensions` (the `executor.ExecuteAsync` call site, `:276`) → `HttpContext.Items[AuditErrorDetailKey]` →
|
||||
`AuditWriteMiddleware` `errorDetail:` (the HTTP body stays `SCRIPT_ERROR`).
|
||||
- `FlowGraphBuilder`: partition `ScriptLog` rows out before `Fold`, attach per D2 after the steps list is
|
||||
final (a folded outbound step's `EventId` is its first row's, so `stepEventId` must be the pre-minted
|
||||
first-row id — only the sync helpers pre-mint in v1, which is exactly the set D6 scopes).
|
||||
|
||||
## 7. Central UI
|
||||
|
||||
`FlowGraphView`: footer becomes a flex row (subtitle + badge); `NodeClass` unchanged; `data-test="flow-node-logs"`.
|
||||
`FlowStepDetail`: `Log` tab (`data-test="flow-step-tab-log"`), exception block (`flow-step-exception`), line
|
||||
table (`flow-step-log-lines`), level filter, copy (JS interop `navigator.clipboard`, loose in bUnit), the
|
||||
cross-step hint ("n more on <step>" selects that step via a new `OnSelectStep` callback).
|
||||
`FlowDebugger`: strip counts, `flow-logs-truncated` badge, `flow-unattached-logs` note; `ApplyOutcome`
|
||||
unchanged (a run with only warning lines is still Completed).
|
||||
|
||||
## 8. Security
|
||||
|
||||
Log messages are script-authored text and pass the same `IAuditRedactor` as every other summary (secrets in
|
||||
a `Log.Info($"token={t}")` are scrubbed by the body regexes where they match, and the 8 KB cap applies).
|
||||
Exception detail can carry connection strings in `ex.Message` for DB helpers — the DB helpers already
|
||||
store `ex.ToString()` in `errorDetail` today, so no new exposure class; the redactor's error-row cap (64 KB)
|
||||
bounds it. Nothing new crosses the PSK boundary: `ScriptLog` rows ride the existing `AuditEventDto`.
|
||||
|
||||
## 9. Out of scope (recorded)
|
||||
|
||||
Live streaming of lines during a long run (rows still arrive with the reply — D4 of the base design);
|
||||
a run-wide chronological log list (belongs to the Direction B list, register row 110); capturing what
|
||||
**other actors** log for a run (instance actor, DCL) — needs `LogContext` enrichment with `ExecutionId` plus
|
||||
`Enrich.FromLogContext()` and an execution-id column on `site_events`; a `Log` sink to the site event log; capturing `Console.Out` on a site run — `System` is imported so
|
||||
`Console.WriteLine` compiles today, and the Test Run sandbox captures it (`SandboxConsoleCapture`), but on a
|
||||
site node `Console.Out` is process-global and shared by every concurrent run, so per-run capture is unsound;
|
||||
`Log.*` is the leveled, per-run replacement and the sandbox mirror writes to the same console pane.
|
||||
|
||||
## 10. Testing
|
||||
|
||||
Pure: `FlowGraphBuilderTests` (attachment by step id, anchor fallback, first-step fallback, unattached count,
|
||||
ordering by seq, folded-step attachment), `FlowStepProjectorTests` (`ErrorDetail`, `ScriptLog` never a node),
|
||||
`FlowTraceCollectorTests` (low-priority reserve, `LogsTruncated`). Site: `ScriptLoggerTests` (levels, caps,
|
||||
closing row, untraced = ILogger only), `TraceCapturingLoggerTests`, `ScriptRuntimeContext` scope attribution,
|
||||
`ScriptRunLauncher` `errorDetail`. Central: executor `ErrorDetail`, runner inbound row, middleware item key,
|
||||
`InboundScriptContext.Log` traced/untraced. Trust: `Log.*` passes the gate and binds on all four surfaces.
|
||||
UI (bUnit): badge, failed subtitle, Log tab default, filter, cross-step hint, strip counts. Rig:
|
||||
`verify-delmia-notifier.sh` step **J** — a seeded `FlowLogDemo` script logs three levels and throws;
|
||||
Live shows the exception on the script node and the lines on their steps; Replay matches.
|
||||
|
||||
## 11. Documents to update
|
||||
|
||||
`Component-CentralUI.md` (Flow Debugger bullet), `Component-SiteRuntime.md` (`Log` global, caps, capturing
|
||||
logger), `Component-InboundAPI.md` (`Log`, `ErrorDetail`), `Component-AuditLog.md` (`ScriptLog` kind),
|
||||
`Component-ScriptAnalysis.md` (compile surface), CLI README (`--show-logs`), `CLAUDE.md` Flow Debugger bullet
|
||||
(v1.4), deferred-work register row 110 (close the console half; keep Direction B), plus a new row for the
|
||||
node-logger enrichment follow-up (§9).
|
||||
@@ -0,0 +1,357 @@
|
||||
<title>Flow Debugger Step Logs</title>
|
||||
<link rel="stylesheet" href="https://fonts.googleapis.com/css2?family=IBM+Plex+Sans:wght@400;500;600&family=IBM+Plex+Mono:wght@400;500&display=swap">
|
||||
<style>
|
||||
:root {
|
||||
--ground: #f4f3ee; --surface: #fbfaf7; --surface-2: #f0efe9;
|
||||
--ink: #1f231f; --ink-soft: #5d625d; --ink-faint: #8a8f89;
|
||||
--rule: #dcdbd3; --rule-strong: #c7c6bd;
|
||||
--accent: #2f5fd0; --active-bg: #eef2fc;
|
||||
--ok: #2e7d4a; --ok-bg: #e4f2e8; --warn: #b8741a; --warn-bg: #fbf0dc; --danger: #b3362d; --danger-bg: #f9e3e0;
|
||||
--sans: "IBM Plex Sans", system-ui, -apple-system, "Segoe UI", sans-serif;
|
||||
--mono: "IBM Plex Mono", ui-monospace, "SF Mono", Menlo, monospace;
|
||||
}
|
||||
@media (prefers-color-scheme: dark) {
|
||||
:root:not([data-theme="light"]) {
|
||||
--ground: #1b1d1b; --surface: #242724; --surface-2: #2c2f2c;
|
||||
--ink: #e8e8e1; --ink-soft: #b3b6b0; --ink-faint: #7f837e;
|
||||
--rule: #383b37; --rule-strong: #4a4e49;
|
||||
--accent: #7f9ff0; --active-bg: #23304d;
|
||||
--ok: #7dcb95; --ok-bg: #1f3a2a; --warn: #e2b264; --warn-bg: #3f3117; --danger: #ee8b82; --danger-bg: #46231f;
|
||||
}
|
||||
}
|
||||
:root[data-theme="dark"] {
|
||||
--ground: #1b1d1b; --surface: #242724; --surface-2: #2c2f2c;
|
||||
--ink: #e8e8e1; --ink-soft: #b3b6b0; --ink-faint: #7f837e;
|
||||
--rule: #383b37; --rule-strong: #4a4e49;
|
||||
--accent: #7f9ff0; --active-bg: #23304d;
|
||||
--ok: #7dcb95; --ok-bg: #1f3a2a; --warn: #e2b264; --warn-bg: #3f3117; --danger: #ee8b82; --danger-bg: #46231f;
|
||||
}
|
||||
|
||||
body { background: var(--ground); color: var(--ink); font-family: var(--sans); font-size: 14px; line-height: 1.45; }
|
||||
.page { max-width: 1180px; margin: 0 auto; padding: 28px 24px 56px; display: flex; flex-direction: column; gap: 26px; }
|
||||
h1 { font-size: 1.45rem; font-weight: 600; margin: 0; letter-spacing: -0.01em; text-wrap: balance; }
|
||||
h2 { font-size: 0.95rem; font-weight: 600; margin: 0 0 8px; }
|
||||
p { margin: 0; max-width: 68ch; }
|
||||
.lede { color: var(--ink-soft); }
|
||||
.eyebrow { font-size: 0.68rem; font-weight: 600; letter-spacing: 0.08em; text-transform: uppercase; color: var(--ink-faint); }
|
||||
.mono { font-family: var(--mono); font-variant-numeric: tabular-nums; }
|
||||
a { color: var(--accent); }
|
||||
code { font-family: var(--mono); font-size: 0.86em; background: var(--surface-2); padding: 0 4px; border-radius: 3px; }
|
||||
|
||||
/* ── the mocked screen ─────────────────────────────────────────────── */
|
||||
.screen { background: var(--surface); border: 1px solid var(--rule); border-radius: 6px; padding: 16px 18px 18px; display: flex; flex-direction: column; gap: 12px; }
|
||||
.toolbar { display: flex; flex-wrap: wrap; gap: 14px 22px; align-items: flex-end; }
|
||||
.field label { display: block; font-size: 0.72rem; color: var(--ink-soft); margin-bottom: 3px; }
|
||||
.seg { display: inline-flex; border: 1px solid var(--rule-strong); border-radius: 4px; overflow: hidden; }
|
||||
.seg span { padding: 4px 10px; font-size: 0.8rem; color: var(--ink-soft); background: var(--surface); }
|
||||
.seg span.on { background: var(--accent); color: #fff; }
|
||||
.select { border: 1px solid var(--rule-strong); border-radius: 4px; padding: 4px 28px 4px 8px; font-size: 0.8rem; background: var(--surface) linear-gradient(45deg, transparent 50%, var(--ink-faint) 50%) no-repeat right 12px top 55% / 6px 6px; min-width: 190px; }
|
||||
.btn { border: 1px solid var(--rule-strong); border-radius: 4px; padding: 4px 12px; font-size: 0.8rem; background: var(--surface); color: var(--ink); }
|
||||
.btn.primary { background: var(--accent); border-color: var(--accent); color: #fff; }
|
||||
.btn.sm { padding: 1px 8px; font-size: 0.74rem; }
|
||||
.spacer { flex: 1; }
|
||||
|
||||
.status { display: flex; flex-wrap: wrap; gap: 6px 18px; align-items: center; padding: 8px 12px; border: 1px solid var(--rule); border-radius: 4px; background: var(--surface-2); font-size: 0.8rem; }
|
||||
.status .k { color: var(--ink-faint); font-size: 0.68rem; letter-spacing: 0.06em; text-transform: uppercase; margin-right: 6px; }
|
||||
.chip { border: 1px solid var(--ok); color: var(--ok); border-radius: 999px; padding: 1px 10px; font-size: 0.76rem; font-weight: 500; }
|
||||
.chip.failed { border-color: var(--danger); color: var(--danger); }
|
||||
.new { outline: 2px dashed var(--accent); outline-offset: 3px; border-radius: 3px; }
|
||||
.cnt.err { color: var(--danger); font-weight: 600; }
|
||||
.cnt.warn { color: var(--warn); font-weight: 600; }
|
||||
|
||||
.flow-wrap { border: 1px solid var(--rule); border-radius: 4px; background: var(--surface); overflow-x: auto; }
|
||||
svg.fg { display: block; width: 1500px; height: 456px; font-family: var(--sans); }
|
||||
.lane-bg.alt { fill: var(--rule); fill-opacity: .25; } .lane-bg { fill: transparent; }
|
||||
.lane-rule { stroke: var(--rule); stroke-width: 1; }
|
||||
.lane-label { fill: var(--ink-soft); font-size: 11px; font-weight: 600; letter-spacing: .05em; text-transform: uppercase; }
|
||||
.lane-sub { fill: var(--ink-faint); font-size: 10.5px; font-family: var(--mono); }
|
||||
.fg-node { cursor: pointer; }
|
||||
.fg-node rect { fill: var(--surface); stroke: var(--rule-strong); stroke-width: 1; }
|
||||
.fg-node.selected rect { stroke: var(--accent); stroke-width: 2; fill: var(--active-bg); }
|
||||
.fg-node.failed rect { stroke: var(--danger); }
|
||||
.fg-node.failed .eb { color: var(--danger); }
|
||||
.body { box-sizing: border-box; width: 100%; height: 100%; padding: 6px 8px 5px; display: flex; flex-direction: column; gap: 1px; overflow: hidden; line-height: 1.2; color: var(--ink); font-family: var(--sans); }
|
||||
.head { display: flex; justify-content: space-between; align-items: baseline; gap: 6px; }
|
||||
.eb { color: var(--ink-faint); font-size: 9.5px; font-weight: 600; letter-spacing: .06em; text-transform: uppercase; white-space: nowrap; overflow: hidden; text-overflow: ellipsis; }
|
||||
.dur { color: var(--ink-soft); font-size: 9.5px; font-family: var(--mono); white-space: nowrap; }
|
||||
.title { font-size: 12px; font-weight: 600; overflow-wrap: anywhere; display: -webkit-box; -webkit-line-clamp: 2; -webkit-box-orient: vertical; overflow: hidden; }
|
||||
.sub { color: var(--ink-soft); font-size: 10.5px; margin-top: auto; white-space: nowrap; overflow: hidden; text-overflow: ellipsis; }
|
||||
.sub.exc { color: var(--danger); font-family: var(--mono); }
|
||||
.foot { margin-top: auto; display: flex; align-items: center; justify-content: space-between; gap: 4px; min-width: 0; }
|
||||
.foot .sub { margin-top: 0; flex: 1; }
|
||||
/* the new log badge: highest severity first, counts per level, tabular */
|
||||
.lg { display: inline-flex; gap: 3px; flex-shrink: 0; font-family: var(--mono); font-size: 9.5px; font-variant-numeric: tabular-nums; }
|
||||
.lg i { font-style: normal; display: inline-flex; align-items: center; gap: 2px; padding: 0 4px; border-radius: 3px; line-height: 1.35; }
|
||||
.lg .e { color: var(--danger); background: var(--danger-bg); }
|
||||
.lg .w { color: var(--warn); background: var(--warn-bg); }
|
||||
.lg .i { color: var(--ink-faint); background: var(--surface-2); }
|
||||
.pill { align-self: flex-start; display: inline-flex; align-items: center; gap: 5px; font-size: 10px; font-weight: 500; padding: 1px 7px; border-radius: 999px; white-space: nowrap; }
|
||||
.pill::before { content: ""; width: 6px; height: 6px; border-radius: 50%; background: currentColor; }
|
||||
.pill.ok { color: var(--ok); background: var(--ok-bg); }
|
||||
.mode { color: var(--ink-soft); font-size: 10.5px; }
|
||||
|
||||
.edge { fill: none; stroke: var(--ink-faint); stroke-width: 1.5; }
|
||||
.edge.accent { stroke: var(--accent); }
|
||||
.edge.dashed { stroke-dasharray: 4 3; }
|
||||
.arrow { fill: var(--ink-faint); } .arrow.accent { fill: var(--accent); }
|
||||
|
||||
/* detail panel */
|
||||
.detail { border: 1px solid var(--rule); border-radius: 4px; background: var(--surface); padding: 12px 14px 14px; display: flex; flex-direction: column; gap: 10px; }
|
||||
.dhead { display: flex; justify-content: space-between; align-items: flex-start; gap: 12px; flex-wrap: wrap; }
|
||||
.dhead h3 { margin: 2px 0 0; font-size: 1rem; font-weight: 600; }
|
||||
.dhead .subl { font-size: 0.78rem; color: var(--ink-soft); }
|
||||
.badge { font-size: 0.72rem; font-weight: 600; padding: 2px 8px; border-radius: 3px; background: var(--danger); color: #fff; }
|
||||
.cols { display: grid; grid-template-columns: minmax(0, 2fr) minmax(220px, 1fr); gap: 18px; }
|
||||
@media (max-width: 760px) { .cols { grid-template-columns: 1fr; } }
|
||||
.tabs { display: flex; gap: 2px; border-bottom: 1px solid var(--rule); }
|
||||
.tabs span { padding: 5px 11px; font-size: 0.8rem; color: var(--ink-soft); border: 1px solid transparent; border-bottom: none; border-radius: 4px 4px 0 0; margin-bottom: -1px; }
|
||||
.tabs span.on { color: var(--ink); background: var(--surface); border-color: var(--rule); border-bottom-color: var(--surface); font-weight: 500; }
|
||||
.tabs .n { color: var(--ink-faint); margin-left: 4px; font-family: var(--mono); font-size: 0.72rem; }
|
||||
.pane { padding: 12px 2px 0; display: flex; flex-direction: column; gap: 10px; }
|
||||
.exc { border: 1px solid var(--danger); border-left-width: 4px; border-radius: 4px; background: var(--danger-bg); padding: 8px 12px; display: flex; flex-direction: column; gap: 4px; }
|
||||
.exc .t { font-family: var(--mono); font-size: 0.8rem; font-weight: 600; color: var(--danger); }
|
||||
.exc .m { font-size: 0.86rem; }
|
||||
.exc pre { margin: 6px 0 0; font-family: var(--mono); font-size: 0.72rem; line-height: 1.45; color: var(--ink-soft); white-space: pre; overflow-x: auto; }
|
||||
.exc .row { display: flex; gap: 10px; align-items: center; margin-top: 4px; }
|
||||
.exc .row .btn { background: var(--surface); }
|
||||
.logctl { display: flex; align-items: center; gap: 12px; font-size: 0.76rem; color: var(--ink-soft); }
|
||||
.logctl .seg span { padding: 2px 8px; font-size: 0.74rem; }
|
||||
table.log { width: 100%; border-collapse: collapse; font-size: 0.8rem; }
|
||||
table.log th { text-align: left; font-size: 0.66rem; letter-spacing: .06em; text-transform: uppercase; color: var(--ink-faint); font-weight: 600; padding: 4px 8px 6px; border-bottom: 1px solid var(--rule); }
|
||||
table.log td { padding: 5px 8px; border-bottom: 1px solid var(--rule); vertical-align: top; }
|
||||
table.log tr:last-child td { border-bottom: none; }
|
||||
td.t { font-family: var(--mono); font-size: 0.74rem; color: var(--ink-soft); white-space: nowrap; }
|
||||
td.src { color: var(--ink-faint); font-size: 0.74rem; white-space: nowrap; }
|
||||
.lvl { display: inline-block; min-width: 46px; text-align: center; font-size: 0.66rem; font-weight: 600; letter-spacing: .04em; padding: 1px 6px; border-radius: 3px; }
|
||||
.lvl.info { color: var(--ink-soft); background: var(--surface-2); }
|
||||
.lvl.warn { color: var(--warn); background: var(--warn-bg); }
|
||||
.lvl.error { color: var(--danger); background: var(--danger-bg); }
|
||||
.lvl.debug { color: var(--ink-faint); background: transparent; border: 1px dashed var(--rule-strong); }
|
||||
tr.dim td { color: var(--ink-faint); font-style: italic; }
|
||||
.where dl { display: grid; grid-template-columns: max-content 1fr; gap: 4px 12px; margin: 0; font-size: 0.8rem; }
|
||||
.where dt { color: var(--ink-soft); } .where dd { margin: 0; font-family: var(--mono); font-size: 0.76rem; overflow-wrap: anywhere; }
|
||||
.where .acts { display: flex; flex-wrap: wrap; gap: 6px; margin-top: 10px; }
|
||||
|
||||
/* anatomy + author sections */
|
||||
.grid3 { display: grid; grid-template-columns: repeat(auto-fit, minmax(230px, 1fr)); gap: 16px; }
|
||||
.cap { font-size: 0.78rem; color: var(--ink-soft); margin-top: 8px; max-width: none; }
|
||||
.nodebox { width: 150px; height: 84px; border: 1px solid var(--rule-strong); border-radius: 4px; background: var(--surface); }
|
||||
.nodebox.failed { border-color: var(--danger); }
|
||||
.nodebox.failed .eb { color: var(--danger); }
|
||||
pre.code { margin: 0; background: var(--surface); border: 1px solid var(--rule); border-radius: 4px; padding: 12px 14px; font-family: var(--mono); font-size: 0.76rem; line-height: 1.5; overflow-x: auto; }
|
||||
pre.code .c { color: var(--ink-faint); } pre.code .k { color: var(--accent); } pre.code .s { color: var(--ok); }
|
||||
table.plain { border-collapse: collapse; font-size: 0.8rem; width: 100%; }
|
||||
table.plain th, table.plain td { text-align: left; padding: 6px 10px; border-bottom: 1px solid var(--rule); vertical-align: top; }
|
||||
table.plain th { font-size: 0.66rem; letter-spacing: .06em; text-transform: uppercase; color: var(--ink-faint); }
|
||||
.tbl-wrap { overflow-x: auto; border: 1px solid var(--rule); border-radius: 4px; background: var(--surface); }
|
||||
ol.notes { margin: 0; padding-left: 20px; display: flex; flex-direction: column; gap: 8px; max-width: 78ch; }
|
||||
ol.notes li { padding-left: 4px; }
|
||||
ol.notes b { font-weight: 600; }
|
||||
</style>
|
||||
|
||||
<div class="page">
|
||||
<header>
|
||||
<div class="eyebrow">Flow Debugger · v1.4 proposal · 2026-09-09</div>
|
||||
<h1>Exceptions and log lines on the step that produced them</h1>
|
||||
<p class="lede" style="margin-top:6px">A traced run carries every <code>Log.*</code> line a script writes, every warning the runtime logs on the script's behalf, and the full exception a failing step threw. Each lands on its own node: a count badge on the node, a <b>Log</b> tab in the detail panel, and run-wide error and warning counts in the status strip. Live and Replay read the same rows.</p>
|
||||
</header>
|
||||
|
||||
<!-- ───────────────────────────── the screen ───────────────────────────── -->
|
||||
<section class="screen" aria-label="Flow Debugger after a failed Live run">
|
||||
<div class="toolbar">
|
||||
<div class="field"><label>Entry point</label><div class="seg"><span class="on">Inbound API method</span><span>Site script</span></div></div>
|
||||
<div class="field"><label>Method</label><div class="select">DelmiaRecipeDownload</div></div>
|
||||
<div class="field"><label>Mode</label><div class="seg"><span class="on">Live</span><span>Replay</span></div></div>
|
||||
<div class="spacer"></div>
|
||||
<span class="btn">Edit inputs</span><span class="btn primary">Run</span>
|
||||
</div>
|
||||
|
||||
<div class="status">
|
||||
<span class="chip failed">Failed</span>
|
||||
<span><span class="k">Run</span><span class="mono">#7</span></span>
|
||||
<span><span class="k">Started</span><span class="mono">14:02:11.198Z</span></span>
|
||||
<span><span class="k">Total</span><span class="mono">1 842 ms</span></span>
|
||||
<span><span class="k">Steps</span><span class="mono">8</span></span>
|
||||
<span><span class="k">Boundaries</span><span class="mono">2</span></span>
|
||||
<span><span class="k">Writes</span><span class="mono">2</span></span>
|
||||
<span class="new"><span class="k">Log</span><span class="mono"><span class="cnt err">1 error</span> · <span class="cnt warn">2 warnings</span> · 4 info</span></span>
|
||||
<span class="btn sm">Refresh outcomes</span>
|
||||
<span><span class="k">Root</span><a class="mono" href="#">7c1e0f2a-…-9b41</a></span>
|
||||
</div>
|
||||
|
||||
<div class="flow-wrap">
|
||||
<svg class="fg" viewBox="0 0 1500 456" role="img" aria-label="Swimlane: request, failed route call, failed site script with log badge, two writes, a satisfied wait, a database call, and a 500 response">
|
||||
<defs>
|
||||
<marker id="ar" viewBox="0 0 10 10" refX="9" refY="5" markerWidth="8" markerHeight="8" orient="auto-start-reverse"><path d="M0 0L10 5L0 10z" class="arrow"/></marker>
|
||||
<marker id="ar-a" viewBox="0 0 10 10" refX="9" refY="5" markerWidth="8" markerHeight="8" orient="auto-start-reverse"><path d="M0 0L10 5L0 10z" class="arrow accent"/></marker>
|
||||
</defs>
|
||||
<!-- lanes -->
|
||||
<rect x="0" y="0" width="1500" height="110" class="lane-bg"/>
|
||||
<rect x="0" y="110" width="1500" height="110" class="lane-bg alt"/>
|
||||
<rect x="0" y="220" width="1500" height="110" class="lane-bg"/>
|
||||
<rect x="0" y="330" width="1500" height="110" class="lane-bg alt"/>
|
||||
<line x1="0" y1="110" x2="1500" y2="110" class="lane-rule"/><line x1="0" y1="220" x2="1500" y2="220" class="lane-rule"/><line x1="0" y1="330" x2="1500" y2="330" class="lane-rule"/>
|
||||
<text x="12" y="24" class="lane-label">Central</text><text x="12" y="40" class="lane-sub">central-a</text>
|
||||
<text x="12" y="134" class="lane-label">Site</text><text x="12" y="150" class="lane-sub">site-a · DelmiaSim01</text>
|
||||
<text x="12" y="244" class="lane-label">Tags</text><text x="12" y="260" class="lane-sub">DelmiaReceiver.*</text>
|
||||
<text x="12" y="354" class="lane-label">External</text><text x="12" y="370" class="lane-sub">MesAudit</text>
|
||||
|
||||
<!-- edges (columns at x = 140 + 170·n, node 150×84, lane centre y = lane·110 + 55) -->
|
||||
<path d="M290 55 H310" class="edge accent" marker-end="url(#ar-a)"/>
|
||||
<path d="M460 55 H470 V165 H480" class="edge accent" marker-end="url(#ar-a)"/>
|
||||
<path d="M630 165 H640 V275 H650" class="edge" marker-end="url(#ar)"/>
|
||||
<path d="M800 275 H820" class="edge" marker-end="url(#ar)"/>
|
||||
<path d="M970 275 H980 V165 H990" class="edge" marker-end="url(#ar)"/>
|
||||
<path d="M895 233 V190 H990" class="edge dashed" marker-end="url(#ar)"/>
|
||||
<path d="M1140 165 H1150 V385 H1160" class="edge" marker-end="url(#ar)"/>
|
||||
<path d="M460 55 H1330" class="edge accent" marker-end="url(#ar-a)"/>
|
||||
|
||||
<!-- nodes -->
|
||||
<g class="fg-node" transform="translate(140 13)"><rect width="150" height="84" rx="4"/><foreignObject width="150" height="84"><div xmlns="http://www.w3.org/1999/xhtml" class="body"><div class="head"><span class="eb">Inbound</span><span class="dur">1 842 ms</span></div><div class="title">DelmiaRecipeDownload</div><div class="foot"><span class="sub">flow-debugger · jdoherty</span><span class="lg"><i class="i">≡ 1</i></span></div></div></foreignObject></g>
|
||||
|
||||
<g class="fg-node failed" transform="translate(310 13)"><rect width="150" height="84" rx="4"/><foreignObject width="150" height="84"><div xmlns="http://www.w3.org/1999/xhtml" class="body"><div class="head"><span class="eb">Route call</span><span class="dur">1 790 ms</span></div><div class="title">DelmiaSim01.ProcessRecipeDownload</div><div class="foot"><span class="sub exc">Script failed at site</span></div></div></foreignObject></g>
|
||||
|
||||
<g class="fg-node failed selected" transform="translate(480 123)"><rect width="150" height="84" rx="4"/><foreignObject width="150" height="84"><div xmlns="http://www.w3.org/1999/xhtml" class="body"><div class="head"><span class="eb">Script run</span><span class="dur">1 731 ms</span></div><div class="title">ProcessRecipeDownload</div><div class="foot"><span class="sub exc">InvalidOperationException: Recipe 42 rejected by Galaxy (code 7)</span><span class="lg"><i class="e">✕ 1</i><i class="w">! 1</i><i class="i">≡ 2</i></span></div></div></foreignObject></g>
|
||||
|
||||
<g class="fg-node" transform="translate(650 233)"><rect width="150" height="84" rx="4"/><foreignObject width="150" height="84"><div xmlns="http://www.w3.org/1999/xhtml" class="body"><div class="head"><span class="eb">Write</span><span class="dur">12 ms</span></div><div class="title">RecipeId, RecipeName</div><div class="foot"><span class="sub">RecipeId = 42, RecipeName = …</span><span class="lg"><i class="w">! 1</i></span></div></div></foreignObject></g>
|
||||
|
||||
<g class="fg-node" transform="translate(820 233)"><rect width="150" height="84" rx="4"/><foreignObject width="150" height="84"><div xmlns="http://www.w3.org/1999/xhtml" class="body"><div class="head"><span class="eb">Write</span><span class="dur">9 ms</span></div><div class="title">DownloadRequest</div><div class="foot"><span class="sub">DownloadRequest = true</span></div></div></foreignObject></g>
|
||||
|
||||
<g class="fg-node" transform="translate(990 123)"><rect width="150" height="84" rx="4"/><foreignObject width="150" height="84"><div xmlns="http://www.w3.org/1999/xhtml" class="body"><div class="head"><span class="eb">Wait</span><span class="dur">1 640 ms</span></div><div class="title">RecipeProcessedFlag</div><div class="foot"><span class="sub">satisfied · true</span></div></div></foreignObject></g>
|
||||
|
||||
<g class="fg-node" transform="translate(1160 343)"><rect width="150" height="84" rx="4"/><foreignObject width="150" height="84"><div xmlns="http://www.w3.org/1999/xhtml" class="body"><div class="head"><span class="eb">Database</span><span class="dur">23 ms</span></div><div class="title">MesAudit</div><div class="foot"><span class="pill ok">Ok</span><span class="mode">· write · 1 row</span><span class="lg"><i class="i">≡ 1</i></span></div></div></foreignObject></g>
|
||||
|
||||
<g class="fg-node failed" transform="translate(1330 13)"><rect width="150" height="84" rx="4"/><foreignObject width="150" height="84"><div xmlns="http://www.w3.org/1999/xhtml" class="body"><div class="head"><span class="eb">Response</span><span class="dur"></span></div><div class="title">Response</div><div class="foot"><span class="sub exc">500 · SCRIPT_ERROR</span></div></div></foreignObject></g>
|
||||
</svg>
|
||||
</div>
|
||||
|
||||
<!-- detail panel for the selected (failed) script run -->
|
||||
<div class="detail" aria-label="Step detail: ProcessRecipeDownload, Log tab">
|
||||
<div class="dhead">
|
||||
<div>
|
||||
<div class="eyebrow">Script run · Site</div>
|
||||
<h3>ProcessRecipeDownload</h3>
|
||||
<div class="subl">DelmiaSim01.DelmiaReceiver · call</div>
|
||||
</div>
|
||||
<span class="badge">Failed</span>
|
||||
</div>
|
||||
<div class="cols">
|
||||
<div>
|
||||
<div class="tabs"><span>Input</span><span>Output</span><span class="on new">Log<span class="n">5</span></span><span>Writes</span><span>Timing</span></div>
|
||||
<div class="pane">
|
||||
<div class="exc">
|
||||
<div class="t">System.InvalidOperationException</div>
|
||||
<div class="m">Recipe 42 rejected by Galaxy (code 7)</div>
|
||||
<pre> at Submission#0.<<Initialize>>d__0.MoveNext() in ProcessRecipeDownload:line 41
|
||||
at ZB.MOM.WW.ScadaBridge.SiteRuntime.Scripts.ScriptRunLauncher.RunScriptAsync(…)
|
||||
Inner exception: none</pre>
|
||||
<div class="row"><span class="btn sm">Copy</span><span class="btn sm">Open in Audit Log</span><span style="font-size:.74rem;color:var(--ink-soft)">Thrown by the script body · site-a / node-a</span></div>
|
||||
</div>
|
||||
|
||||
<div class="logctl">
|
||||
<div class="seg"><span class="on">All</span><span>Warn +</span></div>
|
||||
<span>5 lines on this step · <a href="#">1 more on Write RecipeId, RecipeName</a></span>
|
||||
<span class="spacer"></span>
|
||||
<span class="btn sm">Copy lines</span>
|
||||
</div>
|
||||
<table class="log">
|
||||
<thead><tr><th>Time (UTC)</th><th>Level</th><th>Source</th><th>Message</th></tr></thead>
|
||||
<tbody>
|
||||
<tr><td class="t">14:02:11.204</td><td><span class="lvl info">info</span></td><td class="src">script</td><td>Recipe 42 requested for line L3 by flow-debugger</td></tr>
|
||||
<tr><td class="t">14:02:11.206</td><td><span class="lvl debug">debug</span></td><td class="src">script</td><td>Writing header attributes then DownloadRequest</td></tr>
|
||||
<tr><td class="t">14:02:12.861</td><td><span class="lvl info">info</span></td><td class="src">script</td><td>Galaxy answered: RecipeProcessedFlag = true, ResultCode = 7</td></tr>
|
||||
<tr><td class="t">14:02:12.862</td><td><span class="lvl warn">warn</span></td><td class="src">script</td><td>ResultCode 7 is outside the accepted set {0, 1}</td></tr>
|
||||
<tr><td class="t">14:02:12.870</td><td><span class="lvl error">error</span></td><td class="src">script</td><td>Rejecting recipe 42 (code 7) — see exception above</td></tr>
|
||||
<tr class="dim"><td class="t">14:02:12.929</td><td><span class="lvl warn">warn</span></td><td class="src">runtime</td><td>Log truncated inline: 0 lines dropped (shown only when the per-run cap is hit)</td></tr>
|
||||
</tbody>
|
||||
</table>
|
||||
</div>
|
||||
</div>
|
||||
<div class="where">
|
||||
<div class="eyebrow" style="margin-bottom:6px">Where this ran</div>
|
||||
<dl>
|
||||
<dt>Site / node</dt><dd>site-a / node-a</dd>
|
||||
<dt>Instance</dt><dd>DelmiaSim01</dd>
|
||||
<dt>Target</dt><dd>DelmiaReceiver.ProcessRecipeDownload</dd>
|
||||
<dt>Trigger</dt><dd>call</dd>
|
||||
<dt>Log lines</dt><dd>5 here · 1 on other steps</dd>
|
||||
</dl>
|
||||
<div class="acts"><span class="btn sm">Open in Debug View</span><span class="btn sm">Audit rows (9)</span></div>
|
||||
</div>
|
||||
</div>
|
||||
</div>
|
||||
</section>
|
||||
|
||||
<!-- ───────────────────────────── node anatomy ─────────────────────────── -->
|
||||
<section>
|
||||
<h2>Node anatomy</h2>
|
||||
<p class="lede" style="margin-bottom:12px">Nothing moves on a node that has no log lines. A node with lines gains a count badge in the footer, highest severity first; a failed node swaps its subtitle for the exception's type and message.</p>
|
||||
<div class="grid3">
|
||||
<div>
|
||||
<div class="nodebox"><div class="body"><div class="head"><span class="eb">Inbound</span><span class="dur">1 842 ms</span></div><div class="title">DelmiaRecipeDownload</div><div class="foot"><span class="sub">flow-debugger · jdoherty</span><span class="lg"><i class="i">≡ 1</i></span></div></div></div>
|
||||
<div class="cap"><b>Info only.</b> A faint <span class="mono">≡ n</span> badge. Debug lines count here too; the tab's <i>Warn +</i> filter hides them.</div>
|
||||
</div>
|
||||
<div>
|
||||
<div class="nodebox"><div class="body"><div class="head"><span class="eb">Write</span><span class="dur">12 ms</span></div><div class="title">RecipeId, RecipeName</div><div class="foot"><span class="sub">RecipeId = 42, RecipeName = …</span><span class="lg"><i class="w">! 1</i></span></div></div></div>
|
||||
<div class="cap"><b>Runtime warning on a step.</b> The write helper's own log line ("acked with quality Uncertain") lands on the write node, not on the script run, because the helper was inside its step scope when it logged.</div>
|
||||
</div>
|
||||
<div>
|
||||
<div class="nodebox failed"><div class="body"><div class="head"><span class="eb">Script run</span><span class="dur">1 731 ms</span></div><div class="title">ProcessRecipeDownload</div><div class="foot"><span class="sub exc">InvalidOperationException: Recipe 42 rejected …</span><span class="lg"><i class="e">✕ 1</i><i class="w">! 1</i><i class="i">≡ 2</i></span></div></div></div>
|
||||
<div class="cap"><b>Failed with an exception.</b> Red stroke and eyebrow as today; the subtitle becomes <span class="mono">Type: message</span>. Selecting it opens the Log tab first.</div>
|
||||
</div>
|
||||
</div>
|
||||
</section>
|
||||
|
||||
<!-- ───────────────────────────── the author's side ────────────────────── -->
|
||||
<section>
|
||||
<h2>What the script author writes</h2>
|
||||
<p class="lede" style="margin-bottom:12px">One new global, <code>Log</code>, on every script surface (site scripts, shared scripts, inbound API methods, the Test Run editor). Always forwards to the node's logger; becomes a trace row only when the run is traced, so untraced production runs add no audit volume.</p>
|
||||
<pre class="code"><span class="c">// ProcessRecipeDownload — site Call script (excerpt)</span>
|
||||
<span class="k">var</span> recipeId = Parameters.Get<<span class="k">int</span>>(<span class="s">"RecipeId"</span>);
|
||||
Log.Info(<span class="s">$"Recipe {recipeId} requested for line {Parameters.Get<string>("Line")} by {Parameters.Get<string>("Requester")}"</span>);
|
||||
Log.Debug(<span class="s">"Writing header attributes then DownloadRequest"</span>);
|
||||
|
||||
<span class="k">await</span> Children[<span class="s">"DelmiaReceiver"</span>].SetAsync(<span class="s">"RecipeId"</span>, recipeId);
|
||||
<span class="c">// … writes, wait …</span>
|
||||
|
||||
<span class="k">var</span> code = <span class="k">await</span> Children[<span class="s">"DelmiaReceiver"</span>].GetAsync<<span class="k">int</span>>(<span class="s">"ResultCode"</span>);
|
||||
Log.Info(<span class="s">$"Galaxy answered: RecipeProcessedFlag = true, ResultCode = {code}"</span>);
|
||||
<span class="k">if</span> (code <span class="k">is not</span> (0 <span class="k">or</span> 1))
|
||||
{
|
||||
Log.Warn(<span class="s">$"ResultCode {code} is outside the accepted set {{0, 1}}"</span>);
|
||||
Log.Error(<span class="s">$"Rejecting recipe {recipeId} (code {code})"</span>);
|
||||
<span class="k">throw new</span> InvalidOperationException(<span class="s">$"Recipe {recipeId} rejected by Galaxy (code {code})"</span>);
|
||||
}
|
||||
Log.Warn(<span class="s">"Recoverable problem"</span>, caughtException); <span class="c">// an exception on a line renders as an expandable chip</span></pre>
|
||||
</section>
|
||||
|
||||
<section>
|
||||
<h2>Where a line lands</h2>
|
||||
<div class="tbl-wrap">
|
||||
<table class="plain">
|
||||
<thead><tr><th>Produced by</th><th>Source</th><th>Lands on</th><th>How</th></tr></thead>
|
||||
<tbody>
|
||||
<tr><td><code>Log.*</code> in a site script (incl. inline shared scripts)</td><td>script</td><td>That execution's <b>Script run</b> node</td><td>One <code>ScriptTrace.ScriptLog</code> row per line, keyed by the run's <code>ExecutionId</code>; no step id</td></tr>
|
||||
<tr><td><code>Log.*</code> in an inbound API method script</td><td>script</td><td>The <b>Inbound</b> node (or the debugger's route-call root for a script entry)</td><td>Same row, written centrally with the inbound <code>ExecutionId</code>; inline on a Live run through the runner's collector</td></tr>
|
||||
<tr><td>The runtime's own warnings while a helper step runs (write, wait, sync API call)</td><td>runtime</td><td>That <b>step's</b> node</td><td>The helper pre-mints its step's event id and holds it in an ambient scope; the context's logger copies Information + lines into a row stamped <code>stepEventId</code></td></tr>
|
||||
<tr><td>Runtime warnings outside any helper step</td><td>runtime</td><td>The <b>Script run</b> node</td><td>No scope active → falls back to the execution anchor</td></tr>
|
||||
<tr><td>The exception that failed a script run</td><td>—</td><td>The <b>Script run</b> node's exception block</td><td>Not a log row: <code>ScriptRun.errorDetail</code> now carries <code>ex.ToString()</code> (type, message, stack, inner); the inbound row gets the same for a central method failure</td></tr>
|
||||
<tr><td>Log lines from other actors on the node (instance actor, DCL)</td><td>—</td><td>Not captured in v1</td><td>No execution-id enrichment exists on the node loggers; recorded as the follow-up, not attempted here</td></tr>
|
||||
</tbody>
|
||||
</table>
|
||||
</div>
|
||||
</section>
|
||||
|
||||
<section>
|
||||
<h2>Decision notes</h2>
|
||||
<ol class="notes">
|
||||
<li><b>Lines are audit rows, not a side channel.</b> A new <code>ScriptLog</code> kind in the existing <code>ScriptTrace</code> channel rides the collector for Live and the audit store for Replay, with redaction, retention and the site 7-day purge applying unchanged. The graph builder folds them into their owning step; they are never drawn as nodes.</li>
|
||||
<li><b>Untraced runs pay nothing.</b> <code>Log.*</code> always writes to the node's ILogger at the given level (so it shows in Serilog and the site log as usual) and emits a row only when the run is traced. <code>TraceAllCalls</code> methods therefore gain lines in Replay at ~1 row per line.</li>
|
||||
<li><b>Bounded by design.</b> A per-run cap (200 lines, configurable) and a 2 000-character message cap sit at the API; past the cap lines are dropped and one closing runtime warning names the count. Inline, log rows are low-priority in the collector: they stop 50 events short of the 500 cap so the step rows emitted at run end are never crowded out, and the page shows <i>log lines truncated inline — Replay is complete</i> when that happens.</li>
|
||||
<li><b>Attribution is explicit, never inferred from time.</b> A row carries <code>stepEventId</code> or it belongs to the execution's anchor step. Steps whose row is written later by another actor (cached calls, notifications) keep the fallback.</li>
|
||||
<li><b>Exceptions stay where they are already recorded.</b> The failure row exists on every path today; it only lacked the detail. Adding <code>errorDetail</code> costs one argument on the site and one internal field centrally; the HTTP caller still receives the safe <code>SCRIPT_ERROR</code> body.</li>
|
||||
<li><b>Selecting a failed node opens the Log tab.</b> Every other node keeps Input as its first tab; the Output tab's red alert stays and links across.</li>
|
||||
<li><b>Not in this slice:</b> live streaming of lines during a long run (Live rows still arrive with the reply), a run-wide chronological log view (the register's Direction B list would host it), and node-logger enrichment by execution id.</li>
|
||||
</ol>
|
||||
</section>
|
||||
</div>
|
||||
@@ -0,0 +1,528 @@
|
||||
# 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.
|
||||
|
||||
**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**
|
||||
|
||||
```csharp
|
||||
[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):
|
||||
```csharp
|
||||
/// <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`:
|
||||
```csharp
|
||||
/// <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`:
|
||||
```csharp
|
||||
/// <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:
|
||||
```csharp
|
||||
/// <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**
|
||||
```csharp
|
||||
[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
|
||||
```csharp
|
||||
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)
|
||||
```csharp
|
||||
[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:
|
||||
```csharp
|
||||
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`:
|
||||
|
||||
```csharp
|
||||
/// <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`:
|
||||
```csharp
|
||||
/// <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:
|
||||
```csharp
|
||||
/// <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`:
|
||||
```csharp
|
||||
/// <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.
|
||||
@@ -0,0 +1,128 @@
|
||||
{
|
||||
"planPath": "docs/plans/2026-09-09-flow-debugger-step-logs.md",
|
||||
"tasks": [
|
||||
{
|
||||
"id": 1,
|
||||
"subject": "Task 1: Commons \u2014 ScriptLog kind, trace extra fields, FlowStep.ErrorDetail/Logs",
|
||||
"status": "pending"
|
||||
},
|
||||
{
|
||||
"id": 2,
|
||||
"subject": "Task 2: Commons \u2014 FlowTraceCollector.AddLowPriority + LogsTruncated",
|
||||
"status": "pending"
|
||||
},
|
||||
{
|
||||
"id": 3,
|
||||
"subject": "Task 3: Commons \u2014 FlowGraphBuilder attaches log lines to steps",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
1
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 4,
|
||||
"subject": "Task 4: SiteRuntime \u2014 ScriptLogger, TraceStepScope, TraceCapturingLogger",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
1
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 5,
|
||||
"subject": "Task 5: SiteRuntime \u2014 wire Log into ScriptRuntimeContext + ScriptGlobals",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
1,
|
||||
2,
|
||||
4
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 6,
|
||||
"subject": "Task 6: SiteRuntime \u2014 launcher errorDetail, dropped-lines flush, MaxLogLinesPerRun",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
5
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 7,
|
||||
"subject": "Task 7: Script surfaces \u2014 ScriptCompileSurface.Log, sandbox mirrors, trust pin",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
5
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 8,
|
||||
"subject": "Task 8: InboundAPI \u2014 InboundScriptContext.Log + MaxLogLinesPerRun",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
1
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 9,
|
||||
"subject": "Task 9: InboundAPI \u2014 exception detail on the inbound row",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
8
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 10,
|
||||
"subject": "Task 10: ManagementService \u2014 runner inbound row ErrorDetail; LogsTruncated on results",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
9
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 11,
|
||||
"subject": "Task 11: CentralUI \u2014 FlowGraphView log badge + failed-node exception subtitle",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
1
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 12,
|
||||
"subject": "Task 12: CentralUI \u2014 FlowStepDetail Log tab",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
1
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 13,
|
||||
"subject": "Task 13: CentralUI \u2014 Flow Debugger page strip counts, truncation notes, selection hookup",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
3,
|
||||
10,
|
||||
11,
|
||||
12
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 14,
|
||||
"subject": "Task 14: CLI \u2014 logs column and --show-logs",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
3
|
||||
]
|
||||
},
|
||||
{
|
||||
"id": 15,
|
||||
"subject": "Task 15: Specs, register, rig demo + verification step J, full build",
|
||||
"status": "pending",
|
||||
"blockedBy": [
|
||||
6,
|
||||
7,
|
||||
13,
|
||||
14
|
||||
]
|
||||
}
|
||||
],
|
||||
"lastUpdated": "2026-09-09T15:20:12.803167+00:00"
|
||||
}
|
||||
Reference in New Issue
Block a user