From ca9be68d91254633a24b6e58c326cf33dcf0dfa7 Mon Sep 17 00:00:00 2001 From: Joseph Doherty Date: Tue, 8 Sep 2026 01:42:17 -0400 Subject: [PATCH] =?UTF-8?q?fix(management):=20FlowDebugRunner=20=E2=80=94?= =?UTF-8?q?=20transport=20faults=20still=20write=20the=20root=20row;=20wri?= =?UTF-8?q?te-kind=20completion=20is=20script-specific;=20standby/unreadab?= =?UTF-8?q?le-trigger=20tests?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Claude-Session: https://claude.ai/code/session_01NcMG6xXdsJbmD2wYAgkK29 --- .../FlowDebug/FlowDebugRunner.cs | 71 ++++++++++---- .../FlowDebugRunnerTests.cs | 98 +++++++++++++++++++ 2 files changed, 151 insertions(+), 18 deletions(-) diff --git a/src/ZB.MOM.WW.ScadaBridge.ManagementService/FlowDebug/FlowDebugRunner.cs b/src/ZB.MOM.WW.ScadaBridge.ManagementService/FlowDebug/FlowDebugRunner.cs index a79f0936..4b6952d6 100644 --- a/src/ZB.MOM.WW.ScadaBridge.ManagementService/FlowDebug/FlowDebugRunner.cs +++ b/src/ZB.MOM.WW.ScadaBridge.ManagementService/FlowDebug/FlowDebugRunner.cs @@ -53,6 +53,15 @@ public sealed class FlowDebugRunner /// public const int DefaultScriptTimeoutSeconds = 30; + /// + /// Ceiling on a write-kind run's spawned-run wait, whatever the command asks for. It must stay + /// UNDER ManagementServiceOptions.LongRunningCommandTimeout (5 minutes by default), which + /// is the Ask the management endpoint wraps this command in: a longer wait would leave the poll + /// loop running on the node after the caller's Ask has already expired, holding its scoped + /// provider and pulling from the site for a result nobody can receive. + /// + public const int MaxWaitSeconds = 300; + /// /// Arch-review F2: 's code for a routed call refused /// because the target site is outside the operator's site scope. InboundAPI cannot @@ -304,7 +313,9 @@ public sealed class FlowDebugRunner DateTimeOffset.UtcNow, ParentExecutionId: root, Trace: true); RouteToCallResponse response; - var timedOut = false; + // Null while the site ANSWERED (a success or a Success=false reply); otherwise the code to + // report for a routed Ask that threw instead of answering. + string? faultCode = null; using (var runCts = CancellationTokenSource.CreateLinkedTokenSource(ct)) { runCts.CancelAfter(timeout + RunGrace); @@ -314,10 +325,27 @@ public sealed class FlowDebugRunner } catch (OperationCanceledException) when (!ct.IsCancellationRequested) { - timedOut = true; + faultCode = TimeoutCode; response = new RouteToCallResponse( request.CorrelationId, false, null, TimeoutMessage(timeout), DateTimeOffset.UtcNow); } + catch (Exception ex) when (ex is not OperationCanceledException) + { + // RouteToCallAsync is an Akka Ask bounded by CommunicationOptions.IntegrationTimeout, + // so it throws AskTimeoutException (NOT an OperationCanceledException) when the site + // never answers — and any transport fault throws too. "No answer" is NOT "did not + // happen": the site may already have run the script. Letting the exception escape + // would lose the root row entirely and show the operator MapFault's generic internal + // error for a call that ran, so it is converted into a failed response the same way + // RouteHelper.CallAsync types its Ask faults and WriteAndPollAsync reports a failed + // write. A cancellation of the CALLER's token still propagates (filtered out above). + faultCode = ex is Akka.Actor.AskTimeoutException ? TimeoutCode : CallFailedCode; + _logger.LogWarning(ex, + "Flow Debugger routed call to site {Site} for {Instance}.{Script} faulted", + site.SiteIdentifier, instance.UniqueName, script.CanonicalName); + response = new RouteToCallResponse( + request.CorrelationId, false, null, ex.Message, DateTimeOffset.UtcNow); + } } // Everything from here to WriteCentralAsync runs AFTER the site already executed the @@ -366,7 +394,7 @@ public sealed class FlowDebugRunner ordered.AddRange(events); return new FlowDebugRunResult( root, response.Success, response.ErrorMessage, - response.Success ? null : timedOut ? TimeoutCode : CallFailedCode, + response.Success ? null : faultCode ?? CallFailedCode, ordered, Truncated: collector.Truncated, startedAt, DateTimeOffset.UtcNow); } @@ -424,11 +452,26 @@ public sealed class FlowDebugRunner [redactedRoot], false, startedAt, DateTimeOffset.UtcNow); } + // The run that COUNTS as completion. For the script entry (design 2026-09-08 §4.3) that is + // the script the operator chose, matched on Target — the site stamps ScriptRunLauncher's + // `target: scriptName` on the row. Other scripts the same write happens to fire are still + // collected below (the graph draws the siblings) but must never report the CHOSEN script as + // having run. triggerScript == null is the attribute-level command, which expects no + // particular script, so any spawned run satisfies it. + bool IsAwaitedRun(AuditEvent e) + { + var d = AuditDetailsCodec.Deserialize(e.DetailsJson); + if (d.Kind != nameof(AuditKind.ScriptRun) || d.ParentExecutionId != root) return false; + return triggerScript is null + || string.Equals(e.Target, triggerScript, StringComparison.OrdinalIgnoreCase); + } + // Poll the site for the traced run(s) the write spawned — matched by ParentExecutionId - // == root, then their children — until a ScriptRun parented to root exists AND the - // set has been quiet for SettleWindow, or WaitSeconds elapses. + // == root, then their children — until the awaited ScriptRun exists AND the set has been + // quiet for SettleWindow, or the (clamped) wait elapses. var puller = sp.GetRequiredService(); - var deadline = _now() + TimeSpan.FromSeconds(Math.Max(1, waitSeconds)); + var wait = Math.Clamp(waitSeconds, 1, MaxWaitSeconds); + var deadline = _now() + TimeSpan.FromSeconds(wait); var known = new Dictionary(); DateTimeOffset? lastNew = null; var since = startedAt.UtcDateTime.AddSeconds(-5); @@ -448,11 +491,7 @@ public sealed class FlowDebugRunner } if (added) lastNew = _now(); - var spawned = known.Values.Any(e => - { - var d = AuditDetailsCodec.Deserialize(e.DetailsJson); - return d.Kind == nameof(AuditKind.ScriptRun) && d.ParentExecutionId == root; - }); + var spawned = known.Values.Any(IsAwaitedRun); var now = _now(); if (spawned && lastNew is { } ln && now - ln >= SettleWindow) break; if (now >= deadline) break; @@ -461,16 +500,12 @@ public sealed class FlowDebugRunner var ordered = new List { redactedRoot }; ordered.AddRange(known.Values.OrderBy(e => e.OccurredAtUtc).ThenBy(e => e.EventId)); - var completed = known.Values.Any(e => - { - var d = AuditDetailsCodec.Deserialize(e.DetailsJson); - return d.Kind == nameof(AuditKind.ScriptRun) && d.ParentExecutionId == root; - }); + var completed = known.Values.Any(IsAwaitedRun); return new FlowDebugRunResult( root, completed, completed ? null : triggerScript is null - ? $"No traced run was spawned within {waitSeconds}s (no value-change trigger on '{attributeName}', or no device echo)." - : $"No traced run of '{triggerScript}' was spawned within {waitSeconds}s after writing '{attributeName}' (trigger condition not met, or no device echo).", + ? $"No traced run was spawned within {wait}s (no value-change trigger on '{attributeName}', or no device echo)." + : $"No traced run of '{triggerScript}' was spawned within {wait}s after writing '{attributeName}' (trigger condition not met, or no device echo).", completed ? null : NoTriggerCode, ordered, false, startedAt, DateTimeOffset.UtcNow); } diff --git a/tests/ZB.MOM.WW.ScadaBridge.ManagementService.Tests/FlowDebugRunnerTests.cs b/tests/ZB.MOM.WW.ScadaBridge.ManagementService.Tests/FlowDebugRunnerTests.cs index acc3b345..67d31354 100644 --- a/tests/ZB.MOM.WW.ScadaBridge.ManagementService.Tests/FlowDebugRunnerTests.cs +++ b/tests/ZB.MOM.WW.ScadaBridge.ManagementService.Tests/FlowDebugRunnerTests.cs @@ -519,6 +519,39 @@ public class FlowDebugRunnerTests await _router.DidNotReceiveWithAnyArgs().RouteToCallAsync(default!, default!, default); } + [Fact] + public async Task RunScript_OnStandby_RefusesWithStandbyCode_BeforeTouchingTheInstance() + { + var (templates, _, _, pipeline) = WireScript(CallScript("Manual")); + _gate.IsActiveNode.Returns(false); + + var ex = await Assert.ThrowsAsync(() => Runner().RunScriptAsync( + _services.BuildServiceProvider(), new FlowDebugRunScriptCommand(5, "Manual", null, null), Deployer, CancellationToken.None)); + + Assert.Equal(FlowDebugRunner.StandbyNodeCode, ex.Code); + Assert.Contains("ACTIVE central node", ex.Message); + await templates.DidNotReceiveWithAnyArgs().GetInstanceByIdAsync(default, default); + await pipeline.DidNotReceiveWithAnyArgs().FlattenAndValidateAsync(default, default, default, default); + } + + [Fact] + public async Task RunScript_WriteKind_UnreadableTriggerConfig_FailsValidation() + { + // A write-kind trigger whose configuration names no attribute: there is nothing to write, + // so the run is refused rather than guessing an attribute. + WireScript(new ResolvedScript + { + CanonicalName = "OnLevel", Code = "return 1;", TriggerType = "ValueChange", TriggerConfiguration = "{}", + }); + + var ex = await Assert.ThrowsAsync(() => Runner().RunScriptAsync( + _services.BuildServiceProvider(), new FlowDebugRunScriptCommand(5, "OnLevel", null, "7"), Deployer, CancellationToken.None)); + + Assert.Equal(FlowDebugRunner.ValidationFailedCode, ex.Code); + Assert.Contains("trigger configuration", ex.Message); + await _router.DidNotReceiveWithAnyArgs().RouteToSetAttributesAsync(default!, default!, default); + } + [Fact] public async Task RunScript_WriteKind_WithoutValue_FailsValidation_BeforeAnyWrite() { @@ -529,6 +562,28 @@ public class FlowDebugRunnerTests await _router.DidNotReceiveWithAnyArgs().RouteToSetAttributesAsync(default!, default!, default); } + [Fact] + public async Task RunScript_WriteKind_SiblingScriptRun_DoesNotCountAsCompletion() + { + // The write may fire several scripts. A sibling's run is still COLLECTED (the graph draws + // it) but must not report the script the operator chose as having run. + var (_, _, puller, _) = WireScript(WriteScript("OnLevel", "ValueChange", "Level")); + puller.PullAsync("site-a", Arg.Any>(), Arg.Any(), Arg.Any(), Arg.Any()) + .Returns(ci => (IReadOnlyList)[ScadaBridgeAuditEventFactory.Create(AuditChannel.ScriptTrace, AuditKind.ScriptRun, AuditStatus.Delivered, + eventId: Guid.Parse("cccccccc-0000-0000-0000-000000000001"), + executionId: Guid.NewGuid(), parentExecutionId: ((IReadOnlyCollection)ci[1]).First(), target: "OtherScript")]); + + var result = await Runner().RunScriptAsync(_services.BuildServiceProvider(), + new FlowDebugRunScriptCommand(5, "OnLevel", null, "7", WaitSeconds: 3), Deployer, CancellationToken.None); + + Assert.False(result.Completed); + Assert.Equal(FlowDebugRunner.NoTriggerCode, result.ErrorCode); + Assert.Contains("OnLevel", result.Error); + // ...but the sibling is in the events, so the operator can see what DID run. + Assert.Equal(2, result.Events.Count); + Assert.Equal("OtherScript", result.Events[1].Target); + } + [Fact] public async Task RunScript_CallKind_RoutesATracedCall_AndReturnsRootRouteCallRow_ThenSiteRows() { @@ -636,6 +691,49 @@ public class FlowDebugRunnerTests Assert.Equal(AuditKind.RouteCall, written.AsRow().Kind); } + [Fact] + public async Task RunScript_CallKind_TransportFault_StillWritesTheRootRow_AsCallFailed() + { + // A throwing Ask is NOT proof the script did not run — the site may have executed it and + // the reply been lost. The root row must still be written against the operator's name. + WireScript(CallScript("Manual")); + _router.RouteToCallAsync("site-a", Arg.Any(), Arg.Any()) + .Returns(_ => Task.FromException(new InvalidOperationException("channel is broken"))); + + var result = await Runner().RunScriptAsync(_services.BuildServiceProvider(), + new FlowDebugRunScriptCommand(5, "Manual", null, null), Deployer, CancellationToken.None); + + Assert.False(result.Completed); + Assert.Equal(FlowDebugRunner.CallFailedCode, result.ErrorCode); + Assert.Contains("channel is broken", result.Error); + var root = Assert.Single(result.Events).AsRow(); + Assert.Equal(AuditKind.RouteCall, root.Kind); + Assert.Equal(AuditStatus.Failed, root.Status); + Assert.Equal("ops", result.Events[0].Actor); + var written = Assert.Single(_central); + Assert.Equal(AuditKind.RouteCall, written.AsRow().Kind); + } + + [Fact] + public async Task RunScript_CallKind_AskTimeout_ReportsTimeoutCode() + { + // The communication layer's own signal that the site never answered — an AskTimeoutException, + // NOT an OperationCanceledException, so it needs its own classification. + WireScript(CallScript("Manual")); + _router.RouteToCallAsync("site-a", Arg.Any(), Arg.Any()) + .Returns(_ => Task.FromException( + new Akka.Actor.AskTimeoutException("no response from site-a"))); + + var result = await Runner().RunScriptAsync(_services.BuildServiceProvider(), + new FlowDebugRunScriptCommand(5, "Manual", null, null), Deployer, CancellationToken.None); + + Assert.False(result.Completed); + Assert.Equal(FlowDebugRunner.TimeoutCode, result.ErrorCode); + var root = Assert.Single(result.Events).AsRow(); + Assert.Equal(AuditStatus.Failed, root.Status); + Assert.Single(_central); + } + /// A routed call that never answers until its token is cancelled — the timeout path. private static async Task NeverAnswersAsync(CancellationToken ct) {