docs+rig(flow-debugger): step logs v1.4 specs, register rows, FlowLogDemo seed + verification step J

This commit is contained in:
Joseph Doherty
2026-09-09 12:56:39 -04:00
parent f174725557
commit 82739ec912
12 changed files with 221 additions and 12 deletions
+10 -1
View File
@@ -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.