diff --git a/src/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting.OutOfProcess/OutOfProcessScriptRunner.cs b/src/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting.OutOfProcess/OutOfProcessScriptRunner.cs index 723eb0a42..740bd84bf 100644 --- a/src/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting.OutOfProcess/OutOfProcessScriptRunner.cs +++ b/src/Core/ZB.MOM.WW.OtOpcUa.Core.Scripting.OutOfProcess/OutOfProcessScriptRunner.cs @@ -102,7 +102,7 @@ public sealed class OutOfProcessScriptRunner : IScriptRunner, IAsyncDisposable, private static readonly Counter TransportTimeoutCounter = OtOpcUaTelemetry.Meter.CreateCounter( "otopcua.script.ipc.timeouts", unit: "{eval}", - description: "Out-of-process evaluations answered 'script worker unresponsive': no result and no soft-deadline notice from the worker within T + G of submit — a starved or stalled worker, not a slow script (tag: kind; lmxopcua#827)."); + description: "Out-of-process evaluations answered 'script worker unresponsive' (lmxopcua#827; tags: kind, answer = stalled | retrigger). stalled: no result and no soft-deadline notice from the worker within T + G of submit — a starved or stalled worker, not a slow script; retrigger: a later trigger of the same script refused while that stalled run is still unanswered."); static OutOfProcessScriptRunner() { @@ -758,7 +758,12 @@ public sealed class OutOfProcessScriptRunner : IScriptRunner, IAsyncDisposable, private static ScriptRunOutcome Refused(string key, KeyState state) { if (Volatile.Read(ref state.StalledRun) is { IsCompleted: false } stalled) + { + // Counted, like the run it waits on (#827 review F5): it is not a script refusal, so not ScriptRunGuard's. + TransportTimeoutCounter.Add(1, new KeyValuePair("kind", KindTag(state.Kind)), + new KeyValuePair("answer", "retrigger")); return ScriptRunOutcome.Unavailable(ScriptRunOutcome.WorkerUnresponsiveReason) with { Recovery = stalled }; + } ScriptRunGuard.RefusedCounter.Add(1, new KeyValuePair("script", key)); return ScriptRunOutcome.Failed(ScriptRunGuard.PreviousRunStillRunningReason); } @@ -1014,6 +1019,9 @@ public sealed class OutOfProcessScriptRunner : IScriptRunner, IAsyncDisposable, public readonly string Source = source; + /// The seam (metric tags). + public readonly ScriptContextKind Kind = kind; + /// SHA-256 of (computed on first use; a benign race computes the same bytes). public byte[] Sha => _sha ??= SHA256.HashData(Encoding.UTF8.GetBytes(Source)); @@ -1021,7 +1029,7 @@ public sealed class OutOfProcessScriptRunner : IScriptRunner, IAsyncDisposable, public string ShaHex => _shaHex ??= Convert.ToHexString(Sha); /// The negative compile cache's key for this source (kind-scoped). - public string FailureKey => _failureKey ??= InProcessScriptRunner.ScopedKey(kind, ShaHex); + public string FailureKey => _failureKey ??= InProcessScriptRunner.ScopedKey(Kind, ShaHex); /// The slot order last used for this key (see ). public string[]? Paths; diff --git a/tests/Server/ZB.MOM.WW.OtOpcUa.ScriptWorker.Tests/WorkerSoftClockTests.cs b/tests/Server/ZB.MOM.WW.OtOpcUa.ScriptWorker.Tests/WorkerSoftClockTests.cs index f0da183bc..eb7631fac 100644 --- a/tests/Server/ZB.MOM.WW.OtOpcUa.ScriptWorker.Tests/WorkerSoftClockTests.cs +++ b/tests/Server/ZB.MOM.WW.OtOpcUa.ScriptWorker.Tests/WorkerSoftClockTests.cs @@ -87,6 +87,19 @@ public sealed class WorkerSoftClockTests var grace = TimeSpan.FromMilliseconds(400); await using var runner = Runner(grace); var worker = await WarmAsync(runner, "trivial"); + // Review F5: both answers are counted (otopcua.script.ipc.timeouts, answer = stalled | retrigger). + var answers = new System.Collections.Concurrent.ConcurrentQueue(); + using var listener = new System.Diagnostics.Metrics.MeterListener(); + listener.InstrumentPublished = (instrument, l) => + { + if (instrument.Name == "otopcua.script.ipc.timeouts") l.EnableMeasurementEvents(instrument); + }; + listener.SetMeasurementEventCallback((_, _, tags, _) => + { + foreach (var tag in tags) + if (tag.Key == "answer") answers.Enqueue((string)tag.Value!); + }); + listener.Start(); ScriptRunOutcome stalled, retriggered; using (ProcessFreezer.Freeze(worker.Pid)) @@ -101,6 +114,7 @@ public sealed class WorkerSoftClockTests retriggered.Status.ShouldBe(ScriptRunStatus.Unavailable, retriggered.Reason); retriggered.Reason.ShouldBe(ScriptRunOutcome.WorkerUnresponsiveReason); stalled.ToVirtualTagEvalResult().StatusCode.ShouldBe(Commons.OpcUa.OpcUaStatus.BadResourceUnavailable); + answers.ToArray().ShouldBe(["stalled", "retrigger"], ignoreOrder: true); await stalled.Recovery!.WaitAsync(TimeSpan.FromSeconds(30), Ct); var next = await runner.RunAsync(Scripts.Vt("trivial", Trivial, softT), Ct);