Files
ScadaBridge/src/ZB.MOM.WW.ScadaBridge.SiteRuntime/Scripts/ScriptLogger.cs
T

197 lines
9.1 KiB
C#

using Microsoft.Extensions.Logging;
namespace ZB.MOM.WW.ScadaBridge.SiteRuntime.Scripts;
/// <summary>
/// The row-emitting callback a <see cref="ScriptLogger"/> uses: level name, source, message,
/// optional exception, owning step id (design 2026-09-09 D1/D2).
/// </summary>
/// <param name="level">Level name as it appears on the wire: <c>debug|info|warn|error</c>.</param>
/// <param name="source">Line origin: <c>script</c> (the author's own <c>Log.*</c> call) or <c>runtime</c>.</param>
/// <param name="message">The already-clipped message text.</param>
/// <param name="exception">The exception attached to the line, if any.</param>
/// <param name="stepEventId">The step row the line belongs to, or <see langword="null"/> to fall back to the run's anchor row.</param>
public delegate void ScriptLogEmitter(string level, string source, string message, Exception? exception, Guid? stepEventId);
/// <summary>
/// Flow Debugger step logs (design 2026-09-09 D4/D5/D7): the <c>Log</c> global site scripts call.
///
/// <para>Every line ALWAYS forwards to the node's <see cref="ILogger"/> — an untraced run is a
/// normal logging surface and pays nothing else. A <c>ScriptLog</c> audit row is emitted only
/// when the run is traced, i.e. only when the owning <c>ScriptRuntimeContext</c> supplied an
/// emitter; untraced runs construct the logger with a <see langword="null"/> emitter and the row
/// path is a single null check.</para>
///
/// <para><b>Bounded (D7).</b> At most <c>maxLines</c> rows per run — one <see cref="ScriptLogger"/>
/// instance is one run's counter, and inline shared scripts share the context, hence the counter —
/// plus a hard <see cref="MaxMessageChars"/> cap per message. Lines past the cap are counted and
/// dropped; <see cref="FlushDropped"/> emits the single closing warning that names the count.</para>
///
/// <para><b>Never throws into the script.</b> A logging or emitting failure is swallowed: this is a
/// debug observer, and a broken observer must not fail a production script run.</para>
/// </summary>
public sealed class ScriptLogger
{
/// <summary>Per-message character cap (design D7); longer messages are truncated and suffixed with an ellipsis.</summary>
public const int MaxMessageChars = 2_000;
private readonly ILogger _logger;
private readonly ScriptLogEmitter? _emit;
private readonly int _maxLines;
private readonly string _instance;
private readonly string _script;
private readonly Guid? _executionId;
private int _emitted;
private int _dropped;
/// <summary>Creates the <c>Log</c> global for one script run.</summary>
/// <param name="logger">The node logger every line forwards to, traced or not.</param>
/// <param name="emit">Row emitter; <see langword="null"/> when the run is not traced (no rows are produced).</param>
/// <param name="maxLines">Per-run row cap (design D7); must be greater than zero.</param>
/// <param name="instance">Instance unique name, for the structured log entry.</param>
/// <param name="script">Script name, for the structured log entry.</param>
/// <param name="executionId">The run's execution id, for the structured log entry.</param>
/// <exception cref="ArgumentNullException"><paramref name="logger"/> is null.</exception>
/// <exception cref="ArgumentOutOfRangeException"><paramref name="maxLines"/> is not greater than zero.</exception>
public ScriptLogger(ILogger logger, ScriptLogEmitter? emit, int maxLines, string instance, string script, Guid? executionId)
{
ArgumentNullException.ThrowIfNull(logger);
ArgumentOutOfRangeException.ThrowIfLessThan(maxLines, 1);
_logger = logger;
_emit = emit;
_maxLines = maxLines;
_instance = instance;
_script = script;
_executionId = executionId;
}
/// <summary>Logs a diagnostic line at Debug level.</summary>
/// <param name="message">The message text (clipped at <see cref="MaxMessageChars"/>).</param>
/// <param name="exception">An optional exception to attach to the line.</param>
public void Debug(string message, Exception? exception = null) => Write(LogLevel.Debug, "debug", message, exception);
/// <summary>Logs an informational line.</summary>
/// <param name="message">The message text (clipped at <see cref="MaxMessageChars"/>).</param>
/// <param name="exception">An optional exception to attach to the line.</param>
public void Info(string message, Exception? exception = null) => Write(LogLevel.Information, "info", message, exception);
/// <summary>Logs a warning line.</summary>
/// <param name="message">The message text (clipped at <see cref="MaxMessageChars"/>).</param>
/// <param name="exception">An optional exception to attach to the line.</param>
public void Warn(string message, Exception? exception = null) => Write(LogLevel.Warning, "warn", message, exception);
/// <summary>Logs an error line. Does not fail the run — the script decides what to do next.</summary>
/// <param name="message">The message text (clipped at <see cref="MaxMessageChars"/>).</param>
/// <param name="exception">An optional exception to attach to the line.</param>
public void Error(string message, Exception? exception = null) => Write(LogLevel.Error, "error", message, exception);
/// <summary>
/// Runtime-sourced line (fed by <see cref="TraceCapturingLogger"/>); same caps, source
/// <c>runtime</c>; does NOT forward to the <see cref="ILogger"/> — the caller already logged it,
/// and re-logging would loop back through the decorator.
/// </summary>
/// <param name="level">Level name (<c>info|warn|error</c>).</param>
/// <param name="message">The already-formatted message text.</param>
/// <param name="exception">The exception attached to the entry, if any.</param>
internal void Runtime(string level, string message, Exception? exception) => WriteRow(level, "runtime", message, exception);
/// <summary>Forwards to the node logger, then records the trace row (when traced).</summary>
private void Write(LogLevel level, string name, string message, Exception? exception)
{
message = Clip(message);
try
{
_logger.Log(level, exception, "[script] {Instance}/{Script} {ExecutionId}: {Message}", _instance, _script, _executionId, message);
}
catch
{
// Deliberate swallow: a failing logger sink must never propagate into the script body.
}
WriteRow(name, "script", message, exception);
}
/// <summary>Emits one trace row, subject to the per-run line cap.</summary>
private void WriteRow(string level, string source, string message, Exception? exception)
{
if (_emit is null)
{
return; // Untraced run: no rows, no counting.
}
if (Interlocked.Increment(ref _emitted) > _maxLines)
{
Interlocked.Increment(ref _dropped);
return;
}
try
{
_emit(level, source, Clip(message), exception, TraceStepScope.Current);
}
catch
{
// Deliberate swallow: the trace collector/audit writer is a debug observer, never a run failure.
}
}
/// <summary>
/// Run end: emits one closing warning naming the dropped count (nothing when none were
/// dropped). Bypasses the counter on purpose — it is the one row that must always land.
/// Idempotent: the count is cleared as it is reported, so a second call emits nothing.
/// </summary>
public void FlushDropped()
{
if (_emit is null)
{
return;
}
var n = Interlocked.Exchange(ref _dropped, 0);
if (n == 0)
{
return;
}
try
{
// 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
{
// Deliberate swallow: same reason as WriteRow — the observer must not fail the run.
}
}
/// <summary>
/// Applies the per-message cap, marking a truncated message with a trailing ellipsis.
///
/// <para>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. Re-clipping an already-clipped message
/// is a no-op, which matters because the script path clips once before logging and again
/// before emitting.</para>
/// </summary>
private static string Clip(string? m)
{
if (m is null)
{
return string.Empty;
}
if (m.Length <= MaxMessageChars)
{
return m;
}
var keep = char.IsHighSurrogate(m[MaxMessageChars - 1]) ? MaxMessageChars - 1 : MaxMessageChars;
return m[..keep] + "…";
}
}