From 7de094c6aa5add9b7704e4c357ffd2ecd7fa262b Mon Sep 17 00:00:00 2001 From: Oliver Kieselbach Date: Wed, 20 May 2026 23:00:41 +0200 Subject: [PATCH] fix decisionEngine missing cancel deadlines in FinalizingStage --- .../buildcounter.txt | 2 +- .../AutopilotMonitor.Agent/buildcounter.txt | 2 +- .../FinalizingStageTests.cs | 164 ++++++++++++++++++ .../Engine/DecisionEngine.Classic.cs | 61 ++++++- .../Engine/DecisionEngine.cs | 42 +++++ 5 files changed, 266 insertions(+), 5 deletions(-) diff --git a/src/Agent/AutopilotMonitor.Agent.V2/buildcounter.txt b/src/Agent/AutopilotMonitor.Agent.V2/buildcounter.txt index 20f9720b..a05e0eed 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2/buildcounter.txt +++ b/src/Agent/AutopilotMonitor.Agent.V2/buildcounter.txt @@ -1 +1 @@ -823 +826 diff --git a/src/Agent/AutopilotMonitor.Agent/buildcounter.txt b/src/Agent/AutopilotMonitor.Agent/buildcounter.txt index 56bf2912..2069e313 100644 --- a/src/Agent/AutopilotMonitor.Agent/buildcounter.txt +++ b/src/Agent/AutopilotMonitor.Agent/buildcounter.txt @@ -1 +1 @@ -1387 +1388 diff --git a/src/Agent/AutopilotMonitor.DecisionCore.Tests/FinalizingStageTests.cs b/src/Agent/AutopilotMonitor.DecisionCore.Tests/FinalizingStageTests.cs index ec68252e..a9407a48 100644 --- a/src/Agent/AutopilotMonitor.DecisionCore.Tests/FinalizingStageTests.cs +++ b/src/Agent/AutopilotMonitor.DecisionCore.Tests/FinalizingStageTests.cs @@ -217,5 +217,169 @@ namespace AutopilotMonitor.DecisionCore.Tests Assert.False(SessionStage.Finalizing.IsTerminal()); Assert.True(SessionStage.Completed.IsTerminal()); } + + // =================================================================== + // Session 8b8d611d regression coverage (2026-05-20): + // + // Bug: HandleHelloResolvedV1 / HandleDesktopArrivedV1 cancelled HelloSafety in the + // reducer state but did NOT emit a CancelDeadline EFFECT — the live + // DeadlineScheduler timer kept ticking and later fired DeadlineFired:HelloSafety + // AFTER the session had already reached Completed via the FinalizingGrace path. + // The dispatcher then re-entered HandleHelloSafetyDeadlineFired, which routes + // through TransitionToFinalizing → second phase_transition + second + // enrollment_complete on the wire. + // + // Fix: a) Emit CancelDeadline(HelloSafety) effect from both signal handlers when the + // deadline is actually armed in state.Deadlines. + // b) Defense-in-depth dispatch guard: any signal arriving with state.Stage in + // {Completed, Failed} is short-circuited to a bookkept dead-end before + // reaching the handlers. + // =================================================================== + + /// + /// Build a state where the deferred-promote path of + /// HandleAccountSetupProvisioningCompleteV1 has just armed HelloSafety. Mirrors + /// the 8b8d611d production sequence: ESP intermediate exit → AccountSetup entered → + /// AccountSetup provisioning completed (deferred-promote → AwaitingHello, HelloSafety + /// armed for +300 s). + /// + private static DecisionState InitialAwaitingHello_WithHelloSafetyArmed(DecisionEngine engine, out DateTime accountSetupProvisioningCompleteUtc) + { + var state = DecisionState.CreateInitial("sess-hs", "tenant-hs", T0); + state = engine.Reduce(state, MakeSignal(0, DecisionSignalKind.SessionStarted, T0, null)).NewState; + state = engine.Reduce(state, MakeSignal(1, DecisionSignalKind.EspPhaseChanged, T0.AddMinutes(1), + new Dictionary { [SignalPayloadKeys.EspPhase] = "AccountSetup" })).NewState; + // EspExiting fires before AccountSetup provisioning completes — guard blocks the + // promote, but EspFinalExitUtc is recorded so the next AccountSetupProvisioningComplete + // takes the deferred-promote path. + state = engine.Reduce(state, MakeSignal(2, DecisionSignalKind.EspExiting, T0.AddMinutes(2), null)).NewState; + Assert.NotNull(state.EspFinalExitUtc); + + accountSetupProvisioningCompleteUtc = T0.AddMinutes(3); + state = engine.Reduce(state, MakeSignal(3, DecisionSignalKind.AccountSetupProvisioningComplete, + accountSetupProvisioningCompleteUtc, null)).NewState; + + // Sanity: deferred-promote landed us in AwaitingHello with HelloSafety armed. + Assert.Equal(SessionStage.AwaitingHello, state.Stage); + Assert.Single(state.Deadlines, d => d.Name == DeadlineNames.HelloSafety); + return state; + } + + [Fact] + public void HelloResolved_when_HelloSafety_armed_emits_CancelDeadline_effect_to_scheduler() + { + // Session 8b8d611d primary fix #1. AwaitingDesktop branch: Hello resolves before + // Desktop arrives. The reducer cancels HelloSafety in state — we now require the + // matching CancelDeadline effect so the live DeadlineScheduler timer is disposed. + var engine = new DecisionEngine(); + var state = InitialAwaitingHello_WithHelloSafetyArmed(engine, out _); + + var step = engine.Reduce(state, MakeSignal(4, DecisionSignalKind.HelloResolved, T0.AddMinutes(4), + new Dictionary { [SignalPayloadKeys.HelloOutcome] = "Success" })); + + Assert.Equal(SessionStage.AwaitingDesktop, step.NewState.Stage); + Assert.DoesNotContain(step.NewState.Deadlines, d => d.Name == DeadlineNames.HelloSafety); + + var cancelEffect = Assert.Single( + step.Effects, + e => e.Kind == DecisionEffectKind.CancelDeadline + && e.CancelDeadlineName == DeadlineNames.HelloSafety); + Assert.NotNull(cancelEffect); + } + + [Fact] + public void HelloResolved_when_HelloSafety_armed_and_Desktop_already_arrived_cancels_then_arms_Finalizing() + { + // Both-prereqs path: HelloSafety must be cancelled BEFORE FinalizingGrace is armed + // so the scheduler observes the cancel before any subsequent state read could see + // both timers active. TransitionToFinalizing's extraLeadingEffects parameter orders + // the cancel before ScheduleDeadline + phase_transition. + var engine = new DecisionEngine(); + var state = InitialAwaitingHello_WithHelloSafetyArmed(engine, out _); + state = engine.Reduce(state, MakeSignal(4, DecisionSignalKind.DesktopArrived, T0.AddMinutes(4), null)).NewState; + Assert.NotNull(state.DesktopArrivedUtc); + // Desktop without HelloResolved keeps us in AwaitingHello with HelloSafety still armed. + Assert.Single(state.Deadlines, d => d.Name == DeadlineNames.HelloSafety); + + var step = engine.Reduce(state, MakeSignal(5, DecisionSignalKind.HelloResolved, T0.AddMinutes(5), + new Dictionary { [SignalPayloadKeys.HelloOutcome] = "Success" })); + + Assert.Equal(SessionStage.Finalizing, step.NewState.Stage); + Assert.DoesNotContain(step.NewState.Deadlines, d => d.Name == DeadlineNames.HelloSafety); + + // Effect ordering: cancel HelloSafety → schedule FinalizingGrace → emit phase_transition. + Assert.Equal(3, step.Effects.Count); + Assert.Equal(DecisionEffectKind.CancelDeadline, step.Effects[0].Kind); + Assert.Equal(DeadlineNames.HelloSafety, step.Effects[0].CancelDeadlineName); + Assert.Equal(DecisionEffectKind.ScheduleDeadline, step.Effects[1].Kind); + Assert.Equal(DeadlineNames.FinalizingGrace, step.Effects[1].Deadline!.Name); + Assert.Equal(DecisionEffectKind.EmitEventTimelineEntry, step.Effects[2].Kind); + } + + [Fact] + public void HelloSafetyDeadline_firing_after_Completed_is_dead_end_with_no_duplicate_enrollment_complete() + { + // Session 8b8d611d defense-in-depth. Simulate the production race: HelloSafety + // armed by the deferred-promote path, HelloResolved + DesktopArrived drive the + // session through Finalizing → Completed, THEN the stale HelloSafety timer fires + // its synthetic DeadlineFired signal. Without the dispatch guard the signal would + // hit HandleHelloSafetyDeadlineFired → TransitionToFinalizing → duplicate + // enrollment_complete. With the guard it produces a bookkept dead-end and + // emits no effects. + var engine = new DecisionEngine(); + var state = InitialAwaitingHello_WithHelloSafetyArmed(engine, out _); + state = engine.Reduce(state, MakeSignal(4, DecisionSignalKind.HelloResolved, T0.AddMinutes(4), + new Dictionary { [SignalPayloadKeys.HelloOutcome] = "Success" })).NewState; + state = engine.Reduce(state, MakeSignal(5, DecisionSignalKind.DesktopArrived, T0.AddMinutes(5), null)).NewState; + Assert.Equal(SessionStage.Finalizing, state.Stage); + + // Drive Finalizing → Completed via the FinalizingGrace deadline (+5s). + state = engine.Reduce(state, MakeSignal(6, DecisionSignalKind.DeadlineFired, + T0.AddMinutes(5).AddSeconds(5), + new Dictionary { [SignalPayloadKeys.Deadline] = DeadlineNames.FinalizingGrace })).NewState; + Assert.Equal(SessionStage.Completed, state.Stage); + + // Stale HelloSafety timer fires AFTER Completed. + var step = engine.Reduce(state, MakeSignal(7, DecisionSignalKind.DeadlineFired, + T0.AddMinutes(8), + new Dictionary { [SignalPayloadKeys.Deadline] = DeadlineNames.HelloSafety })); + + // State must NOT regress out of Completed. + Assert.Equal(SessionStage.Completed, step.NewState.Stage); + Assert.Equal(SessionOutcome.EnrollmentComplete, step.NewState.Outcome); + + // No effects — in particular, no second ScheduleDeadline(FinalizingGrace) and no + // second enrollment_complete emission. + Assert.Empty(step.Effects); + + // Recorded as a dead-end with a descriptive reason. + Assert.False(step.Transition.Taken); + Assert.StartsWith("signal_after_terminal:", step.Transition.DeadEndReason!); + } + + [Fact] + public void Dispatch_guard_short_circuits_arbitrary_signals_after_Completed() + { + // Defense-in-depth coverage beyond the HelloSafety-specific scenario: any signal + // arriving in Completed must be bookkept-only. + var engine = new DecisionEngine(); + var state = InitialAwaitingDesktop(engine); + state = engine.Reduce(state, MakeSignal(5, DecisionSignalKind.DesktopArrived, T0.AddMinutes(5), null)).NewState; + state = engine.Reduce(state, MakeSignal(6, DecisionSignalKind.DeadlineFired, + T0.AddMinutes(5).AddSeconds(5), + new Dictionary { [SignalPayloadKeys.Deadline] = DeadlineNames.FinalizingGrace })).NewState; + Assert.Equal(SessionStage.Completed, state.Stage); + + // A late ImeUserSessionCompleted (replayed CMTrace tail after Completed) must not + // mutate state or emit effects. + var step = engine.Reduce(state, MakeSignal(7, DecisionSignalKind.ImeUserSessionCompleted, + T0.AddMinutes(7), + new Dictionary { [SignalPayloadKeys.ImePatternId] = "IME-USER-COMPLETE" })); + + Assert.Equal(SessionStage.Completed, step.NewState.Stage); + Assert.Empty(step.Effects); + Assert.False(step.Transition.Taken); + Assert.Equal("signal_after_terminal:Completed", step.Transition.DeadEndReason); + } } } diff --git a/src/Shared/AutopilotMonitor.DecisionCore/Engine/DecisionEngine.Classic.cs b/src/Shared/AutopilotMonitor.DecisionCore/Engine/DecisionEngine.Classic.cs index 9207d89f..18756ab6 100644 --- a/src/Shared/AutopilotMonitor.DecisionCore/Engine/DecisionEngine.Classic.cs +++ b/src/Shared/AutopilotMonitor.DecisionCore/Engine/DecisionEngine.Classic.cs @@ -195,6 +195,17 @@ namespace AutopilotMonitor.DecisionCore.Engine /// Handle . Records the resolution fact /// and cancels the Hello-safety deadline. If Desktop has already arrived the session /// completes here; otherwise stage transitions to . + /// + /// Session 8b8d611d fix (2026-05-20): when is + /// armed in the live set we also emit a + /// effect so the wall-clock + /// timer is disposed. Without that effect the builder + /// cancel only cleared the reducer-state view; the OS timer kept ticking and fired + /// later (~300 s after arm), re-entering + /// from a Completed stage and emitting a duplicate enrollment_complete. + /// Mirrors the pattern already used by the Hello-disabled fast-path in + /// . + /// /// private DecisionStep HandleHelloResolvedV1(DecisionState state, DecisionSignal signal) { @@ -211,6 +222,7 @@ namespace AutopilotMonitor.DecisionCore.Engine builder.HelloOutcome = new SignalFact(outcome, signal.SessionSignalOrdinal); var desktopAlreadyArrived = state.DesktopArrivedUtc != null; + var helloSafetyCancelEffect = BuildHelloSafetyCancelEffectIfArmed(state); // Plan §5 Fix 6: when both prerequisites have resolved, go through the // non-terminal Finalizing stage with a short grace period before Completed. @@ -223,7 +235,10 @@ namespace AutopilotMonitor.DecisionCore.Engine signal: signal, preparedBuilder: builder, nextStepIndex: nextStep, - trigger: nameof(DecisionSignalKind.HelloResolved)); + trigger: nameof(DecisionSignalKind.HelloResolved), + extraLeadingEffects: helloSafetyCancelEffect != null + ? new[] { helloSafetyCancelEffect } + : null); } builder.WithStage(SessionStage.AwaitingDesktop); @@ -236,7 +251,32 @@ namespace AutopilotMonitor.DecisionCore.Engine nextStepIndex: nextStep, trigger: nameof(DecisionSignalKind.HelloResolved)); - return new DecisionStep(newState, transition, Array.Empty()); + var effects = helloSafetyCancelEffect != null + ? new[] { helloSafetyCancelEffect } + : Array.Empty(); + return new DecisionStep(newState, transition, effects); + } + + /// + /// Session 8b8d611d fix (2026-05-20): emit a + /// effect for when it is actually armed in + /// . Returns null when the deadline is not present — + /// avoids spurious cancel-noise on the scheduler. Callers chain this in front of any + /// reducer-side CancelDeadline(HelloSafety) so the live timer is disposed + /// before it can fire after a Completed transition. + /// + private static DecisionEffect? BuildHelloSafetyCancelEffectIfArmed(DecisionState state) + { + foreach (var d in state.Deadlines) + { + if (d.Name == DeadlineNames.HelloSafety) + { + return new DecisionEffect( + DecisionEffectKind.CancelDeadline, + cancelDeadlineName: DeadlineNames.HelloSafety); + } + } + return null; } /// @@ -311,14 +351,29 @@ namespace AutopilotMonitor.DecisionCore.Engine // Plan §5 Fix 6: mirror of HandleHelloResolvedV1. When both prerequisites are in, // go through Finalizing (non-terminal) instead of jumping straight to Completed. + // Session 8b8d611d fix (2026-05-20): when HelloSafety is still armed in the live + // state (deferred-promote path from HandleAccountSetupProvisioningCompleteV1 — the + // HelloResolved branch did not clear it because Hello came in via the Hello-timeout + // synthesis after this Desktop signal in some orderings), cancel the scheduler + // timer too. Without the effect the timer fires after Completed and re-enters + // HandleHelloSafetyDeadlineFired → TransitionToFinalizing → duplicate + // enrollment_complete. if (helloAlreadyResolved) { + var helloSafetyCancelEffect = BuildHelloSafetyCancelEffectIfArmed(state); + if (helloSafetyCancelEffect != null) + { + builder.CancelDeadline(DeadlineNames.HelloSafety); + } return TransitionToFinalizing( state: state, signal: signal, preparedBuilder: builder, nextStepIndex: nextStep, - trigger: nameof(DecisionSignalKind.DesktopArrived)); + trigger: nameof(DecisionSignalKind.DesktopArrived), + extraLeadingEffects: helloSafetyCancelEffect != null + ? new[] { helloSafetyCancelEffect } + : null); } // Desktop came first: keep current stage (AwaitingHello or EspAccountSetup) until diff --git a/src/Shared/AutopilotMonitor.DecisionCore/Engine/DecisionEngine.cs b/src/Shared/AutopilotMonitor.DecisionCore/Engine/DecisionEngine.cs index da510e07..bfd4b000 100644 --- a/src/Shared/AutopilotMonitor.DecisionCore/Engine/DecisionEngine.cs +++ b/src/Shared/AutopilotMonitor.DecisionCore/Engine/DecisionEngine.cs @@ -49,9 +49,30 @@ namespace AutopilotMonitor.DecisionCore.Engine /// Pure dispatch on (Kind, SchemaVersion) — no mutation here, no try/catch /// (outer provides the fail-safe wrapper). Handlers return fully /// constructed instances. + /// + /// Session 8b8d611d defense-in-depth (2026-05-20): when the state already reached a + /// classic terminal stage ( / + /// ), reject any further signal as a bookkept dead + /// end before it can re-enter a handler that mutates state or emits effects. The + /// orchestrator tear-down after OnDecisionTerminalStage runs on a background + /// task (off-worker dispatch in EnrollmentOrchestrator.OnDecisionTerminalStage), + /// so the SignalIngress worker can still pump queued or late-fired signals through + /// for seconds afterwards. A live timer that escaped a missing + /// effect (e.g. a stale HelloSafety + /// firing post-Completed) would otherwise re-enter TransitionToFinalizing and + /// emit a duplicate enrollment_complete. + /// is intentionally NOT guarded here — Part-2 resume runs as a fresh decision state + /// after archive-and-reset, so no signal ever reaches the engine with that stage in + /// a position that would warrant a dead-end. + /// /// private DecisionStep Dispatch(DecisionState state, DecisionSignal signal) { + if (state.Stage == SessionStage.Completed || state.Stage == SessionStage.Failed) + { + return BuildPostTerminalDeadEnd(state, signal); + } + return (signal.Kind, signal.KindSchemaVersion) switch { // ----- Lifecycle (DecisionEngine.Shared.cs) ----- @@ -220,6 +241,27 @@ namespace AutopilotMonitor.DecisionCore.Engine return new DecisionStep(bookkept, transition, Array.Empty()); } + /// + /// Bookkeeping-only step for signals that arrive after the session reached a classic + /// terminal stage. State (Stage / Outcome / facts / deadlines) is unchanged; only + /// StepIndex and LastAppliedSignalOrdinal advance so the signal is recorded as + /// processed in the SignalLog. DeadEndReason="signal_after_terminal:<stage>" + /// lets the Inspector pinpoint which late-arriving signal would have re-entered the + /// terminal handlers without this guard. + /// + private DecisionStep BuildPostTerminalDeadEnd(DecisionState state, DecisionSignal signal) + { + var bookkept = BumpStepBookkeeping(state, signal); + var transition = BuildDeadEndTransition( + state: state, + signal: signal, + nextStepIndex: bookkept.StepIndex, + trigger: signal.Kind.ToString(), + deadEndReason: $"signal_after_terminal:{state.Stage}"); + + return new DecisionStep(bookkept, transition, Array.Empty()); + } + private static string HashStackTrace(Exception exception) { var raw = exception.StackTrace ?? exception.GetType().FullName ?? "unknown";