Merge wt/step-logs-t15: Task 15 specs, register, FlowLogDemo seed + step J
This commit is contained in:
Joseph Doherty
+2
-1
@@ -100,7 +100,8 @@ docker/
|
||||
├── seed-delmia-sim.sh # Seed the in-memory Delmia machine stand-in (DelmiaSim01) on site-a
|
||||
├── seed-delmia-api.sh # Seed the DelmiaRecipeDownload inbound method + a scoped API key (token printed once)
|
||||
├── seed-flow-outbound-demo.sh # Seed the Flow Debugger outbound-calls demo: RigRest external system, RigDb connection, FlowDemo list, OutboundDemo script + FlowOutboundDemo method/key
|
||||
├── verify-delmia-notifier.sh # DelmiaNotifier end-to-end vs the rig: standby relay, active-central crash/takeover, rejoin; step H = Flow Debugger live run + replay (CLI flow-debug); step I = outbound API/DB/notify nodes live + replay
|
||||
├── seed-flow-log-demo.sh # Seed the Flow Debugger STEP-LOGS demo: FlowLogDemo Call script on SimMachine (logs info/debug/warn, writes an attribute, then throws) — idempotent
|
||||
├── verify-delmia-notifier.sh # DelmiaNotifier end-to-end vs the rig: standby relay, active-central crash/takeover, rejoin; step H = Flow Debugger live run + replay (CLI flow-debug); step I = outbound API/DB/notify nodes live + replay; step J = step logs + exception detail live + replay
|
||||
├── teardown.sh # Stop and remove containers
|
||||
├── central-node-a/
|
||||
│ ├── appsettings.Central.json # Central node A configuration
|
||||
|
||||
Executable
+83
@@ -0,0 +1,83 @@
|
||||
#!/bin/bash
|
||||
set -euo pipefail
|
||||
|
||||
# Seed the Flow Debugger STEP-LOGS demo on the docker rig (plan
|
||||
# docs/plans/2026-09-09-flow-debugger-step-logs.md, Task 15): one site Call script that writes a
|
||||
# line at three levels, writes a static attribute, warns, and then throws — so a traced run shows
|
||||
# BOTH halves of the step-logs feature on one graph:
|
||||
#
|
||||
# * the ScriptRun node ends Failed and carries the whole exception (errorDetail = ex.ToString()),
|
||||
# rendered as a red `InvalidOperationException: demo failure` subtitle plus the Log tab's
|
||||
# exception block;
|
||||
# * the info / debug / warn lines fold onto their owning step as ScriptTrace/ScriptLog rows —
|
||||
# the badge reads `✕ 0 ! 1 ≡ 2`-style counts, never separate nodes.
|
||||
#
|
||||
# What it creates:
|
||||
# - Script FlowLogDemo (Call, no parameters) on template SimMachine (docker/seed-delmia-sim.sh),
|
||||
# then redeploys DelmiaSim01 so the site actually has it.
|
||||
#
|
||||
# IDEMPOTENT: re-running UPDATES the script in place (template script update) instead of failing on
|
||||
# the unique name, so this is the script to re-run after a rig rebuild.
|
||||
#
|
||||
# Prerequisites: bash docker/deploy.sh; docker/seed-sites.sh; docker/seed-delmia-sim.sh.
|
||||
#
|
||||
# Try:
|
||||
# scadabridge --url http://localhost:9000 --username multi-role --password password \
|
||||
# flow-debug run-script --instance-id <id> --script FlowLogDemo --show-logs
|
||||
# then open /deployment/flow-debugger?executionId=<rootExecutionId>
|
||||
# Covered by docker/verify-delmia-notifier.sh step J.
|
||||
|
||||
SCRIPT_DIR="$(cd "$(dirname "$0")" && pwd)"
|
||||
PROJECT_ROOT="$(cd "$SCRIPT_DIR/.." && pwd)"
|
||||
CLI="$PROJECT_ROOT/src/ZB.MOM.WW.ScadaBridge.CLI/bin/Debug/net10.0/scadabridge"
|
||||
A=(--url "${SCADABRIDGE_URL:-http://localhost:9000}" --format=json --username "${SCADABRIDGE_USERNAME:-multi-role}" --password "${SCADABRIDGE_PASSWORD:-password}")
|
||||
INSTANCE_NAME="${INSTANCE_NAME:-DelmiaSim01}"
|
||||
TEMPLATE_NAME="${TEMPLATE_NAME:-SimMachine}"
|
||||
SCRIPT_NAME="${SCRIPT_NAME:-FlowLogDemo}"
|
||||
# A static attribute that exists on SimMachine through the composed DelmiaReceiver child, and that
|
||||
# nothing triggers on (RecipeDownloadFlag would fire the simulator script and muddy the graph).
|
||||
WRITE_ATTRIBUTE="${WRITE_ATTRIBUTE:-RecipeProcessResultText}"
|
||||
|
||||
find_id() { # stdin = JSON array, $1 = key, $2 = value
|
||||
python3 -c 'import json,sys; k,v=sys.argv[1],sys.argv[2]; print(next(x["id"] for x in json.load(sys.stdin) if x.get(k)==v))' "$1" "$2"; }
|
||||
|
||||
# The demo body. Log.* is the leveled per-run logging global (design 2026-09-09 D4): every line
|
||||
# always reaches the node ILogger, and becomes a ScriptLog trace row only when the run is traced.
|
||||
read -r -d '' DEMO_CODE <<'CS' || true
|
||||
// Flow Debugger step-logs demo. Three levels, one real static write between them, then a throw:
|
||||
// the lines fold onto the steps that produced them, and the throw gives the ScriptRun node its
|
||||
// exception block. Nothing here is debugger-specific — Log.* is an ordinary script API.
|
||||
Log.Info("FlowLogDemo starting");
|
||||
Log.Debug("about to write");
|
||||
await Children["DelmiaReceiver"].Attributes.SetAsync("RecipeProcessResultText", "42");
|
||||
Log.Warn("demo warning after the write");
|
||||
throw new System.InvalidOperationException("demo failure");
|
||||
CS
|
||||
|
||||
echo "1/3 Locating template $TEMPLATE_NAME..."
|
||||
TEMPLATE_ID=$("$CLI" template list "${A[@]}" | find_id name "$TEMPLATE_NAME")
|
||||
echo " template id=$TEMPLATE_ID"
|
||||
|
||||
echo "2/3 Adding or updating script $SCRIPT_NAME (Call)..."
|
||||
EXISTING_ID=$("$CLI" template get "${A[@]}" --id "$TEMPLATE_ID" | python3 -c '
|
||||
import json, sys
|
||||
t = json.load(sys.stdin)
|
||||
name = sys.argv[1]
|
||||
print(next((s["id"] for s in (t.get("scripts") or []) if s.get("name") == name), ""))' "$SCRIPT_NAME")
|
||||
if [ -n "$EXISTING_ID" ]; then
|
||||
"$CLI" template script update "${A[@]}" --id "$EXISTING_ID" --name "$SCRIPT_NAME" --trigger-type Call --code "$DEMO_CODE" > /dev/null
|
||||
echo " updated script id=$EXISTING_ID"
|
||||
else
|
||||
EXISTING_ID=$("$CLI" template script add "${A[@]}" --template-id "$TEMPLATE_ID" --name "$SCRIPT_NAME" --trigger-type Call --code "$DEMO_CODE" \
|
||||
| python3 -c 'import json,sys; d=json.load(sys.stdin); print(d.get("id",""))')
|
||||
echo " added script id=$EXISTING_ID"
|
||||
fi
|
||||
|
||||
echo "3/3 Redeploying $INSTANCE_NAME so the site has $SCRIPT_NAME..."
|
||||
INSTANCE_ID=$("$CLI" instance list "${A[@]}" | find_id uniqueName "$INSTANCE_NAME")
|
||||
"$CLI" instance deploy "${A[@]}" --id "$INSTANCE_ID" > /dev/null
|
||||
echo " instance id=$INSTANCE_ID"
|
||||
|
||||
echo
|
||||
echo "FLOW_LOG_DEMO_TEMPLATE_ID=$TEMPLATE_ID FLOW_LOG_DEMO_INSTANCE_ID=$INSTANCE_ID SCRIPT=$SCRIPT_NAME (writes $WRITE_ATTRIBUTE)"
|
||||
echo "Try: $CLI --url http://localhost:9000 --username multi-role --password password flow-debug run-script --instance-id $INSTANCE_ID --script $SCRIPT_NAME --show-logs"
|
||||
@@ -5,7 +5,7 @@ set -euo pipefail
|
||||
# crash (docker kill = SIGKILL, so auto-down failover is exercised, not CoordinatedShutdown's
|
||||
# graceful handover) + rejoin. Requires: seed-delmia-sim.sh + seed-delmia-api.sh already run, and
|
||||
# DELMIA_API_KEY exported (the token printed by seed-delmia-api.sh). FLOW_ONLY=1 skips A-G (no
|
||||
# notifier build, no docker kill) and runs the Flow Debugger steps H, H2 and I alone.
|
||||
# docker kill) and runs the Flow Debugger steps H, H2, I and J alone.
|
||||
#
|
||||
# HISTORY (2026-09-02): the first run of this script found that inbound API keys were a PER-NODE
|
||||
# SQLite store, so the key minted through the active node did not exist on the standby and every
|
||||
@@ -41,6 +41,11 @@ set -euo pipefail
|
||||
# DB write Submitted or — DB reachable, immediate-completion path — already Delivered, the
|
||||
# notification Submitted; replay is retried <= 90 s until the write is Delivered and the
|
||||
# notification has a terminal NotifyDeliver row). Skipped with a note when the demo is not seeded.
|
||||
# J Flow Debugger STEP LOGS (2026-09-09) -> YES (FlowLogDemo — seed-flow-log-demo.sh — logs
|
||||
# info/debug/warn, writes a static attribute, then throws: the ScriptRun step comes back Failed with
|
||||
# errorDetail naming InvalidOperationException, and >= 3 ScriptTrace/ScriptLog rows carry levels
|
||||
# {info,debug,warn}. Replay asserts the same from the central audit store. Skipped with a note when
|
||||
# the demo is not seeded.)
|
||||
|
||||
: "${DELMIA_API_KEY:?export DELMIA_API_KEY=sbk_... first}"
|
||||
SCRIPT_DIR="$(cd "$(dirname "$0")" && pwd)"; PROJECT_ROOT="$(cd "$SCRIPT_DIR/.." && pwd)"
|
||||
@@ -81,7 +86,7 @@ for n in a b; do
|
||||
done
|
||||
|
||||
if [ "${FLOW_ONLY:-}" = 1 ]; then
|
||||
echo "== FLOW_ONLY=1: skipping A-G (notifier + failover drill); running the Flow Debugger steps H, H2 and I only"
|
||||
echo "== FLOW_ONLY=1: skipping A-G (notifier + failover drill); running the Flow Debugger steps H, H2, I and J only"
|
||||
else
|
||||
echo "== A baseline (active first)"; write_cfg "$(url_of "$ACT"),$(url_of "$STB")" "$DELMIA_API_KEY"; notify A YES
|
||||
echo "== B standby first (relay)"; write_cfg "$(url_of "$STB"),$(url_of "$ACT")" "$DELMIA_API_KEY"; notify B YES
|
||||
@@ -232,4 +237,69 @@ sys.exit(0 if ok else 1)' "$1"
|
||||
echo " replay: $I_REPLAY"
|
||||
echo "I outbound live+replay -> YES"
|
||||
fi
|
||||
# J — Flow Debugger step logs + exception detail (design 2026-09-09). FlowLogDemo logs at three
|
||||
# levels, writes a static attribute, then throws. Live: the site returns its ScriptRun row (Failed,
|
||||
# errorDetail = the exception's ToString()) and the ScriptLog rows inline on the same reply. Replay:
|
||||
# the same rows are read back from the central AuditLog once the 5 s telemetry push has landed.
|
||||
echo "== J Flow Debugger step logs (live + replay)"
|
||||
J_INSTANCE_ID=$("$CLI" instance list "${H_ARGS[@]}" | python3 -c 'import json,sys; xs=json.load(sys.stdin); print(next((i["id"] for i in xs if i.get("uniqueName")==sys.argv[1]), ""))' "$MACHINE")
|
||||
if [ -z "$J_INSTANCE_ID" ]; then
|
||||
echo "J step logs live+replay -> SKIPPED ($MACHINE not seeded — run docker/seed-delmia-sim.sh)"
|
||||
else
|
||||
j_check() { # $1 = live|replay; stdin = FlowDebugRunResult JSON
|
||||
python3 -c '
|
||||
import json, sys
|
||||
mode = sys.argv[1]
|
||||
r = json.load(sys.stdin)
|
||||
rows = []
|
||||
for e in r.get("events", []):
|
||||
d = json.loads(e["detailsJson"])
|
||||
d["_extra"] = json.loads(d["extra"]) if d.get("extra") else {}
|
||||
rows.append(d)
|
||||
runs = [d for d in rows if d.get("kind") == "ScriptRun"]
|
||||
logs = [d for d in rows if d.get("kind") == "ScriptLog"]
|
||||
levels = sorted({(d["_extra"].get("logLevel") or "?") for d in logs})
|
||||
problems = []
|
||||
if not runs:
|
||||
problems.append("no ScriptRun row")
|
||||
else:
|
||||
failed = [d for d in runs if d.get("status") == "Failed"]
|
||||
if not failed:
|
||||
problems.append("ScriptRun not Failed (" + ",".join(str(d.get("status")) for d in runs) + ")")
|
||||
elif not any("InvalidOperationException" in (d.get("errorDetail") or "") for d in failed):
|
||||
problems.append("no InvalidOperationException in errorDetail")
|
||||
if len(logs) < 3:
|
||||
problems.append("only " + str(len(logs)) + " ScriptLog row(s)")
|
||||
missing = [lv for lv in ("info", "debug", "warn") if lv not in levels]
|
||||
if missing:
|
||||
problems.append("levels missing " + ",".join(missing))
|
||||
ok = not problems
|
||||
print(("YES" if ok else "NO") + " root=" + str(r.get("rootExecutionId")) + " logs=" + str(len(logs))
|
||||
+ " levels=" + ",".join(levels) + " scriptRun=" + ",".join(str(d.get("status")) for d in runs)
|
||||
+ (" problems=" + ";".join(problems) if problems else "") + (" error=" + str(r.get("errorCode")) if r.get("errorCode") else ""))
|
||||
sys.exit(0 if ok else 1)' "$1"
|
||||
}
|
||||
# The script throws by design, so the run reports Completed=false with CALL_FAILED — that is the
|
||||
# expected outcome here, and the CLI still prints the full result. Do not gate on the exit code.
|
||||
set +e; J_RUN=$("$CLI" flow-debug run-script --instance-id "$J_INSTANCE_ID" --script FlowLogDemo "${H_ARGS[@]}"); set -e
|
||||
case "$J_RUN" in
|
||||
*rootExecutionId*) ;;
|
||||
*) echo "J step logs live+replay -> SKIPPED (FlowLogDemo not seeded — run docker/seed-flow-log-demo.sh): $(echo "$J_RUN" | head -2)"; J_RUN=""; ;;
|
||||
esac
|
||||
if [ -n "$J_RUN" ]; then
|
||||
J_LIVE=$(echo "$J_RUN" | j_check live) || { echo "FAIL: live run: $J_LIVE"; exit 1; }
|
||||
echo " live: $J_LIVE"
|
||||
J_ROOT=$(echo "$J_RUN" | python3 -c 'import json,sys; print(json.load(sys.stdin)["rootExecutionId"])')
|
||||
J_REPLAY=""
|
||||
for i in $(seq 1 20); do
|
||||
set +e; J_REPLAY=$("$CLI" flow-debug replay --execution-id "$J_ROOT" "${H_ARGS[@]}" | j_check replay); J_RRC=$?; set -e
|
||||
[ "$J_RRC" -eq 0 ] && break
|
||||
sleep 2
|
||||
done
|
||||
[ "${J_RRC:-1}" -eq 0 ] || { echo "FAIL: replay never showed the logs + exception after 40 s: $J_REPLAY"; exit 1; }
|
||||
echo " replay: $J_REPLAY"
|
||||
echo " root: $J_ROOT (open /deployment/flow-debugger?executionId=$J_ROOT)"
|
||||
echo "J step logs live+replay -> YES"
|
||||
fi
|
||||
fi
|
||||
echo "== done. Notifier log: $RUN_DIR/delmia-notifier.log"
|
||||
|
||||
@@ -102,9 +102,11 @@ All 7 fix-now items landed via PLAN-04/05/06/07/08 (verified in review 08 round
|
||||
| 107 | **Prod `CvdReactor.ProcessRecipeDownload` still addresses `Children["DelmiaRecv"]` after the 2026-06-27 `DelmiaRecv` → `DelmiaReceiver` composition rename** — inferred from the deployed script (`docs/api-specs/Delmia-Recipe-Download-API.md` §7 item 1): `ChildrenAccessor` concatenates the name into a path, an unknown path yields null, so every call answers `Receiver ready flag not set to true` regardless of the real flag. No call has hit prod since the rename, so this is inferred, not observed. The docker rig's stand-in (`docker/seed-delmia-sim.sh`) uses `Children["DelmiaReceiver"]` and the same handshake answers correctly, which is the working reference. | Found 2026-09-02 while capturing the as-deployed spec; QA copy unread (credentials) | Separate change with its own deployment record: `scadabridge template script update` on the `CvdReactor` template + redeploy Z28061/Z28062/Z28061Sim, then a live `WWNotifier` call. | Before the first production Delmia recipe download. |
|
||||
| 108 | ~~**Inbound API keys are a PER-NODE SQLite store — a central failover invalidates every inbound client's key**~~ **RESOLVED 2026-09-02 — `ZB.MOM.WW.Auth` 0.3.0 (new `ZB.MOM.WW.Auth.ApiKeys.SqlServer` package) + ScadaBridge `ScadaBridge:InboundApi:ApiKeyStore:Provider=SqlServer`.** A central pair now shares one row set: both nodes' key stores, admin stores, and audit stores point at the same `zbauth` schema in the configuration database (connection string defaults to `ScadaBridge:Database:ConfigurationDb` — never a `${secret:}` reference, to avoid a circular dependency on the SQL-backed secrets store), so create/revoke/rotate/scope changes are cluster-wide immediately instead of per-node. Each node's existing SQLite file is imported once at boot (insert-where-absent, so both nodes importing is safe and the result is the union) and renamed `*.imported`. `Provider` defaults to `Sqlite` (unchanged behavior for single-node installs, MxAccessGateway, HistorianGateway); a clustered Central left on `Sqlite` now gets a boot-time `StartupValidator` Warning naming this design instead of silently keeping the gap. Both docker rigs (`docker/`, `docker-env2/`) run `Provider=SqlServer` on both centrals; `docker/sync-inbound-api-keys.sh` is deleted, superseded by the shared store. Rig proof 2026-09-03 (`docker/`, both centrals redeployed on `Provider=SqlServer`): both nodes imported their SQLite file at the same second with no PK race — central-a `1 key / 264 audit rows inserted`, central-b `0 / 26 inserted, 1 / 264 already present` (the union), files renamed `*.imported`; a key minted via `:9001` answered `200` via `:9002`, `--enabled false` via `:9001` made both nodes answer `401` and `:9002`'s own list showed `enabled=False`, re-enable via `:9002` restored `200` on `:9001`, delete via `:9002` made `:9001` answer `401`; `verify-delmia-notifier.sh` with a freshly minted key and NO file copy: A/B/E/F `YES`, C/G `NO`, active-central `docker kill` takeover **28 s**, rejoin as standby in 2 s. `docker-env2` (second pair, `ScadaBridgeConfig2`): both centrals booted, `zbauth` v1 created, empty files imported. QA (`vq03`/`vq04`) and prod (`vd03`) still run `Provider=Sqlite` — their move is a planned deployment record (`docs/deployment/deployment-records/2026-09-XX-zb-servers-inbound-key-store.md`), not yet applied. Design: `docs/plans/2026-09-02-inbound-api-key-shared-store-design.md`. Original: | `docs/api-specs/Delmia-Recipe-Download-API.md` §8; `docker/sync-inbound-api-keys.sh` header | Fix is an architecture decision, not a patch: move the store to the shared SQL Server (as Secrets 0.5.0 did for its central store) or replicate the file; either way revocation must become cluster-wide. Needs the `ZB.MOM.WW.Auth.ApiKeys` library (scadaproj), not just this repo. | Before any 2-node central goes live with inbound API clients; before the next arch-review wave. |
|
||||
| 109 | **`ZB.MOM.WW.Secrets.Replicator.SqlServer`'s store migrator retries its DDL with a flat `100 * attempt` backoff and no jitter — a latent concurrent-boot flake, open in Secrets** *(Low)*. Porting that migrator's retry loop verbatim for the Auth 0.3.0 SQL Server API-key store (register row 108) reproduced an intermittent exhaustion — about once in sixty 8-way concurrent-boot trials the five flat-backoff retries ran out before a DDL/lock conflict cleared; adding jitter to the Auth port's backoff took it to 0 failures in 180 trials. Secrets' own migrator has no concurrent-migrate test, so the same defect is presumed still open there — it just hasn't been exercised at 8-way concurrency, and a ScadaBridge central pair is only ever 2-way, so this is unlikely to bite in practice. | Found 2026-09-02 while implementing `docs/plans/2026-09-02-inbound-api-key-shared-store.md` (Auth 0.3.0 `SqlServerApiKeyStoreMigrator`) | Add jitter to `SqlServerSecretsStoreMigrator`'s backoff in `~/Desktop/scadaproj/ZB.MOM.WW.Secrets` (mirror the Auth fix) and add a `Migrate_Concurrently_FromEightTasks_AllSucceed`-shaped live test to catch a regression. Lives entirely in scadaproj, not this repo. | Next time Secrets' SQL Server migrator is touched, or if a wider-than-2-way concurrent boot of a Secrets-backed cluster is ever planned. |
|
||||
| 110 | **Flow Debugger follow-ups: the *Vertical trace* list toggle (mockup Direction B) and console capture on `ScriptRun`** *(Low)*. v1 ships the Direction A swimlane only; the mockup's Direction B — the same steps as a vertical, filterable list with the lane as a column — was kept as an alternate for long flows and screen readers, and the detail panel's *Console* tab is absent because script `Console`/log output is not captured per run (`ScriptRun` rows carry parameters, return value, error and timing, not stdout). Both are additive: a list view over the existing `FlowGraph`, and an extra `Extra.console` field on the `ScriptRun` row's `ScriptTraceExtra` (payload cap applies). | Design `docs/plans/2026-09-05-flow-debugger-design.md` §11; plan `2026-09-05-flow-debugger.md` Task 23 | Neither was asked for by an operator; the swimlane + Timing/Writes tabs cover the acceptance flow (Delmia recipe download, rig step H), and console capture needs a per-run writer seam in `ScriptRuntimeContext` plus a redaction decision. | First operator request for a list view or for script log lines in the step detail. |
|
||||
| 110 | **Flow Debugger follow-up: the *Vertical trace* list toggle (mockup Direction B)** *(Low)*. v1 ships the Direction A swimlane only; the mockup's Direction B — the same steps as a vertical, filterable list with the lane as a column — was kept as an alternate for long flows and screen readers. Additive: a list view over the existing `FlowGraph`. ~~and console capture on `ScriptRun`~~ **The console-capture half is RESOLVED 2026-09-09 (plan `docs/plans/2026-09-09-flow-debugger-step-logs.md`)** — and deliberately not as this row sketched it. `Extra.console` on the `ScriptRun` row was rejected (the 8 KB payload cap would silently drop lines, and helper-step attribution would need every helper to buffer); shipped instead is a leveled `Log` global on all four script surfaces plus one `ScriptTrace.ScriptLog` audit row per line, folded onto the step that produced it, with the failing step's full exception on `errorDetail`. `Console.Out` capture on a site node is recorded as permanently out of scope in the design's §9: `Console.Out` is process-global and shared by every concurrent run, so per-run capture is unsound. | Design `docs/plans/2026-09-05-flow-debugger-design.md` §11; plan `2026-09-05-flow-debugger.md` Task 23 | The list view was not asked for by an operator; the swimlane + Timing/Writes/Log tabs cover the acceptance flow (Delmia recipe download, rig steps H and J). | First operator request for a list view. |
|
||||
| 111 | ~~**Flow Debugger outbound nodes: no Retry/Discard on a parked node, and no `?correlationId=` deep link from the node to the Site Calls / Notification report pages** *(Low)*~~ **RESOLVED 2026-09-06 (plan `docs/plans/2026-09-06-flow-debugger-followups.md`).** `FlowStep` now carries the row's `CorrelationId`; the detail panel deep-links to `/site-calls/report?correlationId=` / `/notifications/report?correlationId=` (both pages accept it through additive per-id query filters — `SiteCallQueryRequest.TrackedOperationIdFilter`, `NotificationOutboxQueryRequest.NotificationIdFilter` — pre-filter to the row and auto-open its detail), and a `Parked` node offers Retry / Discard in place through `IFlowDebugService.RetryOutboundAsync` / `DiscardOutboundAsync`, which reuse the report pages' relay, site-scope re-check and confirm wording, after which the page re-polls Replay until the node leaves Parked. Per-attempt request/response diff is still not shown (the lifecycle rows carry the error summary only). Found on the way: the prediction circuit deadlock (`4769e192`). | Plan 2026-09-06 "Out of scope"; `FlowStepDetail.razor` parked hint | The Site Calls page owns the retry semantics and its audit rows; duplicating the action on the debugger node would need the same Deployer gate + confirm flow. | First operator who reaches a parked node from the debugger and asks for the button. |
|
||||
| 112 | **Flow Debugger: a SITE-side inline trace truncation is invisible to the operator** *(Low)*. `ScriptCallResult` / `RouteToCallResponse` carry `TraceEvents` but no `Truncated` flag, so the page's *event list truncated* badge reflects central's `FlowTraceCollector` only — a site run whose own collector dropped rows returns a silently short list. The new 1 MB byte budget (arch-review F1) makes site truncation reachable sooner than the old 500-event count cap did. The fix is additive: a trailing `bool Truncated = false` on both records, a new field on `RouteToCallResponseDto` (regen via `docker/regen-proto.sh sitecommand`), and `FlowDebugRunner` ORing it into `FlowDebugRunResult.Truncated`. | Arch-review remediation code review 2026-09-06 | Needs a proto regeneration plus a rig rebuild to prove end-to-end, and nothing is lost meanwhile: the site's audit rows are written in full, so a Replay of the same execution is never truncated. | The first Live run that shows fewer site steps than its Replay of the same execution. |
|
||||
| 113 | **Other actors' log lines are not captured for an execution — only the script's own `Log.*` and the runtime lines inside a scoped helper** *(Low)*. The Flow Debugger's step logs (2026-09-09) capture what the script logs and what `ScriptRuntimeContext`'s own logger emits while a run is traced, because those two go through one seam. What the *Instance Actor*, the *DCL*, the alarm actors or the S&F engine log while working on the same execution never reaches the graph: there are **zero** `LogContext.PushProperty` calls in the repo, `Enrich.FromLogContext()` is not configured on the Serilog pipeline (`TraceContextEnricher` stamps W3C ids only), and `site_events` has no execution-id column. Capturing them is a separate enrichment initiative: push `ExecutionId` (and instance/script) onto the ambient `LogContext` at run start, enable `Enrich.FromLogContext()`, add an execution-id column + index to `site_events`, then either sink matching entries into `ScriptLog` rows or query the site event log by execution id. | Step-logs design `docs/plans/2026-09-09-flow-debugger-step-logs-design.md` §2 + §9 ("Out of scope") | Out of proportion to the ask: it changes the logging pipeline of every actor on a site node, adds a replicated-table column (`site_events` is one of LocalDb's ten `ReplicatedTables`, so the change is a both-nodes-together schema edit), and risks a volume increase on untraced runs unless the enrichment is itself gated. The script-authored lines cover the debugging case the Flow Debugger exists for. | First investigation where the answer sits in what the Instance Actor or the DCL logged during a traced run and the operator cannot correlate it by hand. |
|
||||
| 114 | **`CompileSurfaceParityTests.AccessorMirrorPairs` cannot guard the `(ScriptLogger, CompileLog)` pair — the theory has no per-member exclusion mechanism** *(Low)*. The arity theory asserts the compile mirror exposes at least as many overloads as the runtime accessor for **every** public instance method, and `ScriptLogger` has one the mirror must NOT have: `FlushDropped()`, the run-end closing-row flush, which is called by `ScriptRunLauncher`, not by a script. Adding the pair today would fail the theory for a member that is correctly absent, so the pair is left out and `Log`'s four methods are guarded only by the top-level name-superset check plus the hand-written surface tests. The fix is an exclusion seam on the theory — an optional `IReadOnlySet<string> ignoredRuntimeMethods` per row (or an `[NotScriptReachable]` marker attribute on `FlushDropped`, which also documents the intent at the declaration) — after which the pair joins `AccessorMirrorPairs`. | Found while wiring Task 15 of `docs/plans/2026-09-09-flow-debugger-step-logs.md`; test `tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/CompileSurfaceParityTests.cs` | No drift is possible without a code change to `ScriptLogger`, and a missing `Log` method on the mirror surfaces immediately as a `CS1061` at the design-time gate for any script that calls it. The seam is a test-infrastructure change that touches every existing row's signature. | The next public method added to `ScriptLogger` (or to any runtime accessor whose mirror must deliberately omit a member) — at that point build the exclusion seam and add the pair. |
|
||||
| 113 | **Flow Debugger: the method-entry site scope (F2) gates ROUTED site traffic only** *(Low)*. A site-scoped Deployer who Live-runs a method belonging to another plant is still refused at `RouteTarget.ResolveSiteAsync`, but the method's central-side side effects — its `Database.*` calls, `ExternalSystem` calls, notifications — execute before or regardless of that refusal. Only routing is scoped. | Arch-review remediation code review 2026-09-06 | F2's stated property ("no site traffic outside the operator's scope") holds as written. Going further needs a per-method site affinity, which does not exist in the model — ApiMethods are central objects with no site column — so there is nothing to scope a method against without inventing that concept. | A decision to give `ApiMethod` a site affinity, or an operator report of a scoped user reaching another plant's central-side effects. |
|
||||
| 68 | ~~**`deploy.sh` run from a git worktree silently rehomes every node's bind-mount data dir**~~ **RESOLVED 2026-08-15 (guard added in the same close-out).** The compose files' bind mounts are relative (`./site-a-node-a/data`), so a deploy from a worktree checkout mounts the worktree's copies — the rig keeps running and looks healthy, but its SQLite stores split from the main checkout's and everything written there is orphaned by the next deploy from main. Bit the rows-46–53 close-out live: the seeding agent's `rig-probe-1` deploy persisted into worktree-homed dirs and "vanished" after the orchestrator's redeploy (no tombstone, no product bug — LWW/tombstone forensics ruled out deletion; the row sat in `.claude/worktrees/…/docker/site-a-node-a/data/site-localdb.db` the whole time). Both `docker/deploy.sh` and `docker-env2/deploy.sh` now refuse to run from a `.claude/worktrees/` path (override: `SCADABRIDGE_ALLOW_WORKTREE_DEPLOY=1`). | Found during the rows-46–53 close-out | Closed 2026-08-15. | — |
|
||||
|
||||
|
||||
@@ -1,6 +1,6 @@
|
||||
# Flow Debugger — design
|
||||
|
||||
**Status:** implemented 2026-09-06 (branch `feat/flow-debugger`); plan `2026-09-05-flow-debugger.md` (24 tasks, all complete). Residual follow-ups: deferred-work register row 110. **v1.1 outbound calls** (a fourth *External* lane for API / DB / notification nodes, lifecycle folding, async/spawn edges, pending refresh) — see the addendum plan `2026-09-06-flow-debugger-outbound-calls.md`; §4's "three lanes fixed" is amended by its D2. **v1.2 follow-ups** (node Retry/Discard, `?correlationId=` deep links to the report pages, the prediction circuit-deadlock fix, Playwright coverage) — plan `2026-09-06-flow-debugger-followups.md`; register row 111 closed.
|
||||
**Status:** implemented 2026-09-06 (branch `feat/flow-debugger`); plan `2026-09-05-flow-debugger.md` (24 tasks, all complete). Residual follow-ups: deferred-work register row 110. **v1.1 outbound calls** (a fourth *External* lane for API / DB / notification nodes, lifecycle folding, async/spawn edges, pending refresh) — see the addendum plan `2026-09-06-flow-debugger-outbound-calls.md`; §4's "three lanes fixed" is amended by its D2. **v1.2 follow-ups** (node Retry/Discard, `?correlationId=` deep links to the report pages, the prediction circuit-deadlock fix, Playwright coverage) — plan `2026-09-06-flow-debugger-followups.md`; register row 111 closed. **v1.3 script entry** (site → instance → script as a second entry point) — design `2026-09-08-flow-debugger-script-entry-design.md`. **v1.4 step logs and exceptions** (a `Log` global on every script surface, `ScriptTrace.ScriptLog` rows folded onto the step that produced them, the failing step's full exception on the node, per-run caps) — design `2026-09-09-flow-debugger-step-logs-design.md`, plan `2026-09-09-flow-debugger-step-logs.md`; register row 110's console-capture half closed by it.
|
||||
**Mockup:** Claude Design canvas *Flow Debugger Mockup* — <https://claude.ai/code/artifact/3f3e81e5-8e5e-4333-bdf6-59256108494d> (Direction A swimlane boards + two low-fi alternates + decision notes).
|
||||
**Owner components:** Central UI (#page), Inbound API, Site Runtime, Audit Log, Communication, Script Analysis, Configuration Database.
|
||||
|
||||
|
||||
@@ -1,7 +1,7 @@
|
||||
# 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`
|
||||
**Status:** implemented 2026-09-09 (plan `2026-09-09-flow-debugger-step-logs.md`, 15 tasks). Deltas between this design and what shipped are marked *as built* in place.
|
||||
**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)
|
||||
|
||||
@@ -49,7 +49,7 @@ copy); run-wide `n errors · n warnings · n info` in the status strip. Live and
|
||||
| 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). |
|
||||
| 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 ride the collector's low-priority lane — as built that is an optional parameter on the existing method, `FlowTraceCollector.Add(evt, lowPriority: true)`, not a fourth public `AddLowPriority` method (Commons keeps its public method count tight, and every caller already had the event in hand): 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` (see §7 for the shipped wording). | 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. | — |
|
||||
|
||||
@@ -63,8 +63,12 @@ rows. `ScriptTraceExtra` gains `LogLevel` (`debug|info|warn|error`), `LogSource`
|
||||
`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.
|
||||
`FlowLogLine(EventId, ExecutionId, OccurredAtUtc, Level, Source, Message, ExceptionMessage,
|
||||
ExceptionDetail, StepEventId, Seq)` — as built, the line keeps its own `ExecutionId` (so a folded
|
||||
step can say which execution a line came from, and the cross-step hint can name it) plus the
|
||||
attribution inputs `StepEventId` and `Seq` that `FlowGraphBuilder` sorted by, rather than discarding
|
||||
them at projection time. `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
|
||||
@@ -101,9 +105,18 @@ existing rule *upgrade central first* covers it. An old site sends no lines; the
|
||||
`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`
|
||||
`FlowDebugger`: strip counts (`flow-log-counts`, `Log: n errors · n warnings · n info`, counting
|
||||
LINES not steps), the `flow-logs-truncated` badge and the `flow-unattached-logs` note; `ApplyOutcome`
|
||||
unchanged (a run with only warning lines is still Completed).
|
||||
|
||||
**Truncation badge wording and its clearing rule.** The badge reads **"inline log lines capped —
|
||||
refresh outcomes pulls the rest"**: it is a *this-copy-is-short* notice with the remedy in it, not a
|
||||
data-loss warning — the rows exist in full in the audit store, and Replay reads them all. It is
|
||||
driven by `FlowGraph.LogsTruncated`, which the page recomputes from the rows it currently holds, so
|
||||
a *Refresh outcomes* that merges in more log rows **clears the badge on its own**; it must never be
|
||||
latched on the run. (Contrast `Truncated`, the event-list cap, which is a property of the Live reply
|
||||
itself.)
|
||||
|
||||
## 8. Security
|
||||
|
||||
Log messages are script-authored text and pass the same `IAuditRedactor` as every other summary (secrets in
|
||||
|
||||
@@ -57,9 +57,10 @@ boundary:
|
||||
| `POST /api/{method}` (Inbound API) | External | Inbound (invokes a script) | No (gap) |
|
||||
| `Route.To(x).Call(y)` (Inbound API → site) | Script | Central → site | Yes — `ScriptTrace.RouteCall`, **always-on** (2026-09-05) |
|
||||
| Site script run / attribute write / attribute wait under a **traced** run | Script | Site-local | Yes — `ScriptTrace.ScriptRun` / `AttributeWrite` / `AttributeWait`, **gated** by the `Trace` flag (Flow Debugger Live runs, `ApiMethod.TraceAllCalls`) |
|
||||
| Script `Log.Debug/Info/Warn/Error(...)` — and the runtime's own Information+ entries during a **traced** run | Script / runtime | Site-local or central | Yes — `ScriptTrace.ScriptLog`, one row per line, **gated** by the same `Trace` flag (2026-09-09) |
|
||||
| Central method-script `Database.QuerySingle/Query/Execute` (`InboundDatabaseHelper`) | Script | Outbound | Yes — `DbOutbound.DbWrite` via `ICentralAuditWriter` (2026-09-06; was an unaudited gap) — `Target` = connection name, `Actor` = `api:{method}`, the request's `ExecutionId`, `Extra` = `{op, rowsAffected\|rowsReturned}` |
|
||||
|
||||
**`AuditChannel.ScriptTrace` (Flow Debugger, design `docs/plans/2026-09-05-flow-debugger-design.md` §5.1).** Trace steps ARE audit events — no parallel store. One kind is always-on (`RouteCall`, a central direct write per `Route.To().Call`, carrying the child run's id in `Extra.childExecutionId`); the three site kinds are emitted only when the run's `Trace` flag is set, ride the ordinary site `IAuditWriter` → SQLite → telemetry → central path, share the run's `ExecutionId` / `ParentExecutionId`, and are additionally returned inline on the routed reply so a Live run does not wait on the 5 s telemetry cadence. The Flow Debugger's graph (`FlowStep` / `FlowGraphBuilder`, Commons) is a central-side projection of these rows — **and, since 2026-09-06, of the run's `ApiOutbound` / `DbOutbound` / `Notification` rows too** (plan `docs/plans/2026-09-06-flow-debugger-outbound-calls.md`): the outbound rows already sit in the execution tree under the run's `ExecutionId`, so the replay query (`GetTraceEventsAsync`) simply widens its channel filter to the four channels plus the inbound row, and a traced site run also passes the outbound rows it emits through the same inline trace collector as its `ScriptTrace` rows (same `AuditEvent` instance the writer receives — no duplicate construction; a collector that throws can neither fail the call nor skip the durable write). Rows written after the run returned (the S&F forwarder's `Forwarded` / `Attempted` / `CachedResolve`, the Notification Outbox's `NotifyDeliver`) are not inline — the page re-reads the tree for them.
|
||||
**`AuditChannel.ScriptTrace` (Flow Debugger, design `docs/plans/2026-09-05-flow-debugger-design.md` §5.1).** Trace steps ARE audit events — no parallel store. One kind is always-on (`RouteCall`, a central direct write per `Route.To().Call`, carrying the child run's id in `Extra.childExecutionId`); the three site kinds are emitted only when the run's `Trace` flag is set, ride the ordinary site `IAuditWriter` → SQLite → telemetry → central path, share the run's `ExecutionId` / `ParentExecutionId`, and are additionally returned inline on the routed reply so a Live run does not wait on the 5 s telemetry cadence. The Flow Debugger's graph (`FlowStep` / `FlowGraphBuilder`, Commons) is a central-side projection of these rows — **and, since 2026-09-06, of the run's `ApiOutbound` / `DbOutbound` / `Notification` rows too** (plan `docs/plans/2026-09-06-flow-debugger-outbound-calls.md`): the outbound rows already sit in the execution tree under the run's `ExecutionId`, so the replay query (`GetTraceEventsAsync`) simply widens its channel filter to the four channels plus the inbound row, and a traced site run also passes the outbound rows it emits through the same inline trace collector as its `ScriptTrace` rows (same `AuditEvent` instance the writer receives — no duplicate construction; a collector that throws can neither fail the call nor skip the durable write). Rows written after the run returned (the S&F forwarder's `Forwarded` / `Attempted` / `CachedResolve`, the Notification Outbox's `NotifyDeliver`) are not inline — the page re-reads the tree for them. **Since 2026-09-09 the channel also carries `ScriptLog`** (design `docs/plans/2026-09-09-flow-debugger-step-logs-design.md` D1) — one row per line a traced script or the runtime logged, with `RequestSummary` = the message, `ErrorMessage` / `ErrorDetail` = the attached exception's message / `ToString()`, and `Extra` (`ScriptTraceExtra`) carrying `logLevel` (`debug|info|warn|error`), `logSource` (`script|runtime`), the owning `stepEventId` and a per-run `seq`. It is **never a step**: `FlowGraphBuilder` folds it into its owning step's `Logs` list, and the same rows carry the exception the failing step threw via the `errorDetail` field that already existed on `AuditDetails` (site `ScriptRun` rows and the central inbound row now populate it). Redaction, the 8 KB / 64 KB-on-error payload caps and `AuditLog:PerChannelRetentionDays:ScriptTrace` all cover the new kind unchanged — a log line is an ordinary audit row, not a side channel.
|
||||
|
||||
Out of scope — framework traffic is not audited:
|
||||
|
||||
|
||||
@@ -219,6 +219,7 @@ Per-leaf alarm rendering (leaf nodes are individual conditions for native alarms
|
||||
- **`/deployment/flow-debugger`** (nav: Deployment → Flow Debugger; design `docs/plans/2026-09-05-flow-debugger-design.md`, plan `docs/plans/2026-09-05-flow-debugger.md`). Runs one entry point with operator-supplied inputs and renders every step the run passes through as a **four-lane swimlane** (Central / Site / Tags / **External**) — request, route call, site script run, attribute writes, attribute waits, **outbound API / database / notification calls**, response — each node carrying its input, output, duration and outcome; a tabbed detail panel (Input · Output · Writes *or* Lifecycle · Timing, plus a *Where this ran* column) opens on the selected node with `Open in Debug View` (script entries, where the instance is known) and `Audit rows (n)` (→ `/audit/log?executionId=`) drill-ins.
|
||||
- **Two modes.** *Live* is a real run — the method script executes on the active central node with tracing on, or a real attribute write goes through the routed-write path and the site's triggered run is polled back — audited like any other call. *Replay* executes nothing: it rebuilds the flow from an existing execution's `ScriptTrace` audit rows plus its `ApiOutbound` / `DbOutbound` / `Notification` rows (`?executionId=` drill-in from the Audit Log drawer's and the Execution Chain page's **Open in Flow Debugger** actions).
|
||||
- **External lane (v1.1, plan `docs/plans/2026-09-06-flow-debugger-outbound-calls.md`).** Every `ExternalSystem.Call/CachedCall`, `Database.*` and `Notify.Send` a traced run makes is a node on the fourth lane — kinds `ApiCall` / `DbCall` / `Notify` (eyebrows `API CALL` / `DATABASE` / `NOTIFY`), title = the system.method / connection / list, a status pill (`Ok` / `Pending` / `Parked` / `Failed`) plus `sync` | `cached` | `notify`. **One node per operation:** a cached call's or notification's later lifecycle rows (Forwarded → Attempted → Delivered / Parked, written minutes later by the S&F forwarder or the Notification Outbox) fold into the node (`FlowStep.Lifecycle`, a Lifecycle tab in the detail panel with *Delivered by*) instead of drawing four boxes. A sync call sits in the execution chain; a cached call or notification hangs off it on a dashed **async** connector, and a trigger cascade's spawn edge carries a **bolt badge on the connector's riser** — the edge itself keeps an ordinary arrowhead (the bolt was the arrowhead until 2026-09-08, and on the upward Tags→Site hop it read as a broken arrow). The spawn edge starts at the parent's **last write of the attribute the child's `triggerAttribute` names** (`FlowGraphBuilder`); only when the child names no attribute, or the parent never wrote it, does the timestamp rule (last non-async parent step at or before the child) decide — a burst of writes landing in one millisecond used to draw the cascade from the last of them rather than the one that fired it. A Live run returns only the rows the run itself emitted, so a graph left with `Pending` nodes **refreshes itself** through the Replay command every 5 s for up to 2 min (page constants), and a *Refresh outcomes* button re-reads on demand in either mode; the state chip stays *Completed* — pending outbound work is not a failed run. A refresh **merges** the re-read rows into the run's known rows by `EventId` (fresh copy wins) and rebuilds the graph from the union, so it only ever adds nodes: the site's outbound rows reach central's audit store by telemetry seconds after the run returned them inline, and a Replay read taken in between would otherwise erase an already-drawn node (observed on the rig 2026-09-06 with a resolved cached DB write). The union is exact because the inline rows are the very `AuditEvent` objects the site writer persists. **v1.2 (follow-ups plan `docs/plans/2026-09-06-flow-debugger-followups.md`, register row 111 closed):** a folded node carries its `CorrelationId` (`FlowStep.CorrelationId` — the `TrackedOperationId` / `NotificationId`), so the detail panel deep-links to **`/site-calls/report?correlationId=<id>`** / **`/notifications/report?correlationId=<id>`** (*Open in Site Calls* / *Open in Notification report*; both pages accept that query, pre-filter to the one row through an additive per-id query filter — `SiteCallQueryRequest.TrackedOperationIdFilter` / `NotificationOutboxQueryRequest.NotificationIdFilter` — show a removable *Operation* / *Notification* pill and auto-open the row's detail modal; note `NotificationId` is minted as a Guid in **`N` form** — no dashes — so the Notify link passes `N` and the report page normalises any Guid-shaped value to `N`, while `TrackedOperationId` is a `varchar(36)` `D` string and the Site Calls filter binds a `varchar` parameter for the PK seek), and a **`Parked` node offers Retry / Discard in place**: the same site-scope re-check, confirm dialog (Discard = danger) and central→site / Notification Outbox relay the report pages use (`IFlowDebugService.RetryOutboundAsync` / `DiscardOutboundAsync` → `CommunicationService`), then the page re-polls Replay (5 s / 2 min) until the node leaves `Parked`. **Prediction is async-safe:** `FlowDebugService.PredictMethodAsync` resolves route targets by a resolve-and-rewalk loop — its original blocking resolver deadlocked the whole Blazor circuit on the renderer sync context the moment a method routing to a site script was chosen (found 2026-09-06; pinned by a single-thread-pump unit test and the Playwright `FlowDebuggerTests`, which log in through the fixture and run a Live run of an ephemeral method in a real browser).
|
||||
- **Step logs and exceptions (v1.4, 2026-09-09, design `docs/plans/2026-09-09-flow-debugger-step-logs-design.md`).** A traced run shows, **on the node that produced them**, the exception a failing step threw and every line the script (or the runtime on its behalf) logged. A log line is an ordinary audit row — `ScriptTrace` / `ScriptLog`, one per line — that `FlowGraphBuilder` folds into its owning step's `FlowStep.Logs` and **never draws as a node**; attribution is `Extra.stepEventId` when the emitting helper pre-minted its step id, else the execution's anchor row (`ScriptRun` on a site, `InboundRequest` / the debugger's synthesized `RouteCall` root centrally), else that execution's first step, else `FlowGraph.UnattachedLogLines`. Rendering: a node footer badge (`✕ n` errors, `! n` warnings, `≡ n` info, highest severity first, `data-test="flow-node-logs"`, hidden with no lines); a failed node's subtitle becomes `ExceptionType: message` (namespace stripped, innermost exception, generic-safe) fed by the new `FlowStep.ErrorDetail`; a **Log (n)** tab in the detail panel (`flow-step-tab-log`) carrying the full exception block first, then the lines under an `All | Warn +` filter with a copy button and a *"n more on <step>"* cross-step hint that selects the named step; and a `Log: n errors · n warnings · n info` count in the status strip (`flow-log-counts`) that counts LINES, not steps — a `Log.Error` line is not a failed step and never moves the state chip. Two truncation notes sit beside it: `flow-logs-truncated` (*inline log lines capped — refresh outcomes pulls the rest*, from `FlowDebugRunResult.LogsTruncated`; it clears once a refresh merges in more log rows, because Replay reads the complete set) and `flow-unattached-logs`. Live and Replay read the same rows, so the two modes render identically once telemetry has landed.
|
||||
- **Authorization (arch-review F3).** The page is `RequireFlowDebugger` — `AuthorizationPolicies.FlowDebuggerAccessRoles` = Deployer, Administrator, Viewer — so an auditor can open it and Replay a past execution without the ability to run anything, and `FlowDebugReplayCommand` accepts the same set. **Everything that executes stays Deployer-only:** the three run commands (`FlowDebugRunMethodCommand` / `FlowDebugRunScriptCommand` / `FlowDebugRunValueChangeCommand`), the Live entry-point controls, the parked-node Retry/Discard actions and the `?methodId=` / `?instanceId=` / `?script=` drill-ins; for a non-Deployer the page pins itself to Replay mode.
|
||||
- **Two entry points** (script entry redesigned 2026-09-08, `docs/plans/2026-09-08-flow-debugger-script-entry-design.md`). An inbound API method (inputs form generated from the method's `ParameterDefinitions`, values coerced by declared type) or a **site script** (Site → Instance → Script pickers, site-scope filtered): a script whose trigger is ValueChange or Conditional shows one *New value for `<attribute>`* field, with the attribute derived from the script's own trigger configuration rather than picked; every other script kind (Call, Interval, Expression, or no trigger) shows a `ParameterValueForm` generated from the script's `ParameterDefinitions`, or a "this script takes no parameters" note when there are none. A method-entry Live run is additionally site-scoped **at route time** on the server (`RouteHelper.WithSiteScope` → `SITE_SCOPE_DENIED`, arch-review F2), so an operator cannot reach a site outside their scope by choosing a method that routes there. Both entry points pick the target instance through the shared **`InstancePicker`** combobox (2026-09-08, `docs/plans/2026-09-08-instance-picker-design.md`): a text field whose dropdown is the site's area tree (`InstanceTreeBuilder` — all areas collapsed on open, un-areaed instances at the root, orphaned rows surface at the root), typed text filters by instance name and expands to the matches, Enter picks the first visible match, Escape restores the selection.
|
||||
- **Predicted graph first.** Choosing an entry point renders the statically predicted shape (`FlowShapePredictor`, Script Analysis REQ-SA-7) before anything runs — nodes whose target depends on inputs render dashed; after a run, predicted nodes the run never produced render greyed.
|
||||
|
||||
@@ -152,7 +152,7 @@ The `sbk_<keyId>_<secret>` design already supports zero-downtime rotation — a
|
||||
| `TIMEOUT` | 500 | The method script exceeded its execution timeout. |
|
||||
| `SITE_UNREACHABLE` | 500 | The target site did not respond to the routed request within the routing timeout (no contact / down / partitioned) — typed from the routed Ask expiring (`AskTimeoutException`), never inferred from an error-message substring. A `Success=false` response means the site answered and is classified `SCRIPT_ERROR`. |
|
||||
| `SCRIPT_COMPILE_FAILED` | 500 | The method's script failed to compile (returned consistently on every node until a compiling version is saved). |
|
||||
| `SCRIPT_ERROR` | 500 | Catch-all for any other script-execution failure (details are logged centrally, never leaked to the caller). |
|
||||
| `SCRIPT_ERROR` | 500 | Catch-all for any other script-execution failure (details are logged centrally, never leaked to the caller — the exception's `ToString()` is captured on the audit row as `ErrorDetail`, never in the response body). |
|
||||
|
||||
### Extended Type System
|
||||
- API method parameter and return type definitions support an **extended type system** beyond the four template attribute types (Boolean, Integer, Float, String):
|
||||
@@ -295,6 +295,33 @@ Containment rules (enforced, not advisory):
|
||||
For everything else, scripts interact with the system through the curated `Route` and
|
||||
`Parameters` surfaces above.
|
||||
|
||||
#### Logging (`Log`)
|
||||
|
||||
Method scripts get the same leveled `Log` global site scripts do (design
|
||||
`docs/plans/2026-09-09-flow-debugger-step-logs-design.md` D4/D5) — `InboundScriptContext.Log`,
|
||||
backed by `InboundScriptLogger`:
|
||||
|
||||
- `Log.Debug(message, exception?)` / `Log.Info` / `Log.Warn` / `Log.Error` — synchronous, `void`,
|
||||
never throws into the script.
|
||||
- **Always** forwards to the central node's `ILogger`. A `ScriptTrace` / `ScriptLog` audit row is
|
||||
written **only when the request is traced** (a Flow Debugger Live run, or a real call to a method
|
||||
with `TraceAllCalls`), through the executor's inline trace sink and `ICentralAuditWriter`; an
|
||||
ordinary call pays a log entry and nothing more.
|
||||
- Lines with no explicit step id are attributed to the request's anchor row (the `InboundRequest`
|
||||
row, or the debugger's synthesized `RouteCall` root), so they render on the inbound node.
|
||||
- **Bounded:** `ScadaBridge:InboundApi:MaxLogLinesPerRun` (default 200, validated `> 0`) caps the
|
||||
rows one request may emit, messages are clipped at 2 000 characters, and one closing `warn` row
|
||||
names the dropped count.
|
||||
|
||||
#### Script exception detail
|
||||
|
||||
`InboundScriptResult` carries an internal `ErrorDetail` (`ex.ToString()` of the fault the method
|
||||
script threw). It is written to the request's audit row — by `FlowDebugRunner` for a Live run, and
|
||||
on the ordinary HTTP path via `HttpContext.Items[AuditWriteMiddleware.ErrorDetailItemKey]` so a
|
||||
`TraceAllCalls` Replay has it too — and is projected onto `FlowStep.ErrorDetail` for the Flow
|
||||
Debugger's exception block. **It is never returned to the HTTP caller:** the response body stays the
|
||||
generic `SCRIPT_ERROR` envelope, unchanged.
|
||||
|
||||
### Routing Behavior
|
||||
- The `Route.To()` helper resolves the instance's site assignment from the configuration database and routes the request to the correct site cluster via the Communication Layer.
|
||||
- The call is **synchronous from the API caller's perspective** — the API method blocks until the site responds or the **method-level timeout** is reached.
|
||||
|
||||
@@ -148,6 +148,8 @@ var errors = RoslynScriptCompiler.Compile(code, typeof(ScriptCompileSurface));
|
||||
```
|
||||
This allows the compile to bind `Attributes["name"]`, `Notify.To("x").Send(...)`, `ExternalSystem.Call(...)`, `Alarms.CurrentAsync()`, and similar API calls against real types, catching undefined-symbol and type-mismatch errors before deployment.
|
||||
|
||||
The surface also mirrors the **`Log` global** (step logs design `docs/plans/2026-09-09-flow-debugger-step-logs-design.md` D4) as the compile-only `ScriptCompileSurface.CompileLog` — `Debug` / `Info` / `Warn` / `Error(string message, Exception? exception = null)`, including the optional exception parameter, so `Log.Warn("…", ex)` binds at the design-time gate exactly as it does at the site. `Log` needs no `ScriptTrustPolicy` change for the same reason `Alarms` did not: the trust boundary is a deny-list over API roots, not an allow-list of context members.
|
||||
|
||||
Where an accessor returns a domain type rather than a primitive, the stub returns the **same** type the runtime returns (not a compile-only stand-in) — `Alarms.CurrentAsync()` yields `IReadOnlyList<ScriptAlarm>` on both surfaces, so a script reading `a.Severity` / `a.AckTime` binds identically at the gate and at the site. This works because those types live in Commons, which is already in `DefaultAssemblies`.
|
||||
|
||||
**Trust-model note:** the script trust boundary is a **deny-list over API roots**, not an allow-list of context members, so adding a globals member such as `Alarms` requires no `ScriptTrustPolicy` change. What must hold is that the member's return type resolves in a *permitted* namespace — pinned by a test asserting no entry in `ForbiddenScopes` prefixes the Commons script-surface namespace.
|
||||
|
||||
@@ -516,6 +516,15 @@ Available to all script runs and alarm on-trigger runs:
|
||||
- The type lives in Commons so the runtime accessor and the Script Analysis compile-only surface (`ScriptCompileSurface.CompileAlarmsAccessor`) project to the **same** type — a script binding at the design-time gate binds identically at the site. Parity is pinned by `CompileSurfaceParityTests`.
|
||||
- Design record: `docs/plans/2026-06-30-mes-alarm-status-api.md` §5.2.
|
||||
|
||||
### Logging (`Log`)
|
||||
- `Log.Debug(message, exception?)` / `Log.Info` / `Log.Warn` / `Log.Error` — leveled, per-run logging available to **every** script, alongside the `Alarms` accessor above (design `docs/plans/2026-09-09-flow-debugger-step-logs-design.md` D4/D5). Synchronous, `void`, and it **never throws into the script**: a failing sink is swallowed, because a debug observer must not fail a production run.
|
||||
- **Every line always reaches the node's `ILogger`** (structured `Instance` / `Script` / `ExecutionId` / message), traced or not — an untraced run is an ordinary logging surface and pays nothing else. A `ScriptTrace` / `ScriptLog` **audit row** is emitted **only when the run is traced** (a Flow Debugger Live run, or a real call to a method with `TraceAllCalls`), so a timer or value-change script logging at high rate costs no audit volume. There is no site-event-log sink for `Log.*`.
|
||||
- The implementation is `ScriptLogger` (`SiteRuntime/Scripts/ScriptLogger.cs`), created by `ScriptRuntimeContext` and exposed as `ScriptGlobals.Log`. **One logger instance is one run's counter** — `CallShared` shares the calling context, so an inline shared script shares the caller's counter, execution id and anchor row rather than starting its own.
|
||||
- **Runtime lines land on the step that produced them.** While a run is traced, `ScriptRuntimeContext` wraps its own `ILogger` in a `TraceCapturingLogger`, which forwards everything to the inner logger unchanged and additionally copies **Information and above** into `ScriptLog` rows with `logSource = "runtime"` (Debug/Trace are deliberately not captured — internal chatter). `IsEnabled` returns true for Information and above regardless of the node's minimum level, because those entries are trace data rather than node log output. Attribution rides an ambient `TraceStepScope` (`AsyncLocal<Guid?>`): `SetAttribute`, `WriteBatchAndWait`, `WaitInternal` and the synchronous `ExternalSystem.Call` pre-mint their step row's `EventId`, open the scope around their body and pass the id to `EmitTrace`, so a warning the runtime logs inside a write shows on that write's node. Everything else falls back to the run's anchor `ScriptRun` row. **Build `ScriptLogger` over the UNDECORATED logger** — `TraceCapturingLogger`'s constructor rejects an inner `TraceCapturingLogger`, since double wrapping would emit two rows per line.
|
||||
- **Bounded (D7).** `ScadaBridge:SiteRuntime:MaxLogLinesPerRun` (default 200, validated `> 0`) caps the rows one run may emit; messages are clipped at 2 000 characters. Lines past the cap are counted and dropped, and a single closing `warn` / `runtime` row naming the dropped count is flushed at run end (it bypasses the counter — it is the one row that must always land).
|
||||
- **Exception detail.** A failed run's `ScriptRun` row now carries `errorDetail = ex.ToString()` alongside the existing one-line `errorMessage`, so the Flow Debugger can show type, message, stack and inner exception. A timeout emits no detail — an `OperationCanceledException` stack is noise.
|
||||
- **`Console.WriteLine` is not the logging surface on a site.** `System` is imported, so it compiles, and the Central UI Test Run sandbox does capture it; but on a site node `Console.Out` is process-global and shared by every concurrent script run, so per-run capture is unsound. `Log.*` is the leveled, per-run replacement, and the sandbox's mirror writes to the same console pane.
|
||||
|
||||
### Parameter Access
|
||||
- `Parameters["key"]` — Raw dictionary access (returns `object?`, requires manual casting).
|
||||
- `Parameters.Get<T>("key")` — Typed access with descriptive error messages. Throws `ScriptParameterException` if parameter is missing, null, or cannot be converted to `T`.
|
||||
@@ -535,7 +544,7 @@ Available to all script runs and alarm on-trigger runs:
|
||||
|
||||
Scripts execute **in-process** with constrained access. The following restrictions are enforced at compilation and runtime:
|
||||
|
||||
- **Allowed**: Access to the Script Runtime API (GetAttribute, SetAttribute, CallScript, CallShared, ExternalSystem, Notify, Database, Tracking, Alarms), standard C# language features, basic .NET types (collections, string manipulation, math, date/time). `System.Diagnostics.Stopwatch`, `Debug`, and `Activity` are permitted.
|
||||
- **Allowed**: Access to the Script Runtime API (GetAttribute, SetAttribute, CallScript, CallShared, ExternalSystem, Notify, Database, Tracking, Alarms, Log), standard C# language features, basic .NET types (collections, string manipulation, math, date/time). `System.Diagnostics.Stopwatch`, `Debug`, and `Activity` are permitted.
|
||||
- **Forbidden**: File system access (`System.IO`), process spawning (`System.Diagnostics.Process`), threading (`System.Threading` — except `Tasks`, `CancellationToken`, and `CancellationTokenSource`), reflection (`System.Reflection`), all raw network access (`System.Net` — must use `ExternalSystem.Call`), native interop (`System.Runtime.InteropServices`, `Microsoft.Win32`), assembly loading, unsafe code, `dynamic`, `Activator`.
|
||||
- **Execution timeout**: Configurable per-script maximum execution time, **measured from enqueue** (WP3.1) — a run that spends its whole budget queued behind blocked scripts is shed at dequeue without executing, rather than being granted a fresh full budget for work whose triggering condition is already stale. Exceeding the timeout cancels the script **cooperatively** (S2/UA5): a script blocked in synchronous I/O or a tight CPU loop does not observe cancellation and continues to occupy its dedicated script-execution thread. A **watchdog names the script** once its thread has not returned within a grace period after the timeout — and, as of WP3.1, **detaches and replaces that worker thread**, so a wedged script costs the pool a thread only until the watchdog fires rather than for the rest of the process. The detached worker exits (instead of pulling more work) when its body finally returns, so capacity never silently doubles. Live detached workers are capped at the pool size — at the cap no replacement is started and an Error site event says so, because bounded starvation is preferable to unbounded thread growth when scripts wedge en masse. The scheduler's **queue depth / busy-thread / oldest-busy-age / detached-thread gauges** and the **per-interval shed count** are reported through Health Monitoring so a saturated, stuck, or shedding scheduler is visible.
|
||||
- **Memory**: Scripts share the host process memory. No per-script memory limit, but the execution timeout prevents runaway allocations.
|
||||
|
||||
Reference in New Issue
Block a user