diff --git a/MainWindow.xaml.cs b/MainWindow.xaml.cs index 55c484a35..5557bca32 100644 --- a/MainWindow.xaml.cs +++ b/MainWindow.xaml.cs @@ -1492,6 +1492,28 @@ await Task.WhenAll(candidates.Select(async signal => SetStatus($"{device.Name}: refreshed {candidates.Length} control value(s)."); } + private bool RejectCommandWhenIedFlightUnavailable( + Iec61850MonitorDevice? device, SignalDefinition signal) + { + // The UI is advisory. The runtime's atomic association-wide gate is + // authoritative, including sticky uncertain-outcome quarantine. + // Reuse existing CommandSignals state instead of mirroring a new + // runtime busy flag into the WPF view model. + if (device is null || + !device.CommandSignals.Any(active => active.ControlCommandBusy)) + return false; + const string reason = + "another IED command is still active or its wire outcome is unresolved"; + signal.ControlLastResult = "Command not sent: " + reason + + ". Verify process status before recovery."; + AddLog("WARN", device.Name, + $"CONTROL_UI_SINGLE_FLIGHT: rejected {signal.ObjectReference}; " + + "same-IED control flight already active or quarantined; no Operate requested."); + SetStatus($"{device.Name}: {signal.Name} — command not sent; {reason}."); + ShowControlShout(Iec61850ControlShout.FromLocalRejection(reason)); + return true; + } + private async void ControlStageAction_Click(object sender, RoutedEventArgs e) { if (sender is not Button button || button.Tag is not SignalDefinition signal || @@ -1502,6 +1524,8 @@ private async void ControlStageAction_Click(object sender, RoutedEventArgs e) var device = _signalOwners.TryGetValue(signal, out var owner) ? owner : SelectedDevice; if (device is null || !device.IsConnected || signal.ControlInspectionBusy || signal.ControlCommandBusy) return; + if (RejectCommandWhenIedFlightUnavailable(device, signal)) + return; DismissControlShout(); // A live Direct/SBO model permits a preflight inspection, not an @@ -1568,6 +1592,8 @@ private async void ControlConfirmAction_Click(object sender, RoutedEventArgs e) return; var device = _signalOwners.TryGetValue(signal, out var owner) ? owner : SelectedDevice; + if (RejectCommandWhenIedFlightUnavailable(device, signal)) + return; AddLog("INFO", device?.Name ?? "IED", $"Confirm click received: {signal.ObjectReference}; pending={signal.ControlConfirmationPending}; action={signal.ControlPendingAction}; value={signal.ControlPendingValue}; commandBusy={signal.ControlCommandBusy}; inspectionBusy={signal.ControlInspectionBusy}."); @@ -1615,6 +1641,8 @@ private async void ControlQuickAction_Click(object sender, RoutedEventArgs e) } var device = _signalOwners.TryGetValue(signal, out var owner) ? owner : SelectedDevice; + if (RejectCommandWhenIedFlightUnavailable(device, signal)) + return; if (!signal.TryBeginDirectControlCommand( requestedValue, button.Content?.ToString()?.Trim() ?? requestedValue, @@ -1710,8 +1738,33 @@ private async Task ExecuteClaimedControlAsync(SignalDefinition signal, ControlCo } catch (OperationCanceledException) { - signal.ControlLastResult = "Command cancelled."; - SetStatus($"{device.Name}: {signal.Name} command cancelled."); + signal.ControlLastResult = "Command cancelled; if Operate was already dispatched, verify actual IED position."; + SetStatus($"{device.Name}: {signal.Name} command cancelled; verify the final process state."); + } + catch (InvalidOperationException ex) when ( + ex.Message.Contains("control", StringComparison.OrdinalIgnoreCase) && + (ex.Message.Contains("in progress", StringComparison.OrdinalIgnoreCase) || + ex.Message.Contains("unresolved", StringComparison.OrdinalIgnoreCase))) + { + signal.ControlLastResult = "Command NOT SENT: " + ex.Message; + AddLog("WARN", device.Name, + $"CONTROL_UI_LOCAL_GATE: {signal.ObjectReference}; {ex.Message}"); + SetStatus($"{device.Name}: {signal.Name} — command not sent; prior flight active or unresolved."); + MarkDiagnosticAlert(); + ShowControlShout(Iec61850ControlShout.FromLocalRejection( + "another control flight is active or unresolved. Verify actual IED status before retrying")); + } + catch (TimeoutException ex) + { + signal.ControlLastResult = + "Control outcome UNKNOWN — MMS flight exceeded deadline. " + + "Verify IED process state and reconnect before another command."; + AddLog("ERROR", device.Name, + $"CONTROL_UI_TIMEOUT: {signal.ObjectReference}; {ex.Message}"); + SetStatus($"{device.Name}: {signal.Name} control outcome UNKNOWN; check Diagnostics."); + MarkDiagnosticAlert(); + ShowControlShout(Iec61850ControlShout.FromLocalRejection( + "Control timed out with UNKNOWN wire outcome. Verify the IED position and reconnect; do not blindly retry")); } catch (Exception ex) { diff --git a/Services/Iec61850ControlFlightAdmission.cs b/Services/Iec61850ControlFlightAdmission.cs new file mode 100644 index 000000000..192160c6c --- /dev/null +++ b/Services/Iec61850ControlFlightAdmission.cs @@ -0,0 +1,62 @@ +using System.Threading; + +namespace ArIED61850Tester.Services; + +/// +/// Atomic association-wide admission for one IEC 61850 control flight. +/// Quarantine is sticky for this session after an uncertain wire outcome. +/// This is ownership only: no value ledger, MMS protocol or second transport. +/// +public static class Iec61850ControlFlightAdmission +{ + public static bool IsUnavailable(ref int active, ref int quarantine) + => Volatile.Read(ref active) != 0 || Volatile.Read(ref quarantine) != 0; + + public static bool TryEnter(ref int active, ref int quarantine) + { + if (Volatile.Read(ref quarantine) != 0 || + Interlocked.CompareExchange(ref active, 1, 0) != 0) + return false; + if (Volatile.Read(ref quarantine) == 0) return true; + Interlocked.Exchange(ref active, 0); + return false; + } + + /// + /// Bounds only the caller's wait, never the actual native lifetime. + /// An unresolved native operation remains owned by its session until its + /// own Task finishes; the caller must retain admission until then. + /// + public static async Task WaitForNativeAsync( + Task nativeFlight, TimeSpan deadline, CancellationToken waitCancellation, + Action quarantine, Action cancelNative) + { + ArgumentNullException.ThrowIfNull(nativeFlight); + ArgumentNullException.ThrowIfNull(quarantine); + ArgumentNullException.ThrowIfNull(cancelNative); + try + { + return await nativeFlight.WaitAsync(deadline, waitCancellation).ConfigureAwait(false); + } + catch (TimeoutException) + { + quarantine(); + cancelNative(); + throw; + } + catch (OperationCanceledException) + { + // Native cancellation may occur *after* a Write/Operate reached + // the wire. A completed canceled Task is not proof of NotSent. + quarantine(); + cancelNative(); + throw; + } + } + + public static void Quarantine(ref int quarantine) + => Interlocked.Exchange(ref quarantine, 1); + + public static void Release(ref int active) + => Interlocked.Exchange(ref active, 0); +} diff --git a/Services/Iec61850MonitorRuntime.cs b/Services/Iec61850MonitorRuntime.cs index ba34aea1f..1b846b6f9 100644 --- a/Services/Iec61850MonitorRuntime.cs +++ b/Services/Iec61850MonitorRuntime.cs @@ -86,7 +86,14 @@ private sealed class DeviceSession public DateTime NextHealthProbeUtc { get; set; } = DateTime.MinValue; public int ConsecutiveHealthProbeFailures { get; set; } public string HealthProbePointKey { get; set; } = string.Empty; + public Guid ControlSessionIdentity { get; } = Guid.NewGuid(); + // Canceled immediately on registry removal: a late native control + // cannot remain authorized to publish into a replacement association. + public CancellationTokenSource ControlLifetimeCancellation { get; } = new(); public int ControlCommandActive; + // A timed-out/cancelled native Operate may still be in-flight on the + // association. Do not admit another control until a fresh session. + public int ControlFlightQuarantined; public HybridReportPhysicalValidationTracker HybridValidation { get; } = new(); public StaticDataSetReportProjectionAccumulator StaticReportProjection { get; } = new(); public bool StaticDataSetReportOnly { get; set; } @@ -729,6 +736,10 @@ public async Task> StartMonitoringAsync( if (!_sessions.TryGetValue(device.DeviceId, out var session) || !session.Client.IsConnected) throw new InvalidOperationException($"{device.Name} is not connected. Connect and discover this IED first."); + if (Iec61850ControlFlightAdmission.IsUnavailable( + ref session.ControlCommandActive, ref session.ControlFlightQuarantined)) + throw new InvalidOperationException( + "Monitoring cannot start during an active or uncertain MMS control flight. Verify IED state and reconnect."); var staticDataSetReportOnly = Iec61850MonitoringModeRegistry.IsStaticDataSetReportOnly(device); var eligible = selectedSignals @@ -879,30 +890,80 @@ Iec61850ControlModelKind.SboNormal or Iec61850ControlModelKind.SboEnhanced)) throw new ArgumentException("A valid expected live ctlModel and target 1-4 are required."); - var targetKey = deviceId + "|" + Iec61850ControlIdentity.Normalize(signal.ObjectReference); + var targetKey = session.ControlSessionIdentity.ToString("N") + "|" + Iec61850ControlIdentity.Normalize(signal.ObjectReference); if (!_activeControlTargets.TryAdd(targetKey, 0)) throw new InvalidOperationException("A command is already running for this object."); - Interlocked.Increment(ref session.ControlCommandActive); + if (!Iec61850ControlFlightAdmission.TryEnter( + ref session.ControlCommandActive, ref session.ControlFlightQuarantined)) + { + _activeControlTargets.TryRemove(targetKey, out _); + throw new InvalidOperationException( + "This IED already has an active or unresolved control flight. No ctlModel Write was sent."); + } + var nativeCancellation = CancellationTokenSource.CreateLinkedTokenSource( + cancellationToken, session.ControlLifetimeCancellation.Token); + Task? nativeFlight = null; try { - if (Volatile.Read(ref session.ControlCommandActive) != 1) - throw new InvalidOperationException("Another IED command is in progress. ctlModel configuration was not started."); Log("WARN", session.Device.Name, $"OPERATOR_CTL_MODEL_CONFIGURATION: {signal.ObjectReference}; expected={expected}; requested={target}; " + "explicit commissioning confirmed; one CF Write maximum, never Operate."); - var result = await session.Client.ConfigureControlModelAsync( - signal, expected, target, cancellationToken).ConfigureAwait(false); + nativeFlight = session.Client.ConfigureControlModelAsync( + signal, expected, target, nativeCancellation.Token); + var result = await Iec61850ControlFlightAdmission.WaitForNativeAsync( + nativeFlight, ControlFlightDeadline, cancellationToken, + () => Iec61850ControlFlightAdmission.Quarantine(ref session.ControlFlightQuarantined), + nativeCancellation.Cancel).ConfigureAwait(false); + if (!_sessions.TryGetValue(deviceId, out var current) || + !ReferenceEquals(current, session) || + session.ControlLifetimeCancellation.IsCancellationRequested) + throw new OperationCanceledException("Control association was replaced during ctlModel Write."); Log(result.ReadbackVerified ? "INFO" : "WARN", session.Device.Name, $"CTL_MODEL_CONFIGURATION_RESULT: {signal.ObjectReference}; " + $"writeAccepted={result.WriteAccepted}; readbackVerified={result.ReadbackVerified}; " + $"before={result.BeforeModel}; after={result.AfterModel}; {result.Detail}"); return result; } + catch (TimeoutException) + { + Log("ERROR", session.Device.Name, + $"CTL_MODEL_OUTCOME_UNKNOWN_TIMEOUT: {signal.ObjectReference}; deadline={ControlFlightDeadline.TotalSeconds:0}s; nativeCompleted={nativeFlight?.IsCompleted}; no other MMS control/write on this association."); + throw new TimeoutException( + "ctlModel configuration exceeded the deadline. The MMS Write outcome is UNKNOWN. Verify the actual IED ctlModel and reconnect before any command."); + } + catch (OperationCanceledException) when (cancellationToken.IsCancellationRequested) + { + if (nativeFlight is { IsCompleted: false }) + { + Log("WARN", session.Device.Name, + $"CTL_MODEL_CANCEL_OUTCOME_UNKNOWN: {signal.ObjectReference}; native Write unresolved; association quarantined."); + } + throw; + } + catch (OperationCanceledException) when (!cancellationToken.IsCancellationRequested && + !session.ControlLifetimeCancellation.IsCancellationRequested) + { + // Cancellation initiated inside the native operation is not + // positive NotSent evidence; the engine may have issued a Write. + Log("ERROR", session.Device.Name, + $"CTL_MODEL_NATIVE_CANCEL_OUTCOME_UNKNOWN: {signal.ObjectReference}; native task canceled without a terminal wire result; association quarantined."); + throw new TimeoutException( + "Native ctlModel Write canceled without a proven wire outcome. Verify actual IED state and reconnect."); + } finally { - Interlocked.Decrement(ref session.ControlCommandActive); - _activeControlTargets.TryRemove(targetKey, out _); + if (nativeFlight is { IsCompleted: false }) + { + _ = ObserveLateControlFlightAsync(session, targetKey, + signal.ObjectReference, nativeFlight, nativeCancellation); + } + else + { + nativeCancellation.Dispose(); + Iec61850ControlFlightAdmission.Release(ref session.ControlCommandActive); + _activeControlTargets.TryRemove(targetKey, out _); + } } } @@ -917,9 +978,20 @@ public async Task InspectControlAsync( if (!_sessions.TryGetValue(deviceId, out var session) || !session.Client.IsConnected) throw new InvalidOperationException("The IED must be connected before a control object can be inspected."); + if (Volatile.Read(ref session.ControlCommandActive) != 0 || + Volatile.Read(ref session.ControlFlightQuarantined) != 0) + throw new InvalidOperationException( + "Control inspection deferred: another command is in flight or the association requires recovery."); try { - var capabilities = await session.Client.InspectControlAsync(signal, cancellationToken).ConfigureAwait(false); + using var inspectionCancellation = CancellationTokenSource.CreateLinkedTokenSource( + cancellationToken, session.ControlLifetimeCancellation.Token); + var capabilities = await session.Client.InspectControlAsync( + signal, inspectionCancellation.Token).ConfigureAwait(false); + if (!_sessions.TryGetValue(deviceId, out var current) || + !ReferenceEquals(current, session) || + session.ControlLifetimeCancellation.IsCancellationRequested) + throw new OperationCanceledException("Control inspection association was replaced."); Log("INFO", session.Device.Name, $"Control inspected: {signal.ObjectReference}; model={capabilities.ControlModelText}; CDC={capabilities.ControlCdc}; current={capabilities.CurrentValue}."); return capabilities; @@ -932,6 +1004,16 @@ public async Task InspectControlAsync( } } + // Covers descriptor acquisition, feedback read, Operate and final feedback + // wait, including native semaphore acquisition. A stage-only timeout does + // not bound this whole command chain. + private static readonly TimeSpan ControlFlightDeadline = TimeSpan.FromSeconds(45); + + public bool IsControlFlightUnavailable(string deviceId) + => _sessions.TryGetValue(deviceId, out var session) && + (Iec61850ControlFlightAdmission.IsUnavailable( + ref session.ControlCommandActive, ref session.ControlFlightQuarantined)); + public async Task ExecuteControlAsync( string deviceId, Iec61850ControlCommandRequest request, @@ -945,7 +1027,7 @@ public async Task ExecuteControlAsync( // One physical control target per device, regardless of DataSet aliases. // Failed concurrent admission is local: no additional MMS Operate. - var targetKey = deviceId + "|" + Iec61850ControlIdentity.Normalize(request.Signal.ObjectReference); + var targetKey = session.ControlSessionIdentity.ToString("N") + "|" + Iec61850ControlIdentity.Normalize(request.Signal.ObjectReference); if (!_activeControlTargets.TryAdd(targetKey, 0)) { Log("WARN", session.Device.Name, @@ -953,22 +1035,85 @@ public async Task ExecuteControlAsync( throw new InvalidOperationException("Command already in progress for this IEC 61850 control object. No new MMS Operate was sent."); } - Log("INFO", session.Device.Name, - $"Control execution requested: {request.Signal.ObjectReference} value={request.ValueText}; test={request.TestMode}; interlock={request.InterlockCheck}; synchro={request.SynchroCheck}; origin={request.OriginCategory}/{request.Originator}; IED acceptance is determined only from native MMS wire evidence."); + // Association-wide single-flight, not merely one lock per control + // object. Different CSWIs on the same MMS socket must never accumulate + // behind the native semaphore while the report loop is paused. + if (!Iec61850ControlFlightAdmission.TryEnter( + ref session.ControlCommandActive, ref session.ControlFlightQuarantined)) + { + _activeControlTargets.TryRemove(targetKey, out _); + Log("WARN", session.Device.Name, + $"CONTROL_IED_SINGLE_FLIGHT: rejected {request.Signal.ObjectReference}; another control is active or its wire outcome is unresolved; Operate NOT SENT."); + throw new InvalidOperationException( + "Another command is active or its wire outcome is unresolved on this IED. No MMS Operate was sent. Reconnect and verify actual status before retrying."); + } var clientStopwatch = Stopwatch.StartNew(); - Interlocked.Increment(ref session.ControlCommandActive); + var nativeCancellation = CancellationTokenSource.CreateLinkedTokenSource( + cancellationToken, session.ControlLifetimeCancellation.Token); + Task? nativeFlight = null; Iec61850ControlCommandResult result; try { - result = await session.Client.ExecuteControlAsync(request, cancellationToken).ConfigureAwait(false); + Log("INFO", session.Device.Name, + $"Control execution requested: {request.Signal.ObjectReference} value={request.ValueText}; test={request.TestMode}; interlock={request.InterlockCheck}; synchro={request.SynchroCheck}; origin={request.OriginCategory}/{request.Originator}; IED acceptance is determined only from native MMS wire evidence."); + nativeFlight = session.Client.ExecuteControlAsync(request, nativeCancellation.Token); + result = await Iec61850ControlFlightAdmission.WaitForNativeAsync( + nativeFlight, ControlFlightDeadline, cancellationToken, + () => Iec61850ControlFlightAdmission.Quarantine(ref session.ControlFlightQuarantined), + nativeCancellation.Cancel).ConfigureAwait(false); + } + catch (TimeoutException) + { + Log("ERROR", session.Device.Name, + $"CONTROL_OUTCOME_UNKNOWN_TIMEOUT: {request.Signal.ObjectReference}; deadline={ControlFlightDeadline.TotalSeconds:0}s; nativeCompleted={nativeFlight?.IsCompleted}; no further commands on this MMS association. Actual IED position must be checked before reconnect."); + throw new TimeoutException( + "Control exceeded the end-to-end deadline. The MMS wire outcome is UNKNOWN, not necessarily rejected. This association is quarantined; verify process state and reconnect before any further Operate."); + } + catch (OperationCanceledException) when (cancellationToken.IsCancellationRequested) + { + if (nativeFlight is { IsCompleted: false }) + { + Log("WARN", session.Device.Name, + $"CONTROL_CANCEL_OUTCOME_UNKNOWN: {request.Signal.ObjectReference}; native flight not completed; association quarantined."); + } + throw; + } + catch (OperationCanceledException) when (!cancellationToken.IsCancellationRequested && + !session.ControlLifetimeCancellation.IsCancellationRequested) + { + // Cancellation initiated inside the native operation is not + // positive NotSent evidence; the engine may have issued a Write. + Log("ERROR", session.Device.Name, + $"CONTROL_NATIVE_CANCEL_OUTCOME_UNKNOWN: {request.Signal.ObjectReference}; native task canceled without a terminal wire result; association quarantined."); + throw new TimeoutException( + "Native control canceled without a proven wire outcome. Verify actual IED state and reconnect."); } finally { - Interlocked.Decrement(ref session.ControlCommandActive); - _activeControlTargets.TryRemove(targetKey, out _); + if (nativeFlight is { IsCompleted: false }) + { + // WaitAsync only cancels the WAIT. The native operation may + // still own a socket and may still apply Operate. Retain the + // per-IED gate until it ACTUALLY terminates. Never dispose its + // CTS or let another command use that association prematurely. + _ = ObserveLateControlFlightAsync(session, targetKey, + request.Signal.ObjectReference, nativeFlight, nativeCancellation); + } + else + { + nativeCancellation.Dispose(); + Iec61850ControlFlightAdmission.Release(ref session.ControlCommandActive); + _activeControlTargets.TryRemove(targetKey, out _); + } } clientStopwatch.Stop(); + // A completed old flight is not authorized to report success into a + // newer IED session, even if its native task returns after disconnect. + if (!_sessions.TryGetValue(deviceId, out var current) || + !ReferenceEquals(current, session) || + session.ControlLifetimeCancellation.IsCancellationRequested) + throw new OperationCanceledException("Control association was replaced before result publication."); if (result.ServiceAccepted || result.FeedbackConfirmed || result.IsSuccess) RecordSuccessfulIo(session); @@ -1060,6 +1205,38 @@ public async Task ExecuteControlAsync( return result; } + private async Task ObserveLateControlFlightAsync(DeviceSession session, + string targetKey, string reference, + Task nativeFlight, + CancellationTokenSource nativeCancellation) + { + try + { + var late = await nativeFlight.ConfigureAwait(false); + var detail = late switch + { + Iec61850ControlCommandResult command => + $"stage={command.Stage}; success={command.IsSuccess}", + AR.Iec61850.Control.Iec61850ControlModelConfigurationResult configuration => + $"writeAccepted={configuration.WriteAccepted}; readbackVerified={configuration.ReadbackVerified}", + _ => "native operation completed" + }; + Log("WARN", session.Device.Name, + $"CONTROL_LATE_NATIVE_RESULT: {reference}; completed after caller timeout/cancellation; {detail}; association remains quarantined pending verified recovery."); + } + catch (Exception ex) + { + Log("WARN", session.Device.Name, + $"CONTROL_LATE_NATIVE_FAILURE: {reference}; {ex.GetType().Name}: {ex.Message}; association remains quarantined."); + } + finally + { + nativeCancellation.Dispose(); + Iec61850ControlFlightAdmission.Release(ref session.ControlCommandActive); + _activeControlTargets.TryRemove(targetKey, out _); + } + } + public HybridReportPhysicalValidationSnapshot CaptureHybridReportPhysicalValidation(string deviceId) { ArgumentException.ThrowIfNullOrWhiteSpace(deviceId); @@ -1075,12 +1252,16 @@ public async Task StopMonitoringAsync(string deviceId) await StopMonitoringSessionAsync(session, preservePointDefinitions: false).ConfigureAwait(false); session.Device.IsMonitoring = false; - session.Device.IsConnected = session.Client.IsConnected; - session.Device.Status = session.Client.IsConnected ? "Ready" : "Disconnected"; - session.Device.AcquisitionMode = "Not started"; - session.Device.Detail = session.Client.IsConnected - ? "Monitoring stopped. The MMS association remains available for a new signal selection." - : "Session stopped."; + var quarantined = Volatile.Read(ref session.ControlFlightQuarantined) != 0; + session.Device.IsConnected = session.Client.IsConnected && !quarantined; + session.Device.Status = quarantined ? "Control recovery required" + : session.Client.IsConnected ? "Ready" : "Disconnected"; + session.Device.AcquisitionMode = quarantined ? "MMS control outcome unknown" : "Not started"; + session.Device.Detail = quarantined + ? "Control/write outcome UNKNOWN. Verify IED state, then reconnect before resuming monitoring or issuing commands." + : session.Client.IsConnected + ? "Monitoring stopped. The MMS association remains available for a new signal selection." + : "Session stopped."; session.Device.RefreshComputed(); Log("INFO", session.Device.Name, "Live monitoring stopped."); } @@ -1089,6 +1270,9 @@ public async Task StopDeviceAsync(string deviceId) { if (!_sessions.TryRemove(deviceId, out var session)) return; + // Revoke old command authority before any native or WPF teardown. + // Linked native flight tokens remain owned until those tasks settle. + session.ControlLifetimeCancellation.Cancel(); // Stop MUST leave a reusable device after any teardown failure. The // session is already removed from the live registry, so never leave a @@ -1103,7 +1287,10 @@ public async Task StopDeviceAsync(string deviceId) } try { - await session.Client.DisposeAsync().ConfigureAwait(false); + await DisposeClientForReconnectAsync( + session.Client, session.Device.Name, + SmartReconnectPolicy.ClientCleanupBudget, + CancellationToken.None).ConfigureAwait(false); } catch (Exception ex) { @@ -1297,6 +1484,21 @@ private async Task MonitorLoopAsync(DeviceSession session, CancellationToken can { try { + // Do not silently spin forever while a native Operate/Write owns + // the MMS gate. Recovery requires an explicitly fresh association; + // the old monitor exits without publishing further observations. + if (Volatile.Read(ref session.ControlFlightQuarantined) != 0) + { + session.Device.IsMonitoring = false; + session.Device.Status = "Control recovery required"; + session.Device.AcquisitionMode = "MMS control outcome unknown"; + session.Device.Detail = + "Monitoring stopped after an uncertain control/write outcome. Verify actual IED state, then Disconnect and Connect to create a fresh MMS association."; + session.Device.RefreshComputed(); + Log("WARN", session.Device.Name, + "CONTROL_MONITOR_QUARANTINE: monitor stopped; no further MMS Read/Report operations on the uncertain association."); + break; + } if (Volatile.Read(ref session.ControlCommandActive) > 0) { await Task.Delay(5, cancellationToken).ConfigureAwait(false); @@ -2631,15 +2833,26 @@ private async Task StopMonitoringSessionAsync(DeviceSession session, bool preser } } - try + // A control/write may still own the native MMS I/O gate after the + // caller has timed out. Never enqueue RCB teardown behind that flight. + if (Iec61850ControlFlightAdmission.IsUnavailable( + ref session.ControlCommandActive, ref session.ControlFlightQuarantined)) { - var results = await session.Client.StopReportMonitorsAsync().ConfigureAwait(false); - foreach (var result in results) - Log(result.IsSuccess ? "INFO" : "WARN", session.Device.Name, result.Message); + Log("WARN", session.Device.Name, + "CONTROL_STOP_DEFERRED_NATIVE_RCB_CLEANUP: active/uncertain MMS operation; report cleanup is deferred to bounded client disposal."); } - catch (Exception ex) + else { - Log("WARN", session.Device.Name, $"Report monitor cleanup: {ex.Message}"); + try + { + var results = await session.Client.StopReportMonitorsAsync().ConfigureAwait(false); + foreach (var result in results) + Log(result.IsSuccess ? "INFO" : "WARN", session.Device.Name, result.Message); + } + catch (Exception ex) + { + Log("WARN", session.Device.Name, $"Report monitor cleanup: {ex.Message}"); + } } session.MonitorTask = null; diff --git a/Services/NativeIec61850Client.cs b/Services/NativeIec61850Client.cs index 0cff7ebaa..9043a68fc 100644 --- a/Services/NativeIec61850Client.cs +++ b/Services/NativeIec61850Client.cs @@ -1161,12 +1161,14 @@ private static string BuildDynamicDataSetName(ReportControlPlan plan) try { var service = new ArControl.Iec61850ControlService(); - return await RunMmsOperationAsync( + var result = await RunMmsOperationAsync( () => service.ConfigureControlModelAsync(_session, signal.ObjectReference, (ArControl.Iec61850ControlModel)(int)expected, (ArControl.Iec61850ControlModel)(int)target, cancellationToken), cancellationToken).ConfigureAwait(false); + cancellationToken.ThrowIfCancellationRequested(); + return result; } finally { @@ -1174,11 +1176,17 @@ private static string BuildDynamicDataSetName(ReportControlPlan plan) // A subsequent explicit read-only inspection must rebuild authority. await InvalidateCachedControlSessionAsync(signal.ObjectReference) .ConfigureAwait(false); - signal.ClearControlConfirmation(); - signal.ClearLiveControlAuthority(); - signal.ControlModelText = "Auto-detect"; - signal.ControlInspectionEvidence = - "ctlModel configuration attempted: fresh typed live inspection required."; + // On session teardown/timeout the runtime invalidates old + // authority. The stale native task must not reset a new + // association's SignalDefinition after it finishes late. + if (!cancellationToken.IsCancellationRequested) + { + signal.ClearControlConfirmation(); + signal.ClearLiveControlAuthority(); + signal.ControlModelText = "Auto-detect"; + signal.ControlInspectionEvidence = + "ctlModel configuration attempted: fresh typed live inspection required."; + } } } finally @@ -1243,6 +1251,7 @@ private async Task InspectControlCoreAsync( signal.ControlModelText = "Auto-detect"; await InvalidateCachedControlSessionAsync(signal.ObjectReference).ConfigureAwait(false); control = await GetOrOpenControlSessionAsync(signal, cancellationToken).ConfigureAwait(false); + cancellationToken.ThrowIfCancellationRequested(); } catch (InvalidOperationException discoveryError) when (_session.IsMmsInitiated) { @@ -1252,6 +1261,7 @@ private async Task InspectControlCoreAsync( () => new ArControl.Iec61850ControlService().ProbeControlModelAsync( _session, signal.ObjectReference, cancellationToken), cancellationToken).ConfigureAwait(false); + cancellationToken.ThrowIfCancellationRequested(); signal.ControlSemanticVerified = false; signal.ControlModelText = probe.Decoded ? FriendlyControlModel(probe.ControlModel) @@ -1289,6 +1299,7 @@ private async Task InspectControlCoreAsync( var status = await RunMmsOperationAsync( () => control.ReadStatusAsync(cancellationToken), cancellationToken).ConfigureAwait(false); + cancellationToken.ThrowIfCancellationRequested(); var normalizedStatus = NormalizeControlFeedback(effectiveCdc, status.DisplayValue, status.State); var currentValue = status.IsSuccess ? normalizedStatus.Value : "-"; var currentState = normalizedStatus.State.ToString(); @@ -1306,6 +1317,7 @@ private async Task InspectControlCoreAsync( "ST", string.IsNullOrWhiteSpace(signal.ControlValueType) ? "Unknown" : signal.ControlValueType, cancellationToken).ConfigureAwait(false); + cancellationToken.ThrowIfCancellationRequested(); if (preferred != null) { var normalizedPreferred = NormalizeControlFeedback( @@ -1393,6 +1405,7 @@ private async Task ExecuteControlCoreAsync( var totalStopwatch = Stopwatch.StartNew(); var control = await GetOrOpenControlSessionAsync(request.Signal, cancellationToken).ConfigureAwait(false); + cancellationToken.ThrowIfCancellationRequested(); var descriptor = control.Descriptor; var semantic = ArControl.Iec61850ControlSemanticResolver.Resolve( descriptor, request.Signal.ControlCdc, request.Signal.ControlStatusReference); @@ -1433,6 +1446,7 @@ private async Task ExecuteControlCoreAsync( request.Signal.ControlValueType, effectiveCdc, cancellationToken).ConfigureAwait(false); + cancellationToken.ThrowIfCancellationRequested(); capabilities = BuildControlCapabilities(descriptor, request.Signal, initialFeedback.Value, effectiveCdc); request.Signal.ControlCdc = capabilities.ControlCdc; @@ -1475,6 +1489,7 @@ private async Task ExecuteControlCoreAsync( action = await RunMmsOperationAsync( () => control.OperateAsync(nativeRequest, cancellationToken), cancellationToken).ConfigureAwait(false); + cancellationToken.ThrowIfCancellationRequested(); } catch (OperationCanceledException) { @@ -1556,6 +1571,7 @@ private async Task ExecuteControlCoreAsync( initialFeedback.Value, Math.Clamp(request.FeedbackTimeoutMs, 1000, 30000), cancellationToken).ConfigureAwait(false); + cancellationToken.ThrowIfCancellationRequested(); feedbackStopwatch.Stop(); totalStopwatch.Stop(); diff --git a/tests/ARSAS.Tests/M217P0ControlSingleFlightRecoveryTests.cs b/tests/ARSAS.Tests/M217P0ControlSingleFlightRecoveryTests.cs new file mode 100644 index 000000000..6132ed923 --- /dev/null +++ b/tests/ARSAS.Tests/M217P0ControlSingleFlightRecoveryTests.cs @@ -0,0 +1,245 @@ +using System.Threading; +using ArIED61850Tester.Services; + +namespace ARSAS.Tests; + +public sealed class M217P0ControlSingleFlightRecoveryTests +{ + private sealed class SessionFence + { + public int Active; + public int Quarantine; + } + + [Fact] + public void DifferentCswiObjectsCannotRunConcurrentCommandsOnSameAssociation() + { + var session = new SessionFence(); + Assert.True(Iec61850ControlFlightAdmission.TryEnter( + ref session.Active, ref session.Quarantine)); + // Same physical MMS session, different CSWI object: reject locally. + Assert.False(Iec61850ControlFlightAdmission.TryEnter( + ref session.Active, ref session.Quarantine)); + Assert.True(Iec61850ControlFlightAdmission.IsUnavailable( + ref session.Active, ref session.Quarantine)); + Iec61850ControlFlightAdmission.Release(ref session.Active); + Assert.True(Iec61850ControlFlightAdmission.TryEnter( + ref session.Active, ref session.Quarantine)); + Iec61850ControlFlightAdmission.Release(ref session.Active); + } + + [Fact] + public void CompetingConcurrentAdmissionsHaveExactlyOneWinner() + { + var session = new SessionFence(); + var winners = 0; + Parallel.For(0, 40, _ => + { + if (Iec61850ControlFlightAdmission.TryEnter( + ref session.Active, ref session.Quarantine)) + Interlocked.Increment(ref winners); + }); + Assert.Equal(1, winners); + Assert.Equal(1, session.Active); + } + + [Fact] + public void TimeoutQuarantineCannotBeClearedByLateNativeCompletion() + { + var session = new SessionFence(); + Assert.True(Iec61850ControlFlightAdmission.TryEnter( + ref session.Active, ref session.Quarantine)); + Iec61850ControlFlightAdmission.Quarantine(ref session.Quarantine); + Assert.False(Iec61850ControlFlightAdmission.TryEnter( + ref session.Active, ref session.Quarantine)); + // Late native completion may release busy ownership, NOT clear the + // uncertain wire outcome on this association. + Iec61850ControlFlightAdmission.Release(ref session.Active); + Assert.Equal(0, session.Active); + Assert.Equal(1, session.Quarantine); + Assert.False(Iec61850ControlFlightAdmission.TryEnter( + ref session.Active, ref session.Quarantine)); + // A newly created DeviceSession has new per-association fence fields. + var fresh = new SessionFence(); + Assert.True(Iec61850ControlFlightAdmission.TryEnter( + ref fresh.Active, ref fresh.Quarantine)); + } + + [Fact] + public async Task NativeDeadlineQuarantinesButNeverFakesTaskCompletion() + { + var session = new SessionFence(); + Assert.True(Iec61850ControlFlightAdmission.TryEnter(ref session.Active, ref session.Quarantine)); + var native = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + using var nativeCancellation = new CancellationTokenSource(); + + await Assert.ThrowsAsync(() => + Iec61850ControlFlightAdmission.WaitForNativeAsync( + native.Task, TimeSpan.FromMilliseconds(40), CancellationToken.None, + () => Iec61850ControlFlightAdmission.Quarantine(ref session.Quarantine), + nativeCancellation.Cancel)); + + Assert.True(nativeCancellation.IsCancellationRequested); + Assert.False(native.Task.IsCompleted); + Assert.True(Iec61850ControlFlightAdmission.IsUnavailable(ref session.Active, ref session.Quarantine)); + Assert.False(Iec61850ControlFlightAdmission.TryEnter(ref session.Active, ref session.Quarantine)); + + native.SetResult(42); + Assert.Equal(42, await native.Task); + Iec61850ControlFlightAdmission.Release(ref session.Active); + // The late native result is observed, not promoted to fresh authority. + Assert.Equal(1, session.Quarantine); + Assert.False(Iec61850ControlFlightAdmission.TryEnter(ref session.Active, ref session.Quarantine)); + } + + [Fact] + public async Task CallerCancellationQuarantinesAnUnresolvedNativeWrite() + { + var session = new SessionFence(); + Assert.True(Iec61850ControlFlightAdmission.TryEnter(ref session.Active, ref session.Quarantine)); + var native = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + using var waiterCancellation = new CancellationTokenSource(); + using var nativeCancellation = new CancellationTokenSource(); + var waiter = Iec61850ControlFlightAdmission.WaitForNativeAsync( + native.Task, TimeSpan.FromSeconds(10), waiterCancellation.Token, + () => Iec61850ControlFlightAdmission.Quarantine(ref session.Quarantine), + nativeCancellation.Cancel); + + waiterCancellation.Cancel(); + await Assert.ThrowsAnyAsync(() => waiter); + Assert.True(nativeCancellation.IsCancellationRequested); + Assert.False(native.Task.IsCompleted); + Assert.True(Iec61850ControlFlightAdmission.IsUnavailable(ref session.Active, ref session.Quarantine)); + } + + [Fact] + public async Task AlreadyCanceledNativeTaskNeverProvesWriteWasNotSent() + { + var session = new SessionFence(); + Assert.True(Iec61850ControlFlightAdmission.TryEnter(ref session.Active, ref session.Quarantine)); + using var nativeCancellation = new CancellationTokenSource(); + await Assert.ThrowsAnyAsync(() => + Iec61850ControlFlightAdmission.WaitForNativeAsync( + Task.FromCanceled(new CancellationToken(canceled: true)), + TimeSpan.FromSeconds(1), CancellationToken.None, + () => Iec61850ControlFlightAdmission.Quarantine(ref session.Quarantine), + nativeCancellation.Cancel)); + Assert.True(nativeCancellation.IsCancellationRequested); + Iec61850ControlFlightAdmission.Release(ref session.Active); + Assert.Equal(1, session.Quarantine); + Assert.False(Iec61850ControlFlightAdmission.TryEnter(ref session.Active, ref session.Quarantine)); + } + + [Fact] + public async Task CompletedNativeResponseKeepsAssociationAvailableAfterRelease() + { + var session = new SessionFence(); + Assert.True(Iec61850ControlFlightAdmission.TryEnter(ref session.Active, ref session.Quarantine)); + var canceled = false; + var result = await Iec61850ControlFlightAdmission.WaitForNativeAsync( + Task.FromResult(17), TimeSpan.FromSeconds(1), CancellationToken.None, + () => Iec61850ControlFlightAdmission.Quarantine(ref session.Quarantine), + () => canceled = true); + Assert.Equal(17, result); + Assert.False(canceled); + Iec61850ControlFlightAdmission.Release(ref session.Active); + Assert.False(Iec61850ControlFlightAdmission.IsUnavailable(ref session.Active, ref session.Quarantine)); + } + + [Fact] + public void RuntimeControlRecoveryClosesAlternativeMmsLanesAndFencesDisconnect() + { + DirectoryInfo? root = new(AppContext.BaseDirectory); + while (root is not null && + !File.Exists(Path.Combine(root.FullName, "Services", "Iec61850MonitorRuntime.cs"))) + root = root.Parent; + Assert.NotNull(root); + var code = File.ReadAllText(Path.Combine(root!.FullName, "Services", "Iec61850MonitorRuntime.cs")); + Assert.Contains("CTL_MODEL_OUTCOME_UNKNOWN_TIMEOUT", code); + Assert.Contains("CONTROL_MONITOR_QUARANTINE", code); + Assert.Contains("CONTROL_STOP_DEFERRED_NATIVE_RCB_CLEANUP", code); + Assert.Contains("ControlLifetimeCancellation.Cancel()", code); + Assert.Contains("session.ControlLifetimeCancellation.Token", code); + Assert.Contains("Control association was replaced before result publication", code); + Assert.Contains("Monitoring cannot start during an active or uncertain MMS control flight", code); + + var nativeCode = File.ReadAllText(Path.Combine(root.FullName, "Services", "NativeIec61850Client.cs")); + Assert.Contains("cancellationToken.ThrowIfCancellationRequested()", nativeCode); + Assert.Contains("if (!cancellationToken.IsCancellationRequested)", nativeCode); + } + + [Fact] + public void RuntimeDoesNotConfuseWaitTimeoutWithNativeOperationCompletion() + { + DirectoryInfo? root = new(AppContext.BaseDirectory); + while (root is not null && + !File.Exists(Path.Combine(root.FullName, "Services", + "Iec61850MonitorRuntime.cs"))) + root = root.Parent; + Assert.NotNull(root); + var code = File.ReadAllText(Path.Combine(root!.FullName, + "Services", "Iec61850MonitorRuntime.cs")); + Assert.Contains("ControlFlightDeadline = TimeSpan.FromSeconds(45)", code); + Assert.Contains("Iec61850ControlFlightAdmission.WaitForNativeAsync(", code); + Assert.Contains("nativeFlight is { IsCompleted: false }", code); + Assert.Contains("ObserveLateControlFlightAsync(", code); + Assert.Contains("CONTROL_OUTCOME_UNKNOWN_TIMEOUT", code); + Assert.Contains("CONTROL_IED_SINGLE_FLIGHT", code); + Assert.Contains("Iec61850ControlFlightAdmission.TryEnter(", code); + } + + [Fact] + public void ControlTargetClaimsAreScopedToSessionNotOnlyDeviceId() + { + // An unresolved old native flight must never block or remove a claim + // belonging to the newly established association for the same IED. + DirectoryInfo? root = new(AppContext.BaseDirectory); + while (root is not null && + !File.Exists(Path.Combine(root.FullName, "Services", + "Iec61850MonitorRuntime.cs"))) + root = root.Parent; + Assert.NotNull(root); + var code = File.ReadAllText(Path.Combine(root!.FullName, + "Services", "Iec61850MonitorRuntime.cs")); + Assert.Contains("ControlSessionIdentity { get; } = Guid.NewGuid()", code); + Assert.Contains("session.ControlSessionIdentity.ToString(\"N\") + \"|\" + Iec61850ControlIdentity.Normalize(signal.ObjectReference)", code); + Assert.Contains("session.ControlSessionIdentity.ToString(\"N\") + \"|\" + Iec61850ControlIdentity.Normalize(request.Signal.ObjectReference)", code); + Assert.DoesNotContain("var targetKey = deviceId +", code); + } + + [Fact] + public void DisconnectCleanupUsesBoundedExistingClientDisposal() + { + DirectoryInfo? root = new(AppContext.BaseDirectory); + while (root is not null && + !File.Exists(Path.Combine(root.FullName, "Services", + "Iec61850MonitorRuntime.cs"))) + root = root.Parent; + Assert.NotNull(root); + var code = File.ReadAllText(Path.Combine(root!.FullName, + "Services", "Iec61850MonitorRuntime.cs")); + var stop = code.IndexOf("public async Task StopDeviceAsync(", StringComparison.Ordinal); + var next = code.IndexOf("private async Task StartReportPlansAsync(", stop, StringComparison.Ordinal); + Assert.True(stop >= 0 && next > stop); + var stopBody = code[stop..next]; + Assert.Contains("DisposeClientForReconnectAsync(", stopBody); + Assert.Contains("SmartReconnectPolicy.ClientCleanupBudget", stopBody); + Assert.DoesNotContain("await session.Client.DisposeAsync()", stopBody); + } + + [Fact] + public void BrowserMustRejectNewConfirmationBeforeClaimingPhysicalCommand() + { + DirectoryInfo? root = new(AppContext.BaseDirectory); + while (root is not null && + !File.Exists(Path.Combine(root.FullName, "MainWindow.xaml.cs"))) + root = root.Parent; + Assert.NotNull(root); + var code = File.ReadAllText(Path.Combine(root!.FullName, + "MainWindow.xaml.cs")); + Assert.Contains("RejectCommandWhenIedFlightUnavailable(device, signal)", code); + Assert.Contains("CONTROL_UI_SINGLE_FLIGHT", code); + Assert.Contains("CONTROL_UI_TIMEOUT", code); + Assert.Contains("Control outcome UNKNOWN", code); + } +} diff --git a/tests/ARSAS.Tests/P109QCommandDockCommissioningRegressionTests.cs b/tests/ARSAS.Tests/P109QCommandDockCommissioningRegressionTests.cs index c190f31c2..4454a5327 100644 --- a/tests/ARSAS.Tests/P109QCommandDockCommissioningRegressionTests.cs +++ b/tests/ARSAS.Tests/P109QCommandDockCommissioningRegressionTests.cs @@ -173,6 +173,9 @@ public void OnlyEngineOwnsSingleControlModelWriteAndInvalidatesOldDescriptor() Assert.Contains("signal.ControlModelText = \"Auto-detect\";", client); Assert.Contains("OPERATOR_CTL_MODEL_CONFIGURATION", runtime); Assert.Contains("_activeControlTargets.TryAdd(targetKey, 0)", runtime); - Assert.Contains("Interlocked.Increment(ref session.ControlCommandActive)", runtime); + // A single atomic IED-wide flight now protects ctlModel Write and + // ordinary Operate. Increment-and-reject was not a safe admission gate. + Assert.Contains("Iec61850ControlFlightAdmission.TryEnter(", runtime); + Assert.Contains("CONTROL_OUTCOME_UNKNOWN_TIMEOUT", runtime); } }