Files
ScadaBridge/tests/ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests/Scripts/ScriptRunLauncherTraceTests.cs
T

160 lines
6.8 KiB
C#

using Akka.Actor;
using Akka.TestKit.Xunit2;
using Microsoft.CodeAnalysis.CSharp.Scripting;
using Microsoft.CodeAnalysis.Scripting;
using Microsoft.Extensions.Logging.Abstractions;
using ZB.MOM.WW.Audit;
using ZB.MOM.WW.ScadaBridge.Commons.Messages.ScriptExecution;
using ZB.MOM.WW.ScadaBridge.Commons.Types.Audit;
using ZB.MOM.WW.ScadaBridge.Commons.Types.Debugging;
using ZB.MOM.WW.ScadaBridge.Commons.Types.Enums;
using ZB.MOM.WW.ScadaBridge.Commons.Types.Scripts;
using ZB.MOM.WW.ScadaBridge.SiteRuntime.Scripts;
namespace ZB.MOM.WW.ScadaBridge.SiteRuntime.Tests.Scripts;
/// <summary>
/// Flow Debugger step logs (design 2026-09-09 D3/D7) at the launcher boundary: the
/// <c>ScriptRun</c> anchor row a traced run returns inline carries the failing run's full
/// exception detail (and deliberately none for a timeout), and the run's log lines are bounded
/// by <c>SiteRuntimeOptions.MaxLogLinesPerRun</c> with one closing row naming the drops — all
/// of it emitted BEFORE the anchor, so the Flow Debugger reads a run's lines in order.
/// </summary>
public class ScriptRunLauncherTraceTests : TestKit, IDisposable
{
/// <summary>Own pool per class (#18 seam), so a wedged body cannot strand the process-wide one.</summary>
private readonly ScriptExecutionScheduler _scheduler = new(4);
private readonly SharedScriptLibrary _sharedLibrary;
public ScriptRunLauncherTraceTests()
=> _sharedLibrary = new SharedScriptLibrary(
new ScriptCompilationService(NullLogger<ScriptCompilationService>.Instance),
NullLogger<SharedScriptLibrary>.Instance);
void IDisposable.Dispose()
{
Shutdown();
_scheduler.Dispose();
}
// ── helpers ──────────────────────────────────────────────────────────────────
private static Script<object?> CompileScript(string code)
{
var scriptOptions = ScriptOptions.Default
.WithReferences(typeof(object).Assembly, typeof(Enumerable).Assembly,
typeof(ScriptGlobals).Assembly)
.WithImports("System", "System.Collections.Generic", "System.Linq", "System.Threading.Tasks");
var script = CSharpScript.Create<object?>(code, scriptOptions, typeof(ScriptGlobals));
script.Compile();
return script;
}
private static AuditRowProjection.AuditRowValues Row(AuditEvent evt) => evt.AsRow();
private static ScriptTraceExtra Extra(AuditEvent evt) => ScriptTraceExtra.TryParse(Row(evt).Extra)!;
/// <summary>Runs one traced script to completion and returns the reply's inline trace rows.</summary>
private ScriptCallResult RunTraced(string body, SiteRuntimeOptions options)
{
var caller = CreateTestProbe();
ScriptRunLauncher.LaunchScript(
scriptName: "Runner",
instanceName: "Inst1",
compiledScript: CompileScript(body),
parameters: null,
callDepth: 0,
instanceActor: CreateTestProbe().Ref,
sharedScriptLibrary: _sharedLibrary,
options: options,
replyTo: caller.Ref,
correlationId: "corr-1",
completionTarget: CreateTestProbe().Ref,
siteCommunicationActor: null,
logger: NullLogger.Instance,
scope: ScriptScope.Root,
runId: 1,
healthCollector: null,
serviceProvider: null,
parentExecutionId: null,
executionTimeoutSeconds: null,
scheduler: _scheduler,
trace: true,
triggerExtra: null);
return caller.ExpectMsg<ScriptCallResult>(TimeSpan.FromSeconds(20));
}
private static SiteRuntimeOptions Options(int timeoutSeconds = 30, int maxLogLines = 200) => new()
{
MaxScriptCallDepth = 10,
ScriptExecutionTimeoutSeconds = timeoutSeconds,
StuckScriptGraceMs = 30000,
MaxLogLinesPerRun = maxLogLines,
};
private static AuditEvent ScriptRunRow(ScriptCallResult result)
=> Assert.Single(result.TraceEvents!, e => Row(e).Kind == AuditKind.ScriptRun);
// ── (a) a throwing run carries the exception's full detail ───────────────────
[Fact]
public void ThrowingTracedRun_ScriptRunRow_CarriesTheFullExceptionDetail()
{
var result = RunTraced("throw new InvalidOperationException(\"boom\");", Options());
Assert.False(result.Success);
var row = Row(ScriptRunRow(result));
Assert.Equal(AuditStatus.Failed, row.Status);
Assert.Contains("boom", row.ErrorMessage);
Assert.NotNull(row.ErrorDetail);
// Type name first, then the stack — the whole point of D3 over the one-line message.
Assert.StartsWith("System.InvalidOperationException", row.ErrorDetail);
Assert.Contains(" at ", row.ErrorDetail);
}
// ── (b) a timeout carries NO detail (the stack would be the launcher's) ──────
[Fact]
public void TimedOutTracedRun_ScriptRunRow_CarriesNoExceptionDetail()
{
var result = RunTraced(
"while (true) { await Task.Delay(25, CancellationToken); }",
Options(timeoutSeconds: 1));
Assert.False(result.Success);
var row = Row(ScriptRunRow(result));
Assert.Equal(AuditStatus.Failed, row.Status);
Assert.Contains("timed out", row.ErrorMessage);
Assert.Null(row.ErrorDetail);
}
// ── (c) the per-run line cap, its closing row, and emission order ────────────
[Fact]
public void TracedRun_CapsLogLines_AndEmitsTheClosingRowBeforeTheAnchor()
{
var result = RunTraced(
"Log.Info(\"a\"); Log.Info(\"b\"); Log.Info(\"c\"); Log.Info(\"d\"); Log.Info(\"e\"); return null;",
Options(maxLogLines: 2));
Assert.True(result.Success);
var rows = result.TraceEvents!;
var logs = rows.Where(e => Row(e).Kind == AuditKind.ScriptLog).ToList();
var scriptLines = logs.Where(e => Extra(e).LogSource == "script").ToList();
Assert.Equal(2, scriptLines.Count);
Assert.Equal(["a", "b"], scriptLines.Select(e => Row(e).RequestSummary));
// 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);
// Every log row — the closing one included — precedes the run's anchor row.
var anchorIndex = rows.ToList().FindIndex(e => Row(e).Kind == AuditKind.ScriptRun);
Assert.All(logs, e => Assert.True(rows.ToList().IndexOf(e) < anchorIndex));
Assert.Equal(logs.Count, anchorIndex);
}
}