From 97f01ae98e5f0e32d908287858e7e5711833eba9 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Wed, 9 Sep 2026 13:30:48 -0400 Subject: [PATCH] =?UTF-8?q?fix(flow-debugger):=20final-review=20remediatio?= =?UTF-8?q?n=20=E2=80=94=202000-row=20trace=20pull,=20shared=20ExceptionHe?= =?UTF-8?q?ader=20parser,=20surrogate-safe=20clip,=20wording,=20alarm=20so?= =?UTF-8?q?urce,=20register=20renumber=20(I1/I2/M1-M8)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- CLAUDE.md | 2 +- .../2026-07-08-deferred-work-register.md | 9 +- docs/requirements/Component-InboundAPI.md | 19 +++- .../Commands/FlowDebugTableProjection.cs | 11 ++- .../Deployment/FlowStepDetail.razor | 32 +++---- .../Pages/Deployment/FlowDebugger.razor.cs | 5 +- .../Components/Shared/FlowGraphView.razor.cs | 35 ++------ .../Types/Debugging/ExceptionHeader.cs | 62 +++++++++++++ .../InboundScriptLogger.cs | 15 +++- .../FlowDebug/FlowDebugRunner.cs | 22 ++++- .../Scripts/ScriptLogger.cs | 6 +- .../Scripts/ScriptRunLauncher.cs | 9 +- .../FlowDebugCommandsTests.cs | 32 ++++++- .../Deployment/FlowStepDetailTests.cs | 21 +++++ .../Debugging/ExceptionHeaderTests.cs | 71 +++++++++++++++ .../InboundScriptLoggerTests.cs | 60 +++++++++++++ .../FlowDebugRunnerTests.cs | 21 +++++ .../Actors/AlarmScriptLogTargetTests.cs | 89 +++++++++++++++++++ .../Scripts/ScriptLoggerTests.cs | 6 +- .../Scripts/ScriptRunLauncherTraceTests.cs | 2 +- .../ScriptRuntimeContextTraceEmissionTests.cs | 4 +- 21 files changed, 462 insertions(+), 71 deletions(-) create mode 100644 src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/ExceptionHeader.cs create mode 100644 tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/ExceptionHeaderTests.cs create mode 100644 tests/ZB.MOM.WW.ScadaBridge.InboundAPI.Tests/InboundScriptLoggerTests.cs create mode 100644 tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/AlarmScriptLogTargetTests.cs diff --git a/CLAUDE.md b/CLAUDE.md index 997bee0b..8bf3e495 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -196,7 +196,7 @@ spec for each is `docs/requirements/Component-.md`, and `README.md` carrie - Central UI: Blazor Server (ASP.NET Core + SignalR) with Bootstrap CSS. No third-party component frameworks (no Blazorise, MudBlazor, Radzen, etc.). Build custom Blazor components for tables, grids, forms, etc. - UI design: Clean, corporate, internal-use aesthetic. Not flashy. Use the `frontend-design` skill when designing UI pages/components. - Debug view: real-time streaming via DebugStreamBridgeActor + gRPC (events via `SiteStreamGrpcClient`, snapshot via the `SiteCommandService` query surface — `QueryReply.DebugViewSnapshot`). Health dashboard: 10s polling timer. Deployment status: real-time push via SignalR. -- **Flow Debugger (2026-09-05, Deployment → `/deployment/flow-debugger` + CLI `flow-debug run-method|run-script|run-value-change|replay`).** Runs one entry point (an inbound API method, or a site script) and draws every step as a Central / Site / Tags / **External** swimlane; *Live* really runs it, *Replay* rebuilds a past execution. **v1.1 (2026-09-06, `docs/plans/2026-09-06-flow-debugger-outbound-calls.md`):** every `ExternalSystem.*` / `Database.*` / `Notify.Send` a traced run makes is an `ApiCall` / `DbCall` / `Notify` node on the External lane — the site routes those already-existing `ApiOutbound` / `DbOutbound` / `Notification` rows through the same inline trace collector, the replay query widens to those channels, and `FlowGraphBuilder` folds a cached operation's rows by `(kind, CorrelationId)` into ONE node with a `Lifecycle` (sync calls in-chain, cached/notify on dashed `Async` edges, trigger cascades on `Spawn` edges, the Response linked from the inbound execution's last step). Later lifecycle rows are not inline, so after a Live run the page polls the Replay command (5 s, ≤ 2 min) while any node is `Pending`, plus a *Refresh outcomes* button. **A refresh MERGES, never replaces (2026-09-06, found live in the browser):** the page unions the re-read rows into the run's own rows by `EventId` and rebuilds the graph, because a Live run carries its site rows inline while the same rows reach central's audit store by telemetry ~5–30 s later — a Replay read taken in between lacks them, and the old wholesale swap made an already-drawn node (a resolved cached DB write) vanish until the next manual refresh. The inline rows ARE the audited rows (`FlowTraceCollector` sinks the same `AuditEvent` objects the site writer persists), so the union is exact. Central method-script `Database.*` calls (`InboundDatabaseHelper`) are now audited (`DbOutbound`/`DbWrite`) — they were not. Rig demo: `docker/seed-flow-outbound-demo.sh` + `verify-delmia-notifier.sh` step I. **Trace steps ARE audit events** — `AuditChannel.ScriptTrace` with kinds `RouteCall` (central, **always-on** per `Route.To().Call`, joins the two halves of a Replay) and `ScriptRun` / `AttributeWrite` / `AttributeWait` (site, **gated** by a `bool Trace` riding beside `ParentExecutionId` on `RouteToCallRequest` / `ScriptCallRequest` / `SetStaticAttributeCommand` / `AttributeValueChanged`; proto fields additive, `site_command.proto` imports `sitestream.proto`). A Live run gets the site rows **inline** on `RouteToCallResponse.TraceEvents` (+ `ChildExecutionId`) because the 5 s telemetry cadence is too slow; Replay reads them from `AuditLog` (`GetTraceEventsAsync`). A value-change on a data-sourced attribute is a REAL tag write; the Instance Actor's **trace arm** (`SiteRuntime:TraceArmWindowSeconds`, 30) stamps the device echo with the writer's execution id so the triggered run is parented and traced, and central polls the site's new `PullTraceEvents` RPC (point read, not reconciliation) for it. Execution path is four management commands on the **per-node `ManagementActor`** (`FlowDebug*`; the three run commands are Deployer-only, Replay is wider) — a standby refuses the three run commands with **`STANDBY_NODE`** (shown verbatim); `ApiMethod.TraceAllCalls` (migration `AddApiMethodTraceAllCalls`, CLI `--trace-all-calls`) traces every real call to a method for later Replay (7–10 rows/call). Prediction before a run is a Roslyn syntax walk (`FlowShapePredictor`, REQ-SA-7, DB-free); the graph (`FlowStep`/`FlowGraphBuilder`, Commons) is a central projection, never a wire type; the renderer is custom SVG (`FlowGraphView`). Rig: `AuditLog:PerChannelRetentionDays:ScriptTrace=30` on both centrals; `verify-delmia-notifier.sh` step H proves live + replay. **Mixed-version caveat:** an older site ignores the flag → central `RouteCall` only, page says *site not traced*. **v1.2 (2026-09-06, `docs/plans/2026-09-06-flow-debugger-followups.md`):** a `Parked` External node offers **Retry / Discard in place** (same site-scope check, confirm and relay as the report pages, via `IFlowDebugService.RetryOutboundAsync`/`DiscardOutboundAsync`, then the page re-polls Replay until the node leaves Parked) and every folded node deep-links to `/site-calls/report?correlationId=` / `/notifications/report?correlationId=` (both pages accept it through additive `TrackedOperationIdFilter` / `NotificationIdFilter` query params and auto-open the row); register row 111 closed. **Trap closed the same day:** `FlowDebugService.PredictMethodAsync` used to resolve route targets with `GetAwaiter().GetResult()` inside the synchronous predictor walk — on the Blazor renderer sync context that DEADLOCKED the whole circuit (page inert, healthy websocket, no error) whenever a method routing to a site script was chosen; now a resolve-and-rewalk loop, pinned by a single-thread-pump test. Never block on a task from a Blazor event/lifecycle path. Browser checks of the page go through Playwright (`FlowDebuggerTests`, fixture login + an ephemeral method), not the login-disabled override. **Arch-reviewed 2026-09-06** (`docs/plans/2026-09-06-flow-debugger-arch-review.md`, remediation `docs/plans/2026-09-06-flow-debugger-arch-review-remediation.md`): the inline Live trace copy is now redacted and capped by the shared `FlowTraceCollector` (500 events **and** 1 MB of `DetailsJson`, F1), a method-entry Live run enforces the operator's site scope at route time (`RouteHelper.WithSiteScope` → `SITE_SCOPE_DENIED` → `ManagementUnauthorized`, F2), and the page/Replay opened to the `OperationalAudit` roles under the new `RequireFlowDebugger` policy while everything that executes stays Deployer-only (F3). Design `docs/plans/2026-09-05-flow-debugger-design.md`; plan `docs/plans/2026-09-05-flow-debugger.md`. **v1.3 (2026-09-08, `docs/plans/2026-09-08-flow-debugger-script-entry-design.md`):** the second entry point is site → instance → **script**; ValueChange/Conditional scripts are fired by writing the trigger's attribute (derived from the trigger config, not picked), every other kind is a direct traced `RouteToCall` with a `ParameterValueForm` from the script's `ParameterDefinitions` and one operator-attributed `RouteCall` root row (`FlowDebugRunScriptCommand`, Deployer-only, long-running); `run-value-change` stays as the attribute-level CLI escape hatch (fires Expression triggers). **Instance picker (2026-09-08, `docs/plans/2026-09-08-instance-picker-design.md`):** Flow Debugger and Debug View both replaced their flat instance `` with the shared **`InstancePicker`** combobox — a text field whose dropdown is the site's area tree (`InstanceTreeBuilder`, all areas collapsed on open), typed text filters and expands to the matches; `Areas`/`Instances` are compared by reference, so callers must assign the loaded lists once per site change, never per render, or the panel closes on every re-render. **v1.4 (2026-09-09, `docs/plans/2026-09-09-flow-debugger-step-logs-design.md`):** scripts can log — a `Log.Debug/Info/Warn/Error(message, exception?)` global on all four surfaces (site `ScriptGlobals`, inbound `InboundScriptContext`, the `ScriptCompileSurface` deploy gate as `CompileLog`, and both Test Run sandboxes/editor hosts, where it appends to the console pane), always reaching the node `ILogger` and emitting a `ScriptTrace`/**`ScriptLog`** audit row (one per line) **only when the run is traced**, so an untraced timer script costs no audit volume. `FlowGraphBuilder` **folds those rows onto the step that produced them** (`FlowStep.Logs`) and never draws them as nodes — attribution is `Extra.stepEventId`, pre-minted by `SetAttribute`/`WriteBatchAndWait`/`WaitInternal`/sync `ExternalSystem.Call` through an `AsyncLocal` `TraceStepScope`, else the execution's anchor row, else its first step, else `FlowGraph.UnattachedLogLines`; the runtime's own Information+ entries are captured for free by a `TraceCapturingLogger` decorator instead of editing every `_logger.LogWarning` call site. The failing step now carries the **whole exception** (`errorDetail = ex.ToString()` on the site `ScriptRun` row and on the central inbound row — the latter never on the HTTP body, which stays `SCRIPT_ERROR`). **The two halves are NOT gated alike:** the central inbound row's `errorDetail` is stamped on **every failing method request, traced or not** (`EndpointExtensions` stashes it on `HttpContext.Items`, `AuditWriteMiddleware` consumes it), bounded only by the redactor's `ApiInbound` cap `AuditLog:InboundMaxBytes` (1 MiB default; the 64 KB `ErrorCapBytes` is what bounds every OTHER channel's error rows, the site `ScriptRun` row included) — tracing only decides whether the row is later readable as a Flow Debugger step; the site `ScriptRun` `errorDetail` is **traced-only**, because an untraced run emits no `ScriptTrace` row at all, rendered as a red `Type: message` subtitle plus a **Log (n)** tab; the node badge is `✕ n ! n ≡ n` and the strip counts `Log: n errors · n warnings · n info` (a `Log.Error` is a line, not a failed step — it never moves the state chip). Bounded: `ScadaBridge:SiteRuntime:MaxLogLinesPerRun` / `ScadaBridge:InboundApi:MaxLogLinesPerRun` (200, validated > 0), 2 000-char messages, one closing `warn`/`runtime` row naming the dropped count, and a **low-priority inline lane** (`FlowTraceCollector.Add(evt, lowPriority: true)`, log rows stop 50 events short of the count cap and at 75 % of the byte budget, reserving the rest for the step rows written at run end) whose overflow sets `LogsTruncated` → the page badge *inline log lines capped — refresh outcomes pulls the rest*, which clears once a refresh merges in more log rows. **"Never `await` an audit write on a script path" still holds** — every log row is enqueued fire-and-continue, exactly like the 2026-09-06 cached-call telemetry fix. **Trap:** build `ScriptLogger` over the UNDECORATED logger — `TraceCapturingLogger` refuses to wrap another `TraceCapturingLogger` (it would emit two rows per line). CLI `flow-debug … --show-logs` + a `logs` column; rig demo `docker/seed-flow-log-demo.sh` + `verify-delmia-notifier.sh` step J. Mixed-version: an OLD central projects a NEW site's `ScriptLog` rows as `Unknown` nodes — upgrade central first, as always. - Health reports: 30s interval, 60s offline threshold, monotonic sequence numbers, raw error counts per interval. - Dead letter monitoring as a health metric. - Site Event Logging: 30-day retention, 1GB storage cap, daily purge, paginated queries with keyword search. **The cap measures `site_events` + its four indexes, NOT the consolidated LocalDb file** (register row 81, 2026-08-17): whole-file measurement made the trim unwinnable on a replicated node — each batch freed event pages while adding an equal count of oplog rows + tombstones to the same file, so it stopped 2.5x over a 64 MB cap and a node with a down peer could not enforce the cap at all. `dbstat` (the exact per-table measurement) is **NOT compiled into the bundled `SQLitePCLRaw.lib.e_sqlite3`** — probed and pinned by `SqliteCapabilityTests`, so don't reach for it — the footprint is modelled from sampled row width instead (−0.8%…+12.8%, biased high). Consequence: `MaxStorageMb` no longer bounds the data volume alone; LocalDb bookkeeping is separate overhead bounded by `MaxOplogRows`/`TombstoneRetention` and is deliberately not this component's job. Decision: `docs/plans/2026-08-17-site-event-log-cap-semantics-decision.md`. diff --git a/docs/plans/2026-07-08-deferred-work-register.md b/docs/plans/2026-07-08-deferred-work-register.md index 246d4b3c..7b83d60e 100644 --- a/docs/plans/2026-07-08-deferred-work-register.md +++ b/docs/plans/2026-07-08-deferred-work-register.md @@ -104,10 +104,13 @@ All 7 fix-now items landed via PLAN-04/05/06/07/08 (verified in review 08 round | 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-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 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. | +| 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` **and a `LogsTruncated` flag** on both records (step logs 2026-09-09 gave the site collector a second, low-priority lane whose overflow sets `LogsTruncated` rather than `Truncated`, so a site run that shed only log lines is invisible in exactly the same way — and the page already has the badge for it), a new field on `RouteToCallResponseDto` (regen via `docker/regen-proto.sh sitecommand`), and `FlowDebugRunner` ORing both into `FlowDebugRunResult.Truncated` / `FlowDebugRunResult.LogsTruncated`. | 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 | **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. | +| 114 | *Never issued.* The 2026-09-09 step-logs close-out minted two rows numbered **113** — this one and the "other actors' log lines" follow-up. The duplicates were renumbered **115** / **116** at final review (I2) and 114 was left unused rather than reshuffling every number after it; register numbers are permanent identifiers, cited from code comments and `CLAUDE.md`. | — | — | — | +| 115 | **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. | +| 116 | **`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 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. | +| 117 | **Flow Debugger site trace pull: `FlowDebugRunner.WriteAndPollAsync` fetches ONE bounded page with a fixed `since`** *(Low)*. The write-and-poll loop asks the site for `FlowDebugRunner.PullTraceEventsMax` rows per poll, always `since` the run start, and the site serves `ORDER BY OccurredAtUtc ASC LIMIT` — so the page is the OLDEST rows in the window, never a continuation of the previous one. Step logs made that reachable: one traced run can now emit up to 201 `ScriptLog` rows, so a handful of chatty runs inside the window can fill the page and push a later spawned run's `ScriptRun` row past the end of it, at which point the loop never sees the awaited run and reports a false `NO_TRIGGER_WITHIN_WINDOW` for a run that did happen. Final review I1 raised the cap 500 -> 2 000 (the site's own ceiling, `SiteStreamGrpcServer.MaxTraceEventsPerPull`), which makes it ~10x harder but does not remove it. The real fix is to PAGE — advance `since` to the last-seen `OccurredAtUtc` between polls (keeping the already-known ids so nothing is double-counted) — or to exclude `ScriptLog` from the awaited-run poll entirely and pull the log rows once, after the run has settled. | Final review of `docs/plans/2026-09-09-flow-debugger-step-logs.md` (I1); `src/ZB.MOM.WW.ScadaBridge.ManagementService/FlowDebug/FlowDebugRunner.cs` `WriteAndPollAsync` | 2 000 is the site's hard ceiling, so the headroom cannot be bought again with a bigger number; paging needs the poll loop to track a cursor and the awaited-run predicate to survive a partial view, which is more than the raise was worth at review time. | The first `NO_TRIGGER_WITHIN_WINDOW` reported for a run whose Replay of the same root DOES show the spawned `ScriptRun`. | +| 118 | **Pre-existing bUnit flake: `CentralUI.Tests.Pages.NotificationReportDetailModalTests.CloseButton_DismissesModal` (~10 %)** *(Low)*. Fails intermittently with `UnknownEventHandlerIdException` — the test resolves the close button once and clicks it after a re-render has already retired that element's handler id. Not caused by the step-logs work: the file is untouched since `40944a0d`. The fix is a one-liner — re-`Find` the button immediately before the click (the pattern the other modal tests already use) rather than reusing an element captured earlier in the test. | Observed during the step-logs full-suite runs, 2026-09-09 | It is a test-only race with a known cause and a known fix; it was out of scope for a remediation pass whose rule was to touch only the files under review. | Next time `CentralUI.Tests` is worked on, or the first time the flake blocks a gate run. | | 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. | — | ## Resolved (verified against the code 2026-07-10) diff --git a/docs/requirements/Component-InboundAPI.md b/docs/requirements/Component-InboundAPI.md index 50db911a..3f935292 100644 --- a/docs/requirements/Component-InboundAPI.md +++ b/docs/requirements/Component-InboundAPI.md @@ -317,10 +317,21 @@ backed by `InboundScriptLogger`: `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. +on the ordinary HTTP path via `HttpContext.Items[AuditWriteMiddleware.ErrorDetailItemKey]` — 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. + +**Note the asymmetry with the site half, which is easy to get wrong:** the inbound row's +`errorDetail` is written on **every failing method request**, traced or not — the middleware stamps +it whenever the script faulted, so it is not gated on `TraceAllCalls` or on a Live run (those only +decide whether the row is later *readable as a Flow Debugger step*). Its size is bounded by the +redactor's truncation stage, which for an `ApiInbound` row selects `AuditLog:InboundMaxBytes` +(1 MiB default — `SelectCap` gives this channel its own ceiling instead of the 64 KB +`ErrorCapBytes` other channels' error rows get), so a deep stack is truncated there rather than +dropped. The **site** `ScriptRun` row's `errorDetail`, by contrast, is **traced-only** — an +untraced site script run emits no `ScriptTrace` row at all, so there is nothing to carry it; that +row, being a `ScriptTrace` error row, is the one bounded at the 64 KB `ErrorCapBytes`. ### 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. diff --git a/src/ZB.MOM.WW.ScadaBridge.CLI/Commands/FlowDebugTableProjection.cs b/src/ZB.MOM.WW.ScadaBridge.CLI/Commands/FlowDebugTableProjection.cs index 13a59599..00ce98fa 100644 --- a/src/ZB.MOM.WW.ScadaBridge.CLI/Commands/FlowDebugTableProjection.cs +++ b/src/ZB.MOM.WW.ScadaBridge.CLI/Commands/FlowDebugTableProjection.cs @@ -29,7 +29,7 @@ namespace ZB.MOM.WW.ScadaBridge.CLI.Commands; /// renderer special-cases a single-property { "note": … } row to print it that way /// instead of padding it into a table cell. A trailing note row (the same special case) /// reports a failed / incomplete run (with the error code verbatim, e.g. STANDBY_NODE) -/// or a truncated event list. +/// or a truncated event list — and, separately, an inline log-line cap (logsTruncated). /// /// /// JSON output is never touched — --format json gets the full raw result. @@ -72,6 +72,11 @@ internal static class FlowDebugTableProjection } var truncated = TryGetPropertyCI(root, "truncated", out var t) && t.ValueKind == JsonValueKind.True; + // Step logs (design 2026-09-09 D7): the inline copy sheds low-priority ScriptLog rows + // BEFORE it sheds step rows, so `logsTruncated` is a separate signal from `truncated` + // and needs its own note — the audit rows are complete, so a replay shows every line. + var logsTruncated = TryGetPropertyCI(root, "logsTruncated", out var lt) + && lt.ValueKind == JsonValueKind.True; var rows = ProjectSteps(events, truncated, showLogs); if (rows == null) @@ -98,6 +103,10 @@ internal static class FlowDebugTableProjection if (truncated) notes.Add("event list truncated — the audit rows remain complete (audit tree --execution-id )"); + // Final review M8: the page shows this; the CLI silently dropped it. + if (logsTruncated) + notes.Add("inline log lines capped — replay pulls the rest"); + if (notes.Count > 0) rows.Add(new JsonObject { ["note"] = JsonValue.Create(string.Join("; ", notes)) }); diff --git a/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Deployment/FlowStepDetail.razor b/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Deployment/FlowStepDetail.razor index 1f74b668..4c1a12de 100644 --- a/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Deployment/FlowStepDetail.razor +++ b/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Deployment/FlowStepDetail.razor @@ -372,31 +372,21 @@ }; } - /// First line of the exception detail — Namespace.Type: message for a .NET ToString(). - private string FirstDetailLine - => Step?.ErrorDetail is { } d ? d.Split('\n')[0].Trim('\r', ' ') : string.Empty; + /// + /// The parsed header of the captured exception detail (final review M1: the shared + /// , so this panel and the graph node name the SAME exception — + /// the innermost of a " ---> " chain, where this panel used to show the outermost). + /// The type is NOT shortened here: the node badge is the place that strips the namespace. + /// + private (string Type, string Message)? ExceptionHead + => ExceptionHeader.Parse(Step?.ErrorDetail, shortenType: false); - /// The exception's type, shown in full here (the node badge is the place that shortens it). - private string ExceptionTypeName - { - get - { - var line = FirstDetailLine; - var i = line.IndexOf(": ", StringComparison.Ordinal); - return i > 0 ? line[..i] : line; - } - } + /// The exception's type, shown in full here. + private string ExceptionTypeName => ExceptionHead?.Type ?? string.Empty; /// The exception's message; falls back to the step's own error summary if the detail is not the usual shape. private string ExceptionMessageText - { - get - { - var line = FirstDetailLine; - var i = line.IndexOf(": ", StringComparison.Ordinal); - return i > 0 ? line[(i + 2)..] : (Step?.ErrorMessage ?? string.Empty); - } - } + => ExceptionHead is { Message.Length: > 0 } head ? head.Message : (Step?.ErrorMessage ?? string.Empty); /// Lines shown under the current filter — Warn + hides debug and info, keeping anything unrecognised. private IEnumerable VisibleLogLines diff --git a/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Pages/Deployment/FlowDebugger.razor.cs b/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Pages/Deployment/FlowDebugger.razor.cs index 6d2369f6..695efe69 100644 --- a/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Pages/Deployment/FlowDebugger.razor.cs +++ b/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Pages/Deployment/FlowDebugger.razor.cs @@ -690,7 +690,10 @@ public partial class FlowDebugger : ComponentBase, IDisposable // row the run did not already have, the page is no longer short of lines and the flag // clears. Until then it stays: the site's rows reach central's audit store by telemetry // 5-30 s later, so a refresh that adds nothing proves nothing. - var logsTruncated = (_raw.LogsTruncated || outcome.Raw?.LogsTruncated == true) + // Final review M7: read the OUTCOME's own flag — FlowDebugService copies the raw result's + // onto it precisely so a caller need not unwrap Raw, and reading Raw here left the record + // member with no consumer. + var logsTruncated = (_raw.LogsTruncated || outcome.LogsTruncated) && CountLogRows(merged) <= CountLogRows(_raw.Events); _raw = _raw with { Events = merged, Truncated = truncated, LogsTruncated = logsTruncated }; _graph = FlowGraphBuilder.Build(merged, truncated, logsTruncated); diff --git a/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Shared/FlowGraphView.razor.cs b/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Shared/FlowGraphView.razor.cs index 3b2d1ceb..556f8e7e 100644 --- a/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Shared/FlowGraphView.razor.cs +++ b/src/ZB.MOM.WW.ScadaBridge.CentralUI/Components/Shared/FlowGraphView.razor.cs @@ -272,37 +272,18 @@ public partial class FlowGraphView : ComponentBase /// /// The subtitle a failed or timed-out step shows instead of its own: {Type}: {message}, where - /// the type is the exception's name without its namespace, parsed from the first line of the captured - /// (a .NET ToString() opens with Namespace.Type: message). - /// A wrapper's first line chains its inner exceptions with " ---> "; the LAST segment is taken, - /// since the innermost exception is the one the script author has to act on. The namespace is stripped - /// only from the head of the type name — any generic arity/argument suffix (`1[System.String]) - /// is kept verbatim. Falls back to the line itself when it carries no ": ", and to - /// when there is no detail. Null for every non-failed step. + /// the type is the exception's name without its namespace. Parsing is + /// (final review M1 — the same parser the step detail panel + /// uses), which takes the first line of the captured and follows + /// its " ---> " chain to the innermost exception. Falls back to the line itself when it + /// carries no ": ", and to when there is no usable detail. + /// Null for every non-failed step. /// internal static string? ExceptionSubtitle(FlowStep s) { if (s.Outcome is not (FlowStepOutcome.Failed or FlowStepOutcome.TimedOut)) return null; - if (string.IsNullOrWhiteSpace(s.ErrorDetail)) return s.ErrorMessage; - - var first = s.ErrorDetail.Split('\n', 2)[0].TrimEnd('\r').Trim(); - // A wrapper (AggregateException, a rethrow) chains inner exceptions on the same line — the last is innermost. - var inner = first.LastIndexOf(" ---> ", StringComparison.Ordinal); - if (inner >= 0) first = first[(inner + " ---> ".Length)..].Trim(); - if (first.Length == 0) return s.ErrorMessage; - - var split = first.IndexOf(": ", StringComparison.Ordinal); - if (split < 0) return first; - - var type = first[..split]; - var message = first[(split + 2)..]; - // Shorten only the leading namespace: everything from a generic marker on is part of the name. - var generic = type.IndexOfAny(['`', '[']); - var head = generic < 0 ? type : type[..generic]; - var dot = head.LastIndexOf('.'); - if (dot >= 0 && dot < head.Length - 1) - type = head[(dot + 1)..] + (generic < 0 ? string.Empty : type[generic..]); - return type + ": " + message; + if (ExceptionHeader.Parse(s.ErrorDetail, shortenType: true) is not { } head) return s.ErrorMessage; + return head.Message.Length == 0 ? head.Type : head.Type + ": " + head.Message; } private static string Eyebrow(FlowLayoutNode n) => n.Kind switch diff --git a/src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/ExceptionHeader.cs b/src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/ExceptionHeader.cs new file mode 100644 index 00000000..4f3352b3 --- /dev/null +++ b/src/ZB.MOM.WW.ScadaBridge.Commons/Types/Debugging/ExceptionHeader.cs @@ -0,0 +1,62 @@ +namespace ZB.MOM.WW.ScadaBridge.Commons.Types.Debugging; + +/// +/// Flow Debugger (final review M1): the ONE parser for the header line of a captured +/// exception detail. A .NET Exception.ToString() opens with +/// Namespace.Type: message, and a wrapper (an AggregateException, a rethrow) +/// chains its inner exceptions on that same first line with " ---> ". +/// +/// +/// Two surfaces render that header — the graph node's subtitle (namespace stripped, so the +/// badge stays narrow) and the step detail panel's exception block (type in full) — and they +/// had drifted: the panel showed the OUTERMOST exception while the node showed the innermost. +/// Both now call this, so they always agree on which exception is being named. +/// +/// +public static class ExceptionHeader +{ + private const string InnerMarker = " ---> "; + + /// + /// Parses the innermost exception's type and message out of . + /// Takes the first line, follows the " ---> " chain to its LAST segment (the + /// innermost exception, which is the one a script author has to act on) and splits it on + /// the first ": ". + /// + /// The captured detail (a full ToString()), or null. + /// + /// When true the namespace is stripped from the head of the type name — only the head, + /// so a generic arity/argument suffix (`1[System.String]) is kept verbatim. + /// + /// + /// The type and message; the whole line as the type with an EMPTY message when the line + /// carries no ": "; null when there is no detail, or nothing left after the chain + /// is followed (callers fall back to their own error summary in both those cases). + /// + public static (string Type, string Message)? Parse(string? detail, bool shortenType) + { + if (string.IsNullOrWhiteSpace(detail)) return null; + + var first = detail.Split('\n', 2)[0].TrimEnd('\r').Trim(); + var inner = first.LastIndexOf(InnerMarker, StringComparison.Ordinal); + if (inner >= 0) first = first[(inner + InnerMarker.Length)..].Trim(); + if (first.Length == 0) return null; + + var split = first.IndexOf(": ", StringComparison.Ordinal); + if (split < 0) return (first, string.Empty); + + var type = first[..split]; + var message = first[(split + 2)..]; + if (!shortenType) return (type, message); + + // Shorten only the leading namespace: everything from a generic marker on is part of the name. + var generic = type.IndexOfAny(['`', '[']); + var head = generic < 0 ? type : type[..generic]; + var dot = head.LastIndexOf('.'); + if (dot >= 0 && dot < head.Length - 1) + { + type = head[(dot + 1)..] + (generic < 0 ? string.Empty : type[generic..]); + } + return (type, message); + } +} diff --git a/src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundScriptLogger.cs b/src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundScriptLogger.cs index 34967224..852c17ed 100644 --- a/src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundScriptLogger.cs +++ b/src/ZB.MOM.WW.ScadaBridge.InboundAPI/InboundScriptLogger.cs @@ -209,11 +209,20 @@ public sealed class InboundScriptLogger } } + /// + /// Applies the per-message cap, marking a truncated message with a trailing ellipsis. + /// + /// Final review M2 — mirrors the site runtime's ScriptLogger.Clip: cuts one char + /// short when the cap would land between the two halves of a surrogate pair, so an emoji + /// straddling the boundary is dropped whole rather than leaving a lone surrogate that breaks + /// JSON serialization downstream. + /// private static string Truncate(string? message) { if (string.IsNullOrEmpty(message)) return string.Empty; - return message.Length <= MaxMessageChars - ? message - : string.Concat(message.AsSpan(0, MaxMessageChars), "…"); + if (message.Length <= MaxMessageChars) return message; + + var keep = char.IsHighSurrogate(message[MaxMessageChars - 1]) ? MaxMessageChars - 1 : MaxMessageChars; + return string.Concat(message.AsSpan(0, keep), "…"); } } diff --git a/src/ZB.MOM.WW.ScadaBridge.ManagementService/FlowDebug/FlowDebugRunner.cs b/src/ZB.MOM.WW.ScadaBridge.ManagementService/FlowDebug/FlowDebugRunner.cs index 4498615b..3312e745 100644 --- a/src/ZB.MOM.WW.ScadaBridge.ManagementService/FlowDebug/FlowDebugRunner.cs +++ b/src/ZB.MOM.WW.ScadaBridge.ManagementService/FlowDebug/FlowDebugRunner.cs @@ -82,6 +82,26 @@ public sealed class FlowDebugRunner /// Quiet period after the last new row before a value-change run is declared complete. public static readonly TimeSpan SettleWindow = TimeSpan.FromSeconds(2); + /// + /// Row cap asked of the site on each poll — the + /// site's own ceiling (SiteStreamGrpcServer.MaxTraceEventsPerPull = 2000; a larger + /// max_events is rejected InvalidArgument), so this asks for everything the site + /// will serve. + /// + /// + /// Final review I1: this was 500, which was ample before step logs but is not any more. The + /// site query is ORDER BY OccurredAtUtc ASC LIMIT, so the page is the OLDEST rows in + /// the window — and a single traced run now emits up to 201 ScriptLog rows (design + /// §3, MaxLogLinesPerRun + the closing dropped-count row). Two chatty runs could + /// therefore fill a 500-row page and push a later spawned run's ScriptRun row past the + /// end of it, making report a false + /// for a run that did happen. 2000 makes that ~10x harder; the + /// real fix (paging by last-seen timestamp, or excluding ScriptLog from the awaited-run + /// poll) is deferred-work register row 117. + /// + /// + public const int PullTraceEventsMax = 2000; + private readonly ILogger _logger; private readonly Func _delay; private readonly Func _now; @@ -487,7 +507,7 @@ public sealed class FlowDebugRunner var d = AuditDetailsCodec.Deserialize(e.DetailsJson); if (d.ExecutionId is { } x) ids.Add(x); } - var pulled = await puller.PullAsync(site.SiteIdentifier, ids.Take(64).ToList(), since, 500, ct).ConfigureAwait(false); + var pulled = await puller.PullAsync(site.SiteIdentifier, ids.Take(64).ToList(), since, PullTraceEventsMax, ct).ConfigureAwait(false); var added = false; foreach (var e in pulled) { diff --git a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptLogger.cs b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptLogger.cs index e2a44bd4..743d314d 100644 --- a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptLogger.cs +++ b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptLogger.cs @@ -157,7 +157,11 @@ public sealed class ScriptLogger try { - _emit("warn", "runtime", $"Log truncated: {n} line(s) dropped past the per-run cap of {_maxLines}", null, null); + // Final review M3: worded identically to the central InboundScriptLogger's closing row, + // so the two surfaces read the same in the step-log panel (only the option key differs). + _emit("warn", "runtime", + $"log line cap reached - {n} further log line(s) were not captured " + + $"(ScadaBridge:SiteRuntime:MaxLogLinesPerRun = {_maxLines})", null, null); } catch { diff --git a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs index 2fc29b44..3f119e4c 100644 --- a/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs +++ b/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptRunLauncher.cs @@ -432,7 +432,8 @@ internal static class ScriptRunLauncher var state = await compiledScript.RunAsync(globals, cts.Token); // Step logs (design D7): close the run's log BEFORE the anchor row, so the closing - // "N line(s) dropped" row precedes the ScriptRun in emission order on every path. + // "log line cap reached - N further log line(s)…" row precedes the ScriptRun in + // emission order on every path. context.Log.FlushDropped(); // Flow Debugger: the ScriptRun row goes into the collector BEFORE the reply so the @@ -705,6 +706,12 @@ internal static class ScriptRunLauncher timeout, instanceName, logger, + // Final review M6: name the source so ScriptRuntimeContext's `_logTarget` derives + // the alarm this on-trigger run belongs to ("AlarmActor:Foo" -> "Foo") — without + // it every Log.* line from an alarm script was attributed to the INSTANCE, not the + // alarm. `scriptName` above is already the "AlarmActor:{alarmName}" source key, so + // it is passed as-is (re-prefixing it would leave "AlarmActor:" in the target). + sourceScript: scriptName, // ParentExecutionId tag-cascade: the // alarm on-trigger run mints its own fresh ExecutionId (the // ctor's `?? NewGuid()` fallback) and records the firing diff --git a/tests/ZB.MOM.WW.ScadaBridge.CLI.Tests/FlowDebugCommandsTests.cs b/tests/ZB.MOM.WW.ScadaBridge.CLI.Tests/FlowDebugCommandsTests.cs index 3fac25fe..59a56108 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.CLI.Tests/FlowDebugCommandsTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.CLI.Tests/FlowDebugCommandsTests.cs @@ -159,7 +159,8 @@ public class FlowDebugCommandsTests /// and canonical types with the server's camelCase policy, so /// a rename on either fails this test instead of silently blanking a column. /// - private static string RealPayload(bool completed, string? errorCode, string? error, bool truncated) + private static string RealPayload( + bool completed, string? errorCode, string? error, bool truncated, bool logsTruncated = false) { var root = Guid.NewGuid(); var child = Guid.NewGuid(); @@ -180,7 +181,7 @@ public class FlowDebugCommandsTests }; var result = new FlowDebugRunResult(root, completed, error, errorCode, events, truncated, - new DateTimeOffset(t0), new DateTimeOffset(t0.AddSeconds(1))); + new DateTimeOffset(t0), new DateTimeOffset(t0.AddSeconds(1)), logsTruncated); return JsonSerializer.Serialize(result, CamelCase); } @@ -241,6 +242,33 @@ public class FlowDebugCommandsTests Assert.Contains("audit tree", last.GetProperty("note").GetString()); } + [Fact] + public void Projection_LogsTruncatedRun_NotesThatReplayPullsTheRest() + { + // Final review M8: `logsTruncated` is a SEPARATE signal from `truncated` (the inline + // collector sheds low-priority ScriptLog rows before it sheds step rows). The page shows + // it; the CLI used to drop it silently. + var projected = FlowDebugTableProjection.ProjectEvents( + RealPayload(completed: true, null, null, truncated: false, logsTruncated: true)); + + using var doc = JsonDocument.Parse(projected); + var rows = doc.RootElement.EnumerateArray().ToList(); + Assert.Equal(5, rows.Count); // the four steps plus the note + Assert.Equal("inline log lines capped — replay pulls the rest", rows[^1].GetProperty("note").GetString()); + } + + [Fact] + public void Projection_BothTruncationFlags_AreReportedTogether() + { + var projected = FlowDebugTableProjection.ProjectEvents( + RealPayload(completed: true, null, null, truncated: true, logsTruncated: true)); + + using var doc = JsonDocument.Parse(projected); + var note = doc.RootElement.EnumerateArray().Last().GetProperty("note").GetString(); + Assert.Contains("event list truncated", note); + Assert.Contains("inline log lines capped — replay pulls the rest", note); + } + [Fact] public void Projection_LeavesNonMatchingBodiesUntouched() { diff --git a/tests/ZB.MOM.WW.ScadaBridge.CentralUI.Tests/Deployment/FlowStepDetailTests.cs b/tests/ZB.MOM.WW.ScadaBridge.CentralUI.Tests/Deployment/FlowStepDetailTests.cs index 1c805e22..38a60bc7 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.CentralUI.Tests/Deployment/FlowStepDetailTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.CentralUI.Tests/Deployment/FlowStepDetailTests.cs @@ -254,6 +254,27 @@ public class FlowStepDetailTests : BunitContext Assert.NotNull(cut.Find("[data-test=flow-step-exception-copy]")); } + [Fact] + public void WrappedException_TheBlockHeaderNamesTheINNERMOSTType_InFull() + { + // Final review M1: the panel used to parse the OUTERMOST exception of a " ---> " chain + // while the graph node's subtitle showed the innermost — the two now share + // ExceptionHeader, which always follows the chain to its end. The panel still shows the + // type with its namespace (only the node badge shortens it), and the raw detail is + // untouched, so the wrapper is still visible in the 
.
+        const string wrapped =
+            "System.AggregateException: One or more errors occurred. (Recipe 42 rejected by Galaxy (code 7)) " +
+            "---> ZB.Scada.RecipeRejectedException: Recipe 42 rejected by Galaxy (code 7)\n" +
+            "   at Submission#0.<>d__0.MoveNext()";
+        var step = ScriptStep(FlowStepOutcome.Failed, "ProcessRecipeDownload", Guid.NewGuid(), [], wrapped);
+        var cut = Render(p => p.Add(x => x.Step, step));
+
+        var exc = cut.Find("[data-test=flow-step-exception]");
+        Assert.Equal("ZB.Scada.RecipeRejectedException", exc.QuerySelector(".fsd-exc-type")!.TextContent.Trim());
+        Assert.Equal("Recipe 42 rejected by Galaxy (code 7)", exc.QuerySelector(".fsd-exc-message")!.TextContent.Trim());
+        Assert.Contains("System.AggregateException", exc.QuerySelector("pre")!.TextContent);
+    }
+
     [Fact]
     public void OkStepWithLines_OpensOnInput()
     {
diff --git a/tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/ExceptionHeaderTests.cs b/tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/ExceptionHeaderTests.cs
new file mode 100644
index 00000000..45a129a2
--- /dev/null
+++ b/tests/ZB.MOM.WW.ScadaBridge.Commons.Tests/Debugging/ExceptionHeaderTests.cs
@@ -0,0 +1,71 @@
+using ZB.MOM.WW.ScadaBridge.Commons.Types.Debugging;
+
+namespace ZB.MOM.WW.ScadaBridge.Commons.Tests.Debugging;
+
+/// 
+/// Final review M1: the ONE parser behind the graph node's exception subtitle and the step
+/// detail panel's exception block. Before it, the panel showed the OUTERMOST exception of a
+/// wrapped chain while the node showed the innermost — the two now agree by construction.
+/// 
+public class ExceptionHeaderTests
+{
+    [Fact]
+    public void Parse_PlainDetail_SplitsTypeFromMessage_AndShortensOnlyWhenAsked()
+    {
+        const string detail = "System.InvalidOperationException: Recipe 42 rejected\n   at X.Y()";
+
+        Assert.Equal(("InvalidOperationException", "Recipe 42 rejected"), ExceptionHeader.Parse(detail, shortenType: true));
+        Assert.Equal(("System.InvalidOperationException", "Recipe 42 rejected"), ExceptionHeader.Parse(detail, shortenType: false));
+    }
+
+    [Fact]
+    public void Parse_WrappedChain_TakesTheINNERMOSTException()
+    {
+        const string detail = "A.Outer: outer ---> B.Middle: middle ---> C.Innermost: the real one\n   at X";
+
+        Assert.Equal(("Innermost", "the real one"), ExceptionHeader.Parse(detail, shortenType: true));
+        // The panel keeps the namespace but still names the innermost exception, not the wrapper.
+        Assert.Equal(("C.Innermost", "the real one"), ExceptionHeader.Parse(detail, shortenType: false));
+    }
+
+    [Fact]
+    public void Parse_GenericType_KeepsTheArityAndArgumentsVerbatim_ShorteningOnlyTheHead()
+    {
+        Assert.Equal(("RecipeException`1[System.String]", "msg"),
+            ExceptionHeader.Parse("MyApp.RecipeException`1[System.String]: msg", shortenType: true));
+        Assert.Equal(("RecipeException`1[System.String]", "msg"),
+            ExceptionHeader.Parse("RecipeException`1[System.String]: msg", shortenType: true));
+    }
+
+    [Fact]
+    public void Parse_ChainMarkerIsMatchedAfterTrimming_SoATrailingMarkerIsNotAChain()
+    {
+        // The first line is trimmed BEFORE the " ---> " chain is walked (behaviour carried over
+        // verbatim from the FlowGraphView original), so a detail ending in the marker keeps it as
+        // part of the message rather than resolving to an empty innermost segment.
+        Assert.Equal(("Outer", "outer --->"), ExceptionHeader.Parse("A.Outer: outer ---> ", shortenType: true));
+    }
+
+    [Fact]
+    public void Parse_LineWithoutAColon_IsAllTypeAndNoMessage()
+    {
+        Assert.Equal(("SomethingWentWrong", string.Empty), ExceptionHeader.Parse("SomethingWentWrong", shortenType: true));
+    }
+
+    [Fact]
+    public void Parse_CrLfDetail_TrimsTheCarriageReturnOffTheFirstLine()
+    {
+        Assert.Equal(("TimeoutException", "took too long"),
+            ExceptionHeader.Parse("System.TimeoutException: took too long\r\n   at X\r\n", shortenType: true));
+    }
+
+    [Theory]
+    [InlineData(null)]
+    [InlineData("")]
+    [InlineData("   ")]
+    public void Parse_NothingUsable_ReturnsNull(string? detail)
+    {
+        Assert.Null(ExceptionHeader.Parse(detail, shortenType: true));
+        Assert.Null(ExceptionHeader.Parse(detail, shortenType: false));
+    }
+}
diff --git a/tests/ZB.MOM.WW.ScadaBridge.InboundAPI.Tests/InboundScriptLoggerTests.cs b/tests/ZB.MOM.WW.ScadaBridge.InboundAPI.Tests/InboundScriptLoggerTests.cs
new file mode 100644
index 00000000..9feb4b8f
--- /dev/null
+++ b/tests/ZB.MOM.WW.ScadaBridge.InboundAPI.Tests/InboundScriptLoggerTests.cs
@@ -0,0 +1,60 @@
+using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Logging.Abstractions;
+using ZB.MOM.WW.Audit;
+using ZB.MOM.WW.ScadaBridge.Commons.Types.Audit;
+
+namespace ZB.MOM.WW.ScadaBridge.InboundAPI.Tests;
+
+/// 
+/// Flow Debugger step logs (design 2026-09-09 D7): the central Log global's per-message cap.
+/// Final review M2 — the site runtime's ScriptLogger.Clip already backed off a char when the
+/// cap landed between the halves of a surrogate pair; this side did not, so an emoji straddling the
+/// boundary left a LONE surrogate on the row (which breaks JSON serialization further down the pipe).
+/// 
+public class InboundScriptLoggerTests
+{
+    private static (InboundScriptLogger Logger, List Rows) MakeTraced(int maxLines = 200)
+    {
+        var rows = new List();
+        var logger = new InboundScriptLogger(
+            NullLogger.Instance, rows.Add, maxLines, "DelmiaRecipeDownload", Guid.NewGuid(), "central-a");
+        return (logger, rows);
+    }
+
+    [Fact]
+    public void ASurrogatePairStraddlingTheCap_IsDroppedWhole()
+    {
+        var (logger, rows) = MakeTraced();
+        var straddling = new string('x', InboundScriptLogger.MaxMessageChars - 1) + "🚀" + new string('y', 10);
+
+        logger.Info(straddling);
+
+        var message = Assert.Single(rows).AsRow().RequestSummary!;
+        Assert.Equal(InboundScriptLogger.MaxMessageChars, message.Length);
+        Assert.EndsWith("…", message);
+        Assert.DoesNotContain(message, static c => char.IsSurrogate(c));
+    }
+
+    [Fact]
+    public void AnOverlongMessageWithNoSurrogateAtTheBoundary_KeepsTheFullCap()
+    {
+        var (logger, rows) = MakeTraced();
+
+        logger.Info(new string('x', InboundScriptLogger.MaxMessageChars + 500));
+
+        var message = Assert.Single(rows).AsRow().RequestSummary!;
+        Assert.Equal(InboundScriptLogger.MaxMessageChars + 1, message.Length); // cap + the ellipsis
+        Assert.Equal(new string('x', InboundScriptLogger.MaxMessageChars) + "…", message);
+    }
+
+    [Fact]
+    public void AMessageExactlyAtTheCap_PassesThroughUnclipped()
+    {
+        var (logger, rows) = MakeTraced();
+        var exact = new string('x', InboundScriptLogger.MaxMessageChars);
+
+        logger.Info(exact);
+
+        Assert.Equal(exact, Assert.Single(rows).AsRow().RequestSummary);
+    }
+}
diff --git a/tests/ZB.MOM.WW.ScadaBridge.ManagementService.Tests/FlowDebugRunnerTests.cs b/tests/ZB.MOM.WW.ScadaBridge.ManagementService.Tests/FlowDebugRunnerTests.cs
index d88d703d..e8759b12 100644
--- a/tests/ZB.MOM.WW.ScadaBridge.ManagementService.Tests/FlowDebugRunnerTests.cs
+++ b/tests/ZB.MOM.WW.ScadaBridge.ManagementService.Tests/FlowDebugRunnerTests.cs
@@ -250,6 +250,27 @@ public class FlowDebugRunnerTests
         Assert.Single(result.Events); // just the synthesized write row
     }
 
+    [Fact]
+    public async Task RunValueChange_AsksTheSiteForItsFullPage_NotTheOldFiveHundredRowCap()
+    {
+        // Final review I1: the site serves ORDER BY OccurredAtUtc ASC LIMIT, so the page is the
+        // OLDEST rows in the window. With step logs a single traced run can emit up to 201
+        // ScriptLog rows, so a 500-row request could push a later spawned run's ScriptRun row off
+        // the end of the page and make this loop report a false NO_TRIGGER_WITHIN_WINDOW. Ask for
+        // the site's own ceiling (SiteStreamGrpcServer.MaxTraceEventsPerPull) instead.
+        var (_, _, puller) = WireValueChange();
+        var maxima = new List();
+        puller.PullAsync("site-a", Arg.Any>(), Arg.Any(), Arg.Do(maxima.Add), Arg.Any())
+            .Returns(Array.Empty());
+
+        await Runner().RunValueChangeAsync(_services.BuildServiceProvider(),
+            new FlowDebugRunValueChangeCommand(5, "Status", "Running", WaitSeconds: 3), Deployer, CancellationToken.None);
+
+        Assert.NotEmpty(maxima);
+        Assert.All(maxima, m => Assert.Equal(2000, m));
+        Assert.Equal(2000, FlowDebugRunner.PullTraceEventsMax);
+    }
+
     [Fact]
     public async Task RunValueChange_OutOfScopeSite_IsRefused()
     {
diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/AlarmScriptLogTargetTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/AlarmScriptLogTargetTests.cs
new file mode 100644
index 00000000..5276b501
--- /dev/null
+++ b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Actors/AlarmScriptLogTargetTests.cs
@@ -0,0 +1,89 @@
+using Akka.Actor;
+using Akka.TestKit.Xunit2;
+using Microsoft.CodeAnalysis.CSharp.Scripting;
+using Microsoft.CodeAnalysis.Scripting;
+using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Logging.Abstractions;
+using ZB.MOM.WW.ScadaBridge.Commons.Messages.Streaming;
+using ZB.MOM.WW.ScadaBridge.Commons.Types.Flattening;
+using ZB.MOM.WW.ScadaBridge.SiteRuntime.Actors;
+using ZB.MOM.WW.ScadaBridge.SiteRuntime.Scripts;
+
+namespace ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests.Actors;
+
+/// 
+/// Final review M6: an alarm on-trigger run's ScriptRuntimeContext was built without a
+/// sourceScript, so the context's _logTarget — which names the script on every
+/// Log.* line and on the run's trace rows — fell back to the INSTANCE name. The launcher now
+/// passes the same AlarmActor:{alarmName} source key it already uses for this alarm's site
+/// events, from which the context derives the alarm's own name.
+/// 
+public class AlarmScriptLogTargetTests : TestKit, IDisposable
+{
+    private sealed record Entry(LogLevel Level, string Message);
+
+    /// A minimal recording logger — the alarm path hands its own ILogger down to the script logger.
+    private sealed class RecordingLogger : ILogger
+    {
+        public List Entries { get; } = [];
+
+        public IDisposable? BeginScope(TState state) where TState : notnull => null;
+
+        public bool IsEnabled(LogLevel logLevel) => true;
+
+        public void Log(LogLevel level, EventId eventId, TState state, Exception? exception, Func formatter)
+        {
+            lock (Entries) Entries.Add(new Entry(level, formatter(state, exception)));
+        }
+    }
+
+    private readonly SharedScriptLibrary _sharedLibrary = new(
+        new ScriptCompilationService(NullLogger.Instance),
+        NullLogger.Instance);
+
+    void IDisposable.Dispose() => Shutdown();
+
+    [Fact]
+    public void AlarmOnTriggerRun_AttributesItsLogLinesToTheALARM_NotJustTheInstance()
+    {
+        var options = new SiteRuntimeOptions
+        {
+            ScriptExecutionTimeoutSeconds = 10,
+            MaxScriptCallDepth = 10,
+        };
+        var scriptOptions = ScriptOptions.Default
+            .WithReferences(typeof(object).Assembly, typeof(Enumerable).Assembly, typeof(ScriptGlobals).Assembly)
+            .WithImports("System", "System.Threading.Tasks");
+        var compiled = CSharpScript.Create("Log.Info(\"alarm handler ran\"); return null;", scriptOptions, typeof(ScriptGlobals));
+        compiled.Compile();
+
+        var logger = new RecordingLogger();
+        using var scheduler = new ScriptExecutionScheduler(1);
+        var config = new ResolvedAlarm
+        {
+            CanonicalName = "HighTemp",
+            TriggerType = "ValueMatch",
+            TriggerConfiguration = "{\"attributeName\":\"Status\",\"matchValue\":\"Critical\"}",
+            PriorityLevel = 100,
+        };
+        var alarm = ActorOfAsTestActorRef(
+            Props.Create(() => new AlarmActor(
+                "HighTemp", "Inst1", CreateTestProbe().Ref, config, compiled, _sharedLibrary, options,
+                logger, null, null, null, null, null, scheduler, null)),
+            "alarm-logtarget-" + Guid.NewGuid().ToString("N"));
+
+        alarm.Tell(new AttributeValueChanged("Inst1", "Status", "Status", "Critical", "Good", DateTimeOffset.UtcNow));
+
+        AwaitAssert(
+            () =>
+            {
+                Entry[] snapshot;
+                lock (logger.Entries) snapshot = [.. logger.Entries];
+                // "[script] {Instance}/{Script} {ExecutionId}: {Message}" — the script half is the
+                // alarm's name because the launcher passed "AlarmActor:HighTemp" as the source.
+                Assert.Contains(snapshot, e => e.Message.StartsWith("[script] Inst1/HighTemp ", StringComparison.Ordinal)
+                    && e.Message.EndsWith(": alarm handler ran", StringComparison.Ordinal));
+            },
+            TimeSpan.FromSeconds(15));
+    }
+}
diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptLoggerTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptLoggerTests.cs
index 6c400c61..ec6bc731 100644
--- a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptLoggerTests.cs
+++ b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptLoggerTests.cs
@@ -159,7 +159,9 @@ public class ScriptLoggerTests
         var closing = rows[^1];
         Assert.Equal("warn", closing.Level);
         Assert.Equal("runtime", closing.Source);
-        Assert.Contains("2 line(s)", closing.Message);
+        // M3: worded identically to the central InboundScriptLogger closing row.
+        Assert.Contains("2 further log line(s) were not captured", closing.Message);
+        Assert.Contains("ScadaBridge:SiteRuntime:MaxLogLinesPerRun = 3", closing.Message);
         Assert.Null(closing.StepEventId);
 
         logger.FlushDropped();
@@ -302,7 +304,7 @@ public class ScriptLoggerTests
 
         Assert.Equal(2, rows.Count);
         logger.FlushDropped();
-        Assert.Contains("1 line(s)", rows[^1].Message);
+        Assert.Contains("1 further log line(s) were not captured", rows[^1].Message);
     }
 
     [Fact]
diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRunLauncherTraceTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRunLauncherTraceTests.cs
index bf96916e..c0065352 100644
--- a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRunLauncherTraceTests.cs
+++ b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRunLauncherTraceTests.cs
@@ -149,7 +149,7 @@ public class ScriptRunLauncherTraceTests : TestKit, IDisposable
         // One closing runtime warning naming the three dropped lines.
         var closing = Assert.Single(logs, e => Extra(e).LogSource == "runtime");
         Assert.Equal("warn", Extra(closing).LogLevel);
-        Assert.Contains("3 line(s) dropped", Row(closing).RequestSummary);
+        Assert.Contains("3 further log line(s) were not captured", Row(closing).RequestSummary);
 
         // Every log row — the closing one included — precedes the run's anchor row.
         var anchorIndex = rows.ToList().FindIndex(e => Row(e).Kind == AuditKind.ScriptRun);
diff --git a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRuntimeContextTraceEmissionTests.cs b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRuntimeContextTraceEmissionTests.cs
index 914847ff..0dde4161 100644
--- a/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRuntimeContextTraceEmissionTests.cs
+++ b/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRuntimeContextTraceEmissionTests.cs
@@ -701,7 +701,7 @@ public class ScriptRuntimeContextTraceEmissionTests : TestKit
         var extra = ScriptTraceExtra.TryParse(closing.Extra)!;
         Assert.Equal("warn", extra.LogLevel);
         Assert.Equal("runtime", extra.LogSource);
-        Assert.Contains("1 line(s) dropped", closing.RequestSummary);
+        Assert.Contains("1 further log line(s) were not captured", closing.RequestSummary);
     }
 
     /// 
@@ -780,7 +780,7 @@ public class ScriptRuntimeContextTraceEmissionTests : TestKit
         Assert.Equal(["from the caller", "shared"], rows.Select(e => Row(e).RequestSummary));
 
         parent.Log.FlushDropped();
-        Assert.Contains("2 line(s) dropped", Row(collector.Snapshot()[^1]).RequestSummary);
+        Assert.Contains("2 further log line(s) were not captured", Row(collector.Snapshot()[^1]).RequestSummary);
     }
 
     ///