Joseph Doherty
ee8a8e9d3d
Task 5 code-review follow-ups: - I1: ExternalSystemHelper gates its TraceStepScope on a new isTraced ctor arg (default false for direct construction), not on `_traceSink is not null` — a traced run without an inline collector still writes durable ScriptLog rows that must name their step. - I2 (design §5): an inline shared script now SHARES its caller's ScriptLogger via the new `sharedLog` ctor param — one line cap, one anchor, one closing row. Consequence documented on the Log property: a shared script's lines carry the PARENT run's ExecutionId and land on the parent's ScriptRun node. - M3: TraceCapturingLogger swallows a throwing formatter — most of what it captures is best-effort "audit write failed" warnings logged from inside a catch block, and a formatting exception must not escape that path. - Tests: ApiCall step attribution, traced-without-collector, shared-script logger sharing, nested batch/wait scope attribution + unwind, throwing formatter; test (c) now also pins the anti-recursion property (EmitLog must log through the undecorated logger). CompileSurfaceParityTests stays red until Task 7 mirrors Log on ScriptCompileSurface.
96 lines
4.2 KiB
C#
96 lines
4.2 KiB
C#
using Microsoft.Extensions.Logging;
|
|
|
|
namespace ZB.MOM.WW.ScadaBridge.SiteRuntime.Scripts;
|
|
|
|
/// <summary>
|
|
/// Flow Debugger step logs (design 2026-09-09 D6): decorates the script context's
|
|
/// <see cref="ILogger"/> while a run is traced.
|
|
///
|
|
/// <para>Forwards EVERYTHING to the inner logger unchanged (the node's log file is unaffected by
|
|
/// tracing), and additionally copies <see cref="LogLevel.Information"/> and above into
|
|
/// <c>ScriptLog</c> rows with source <c>runtime</c>, attributed to the ambient
|
|
/// <see cref="TraceStepScope"/>. This is how the warnings the runtime logs on the script's behalf —
|
|
/// inside <c>SetAttribute</c>, <c>WriteBatchAndWait</c>, <c>WaitInternal</c>, the sync
|
|
/// <c>ExternalSystem.Call</c> — reach the Flow Debugger without editing each call site.</para>
|
|
///
|
|
/// <para>Debug and Trace are deliberately NOT captured (internal chatter, design D6), and the
|
|
/// per-run line cap of the sink applies to what is.</para>
|
|
///
|
|
/// <para>Installed only when the run is traced, so an untraced run keeps the bare inner logger.</para>
|
|
/// </summary>
|
|
public sealed class TraceCapturingLogger : ILogger
|
|
{
|
|
private readonly ILogger _inner;
|
|
private readonly ScriptLogger _sink;
|
|
|
|
/// <summary>Wraps <paramref name="inner"/> so that Information and above also reach <paramref name="sink"/>.</summary>
|
|
/// <param name="inner">The node logger every entry is forwarded to.</param>
|
|
/// <param name="sink">The run's <see cref="ScriptLogger"/>, which owns the caps and the row emitter.</param>
|
|
/// <exception cref="ArgumentNullException"><paramref name="inner"/> or <paramref name="sink"/> is null.</exception>
|
|
/// <exception cref="ArgumentException"><paramref name="inner"/> is itself a <see cref="TraceCapturingLogger"/>.</exception>
|
|
public TraceCapturingLogger(ILogger inner, ScriptLogger sink)
|
|
{
|
|
ArgumentNullException.ThrowIfNull(inner);
|
|
ArgumentNullException.ThrowIfNull(sink);
|
|
if (inner is TraceCapturingLogger)
|
|
{
|
|
throw new ArgumentException("inner is already a TraceCapturingLogger — wrapping twice would emit two rows per script line", nameof(inner));
|
|
}
|
|
|
|
_inner = inner;
|
|
_sink = sink;
|
|
}
|
|
|
|
/// <inheritdoc />
|
|
public IDisposable? BeginScope<TState>(TState state) where TState : notnull => _inner.BeginScope(state);
|
|
|
|
/// <summary>
|
|
/// Information and above are always enabled — they are trace data even when the node's minimum
|
|
/// level is Warning. Below Information the inner logger decides.
|
|
/// </summary>
|
|
/// <param name="level">The level being tested.</param>
|
|
/// <returns><see langword="true"/> when the entry should be produced.</returns>
|
|
public bool IsEnabled(LogLevel level) => level >= LogLevel.Information || _inner.IsEnabled(level);
|
|
|
|
/// <inheritdoc />
|
|
public void Log<TState>(LogLevel level, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
|
|
{
|
|
// Forward first, and only if the inner logger actually wants it: IsEnabled above lies
|
|
// upward for trace capture, so the node's own minimum level must be re-checked here.
|
|
if (_inner.IsEnabled(level))
|
|
{
|
|
_inner.Log(level, eventId, state, exception, formatter);
|
|
}
|
|
|
|
if (level < LogLevel.Information || level == LogLevel.None)
|
|
{
|
|
return;
|
|
}
|
|
|
|
var name = level switch
|
|
{
|
|
LogLevel.Information => "info",
|
|
LogLevel.Warning => "warn",
|
|
_ => "error",
|
|
};
|
|
|
|
string message;
|
|
try
|
|
{
|
|
message = formatter(state, exception);
|
|
}
|
|
catch
|
|
{
|
|
// Deliberate swallow: formatting is the CALLER's code, and a great many of the entries
|
|
// captured here are the runtime's own best-effort "audit write failed" warnings logged
|
|
// from inside a catch block. A throwing formatter escaping this decorator would replace
|
|
// the original failure with a formatting exception on a path whose whole contract is
|
|
// that it never throws. The line is dropped; the inner logger already saw (or refused)
|
|
// it above, unchanged.
|
|
return;
|
|
}
|
|
|
|
_sink.Runtime(name, message, exception);
|
|
}
|
|
}
|